Frappe dev server stops with error Command failed with exit code 137

Blue_Jersey · July 15, 2023, 2:01pm

Evening

I have a problem with the Frappe/bench dev server after I do the command bench start it stops working after less than 1-2 minutes

And give me this error “error Command failed with exit code 137”

My server is Ubuntu 22.04 - 1GB Ram

Here is the full log

tada@server ~> cd frappe-bench/
tada@server ~/frappe-bench> bench start
13:53:05 system           | web.1 started (pid=3313)
13:53:05 system           | socketio.1 started (pid=3314)
13:53:05 system           | watch.1 started (pid=3315)
13:53:05 system           | redis_queue.1 started (pid=3316)
13:53:05 system           | schedule.1 started (pid=3317)
13:53:05 system           | worker.1 started (pid=3318)
13:53:05 system           | redis_socketio.1 started (pid=3319)
13:53:05 redis_queue.1    | 3326:C 15 Jul 2023 13:53:05.144 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
13:53:05 redis_queue.1    | 3326:C 15 Jul 2023 13:53:05.144 # Redis version=5.0.7, bits=64, commit=00000000, modified=0, pid=3326, just started
13:53:05 redis_queue.1    | 3326:C 15 Jul 2023 13:53:05.144 # Configuration loaded
13:53:05 redis_queue.1    | 3326:M 15 Jul 2023 13:53:05.145 * Increased maximum number of open files to 10032 (it was originally set to 1024).
13:53:05 redis_queue.1    | 3326:M 15 Jul 2023 13:53:05.149 * Running mode=standalone, port=11000.
13:53:05 redis_queue.1    | 3326:M 15 Jul 2023 13:53:05.149 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
13:53:05 redis_queue.1    | 3326:M 15 Jul 2023 13:53:05.149 # Server initialized
13:53:05 redis_queue.1    | 3326:M 15 Jul 2023 13:53:05.149 * Ready to accept connections
13:53:05 redis_socketio.1 | 3333:C 15 Jul 2023 13:53:05.154 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
13:53:05 redis_socketio.1 | 3333:C 15 Jul 2023 13:53:05.154 # Redis version=5.0.7, bits=64, commit=00000000, modified=0, pid=3333, just started
13:53:05 redis_socketio.1 | 3333:C 15 Jul 2023 13:53:05.154 # Configuration loaded
13:53:05 redis_socketio.1 | 3333:M 15 Jul 2023 13:53:05.155 * Increased maximum number of open files to 10032 (it was originally set to 1024).
13:53:05 redis_socketio.1 | 3333:M 15 Jul 2023 13:53:05.156 * Running mode=standalone, port=12000.
13:53:05 redis_socketio.1 | 3333:M 15 Jul 2023 13:53:05.156 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
13:53:05 redis_socketio.1 | 3333:M 15 Jul 2023 13:53:05.156 # Server initialized
13:53:05 redis_socketio.1 | 3333:M 15 Jul 2023 13:53:05.156 * Ready to accept connections
13:53:05 system           | redis_cache.1 started (pid=3332)
13:53:05 redis_cache.1    | 3335:C 15 Jul 2023 13:53:05.179 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
13:53:05 redis_cache.1    | 3335:C 15 Jul 2023 13:53:05.179 # Redis version=5.0.7, bits=64, commit=00000000, modified=0, pid=3335, just started
13:53:05 redis_cache.1    | 3335:C 15 Jul 2023 13:53:05.179 # Configuration loaded
13:53:05 redis_cache.1    | 3335:M 15 Jul 2023 13:53:05.180 * Increased maximum number of open files to 10032 (it was originally set to 1024).
13:53:05 redis_cache.1    | 3335:M 15 Jul 2023 13:53:05.181 * Running mode=standalone, port=13000.
13:53:05 redis_cache.1    | 3335:M 15 Jul 2023 13:53:05.181 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
13:53:05 redis_cache.1    | 3335:M 15 Jul 2023 13:53:05.181 # Server initialized
13:53:05 redis_cache.1    | 3335:M 15 Jul 2023 13:53:05.181 * Ready to accept connections
13:53:06 socketio.1       | listening on *: 9000
13:53:09 web.1            |  * Running on http://0.0.0.0:8000/ (Press CTRL+C to quit)
13:53:09 web.1            |  * Restarting with inotify reloader
13:53:10 web.1            |  * Debugger is active!
13:53:10 web.1            |  * Debugger PIN: 119-390-329
13:53:11 watch.1          | yarn run v1.22.19
13:53:11 watch.1          | $ node rollup/watch.js
13:53:13 watch.1          | 
13:53:13 watch.1          | Rollup Watcher Started
13:53:13 watch.1          | 
13:53:13 watch.1          | Watching...
13:53:14 watch.1          | Browserslist: caniuse-lite is outdated. Please run:
13:53:14 watch.1          | npx browserslist@latest --update-db
13:53:15 watch.1          | Rebuilding frappe-web-b4.css
13:53:16 watch.1          | Rebuilding frappe-recorder.min.js
13:53:17 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:17] "GET / HTTP/1.1" 200 -
13:53:17 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:17] "GET /assets/css/frappe-web-b4.css?ver=1689387917.0 HTTP/1.1" 200 -
13:53:17 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:17] "GET /assets/css/erpnext-web.css?ver=1689387917.0 HTTP/1.1" 200 -
13:53:17 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:17] "GET /assets/css/login.css?ver=1689387917.0 HTTP/1.1" 200 -
13:53:17 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:17] "GET /assets/frappe/js/lib/jquery/jquery.min.js HTTP/1.1" 200 -
13:53:17 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:17] "GET /assets/js/libs.min.js HTTP/1.1" 200 -
13:53:18 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:18] "GET /assets/js/frappe-web.min.js?ver=1689387917.0 HTTP/1.1" 200 -
13:53:18 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:18] "GET /assets/js/bootstrap-4-web.min.js HTTP/1.1" 200 -
13:53:18 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:18] "GET /website_script.js?ver=1689387917.0 HTTP/1.1" 200 -
13:53:18 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:18] "GET /assets/js/erpnext-web.min.js?ver=1689387917.0 HTTP/1.1" 200 -
13:53:18 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:18] "GET /assets/erpnext/images/erpnext-logo.svg HTTP/1.1" 200 -
13:53:20 web.1            | 190.92.151.201 - - [15/Jul/2023 13:53:20] "GET /api/method/frappe.realtime.get_user_info?sid=Guest HTTP/1.1" 200 -
13:53:20 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:20] "POST / HTTP/1.1" 200 -
13:53:20 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:20] "GET /assets/erpnext/images/erpnext-favicon.svg HTTP/1.1" 200 -
13:53:22 watch.1          | Rebuilding checkout.min.js
13:53:22 watch.1          | Rebuilding frappe-web.min.js
13:53:24 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:24] "POST / HTTP/1.1" 200 -
13:53:26 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:26] "GET /app HTTP/1.1" 200 -
13:53:26 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:26] "GET /assets/css/desk.min.css?ver=1689387917.0 HTTP/1.1" 200 -
13:53:26 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:26] "GET /assets/css/report.min.css?ver=1689387917.0 HTTP/1.1" 200 -
13:53:26 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:26] "GET /assets/css/erpnext.css?ver=1689387917.0 HTTP/1.1" 200 -
13:53:26 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:26] "GET /assets/js/libs.min.js?ver=1689387917.0 HTTP/1.1" 200 -
13:53:26 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:26] "GET /assets/js/desk.min.js?ver=1689387917.0 HTTP/1.1" 200 -
13:53:27 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:27] "GET /assets/js/list.min.js?ver=1689387917.0 HTTP/1.1" 200 -
13:53:27 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:27] "GET /assets/js/form.min.js?ver=1689387917.0 HTTP/1.1" 200 -
13:53:27 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:27] "GET /assets/js/control.min.js?ver=1689387917.0 HTTP/1.1" 200 -
13:53:28 watch.1          | Rebuilding bootstrap-4-web.min.js
13:53:28 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:28] "GET /assets/js/report.min.js?ver=1689387917.0 HTTP/1.1" 200 -
13:53:28 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:28] "GET /assets/frappe/css/fonts/inter/inter_regular.woff2 HTTP/1.1" 200 -
13:53:29 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:29] "GET /assets/js/erpnext.min.js?ver=1689387917.0 HTTP/1.1" 200 -
13:53:30 watch.1          | Rebuilding control.min.js
13:53:31 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:31] "GET /assets/frappe/sounds/email.mp3 HTTP/1.1" 200 -
13:53:31 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:31] "GET /assets/frappe/sounds/submit.mp3 HTTP/1.1" 200 -
13:53:31 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:31] "GET /assets/frappe/sounds/cancel.mp3 HTTP/1.1" 200 -
13:53:31 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:31] "GET /api/method/frappe.client.get_js?items=%5B%22assets%2Ferpnext%2Fjs%2Fsetup_wizard.js%22%5D&_=1689429208651 HTTP/1.1" 200 -
13:53:31 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:31] "POST /api/method/frappe.core.doctype.user_permission.user_permission.get_user_permissions HTTP/1.1" 200 -
13:53:31 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:31] "GET /assets/frappe/sounds/delete.mp3 HTTP/1.1" 200 -
13:53:31 web.1            | 190.92.151.201 - - [15/Jul/2023 13:53:31] "GET /api/method/frappe.realtime.get_user_info?sid=7fbc79296744e60b1fb19e5e1421be10aed8037a96e81841c782d44a HTTP/1.1" 200 -
13:53:32 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:32] "POST /api/method/frappe.desk.page.setup_wizard.setup_wizard.load_languages HTTP/1.1" 200 -
13:53:32 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:32] "GET /assets/frappe/sounds/click.mp3 HTTP/1.1" 200 -
13:53:32 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:32] "GET /assets/frappe/sounds/alert.mp3 HTTP/1.1" 200 -
13:53:32 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:32] "GET /assets/frappe/sounds/error.mp3 HTTP/1.1" 200 -
13:53:32 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:32] "GET /assets/erpnext/sounds/incoming-call.mp3 HTTP/1.1" 200 -
13:53:32 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:32] "GET /assets/erpnext/sounds/call-disconnect.mp3 HTTP/1.1" 200 -
13:53:33 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:33] "GET /assets/frappe/css/fonts/inter/inter_bold.woff2 HTTP/1.1" 200 -
13:53:33 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:33] "GET /assets/frappe/css/fonts/inter/inter_medium.woff2 HTTP/1.1" 200 -
13:53:38 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:38] "POST /api/method/frappe.desk.page.setup_wizard.setup_wizard.load_messages HTTP/1.1" 200 -
13:53:40 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:40] "POST /api/method/frappe.geo.country_info.get_country_timezone_info HTTP/1.1" 200 -
13:53:42 watch.1          | Rebuilding dialog.min.js
13:53:44 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:44] "GET /api/method/frappe.desk.form.load.getdoc?doctype=Currency&name=EGP&_=1689429208652 HTTP/1.1" 200 -
13:53:45 web.1            | 156.192.206.242 - - [15/Jul/2023 13:53:45] "POST /api/method/frappe.desk.page.setup_wizard.setup_wizard.load_user_details HTTP/1.1" 200 -
13:53:46 watch.1          | Rebuilding desk.min.css
13:53:47 watch.1          | Rebuilding printview.css
13:53:47 watch.1          | Rebuilding desk.min.js
13:53:53 watch.1          | Killed
13:53:53 watch.1          | error Command failed with exit code 137.
13:53:53 watch.1          | info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.
13:53:53 system           | watch.1 stopped (rc=0)
13:53:53 system           | sending SIGTERM to redis_cache.1 (pid 3332)
13:53:53 system           | sending SIGTERM to redis_socketio.1 (pid 3319)
13:53:53 system           | sending SIGTERM to redis_queue.1 (pid 3316)
13:53:53 system           | sending SIGTERM to web.1 (pid 3313)
13:53:53 system           | sending SIGTERM to socketio.1 (pid 3314)
13:53:53 system           | sending SIGTERM to schedule.1 (pid 3317)
13:53:53 system           | sending SIGTERM to worker.1 (pid 3318)
13:53:53 redis_cache.1    | 3335:signal-handler (1689429233) Received SIGTERM scheduling shutdown...
13:53:53 redis_socketio.1 | 3333:signal-handler (1689429233) Received SIGTERM scheduling shutdown...
13:53:53 redis_queue.1    | 3326:signal-handler (1689429233) Received SIGTERM scheduling shutdown...
13:53:53 system           | socketio.1 stopped (rc=-15)
13:53:53 system           | worker.1 stopped (rc=-15)
13:53:53 system           | schedule.1 stopped (rc=-15)
13:53:53 redis_queue.1    | 3326:M 15 Jul 2023 13:53:53.771 # User requested shutdown...
13:53:53 redis_queue.1    | 3326:M 15 Jul 2023 13:53:53.771 * Removing the pid file.
13:53:53 redis_socketio.1 | 3333:M 15 Jul 2023 13:53:53.772 # User requested shutdown...
13:53:53 redis_socketio.1 | 3333:M 15 Jul 2023 13:53:53.772 * Removing the pid file.
13:53:53 redis_cache.1    | 3335:M 15 Jul 2023 13:53:53.772 # User requested shutdown...
13:53:53 redis_cache.1    | 3335:M 15 Jul 2023 13:53:53.772 * Removing the pid file.
13:53:53 redis_socketio.1 | 3333:M 15 Jul 2023 13:53:53.774 # Redis is now ready to exit, bye bye...
13:53:53 system           | redis_socketio.1 stopped (rc=-15)
13:53:53 redis_cache.1    | 3335:M 15 Jul 2023 13:53:53.778 # Redis is now ready to exit, bye bye...
13:53:53 system           | redis_cache.1 stopped (rc=-15)
13:53:53 redis_queue.1    | 3326:M 15 Jul 2023 13:53:53.784 # Redis is now ready to exit, bye bye...
13:53:53 system           | redis_queue.1 stopped (rc=-15)
13:53:53 system           | web.1 stopped (rc=-15)

ankush · July 15, 2023, 2:27pm

137 means OOM killer killed your process because it was using too much memory.

Possible fixes:

Add more memory to system. 1GB RAM is nowhere close to enough to run development version. I’d suggest upgrading to 4GB at least. 8GB is recommended.
Remove bench watch from procfile and manually rebuild when you modify JS files.
Use v14 which is somewhat more optimized for memory usage. It’s still unlikely to work in 1GB but it just might work with enough swap. (My developer machine uses 800MB for all processes combined, watch process consumed 500MB)
Drop extra workers. In the recent version of Frappe you can get away with a single background worker in development mode.

 # procfile
- worker_short: bench worker --queue short
- worker_long: bench worker --queue long
- worker_default: bench worker --queue default

+ worker: bench worker --queue short,default,long

We already limit memory usage wherever possible, so not much else can be done in code. Ref: fix: max_old_space_size limit for node processes by surajshetty3416 · Pull Request #12494 · frappe/frappe · GitHub