Answers: <p>The problem is with the image
  <code>microsoft-dsvm:linux-data-science-vm-ubuntu:linuxdsvmubuntu:18.12.01</code> ("Linux
  Data Science VM" (on the Azure portal). This is an old image with <code>R 3.4</code>
  instead of the release version of <code>3.5</code>.</p>
  
  <p>I succeeded with the following virtual machine (Ubuntu Server 19.04.19, size D64 v3):</p>
  
  <pre><code>az vm create \
         --resource-group &lt;resource group&gt; \
         --name &lt;name&gt; \
         --image Canonical:UbuntuServer:19.04:19.04.201906280 \
         --size Standard_D64_v3 \
         --admin-username &lt;azure user&gt; \
         --generate-ssh-keys
  </code></pre>
  
  <p>and installed <code>R</code>, <code>Rstan</code>, and an SSL library for <code>curl</code> and <code>devtools</code> with:</p>
  
  <pre><code>sudo apt update
  sudo apt -y install r-base
  sudo apt -y install r-cran-rstan
  
  # Add LibSSL for installing curl and devtools, see:
  # https://stackoverflow.com/questions/44228055/r-rstudio-install-devtools-fails
  sudo apt-get install libcurl4-openssl-dev libssl-dev
  </code></pre>
  
  <p>and the machine can use multiple cores:</p>
  
  <pre><code>Welcome to PosteriorBootstrap, a parallel approach for adaptive non-parametric learning
  [1] "Speedup performance"
  [1] "n_bootstrap = 100"
  [1] "num_cores = 1"
  [1] "Finished sampling"
  [1] "num_cores = 2"
  [1] "Finished sampling"
  ...
  [1] "num_cores = 64"
  [1] "Finished sampling"
  </code></pre>
  
  <p>I also checked the duration and the speedup is as I expected.</p>
  
Answers: CC BY-SA 4.0
Answers: 2019-07-03T14:40:16.263Z
Answers: 2019-07-03T14:40:16.263Z
Answers: emonigma
Body: <p>I am writing <a href="https://github.com/alan-turing-institute/PosteriorBootstrap/" rel="nofollow noreferrer">an R package</a> with tests using the <code>testthat</code> package. The tests pass locally and on Travis.</p>
  
  <p>I want to plot the benefit of parallelisation on up to 24 cores, so I set up a virtual machine programmatically on Azure:</p>
  
  <pre><code>az vm create \
     --resource-group &lt;resource group&gt; \
     --name &lt;name&gt; \
     --image microsoft-dsvm:linux-data-science-vm-ubuntu:linuxdsvmubuntu:18.12.01 \
     --size Standard_NV24 \
     --admin-username &lt;azure user&gt; \
     --generate-ssh-keys
  </code></pre>
  
  <p>I call <code>devtools::test()</code> and the virtual machine gets stuck at <code>testthat</code> for hours with 0% CPU usage:</p>
  
  <pre><code>✔  checking for unstated dependencies in ‘tests’ ...
  ─  checking tests ...
     Running ‘testthat.R’
  </code></pre>
  
  <p><code>devtools::test()</code> has no specific arguments to print some output, and it calls <code>testthat::test_dir()</code>, which also has no arguments to print output.</p>
  
  <p>When I remove the tests, the code stalls in a function call. I stopped and relaunched multiple times, so I think it's a problem with Azure.</p>
  
  <p>Other sizes of machines, <code>Standard_F16s_v2</code> and <code>Standard DS3 v2</code>, have the same problem.</p>
  
  <p>How can I fix it?</p>
  
  <h2>Update</h2>
  
  <p>I stumbled upon the culprit when I was running another piece of code. The VM hangs when calling the R <code>parallel</code> package on multiple cores (it works fine on just one core).</p>
  
  <p>I added some printouts around that call:</p>
  
  <pre><code>[1] "num_cores = 2"
  [1] "Entering parallel"
  [1] "Drawing 1"
  [1] "Drawing 2"
  </code></pre>
  
  <p>and then it hangs. Following the suggestion of <code>strace</code>, I launched again and see this output around this last printout:</p>
  
  <pre><code>[pid  8571] 21:41:48.718625 write(1, "\n", 1[1] "num_cores = 2"
  ) = 1
  [pid  8571] 21:41:48.719486 write(1, "[1]", 3) = 3
  [pid  8571] 21:41:48.719550 write(1, " \"num_cores = 2\"", 16) = 16
  [pid  8571] 21:41:48.719615 write(1, "\n", 1) = 1
  [pid  8703] 21:41:48.730707 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL &lt;unfinished ...&gt;
  [pid  8705] 21:41:48.730745 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL &lt;unfinished ...&gt;
  [pid  8701] 21:41:48.730757 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL &lt;unfinished ...&gt;
  [pid  8704] 21:41:48.730794 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL &lt;unfinished ...&gt;
  [pid  8702] 21:41:48.730841 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL &lt;unfinished ...&gt;
  [pid  8700] 21:41:48.730852 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL &lt;unfinished ...&gt;
  [pid  8706] 21:41:48.731199 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL &lt;unfinished ...&gt;
  [pid  8571] 21:41:48.742710 futex(0x498fcf4, FUTEX_WAKE_PRIVATE, 2147483647) = 7
  [pid  8706] 21:41:48.742831 &lt;... futex resumed&gt; ) = 0
  [pid  8705] 21:41:48.742847 &lt;... futex resumed&gt; ) = 0
  [pid  8704] 21:41:48.742858 &lt;... futex resumed&gt; ) = 0
  [pid  8703] 21:41:48.742868 &lt;... futex resumed&gt; ) = 0
  [pid  8702] 21:41:48.742878 &lt;... futex resumed&gt; ) = 0
  [pid  8701] 21:41:48.742888 &lt;... futex resumed&gt; ) = 0
  [pid  8700] 21:41:48.742899 &lt;... futex resumed&gt; ) = 0
  [pid  8700] 21:41:48.742931 futex(0x87da514, FUTEX_WAKE_PRIVATE, 2147483647) = 0
  [1] "Entering parallel"
  [pid  8700] 21:41:48.743001 futex(0x87da514, FUTEX_WAKE_PRIVATE, 2147483647) = 0
  [pid  8571] 21:41:48.743411 write(1, "[1]", 3) = 3
  [pid  8571] 21:41:48.743485 write(1, " \"Entering parallel\"", 20) = 20
  [pid  8571] 21:41:48.743545 write(1, "\n", 1) = 1
  [pid  8571] 21:41:48.743946 pipe([4, 11]) = 0
  [pid  8571] 21:41:48.744019 pipe([12, 13]) = 0
  [pid  8571] 21:41:48.744096 rt_sigaction(SIGCHLD, {0x7fdc52d45d40, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x7fdc693d1390}, NULL, 8) = 0
  [pid  8571] 21:41:48.744160 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fdc6f002a90) = 8708
  strace: Process 8708 attached
  [pid  8708] 21:41:48.746022 set_robust_list(0x7fdc6f002aa0, 24) = 0
  [pid  8571] 21:41:48.746478 close(11)   = 0
  [pid  8708] 21:41:48.746529 rt_sigaction(SIGCHLD, {SIG_DFL, [CHLD], SA_RESTORER|SA_RESTART, 0x7fdc6902b4b0},  &lt;unfinished ...&gt;
  [pid  8571] 21:41:48.746549 close(12 &lt;unfinished ...&gt;
  [pid  8708] 21:41:48.746559 &lt;... rt_sigaction resumed&gt; {0x7fdc52d45d40, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x7fdc693d1390}, 8) = 0
  [pid  8571] 21:41:48.746571 &lt;... close resumed&gt; ) = 0
  [pid  8708] 21:41:48.746581 close(4)    = 0
  [pid  8708] 21:41:48.746643 dup2(12, 0) = 0
  [pid  8708] 21:41:48.746704 close(12)   = 0
  [pid  8708] 21:41:48.746764 rt_sigaction(SIGUSR1, {0x7fdc52d45a90, [USR1], SA_RESTORER|SA_RESTART, 0x7fdc6902b4b0}, {0x7fdc6ce94550, [USR1], SA_RESTORER|SA_RESTART, 0x7fdc6902b4b0}, 8) = 0
  [pid  8571] 21:41:48.748205 pipe([11, 12]) = 0
  [pid  8571] 21:41:48.748280 pipe([14, 15]) = 0
  [pid  8571] 21:41:48.748350 rt_sigaction(SIGCHLD, {0x7fdc52d45d40, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x7fdc693d1390}, NULL, 8) = 0
  [pid  8571] 21:41:48.748410 clone([1] "Drawing 1"
   &lt;unfinished ...&gt;
  [pid  8708] 21:41:48.749158 write(1, "[1]", 3) = 3
  [pid  8708] 21:41:48.749242 write(1, " \"Drawing 1\"", 12) = 12
  [pid  8708] 21:41:48.749300 write(1, "\n", 1) = 1
  [pid  8571] 21:41:48.750225 &lt;... clone resumed&gt; child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fdc6f002a90) = 8709
  strace: Process 8709 attached
  [pid  8709] 21:41:48.750313 set_robust_list(0x7fdc6f002aa0, 24) = 0
  [pid  8571] 21:41:48.750630 close(12)   = 0
  [pid  8571] 21:41:48.750695 close(14)   = 0
  [pid  8709] 21:41:48.750829 rt_sigaction(SIGCHLD, {SIG_DFL, [CHLD], SA_RESTORER|SA_RESTART, 0x7fdc6902b4b0}, {0x7fdc52d45d40, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x7fdc693d1390}, 8) = 0
  [pid  8709] 21:41:48.750908 close(11)   = 0
  [pid  8709] 21:41:48.750976 dup2(14, 0) = 0
  [pid  8709] 21:41:48.751050 close(14)   = 0
  [pid  8709] 21:41:48.751119 rt_sigaction(SIGUSR1, {0x7fdc52d45a90, [USR1], SA_RESTORER|SA_RESTART, 0x7fdc6902b4b0}, {0x7fdc6ce94550, [USR1], SA_RESTORER|SA_RESTART, 0x7fdc6902b4b0}, 8) = 0
  [1] "Drawing 2"
  [pid  8571] 21:41:48.752325 wait4(-1, 0x7ffd95fddc44, WNOHANG, NULL) = 0
  [pid  8571] 21:41:48.752392 select(12, [4 11], NULL, NULL, {1, 0} &lt;unfinished ...&gt;
  [pid  8709] 21:41:48.753053 write(1, "[1]", 3) = 3
  [pid  8709] 21:41:48.753138 write(1, " \"Drawing 2\"", 12) = 12
  [pid  8709] 21:41:48.753202 write(1, "\n", 1) = 1
  [pid  8708] 21:41:48.755113 futex(0x498fcf4, FUTEX_WAKE_PRIVATE, 2147483647) = 0
  [pid  8704] 21:41:48.756406 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL &lt;unfinished ...&gt;
  [pid  8703] 21:41:48.756424 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL &lt;unfinished ...&gt;
  [pid  8701] 21:41:48.756557 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL &lt;unfinished ...&gt;
  [pid  8702] 21:41:48.756625 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL &lt;unfinished ...&gt;
  [pid  8705] 21:41:48.756769 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL &lt;unfinished ...&gt;
  [pid  8700] 21:41:48.757066 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL &lt;unfinished ...&gt;
  [pid  8706] 21:41:48.757184 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL &lt;unfinished ...&gt;
  [pid  8709] 21:41:48.758569 futex(0x498fcf4, FUTEX_WAKE_PRIVATE, 2147483647) = 0
  [pid  8708] 21:41:48.768419 futex(0x88b9a04, FUTEX_WAIT_PRIVATE, 0, NULL &lt;unfinished ...&gt;
  [pid  8709] 21:41:48.772260 futex(0x88b9a04, FUTEX_WAIT_PRIVATE, 0, NULL &lt;unfinished ...&gt;
  [pid  8602] 21:41:48.993871 &lt;... futex resumed&gt; ) = -1 ETIMEDOUT (Connection timed out)
  [pid  8602] 21:41:48.993914 clock_gettime(CLOCK_REALTIME, {1558734108, 993928682}) = 0
  [pid  8602] 21:41:48.993978 futex(0x10e40a8, FUTEX_WAKE_PRIVATE, 1) = 0
  [pid  8602] 21:41:48.994032 clock_gettime(CLOCK_REALTIME, {1558734108, 994048584}) = 0
  [pid  8602] 21:41:48.994096 futex(0x10e40dc, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 25, {1558734109, 994048584}, ffffffff &lt;unfinished ...&gt;
  [pid  8571] 21:41:49.753515 &lt;... select resumed&gt; ) = 0 (Timeout)
  [pid  8571] 21:41:49.753623 wait4(-1, 0x7ffd95fddc44, WNOHANG, NULL) = 0
  [pid  8571] 21:41:49.753688 select(12, [4 11], NULL, NULL, {1, 0} &lt;unfinished ...&gt;
  [pid  8602] 21:41:49.994210 &lt;... futex resumed&gt; ) = -1 ETIMEDOUT (Connection timed out)
  [pid  8602] 21:41:49.994299 clock_gettime(CLOCK_REALTIME, {1558734109, 994341104}) = 0
  [pid  8602] 21:41:49.994442 futex(0x10e40a8, FUTEX_WAKE_PRIVATE, 1) = 0
  [pid  8602] 21:41:49.994590 clock_gettime(CLOCK_REALTIME, {1558734109, 994614207}) = 0
  [pid  8602] 21:41:49.994663 futex(0x10e40dc, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 27, {1558734110, 994614207}, ffffffff &lt;unfinished ...&gt;
  [pid  8571] 21:41:50.754833 &lt;... select resumed&gt; ) = 0 (Timeout)
  [pid  8571] 21:41:50.754971 wait4(-1, 0x7ffd95fddc44, WNOHANG, NULL) = 0
  [pid  8571] 21:41:50.755117 select(12, [4 11], NULL, NULL, {1, 0} &lt;unfinished ...&gt;
  [pid  8602] 21:41:50.994707 &lt;... futex resumed&gt; ) = -1 ETIMEDOUT (Connection timed out)
  [pid  8602] 21:41:50.994748 clock_gettime(CLOCK_REALTIME, {1558734110, 994763726}) = 0
  [pid  8602] 21:41:50.994816 futex(0x10e40a8, FUTEX_WAKE_PRIVATE, 1) = 0
  [pid  8602] 21:41:50.994879 clock_gettime(CLOCK_REALTIME, {1558734110, 994894827}) = 0
  [pid  8602] 21:41:50.994944 futex(0x10e40dc, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 29, {1558734111, 994894827}, ffffffff &lt;unfinished ...&gt;
  </code></pre>
  
  <p>The rest of the log is a repetition of the last few lines.</p>
  
  <p>I think that the parent process is 8571, the first spawned process is 8708, which prints <code>Drawing 1</code>, and the second spawned process is 8709, which prints <code>Drawing 2</code>. Then the parent process lists a <code>wait4(-1, 0x7ffd95fddc44, WNOHANG, NULL) = 0</code>, process 8602 lists a <code>&lt;... futex resumed&gt; ) = -1 ETIMEDOUT (Connection timed out)</code>. I have never used <code>strace</code> and could not go beyond that.</p>
  
  <p>I have pushed the code to <a href="https://github.com/alan-turing-institute/PosteriorBootstrap/tree/62-fix-azure" rel="nofollow noreferrer">this Github branch</a>, commit 1b3d1f6, if you want to reproduce the problem. Pull the code from the branch, and run <code>azure-parallel/deploy_azure.sh</code> on a terminal (if you have the <a href="https://docs.microsoft.com/en-us/cli/azure/install-azure-cli-macos?view=azure-cli-latest" rel="nofollow noreferrer">Azure Command-Line-Interface</a> and are logged in), or change the code a bit to use the IP address of a existing virtual machine.</p>
  
  <p>Has anyone succeeded in running parallel on Azure recently? If so, what were the virtual machine and image?</p>
  
Comments: CC BY-SA 4.0
Comments: 2019-05-12T12:55:43.150Z
Comments: Have you used strace to see what it is blocking on?
Comments: Gaius
Comments: CC BY-SA 4.0
Comments: 2019-05-24T23:18:18.570Z
Comments: @Gaius Thanks for the pointer of `strace`. I updated the question.
Comments: emonigma
Tags: <azure>
Title: Azure virtual machine stalls in R due to parallel package
UserDisplayName: emonigma
ThreadText: # Azure virtual machine stalls in R due to parallel package
  
  (Asked by: username_0 on 2019-05-08)
  
  I am writing [an R package](https://github.com/alan-turing-institute/PosteriorBootstrap/) with tests using the `testthat` package. The tests pass locally and on Travis.
  
  I want to plot the benefit of parallelisation on up to 24 cores, so I set up a virtual machine programmatically on Azure:
  
  ```
  az vm create \
     --resource-group <resource group> \
     --name <name> \
     --image microsoft-dsvm:linux-data-science-vm-ubuntu:linuxdsvmubuntu:18.12.01 \
     --size Standard_NV24 \
     --admin-username <azure user> \
     --generate-ssh-keys
  
  ```
  
  I call `devtools::test()` and the virtual machine gets stuck at `testthat` for hours with 0% CPU usage:
  
  ```
  ✔  checking for unstated dependencies in ‘tests’ ...
  ─  checking tests ...
     Running ‘testthat.R’
  
  ```
  
  `devtools::test()` has no specific arguments to print some output, and it calls `testthat::test_dir()`, which also has no arguments to print output.
  
  When I remove the tests, the code stalls in a function call. I stopped and relaunched multiple times, so I think it's a problem with Azure.
  
  Other sizes of machines, `Standard_F16s_v2` and `Standard DS3 v2`, have the same problem.
  
  How can I fix it?
  
  ## Update
  
  I stumbled upon the culprit when I was running another piece of code. The VM hangs when calling the R `parallel` package on multiple cores (it works fine on just one core).
  
  I added some printouts around that call:
  
  ```
  [1] "num_cores = 2"
  [1] "Entering parallel"
  [1] "Drawing 1"
  [1] "Drawing 2"
  
  ```
  
  and then it hangs. Following the suggestion of `strace`, I launched again and see this output around this last printout:
  
  ```
  [pid  8571] 21:41:48.718625 write(1, "\n", 1[1] "num_cores = 2"
  ) = 1
  [pid  8571] 21:41:48.719486 write(1, "[1]", 3) = 3
  [pid  8571] 21:41:48.719550 write(1, " \"num_cores = 2\"", 16) = 16
  [pid  8571] 21:41:48.719615 write(1, "\n", 1) = 1
  [pid  8703] 21:41:48.730707 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL <unfinished ...>
  [pid  8705] 21:41:48.730745 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL <unfinished ...>
  [pid  8701] 21:41:48.730757 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL <unfinished ...>
  [pid  8704] 21:41:48.730794 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL <unfinished ...>
  [pid  8702] 21:41:48.730841 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL <unfinished ...>
  [pid  8700] 21:41:48.730852 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL <unfinished ...>
  [pid  8706] 21:41:48.731199 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4032, NULL <unfinished ...>
  [pid  8571] 21:41:48.742710 futex(0x498fcf4, FUTEX_WAKE_PRIVATE, 2147483647) = 7
  [pid  8706] 21:41:48.742831 <... futex resumed> ) = 0
  [pid  8705] 21:41:48.742847 <... futex resumed> ) = 0
  [pid  8704] 21:41:48.742858 <... futex resumed> ) = 0
  [pid  8703] 21:41:48.742868 <... futex resumed> ) = 0
  [pid  8702] 21:41:48.742878 <... futex resumed> ) = 0
  [pid  8701] 21:41:48.742888 <... futex resumed> ) = 0
  [pid  8700] 21:41:48.742899 <... futex resumed> ) = 0
  [pid  8700] 21:41:48.742931 futex(0x87da514, FUTEX_WAKE_PRIVATE, 2147483647) = 0
  [1] "Entering parallel"
  [pid  8700] 21:41:48.743001 futex(0x87da514, FUTEX_WAKE_PRIVATE, 2147483647) = 0
  [pid  8571] 21:41:48.743411 write(1, "[1]", 3) = 3
  [pid  8571] 21:41:48.743485 write(1, " \"Entering parallel\"", 20) = 20
  [pid  8571] 21:41:48.743545 write(1, "\n", 1) = 1
  [pid  8571] 21:41:48.743946 pipe([4, 11]) = 0
  [pid  8571] 21:41:48.744019 pipe([12, 13]) = 0
  [pid  8571] 21:41:48.744096 rt_sigaction(SIGCHLD, {0x7fdc52d45d40, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x7fdc693d1390}, NULL, 8) = 0
  [pid  8571] 21:41:48.744160 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fdc6f002a90) = 8708
  strace: Process 8708 attached
  [pid  8708] 21:41:48.746022 set_robust_list(0x7fdc6f002aa0, 24) = 0
  [pid  8571] 21:41:48.746478 close(11)   = 0
  [pid  8708] 21:41:48.746529 rt_sigaction(SIGCHLD, {SIG_DFL, [CHLD], SA_RESTORER|SA_RESTART, 0x7fdc6902b4b0},  <unfinished ...>
  [pid  8571] 21:41:48.746549 close(12 <unfinished ...>
  [pid  8708] 21:41:48.746559 <... rt_sigaction resumed> {0x7fdc52d45d40, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x7fdc693d1390}, 8) = 0
  [pid  8571] 21:41:48.746571 <... close resumed> ) = 0
  [pid  8708] 21:41:48.746581 close(4)    = 0
  [pid  8708] 21:41:48.746643 dup2(12, 0) = 0
  [pid  8708] 21:41:48.746704 close(12)   = 0
  [pid  8708] 21:41:48.746764 rt_sigaction(SIGUSR1, {0x7fdc52d45a90, [USR1], SA_RESTORER|SA_RESTART, 0x7fdc6902b4b0}, {0x7fdc6ce94550, [USR1], SA_RESTORER|SA_RESTART, 0x7fdc6902b4b0}, 8) = 0
  [pid  8571] 21:41:48.748205 pipe([11, 12]) = 0
  [pid  8571] 21:41:48.748280 pipe([14, 15]) = 0
  [pid  8571] 21:41:48.748350 rt_sigaction(SIGCHLD, {0x7fdc52d45d40, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x7fdc693d1390}, NULL, 8) = 0
  [pid  8571] 21:41:48.748410 clone([1] "Drawing 1"
   <unfinished ...>
  [pid  8708] 21:41:48.749158 write(1, "[1]", 3) = 3
  [pid  8708] 21:41:48.749242 write(1, " \"Drawing 1\"", 12) = 12
  [pid  8708] 21:41:48.749300 write(1, "\n", 1) = 1
  [pid  8571] 21:41:48.750225 <... clone resumed> child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fdc6f002a90) = 8709
  strace: Process 8709 attached
  [pid  8709] 21:41:48.750313 set_robust_list(0x7fdc6f002aa0, 24) = 0
  [pid  8571] 21:41:48.750630 close(12)   = 0
  [pid  8571] 21:41:48.750695 close(14)   = 0
  [pid  8709] 21:41:48.750829 rt_sigaction(SIGCHLD, {SIG_DFL, [CHLD], SA_RESTORER|SA_RESTART, 0x7fdc6902b4b0}, {0x7fdc52d45d40, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x7fdc693d1390}, 8) = 0
  [pid  8709] 21:41:48.750908 close(11)   = 0
  [pid  8709] 21:41:48.750976 dup2(14, 0) = 0
  [pid  8709] 21:41:48.751050 close(14)   = 0
  [pid  8709] 21:41:48.751119 rt_sigaction(SIGUSR1, {0x7fdc52d45a90, [USR1], SA_RESTORER|SA_RESTART, 0x7fdc6902b4b0}, {0x7fdc6ce94550, [USR1], SA_RESTORER|SA_RESTART, 0x7fdc6902b4b0}, 8) = 0
  [1] "Drawing 2"
  [pid  8571] 21:41:48.752325 wait4(-1, 0x7ffd95fddc44, WNOHANG, NULL) = 0
  [pid  8571] 21:41:48.752392 select(12, [4 11], NULL, NULL, {1, 0} <unfinished ...>
  [pid  8709] 21:41:48.753053 write(1, "[1]", 3) = 3
  [pid  8709] 21:41:48.753138 write(1, " \"Drawing 2\"", 12) = 12
  [pid  8709] 21:41:48.753202 write(1, "\n", 1) = 1
  [pid  8708] 21:41:48.755113 futex(0x498fcf4, FUTEX_WAKE_PRIVATE, 2147483647) = 0
  [pid  8704] 21:41:48.756406 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL <unfinished ...>
  [pid  8703] 21:41:48.756424 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL <unfinished ...>
  [pid  8701] 21:41:48.756557 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL <unfinished ...>
  [pid  8702] 21:41:48.756625 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL <unfinished ...>
  [pid  8705] 21:41:48.756769 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL <unfinished ...>
  [pid  8700] 21:41:48.757066 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL <unfinished ...>
  [pid  8706] 21:41:48.757184 futex(0x498fcf4, FUTEX_WAIT_PRIVATE, 4040, NULL <unfinished ...>
  [pid  8709] 21:41:48.758569 futex(0x498fcf4, FUTEX_WAKE_PRIVATE, 2147483647) = 0
  [pid  8708] 21:41:48.768419 futex(0x88b9a04, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
  [pid  8709] 21:41:48.772260 futex(0x88b9a04, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
  [pid  8602] 21:41:48.993871 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
  [pid  8602] 21:41:48.993914 clock_gettime(CLOCK_REALTIME, {1558734108, 993928682}) = 0
  [pid  8602] 21:41:48.993978 futex(0x10e40a8, FUTEX_WAKE_PRIVATE, 1) = 0
  [pid  8602] 21:41:48.994032 clock_gettime(CLOCK_REALTIME, {1558734108, 994048584}) = 0
  [pid  8602] 21:41:48.994096 futex(0x10e40dc, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 25, {1558734109, 994048584}, ffffffff <unfinished ...>
  [pid  8571] 21:41:49.753515 <... select resumed> ) = 0 (Timeout)
  [pid  8571] 21:41:49.753623 wait4(-1, 0x7ffd95fddc44, WNOHANG, NULL) = 0
  [pid  8571] 21:41:49.753688 select(12, [4 11], NULL, NULL, {1, 0} <unfinished ...>
  [pid  8602] 21:41:49.994210 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
  [pid  8602] 21:41:49.994299 clock_gettime(CLOCK_REALTIME, {1558734109, 994341104}) = 0
  [pid  8602] 21:41:49.994442 futex(0x10e40a8, FUTEX_WAKE_PRIVATE, 1) = 0
  [pid  8602] 21:41:49.994590 clock_gettime(CLOCK_REALTIME, {1558734109, 994614207}) = 0
  [pid  8602] 21:41:49.994663 futex(0x10e40dc, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 27, {1558734110, 994614207}, ffffffff <unfinished ...>
  [pid  8571] 21:41:50.754833 <... select resumed> ) = 0 (Timeout)
  [pid  8571] 21:41:50.754971 wait4(-1, 0x7ffd95fddc44, WNOHANG, NULL) = 0
  [pid  8571] 21:41:50.755117 select(12, [4 11], NULL, NULL, {1, 0} <unfinished ...>
  [pid  8602] 21:41:50.994707 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
  [pid  8602] 21:41:50.994748 clock_gettime(CLOCK_REALTIME, {1558734110, 994763726}) = 0
  [pid  8602] 21:41:50.994816 futex(0x10e40a8, FUTEX_WAKE_PRIVATE, 1) = 0
  [pid  8602] 21:41:50.994879 clock_gettime(CLOCK_REALTIME, {1558734110, 994894827}) = 0
  [pid  8602] 21:41:50.994944 futex(0x10e40dc, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 29, {1558734111, 994894827}, ffffffff <unfinished ...>
  
  ```
  
  The rest of the log is a repetition of the last few lines.
  
  I think that the parent process is 8571, the first spawned process is 8708, which prints `Drawing 1`, and the second spawned process is 8709, which prints `Drawing 2`. Then the parent process lists a `wait4(-1, 0x7ffd95fddc44, WNOHANG, NULL) = 0`, process 8602 lists a `<... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)`. I have never used `strace` and could not go beyond that.
  
  I have pushed the code to [this Github branch](https://github.com/alan-turing-institute/PosteriorBootstrap/tree/62-fix-azure), commit 1b3d1f6, if you want to reproduce the problem. Pull the code from the branch, and run `azure-parallel/deploy_azure.sh` on a terminal (if you have the [Azure Command-Line-Interface](https://docs.microsoft.com/en-us/cli/azure/install-azure-cli-macos?view=azure-cli-latest) and are logged in), or change the code a bit to use the IP address of a existing virtual machine.
  
  Has anyone succeeded in running parallel on Azure recently? If so, what were the virtual machine and image?
  
  **Tags:** azure
  
  > **Comments:**
  > **username_1**: Have you used strace to see what it is blocking on?  
  > **username_0**: @username_1 Thanks for the pointer of `strace`. I updated the question.  
  
  ---
  
  ## 1 answers
  
  ### Answer by username_0 on 2019-07-03. Score: 1 | Accepted answer
  
  The problem is with the image
  `microsoft-dsvm:linux-data-science-vm-ubuntu:linuxdsvmubuntu:18.12.01` ("Linux
  Data Science VM" (on the Azure portal). This is an old image with `R 3.4`
  instead of the release version of `3.5`.
  
  I succeeded with the following virtual machine (Ubuntu Server 19.04.19, size D64 v3):
  
  ```
  az vm create \
         --resource-group <resource group> \
         --name <name> \
         --image Canonical:UbuntuServer:19.04:19.04.201906280 \
         --size Standard_D64_v3 \
         --admin-username <azure user> \
         --generate-ssh-keys
  
  ```
  
  and installed `R`, `Rstan`, and an SSL library for `curl` and `devtools` with:
  
  ```
  sudo apt update
  sudo apt -y install r-base
  sudo apt -y install r-cran-rstan
  
  # Add LibSSL for installing curl and devtools, see:
  # https://stackoverflow.com/questions/44228055/r-rstudio-install-devtools-fails
  sudo apt-get install libcurl4-openssl-dev libssl-dev
  
  ```
  
  and the machine can use multiple cores:
  
  ```
  Welcome to PosteriorBootstrap, a parallel approach for adaptive non-parametric learning
  [1] "Speedup performance"
  [1] "n_bootstrap = 100"
  [1] "num_cores = 1"
  [1] "Finished sampling"
  [1] "num_cores = 2"
  [1] "Finished sampling"
  ...
  [1] "num_cores = 64"
  [1] "Finished sampling"
  
  ```
  
  I also checked the duration and the speedup is as I expected.
  
  
  ---
  
  