{"action":"created","issue":{"url":"https://api.github.com/repos/ropensci/drake/issues/1005","repository_url":"https://api.github.com/repos/ropensci/drake","labels_url":"https://api.github.com/repos/ropensci/drake/issues/1005/labels{/name}","comments_url":"https://api.github.com/repos/ropensci/drake/issues/1005/comments","events_url":"https://api.github.com/repos/ropensci/drake/issues/1005/events","html_url":"https://github.com/ropensci/drake/issues/1005","id":491406152,"node_id":"MDU6SXNzdWU0OTE0MDYxNTI=","number":1005,"title":"clustermq run works for short-running targets but fails with long-running targets ","user":{"login":"kendonB","id":5327505,"node_id":"MDQ6VXNlcjUzMjc1MDU=","avatar_url":"https://avatars2.githubusercontent.com/u/5327505?v=4","gravatar_id":"","url":"https://api.github.com/users/kendonB","html_url":"https://github.com/kendonB","followers_url":"https://api.github.com/users/kendonB/followers","following_url":"https://api.github.com/users/kendonB/following{/other_user}","gists_url":"https://api.github.com/users/kendonB/gists{/gist_id}","starred_url":"https://api.github.com/users/kendonB/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/kendonB/subscriptions","organizations_url":"https://api.github.com/users/kendonB/orgs","repos_url":"https://api.github.com/users/kendonB/repos","events_url":"https://api.github.com/users/kendonB/events{/privacy}","received_events_url":"https://api.github.com/users/kendonB/received_events","type":"User","site_admin":false},"labels":[{"id":543987607,"node_id":"MDU6TGFiZWw1NDM5ODc2MDc=","url":"https://api.github.com/repos/ropensci/drake/labels/type:%20bug","name":"type: bug","color":"b60205","default":false}],"state":"open","locked":false,"assignee":{"login":"wlandau","id":1580860,"node_id":"MDQ6VXNlcjE1ODA4NjA=","avatar_url":"https://avatars1.githubusercontent.com/u/1580860?v=4","gravatar_id":"","url":"https://api.github.com/users/wlandau","html_url":"https://github.com/wlandau","followers_url":"https://api.github.com/users/wlandau/followers","following_url":"https://api.github.com/users/wlandau/following{/other_user}","gists_url":"https://api.github.com/users/wlandau/gists{/gist_id}","starred_url":"https://api.github.com/users/wlandau/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/wlandau/subscriptions","organizations_url":"https://api.github.com/users/wlandau/orgs","repos_url":"https://api.github.com/users/wlandau/repos","events_url":"https://api.github.com/users/wlandau/events{/privacy}","received_events_url":"https://api.github.com/users/wlandau/received_events","type":"User","site_admin":false},"assignees":[{"login":"wlandau","id":1580860,"node_id":"MDQ6VXNlcjE1ODA4NjA=","avatar_url":"https://avatars1.githubusercontent.com/u/1580860?v=4","gravatar_id":"","url":"https://api.github.com/users/wlandau","html_url":"https://github.com/wlandau","followers_url":"https://api.github.com/users/wlandau/followers","following_url":"https://api.github.com/users/wlandau/following{/other_user}","gists_url":"https://api.github.com/users/wlandau/gists{/gist_id}","starred_url":"https://api.github.com/users/wlandau/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/wlandau/subscriptions","organizations_url":"https://api.github.com/users/wlandau/orgs","repos_url":"https://api.github.com/users/wlandau/repos","events_url":"https://api.github.com/users/wlandau/events{/privacy}","received_events_url":"https://api.github.com/users/wlandau/received_events","type":"User","site_admin":false}],"milestone":null,"comments":20,"created_at":"2019-09-10T01:50:00Z","updated_at":"2019-09-10T22:58:52Z","closed_at":null,"author_association":"MEMBER","body":"## Prework\r\n\r\n- [x] Read and abide by `drake`'s [code of conduct](https://github.com/ropensci/drake/blob/master/CODE_OF_CONDUCT.md).\r\n- [x] Search for duplicates among the [existing issues](https://github.com/ropensci/drake/issues), both open and closed.\r\n- [x] Advanced users: verify that the bug still persists in the current development version (i.e. `remotes::install_github(\"ropensci/drake\")`) and mention the [SHA-1 hash](https://git-scm.com/book/en/v1/Getting-Started-Git-Basics#Git-Has-Integrity) of the [Git commit you install](https://github.com/ropensci/drake/commits/master).\r\n\r\nRunning: ropensci/drake@ae3a72f\r\n\r\n## Description\r\n\r\nI have a particularly wicked problem. I am building 100 targets that take around 90 minutes each to build. The basic structure of the code is:\r\n\r\n1. Read a `.fst` in\r\n2. Process for 90 minutes in memory\r\n3. Write a similarly sized `.fst`\r\n4. Return NULL\r\n\r\nI can easily shorten the targets so that they run quickly. When I do that, I have no problems. However, when I run the full version, \r\n\r\n1. The master hangs, as in I see just:\r\n```r\r\n\r\nmake(myplan, verbose = 3, jobs_preprocess = 8, \r\n     jobs = 2, parallelism = \"clustermq\",\r\n     log_progress = TRUE,\r\n     lazy_load = \"promise\",\r\n     console_log_file = NULL, \r\n     memory_strategy = \"lookahead\", \r\n     caching = \"worker\",\r\n     template = list(\r\n       log_file = \"make.log\", \r\n       memory = 5000,\r\n       walltime = 250\r\n     ),\r\n     keep_going = TRUE\r\n)\r\n#> ⠦Warning in private$fill_options(...) :\r\n#>   Add 'CMQ_AUTH={{ auth }}' to template to enable socket authentication\r\n#> target nzdi_df\r\n#> target nzdi_df_2\r\n```\r\n2. I can see the targets complete in the logs. As in, I see:\r\n```r\r\n2019-09-10 11:47:35.742293 | Master: tcp://mahuika01:6020\r\n2019-09-10 11:47:35.803966 | WORKER_UP to: tcp://mahuika01:6020\r\n2019-09-10 11:47:36.410054 | > DO_SETUP (0.548s wait)\r\n2019-09-10 11:47:36.410445 | token from msg: set_common_data_token\r\n2019-09-10 11:47:36.551556 | > DO_CALL (0.000s wait)\r\n\r\n.── Attaching packages ─────────────────────────────────────── tidyverse 1.2.1 ──\r\n✔ ggplot2 3.2.0     ✔ purrr   0.3.2\r\n✔ tibble  2.1.3     ✔ dplyr   0.8.3\r\n✔ tidyr   0.8.3     ✔ stringr 1.4.0\r\n✔ readr   1.3.1     ✔ forcats 0.4.0\r\n── Conflicts ────────────────────────────────────────── tidyverse_conflicts() ──\r\n✖ tidyr::expand() masks drake::expand()\r\n✖ dplyr::filter() masks stats::filter()\r\n✖ tidyr::gather() masks drake::gather()\r\n✖ dplyr::lag()    masks stats::lag()\r\n\r\nAttaching package: ‘lubridate’\r\n\r\nThe following object is masked from ‘package:base’:\r\n\r\n    date\r\n\r\n[1] 5.952027e-05\r\n[1] 0.0001190405\r\n[1] 0.0001785608\r\n[1] 0.0002380811\r\n[1] 0.0002976013\r\n[1] 0.0003571216\r\n[1] 0.0004166419\r\n[1] 0.0004761621\r\n[1] 0.0005356824\r\n...\r\n[1] 0.9997024\r\n[1] 0.9997619\r\n[1] 0.9998214\r\n[1] 0.999881\r\n[1] 0.9999405\r\n[1] 1 # This is my hacky progress indicator completing\r\n[1] \"Writing myfile1.fst completed.\"\r\n..2019-09-10 13:17:18.947444 | eval'd: drake::cmq_buildtargetmetadepslayoutconfig\r\nError in clustermq:::worker(\"tcp://mahuika01:6020\", verbose = TRUE) :\r\n  Timeout reached, terminating\r\nExecution halted\r\n```\r\nand\r\n```r\r\n[1] 0.9997024\r\n[1] 0.9997619\r\n[1] 0.9998214\r\n[1] 0.999881\r\n[1] 0.9999405\r\n[1] 1\r\n[1] \"Writing myfile2.fst completed.\"\r\n..2019-09-10 13:23:26.546925 | eval'd: drake::cmq_buildtargetmetadepslayoutconfig\r\nError in clustermq:::worker(\"tcp://mahuika01:6020\", verbose = TRUE) :\r\n  Timeout reached, terminating\r\nExecution halted\r\n```\r\nSo it looks like the workers stop being able to communicate with the master at the end.\r\n\r\nCan you give me some tips for troubleshooting this problem?\r\n\r\nWhen I close the master R session, reopen and remake I do see that the targets that completed are up-to-date, thankfully."},"comment":{"url":"https://api.github.com/repos/ropensci/drake/issues/comments/530152128","html_url":"https://github.com/ropensci/drake/issues/1005#issuecomment-530152128","issue_url":"https://api.github.com/repos/ropensci/drake/issues/1005","id":530152128,"node_id":"MDEyOklzc3VlQ29tbWVudDUzMDE1MjEyOA==","user":{"login":"kendonB","id":5327505,"node_id":"MDQ6VXNlcjUzMjc1MDU=","avatar_url":"https://avatars2.githubusercontent.com/u/5327505?v=4","gravatar_id":"","url":"https://api.github.com/users/kendonB","html_url":"https://github.com/kendonB","followers_url":"https://api.github.com/users/kendonB/followers","following_url":"https://api.github.com/users/kendonB/following{/other_user}","gists_url":"https://api.github.com/users/kendonB/gists{/gist_id}","starred_url":"https://api.github.com/users/kendonB/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/kendonB/subscriptions","organizations_url":"https://api.github.com/users/kendonB/orgs","repos_url":"https://api.github.com/users/kendonB/repos","events_url":"https://api.github.com/users/kendonB/events{/privacy}","received_events_url":"https://api.github.com/users/kendonB/received_events","type":"User","site_admin":false},"created_at":"2019-09-10T22:58:52Z","updated_at":"2019-09-10T22:58:52Z","author_association":"MEMBER","body":"Yes, I see the timeout happen about 10 minutes after I see the `..2019-09-10 13:23:26.546925 | eval'd: drake::cmq_buildtargetmetadepslayoutconfig` at the end of the worker log"}}
{"actor":{"display_login":"kendonB"}}