C stack usage error

[TomWeishaar]

I have a shiny app under development that is designed to run continuously on an Amazon Lightsail instance with 1 core and 4G memory. It's at dev.open-meta.org/app.

The app has never crashed while I'm using it, but it has now crashed several times while I'm not using it, always with a C stack usage error. The most recent crash is quite interesting, here's the message:

Error: C stack usage  1031500945536 is too close to the limit
Execution halted

How can I have a 1031 Gig C Stack on an instance with only 4 Gigs of memory?

Google searches suggest the C stack usage error is usually caused by out-of-control recursion. I don't have anything like that in my code.

Is this a Shiny-Server, R, or Linux error? Do you have any further ideas for debugging what's happening?

[jeffsaxenci]

We are seeing the same thing, and I have to keep restarting shiny-server. We are running on CentOS 6.10 and using R 3.5.0. This seems to have started when going from R 3.4 to 3.5, but I can't say 100% that that is the case.

[jcheng5]

What versions of Shiny, httpuv, later, and shiny server? Does it happen even with the sample apps we ship in /srv/shiny-server-client/sample-apps?

[jeffsaxenci]

Hi Joe, Here is some info about our system. [root@discover shiny-server]# more /etc/redhat-release CentOS release 6.10 (Final) [root@discover shiny-server]# uname -r 2.6.32-696.23.1.el6.x86_64 [root@discover shiny-server]# The file /opt/shiny-server/VERSION shows 1.5.7.954 [root@discover shiny-server]# R --version R version 3.5.0 (2018-04-23) -- "Joy in Playing" Copyright (C) 2018 The R Foundation for Statistical Computing Platform: x86_64-redhat-linux-gnu (64-bit)

packageVersion("httpuv")

[1] ‘1.4.5’

packageVersion("later")

[1] ‘0.7.3’

packageVersion("shiny")

[1] ‘1.1.0’

I’m not able to comment on whether or not it happens with the sample apps. This application is being used by many people, and it just seems to be random as to when things die and have to be restarted. At the moment I can’t state that it is any one thing that causes the problem. Jeff From: Joe Cheng <notifications@github.com> Sent: Wednesday, September 05, 2018 10:14 AM To: rstudio/shiny-server <shiny-server@noreply.github.com> Cc: Saxe, Jeff (NIH/NCI) [C] <jeff.saxe@nih.gov>; Comment <comment@noreply.github.com> Subject: Re: [rstudio/shiny-server] C stack usage error (#378) What versions of Shiny, httpuv, later, and shiny server? Does it happen even with the sample apps we ship in /srv/shiny-server-client/sample-apps? — You are receiving this because you commented. Reply to this email directly, view it on GitHub<#378 (comment)>, or mute the thread<https://github.com/notifications/unsubscribe-auth/Ai2wcFBYqTrfMkh6f_ErMqZ4XSrfPokHks5uX9wKgaJpZM4WZGG6>.

[TomWeishaar]

Here are the specs of my Amazon Lightsail instance (note that Amazon Linux is also CentOS 6):

R version 3.4.1 (2017-06-30)
Platform: x86_64-redhat-linux-gnu (64-bit)
Running under: Amazon Linux AMI 2018.03

Matrix products: default
BLAS/LAPACK: /usr/lib64/R/lib/libRblas.so

locale:
 [1] LC_CTYPE=en_US.UTF-8          LC_NUMERIC=C                 
 [3] LC_TIME=en_US.UTF-8           LC_COLLATE=en_US.UTF-8       
 [5] LC_MONETARY=en_US.UTF-8       LC_MESSAGES=en_US.UTF-8      
 [7] LC_PAPER=en_US.UTF-8          LC_NAME=en_US.UTF-8          
 [9] LC_ADDRESS=en_US.UTF-8        LC_TELEPHONE=en_US.UTF-8     
[11] LC_MEASUREMENT=en_US.UTF-8    LC_IDENTIFICATION=en_US.UTF-8

attached base packages:
[1] stats     graphics  grDevices utils     datasets  methods   base     

other attached packages:
 [1] DT_0.4           bcrypt_1.1       mailR_0.4.1      RMariaDB_1.0.6  
 [5] pool_0.1.4.1     RefManageR_1.2.0 rvest_0.3.2      RCurl_1.95-4.10 
 [9] bitops_1.0-6     xml2_1.2.0       stringi_1.2.3    magrittr_1.5    
[13] lubridate_1.7.4  jsonlite_1.5     httr_1.3.1       forcats_0.3.0   
[17] stringr_1.3.1    dplyr_0.7.6      purrr_0.2.5      readr_1.1.1     
[21] tidyr_0.8.1      tibble_1.4.2     ggplot2_3.0.0    tidyverse_1.2.1 
[25] htmltools_0.3.6  shiny_1.1.0     

loaded via a namespace (and not attached):
 [1] Rcpp_0.12.17      lattice_0.20-35   assertthat_0.2.0  digest_0.6.15    
 [5] psych_1.8.4       mime_0.5          R6_2.2.2          cellranger_1.1.0 
 [9] plyr_1.8.4        pillar_1.2.3      rlang_0.2.1       lazyeval_0.2.1   
[13] readxl_1.1.0      rstudioapi_0.7    R.oo_1.22.0       R.utils_2.6.0    
[17] foreign_0.8-69    htmlwidgets_1.2   bit_1.1-14        munsell_0.5.0    
[21] broom_0.4.5       compiler_3.4.1    httpuv_1.4.4.2    modelr_0.1.2     
[25] pkgconfig_2.0.1   mnormt_1.5-5      openssl_1.0.1     tidyselect_0.2.4 
[29] crayon_1.3.4      dbplyr_1.2.1      withr_2.1.2       later_0.7.3      
[33] R.methodsS3_1.7.1 grid_3.4.1        nlme_3.1-131      xtable_1.8-2     
[37] gtable_0.2.0      DBI_1.0.0         scales_0.5.0      bibtex_0.4.2     
[41] cli_1.0.0         reshape2_1.4.3    promises_1.0.1    bindrcpp_0.2.2   
[45] tools_3.4.1       bit64_0.9-7       glue_1.2.0        crosstalk_1.0.0  
[49] hms_0.4.2         yaml_2.1.19       parallel_3.4.1    colorspace_1.3-2 
[53] rJava_0.9-10      bindr_0.1.1       haven_1.1.2    

[TomWeishaar]

PS:

Shiny Server v1.5.6.875
Node.js v6.10.3

[TomWeishaar]

This is the version of R installed by yum. I didn't realize it was so old.

[TomWeishaar]

This happened again and I noticed the error message sometimes includes an additional error. Here are the messages from the last three crashes:

Log name: shiny-app-dir-shiny-20180906-191655-35967
Last updated: 9/13/2018 5:22:10 AM

Error: C stack usage  269562919824 is too close to the limit
Error in paste0("shiny.", name) : invalid 'collapse' argument
Calls: runApp ... callAppHook -> getHooksList -> getHook -> get0 -> paste0
Execution halted

Log name: shiny-app-dir-shiny-20180828-215352-35267
Last updated: 8/31/2018 10:07:54 PM

Error: C stack usage  1031500945536 is too close to the limit
Execution halted

Log name: shiny-app-dir-shiny-20180815-011601-39097
Last updated: 8/18/2018 1:33:34 PM

Error: C stack usage  405425681168 is too close to the limit
Error in paste0("shiny.", name) : invalid 'collapse' argument
Calls: runApp ... callAppHook -> getHooksList -> getHook -> get0 -> paste0
Execution halted

In each case the usage limit is hundreds to thousands times more than the 4G allocated to my Amazon instance. This might be Amazon giving the instance an extremely generous burst of memory rather than a shiny-server issue, but it seems very strange.

Tom

[TomWeishaar]

Here's the log from the most recent crash, shiny-app-dir-shiny-20180915-164530-33121, with a last update of 9/17/2018 8:54:34. The log basically says that I (Admin) opened a session in one browser window on 9/15 and never closed the window, so the session continued. I opened a second browser window on 9/16 and closed it 19 seconds later, ending that session. The first session ends when the program crashes.

Since this is still under development and strictly doesn't need to be live, I've temporarily changed the app to Old Faithful to see if the crashes continue with a Shiny sample app that loads no packages except "shiny".

Listening on http://127.0.0.1:33121
Warning in C_valid_tz(tzone) :
  System timezone name is unknown. Please set environment variable TZ.
Session 1 started @ 2018-09-15 16:45:35.
Checking cookies...
...user is Admin
Rendering prjMy v.1
Session 2 started @ 2018-09-16 19:05:51.
Checking cookies...
...user is Admin
Rendering prjMy v.1
Session 2 ended @ 2018-09-16 19:06:10.

Session 1 ended @ 2018-09-17 00:54:34.

Error: C stack usage  821822407328 is too close to the limit
Execution halted

[TomWeishaar]

I was looking through older logs to see if I ever had a crash when there wasn't an open session and I didn't find any. It could be important that this application uses Shiny Server's app directory, not the site directory, and a session stays open until the user sends the browser window to a different URL (or closes the window). That is, a session can be open for days for a user who just leaves browser windows open and doesn't ever power-down.

On the other hand, I did find one crash that occurred soon after starting the app and it includes a longer error message. This log (last saved at :27:17) basically says the app started less than two minutes earlier at 21:25:35. During that time the log says I went from the site home page (session 1), to the site log in page (session 2), to my personal home page (session 3), to the start page for one of my projects (session 4), to some unreported page (session 5), where I clicked on a sub-menu button..

su: ignore --preserve-environment, it's mutually exclusive to --login.
[1] "Credentials loaded..."
── Attaching packages ─────────────────────────────────────── tidyverse 1.2.1 ──
✔ ggplot2 3.0.0     ✔ purrr   0.2.5
✔ tibble  1.4.2     ✔ dplyr   0.7.6
✔ tidyr   0.8.1     ✔ stringr 1.3.1
✔ readr   1.1.1     ✔ forcats 0.3.0
── Conflicts ────────────────────────────────────────── tidyverse_conflicts() ──
✖ dplyr::filter() masks stats::filter()
✖ dplyr::lag()    masks stats::lag()

Attaching package: ‘jsonlite’

The following object is masked from ‘package:purrr’:

    flatten

The following object is masked from ‘package:shiny’:

    validate


Attaching package: ‘lubridate’

The following object is masked from ‘package:base’:

    date


Attaching package: ‘magrittr’

The following object is masked from ‘package:purrr’:

    set_names

The following object is masked from ‘package:tidyr’:

    extract

Loading required package: bitops

Attaching package: ‘RCurl’

The following object is masked from ‘package:tidyr’:

    complete


Attaching package: ‘rvest’

The following object is masked from ‘package:purrr’:

    pluck

The following object is masked from ‘package:readr’:

    guess_encoding


Attaching package: ‘DT’

The following objects are masked from ‘package:shiny’:

    dataTableOutput, renderDataTable

[1] "Getting SQL.DBs..."

Listening on http://127.0.0.1:41819
Warning in C_valid_tz(tzone) :
  System timezone name is unknown. Please set environment variable TZ.
Session 1 started @ 2018-08-13 21:25:35.
Checking cookies...
...cookie is blank.
Rendering prjActive v.2
Session 2 started @ 2018-08-13 21:25:44.
Checking cookies...
...cookie is blank.
Rendering login v.1
Session 3 started @ 2018-08-13 21:25:51.
Checking cookies...
...user is Admin
Rendering prjMy v.1
Click on view_1_1534195556494
Session 4 started @ 2018-08-13 21:25:55.
Checking cookies...
...user is Admin
Rendering Protocol v.1
Session 1 ended @ 2018-08-13 21:25:58.

Session 5 started @ 2018-08-13 21:25:59.
Checking cookies...
...user is Admin
Rendering Search v.1
Session 2 ended @ 2018-08-13 21:26:05.

Session 3 ended @ 2018-08-13 21:26:09.

Session 4 ended @ 2018-08-13 21:26:13.

Click on sub_2_1534195578980
Error: C stack usage  450926740848 is too close to the limit
Execution halted

 *** caught segfault ***
address 0x1, cause 'memory not mapped'
An irrecoverable exception occurred. R is aborting now ...
-bash: line 1: 15566 Segmentation fault      R --no-save --slave -f \/opt\/shiny-server\/R\/SockJSAdapter\.R

[jeffsaxenci]

After many weeks of urging the guys here to test their own R code with valgrind they finally did and sure enough found problems with their code. Upon fixing that the problems related to C stack usage disappeared. I would recommend that you check your code using valgrind if you haven't done that already.

[wch]

On that note: I've spent a lot of time tracking down memory bugs and I created this Docker image with various builds of R to help find them:
https://github.com/wch/r-debug

Here's the accompanying documentation:
https://github.com/wch/r-debug/blob/master/debugging-r.md

If you have memory bugs in compiled code, this is a very useful tool for finding them.

[TomWeishaar]

Thank you for your debugging tool suggestions. They look over my head, but every aspect of this project has been over my head, so I'll look into them and figure this out, too. Many thanks. - Tom

[maryskalicky]

We, too, are seeing this error in our Shiny Server Pro application log:
Error: C stack usage 95485492772 is too close to the limit (with various different numbers)

The error seems to be written to the log after a closed session is detected.

This is only occurring in an app that uses the rJava and xlsx packages. And it only occurs in Pro, not the free version of Shiny Server. We use these packages to dynamically generate formatted Excel workbooks. We cannot use the openxlsx or writexl packages because those packages do not provide the formatting options we need.

I'm attaching a pared down shiny app to demonstrate.

shiny-sample-app.zip

All this app does is load the jvm, rJava package and xlsx package in global.R. It does nothing else. If you run the app you will see nothing when the app loads. When you close the session, and it is detected, the C stack error is written to the log. Since there is really no code to speak of there is no way to prevent this error by optimizing or reconfiguring code.

This is our setup:
Ubuntu 16.04
Shiny Server (Commercial) v1.5.3.770
R version 3.4.1 (2017-06-30) -- "Single Candle"
OpenJDK Runtime Environment (build 1.8.0_181-8u181-b13-0ubuntu0.16.04.1-b13)

We had a crash of a real (not sample) application using rJava and xlsx yesterday but other than the C stack error there was no other indication of why the crash occurred in the application log or the shiny-server.log. A restart of Shiny Server Pro resolved whatever problem had occurred.

Does anybody have any insight:

1. Why does this occur in Pro but not in free Shiny Server?
2. Should we be concerned that this error is affecting Shiny Server Pro stability and performance?
3. Is there something we can do to prevent this error from occurring?

Thank you for any insight or help you can provide.

[MikeKras]

Hey @maryskalicky ,

I have recently spent a decent amount of time trying to debug a similar problem in a much bigger app. Regarding your questions:

Ad 1. I guess it has something to do regarding scoping when spawning two parallel R processes - Shiny Server Pro does it and it seems to be the difference maker compared to the open version.

Ad 3. The solution could be moving loading of your libraries into the server file, before the declaration of the server function. It fixed the issue for me, please let me know whether it helped in your case as well.

I would also be glad to learn more from Shiny Server team as to the possible reasons behind such behavior. There seems to be no reason why global.R shouldn't load libraries.

Cheers,
Michal

[maryskalicky]

@MikeKras

Thanks so much for your suggestion. I just tried it, moved the library function calls into server.R before the server function but, rats, it did not resolve the issue for me. I was so hopeful!

I tried increasing the stack soft limit to unlimited. The hard limit was already at unlimited. When I did that the C stack usage error was gone but then I got a different error:

Error in execCallbacks(timeoutSecs) :
Java called System.exit(130) requesting R to quit - trying to recover
Calls: runApp ... run_now -> execCallbacks -> .Call -> .handleSimpleError -> h

That error seems more nefarious so I reverted the stack limit and am now back to the C stack usage error.

Thankfully the C stack usage error doesn't crash the app as far as I know. The app was running fine for 5 weeks with this error appearing but only crashed just yesterday. I don't know what caused yesterday's crash but I do know we'd like to resolve the C stack usage error if possible.

Thank you again for the suggestion.