Email not working - Workers don't start

diegoscl · February 5, 2016, 8:37pm

Hi friends,

I need some help with mi erpnext installation because the emails aren’t working. In some topics in this forum i see that the following info can be relevant:

I install the ERPnext Bitnami Stack in AWS EC2 (ERPNext Cloud Hosting on AWS).
The apps version are ERPNext v6.20.0 and Frappe Framework v6.21.0.
The bech doctor output is:

Inspecting workers and queues…
Finding locks…
Checking scheduler status…
Workers online: False
Pending tasks 1
Timed out locks:
The bench start output is:

20:29:35 system | worker.1 started (pid=4185)
20:29:35 system | async_worker.1 started (pid=4187)
20:29:35 system | web.1 started (pid=4184)
20:29:35 system | socketio.1 started (pid=4190)
20:29:35 system | redis_async_broker.1 started (pid=4186)
20:29:35 system | redis_async_broker.1 stopped (rc=0)
20:29:35 system | workerbeat.1 started (pid=4188)
20:29:35 system | longjob_worker.1 started (pid=4191)
20:29:35 system | redis_cache.1 started (pid=4189)
20:29:35 system | sending SIGTERM to workerbeat.1 (pid 4188)
20:29:35 system | sending SIGTERM to worker.1 (pid 4185)
20:29:35 system | sending SIGTERM to web.1 (pid 4184)
20:29:35 system | sending SIGTERM to async_worker.1 (pid 4187)
20:29:35 system | sending SIGTERM to socketio.1 (pid 4190)
20:29:35 system | sending SIGTERM to redis_cache.1 (pid 4189)
20:29:35 system | sending SIGTERM to longjob_worker.1 (pid 4191)
20:29:35 system | redis_cache.1 stopped (rc=0)
20:29:35 system | socketio.1 stopped (rc=-15)
20:29:35 system | web.1 stopped (rc=-15)
20:29:35 system | async_worker.1 stopped (rc=-15)
20:29:35 system | workerbeat.1 stopped (rc=-15)
20:29:35 system | worker.1 stopped (rc=-15)
20:29:35 system | longjob_worker.1 stopped (rc=-15)
The sudo supervisorctl status output is:

frappe:frappe-web FATAL Exited too quickly (process log may have details)
frappe:frappe-worker FATAL Exited too quickly (process log may have details)
frappe:frappe-workerbeat FATAL Exited too quickly (process log may have details)
frappe-async-worker FATAL Exited too quickly (process log may have details)
frappe-longjob-worker FATAL Exited too quickly (process log may have details)
node-socketio RUNNING pid 3915, uptime 0:09:23
redis-async-broker FATAL Exited too quickly (process log may have details)
redis-cache FATAL Exited too quickly (process log may have details)

In my investigation i know that i have problems with workers, but i don’t know how start them.

Anyone can help me?

rmehta · February 6, 2016, 5:24am

What does the supervisor log say?

If you are on 512MB RAM, you might want to setup swap.

diegoscl · February 6, 2016, 4:57pm

Hi @rmehta,

Thanks for your help.

I have a 2 Gb swap file running and 1 Gb ram. My supervisor log is:

2016-02-06 14:51:39,477 INFO exited: node-socketio (terminated by SIGKILL; not expected)
2016-02-06 14:51:40,482 INFO spawned: 'node-socketio' with pid 16051
2016-02-06 14:51:42,284 INFO success: node-socketio entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2016-02-06 14:51:49,585 WARN received SIGTERM indicating exit request
2016-02-06 14:51:49,590 INFO waiting for node-socketio to die
2016-02-06 14:51:49,654 WARN received SIGTERM indicating exit request
2016-02-06 14:51:49,657 INFO exited: node-socketio (terminated by SIGTERM; not expected)
2016-02-06 14:57:31,199 CRIT Supervisor running as root (no user in config file)
2016-02-06 14:57:31,200 WARN Included extra file "/etc/supervisor/conf.d/frappe.conf" during parsing
2016-02-06 14:57:31,223 INFO RPC interface 'supervisor' initialized
2016-02-06 14:57:31,223 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2016-02-06 14:57:31,224 INFO daemonizing the supervisord process
2016-02-06 14:57:31,224 INFO supervisord started with pid 1021
2016-02-06 14:57:32,422 INFO spawned: 'redis-async-broker' with pid 1035
2016-02-06 14:57:32,734 INFO spawned: 'node-socketio' with pid 1042
2016-02-06 14:57:33,233 INFO spawned: 'frappe-async-worker' with pid 1048
2016-02-06 14:57:33,234 INFO spawned: 'frappe-longjob-worker' with pid 1049
2016-02-06 14:57:33,235 INFO spawned: 'frappe-worker' with pid 1050
2016-02-06 14:57:33,237 INFO spawned: 'frappe-web' with pid 1051
2016-02-06 14:57:33,238 INFO spawned: 'frappe-workerbeat' with pid 1052
2016-02-06 14:57:33,239 INFO spawned: 'redis-cache' with pid 1053
2016-02-06 14:57:33,239 INFO exited: redis-async-broker (exit status 0; expected)
2016-02-06 14:57:33,310 INFO spawned: 'redis-async-broker' with pid 1055
2016-02-06 14:57:33,310 INFO exited: redis-cache (exit status 0; not expected)
2016-02-06 14:57:33,317 INFO exited: redis-async-broker (exit status 0; not expected)
2016-02-06 14:57:34,319 INFO spawned: 'redis-async-broker' with pid 1092
2016-02-06 14:57:34,319 INFO success: node-socketio entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2016-02-06 14:57:34,319 INFO success: frappe-async-worker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2016-02-06 14:57:34,319 INFO success: frappe-longjob-worker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2016-02-06 14:57:34,319 INFO success: frappe-worker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2016-02-06 14:57:34,319 INFO success: frappe-web entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2016-02-06 14:57:34,319 INFO success: frappe-workerbeat entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2016-02-06 14:57:34,320 INFO spawned: 'redis-cache' with pid 1093
2016-02-06 14:57:34,350 INFO exited: redis-async-broker (exit status 0; not expected)
2016-02-06 14:57:34,351 INFO exited: redis-cache (exit status 0; not expected)
2016-02-06 14:57:34,426 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 14:57:34,426 INFO exited: frappe-longjob-worker (exit status 1; not expected)
2016-02-06 14:57:34,426 INFO exited: frappe-worker (exit status 1; not expected)
2016-02-06 14:57:34,426 INFO exited: frappe-web (exit status 1; not expected)
2016-02-06 14:57:34,427 INFO exited: frappe-workerbeat (exit status 1; not expected)
2016-02-06 14:57:35,429 INFO spawned: 'frappe-async-worker' with pid 1115
2016-02-06 14:57:35,431 INFO spawned: 'frappe-longjob-worker' with pid 1116
2016-02-06 14:57:35,432 INFO spawned: 'frappe-worker' with pid 1117
2016-02-06 14:57:35,435 INFO spawned: 'frappe-web' with pid 1118
2016-02-06 14:57:35,443 INFO spawned: 'frappe-workerbeat' with pid 1119
2016-02-06 14:57:35,834 INFO exited: frappe-longjob-worker (exit status 1; not expected)
2016-02-06 14:57:35,834 INFO exited: frappe-worker (exit status 1; not expected)
2016-02-06 14:57:35,835 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 14:57:35,835 INFO exited: frappe-web (exit status 1; not expected)
2016-02-06 14:57:35,837 INFO exited: frappe-workerbeat (exit status 1; not expected)
2016-02-06 14:57:36,839 INFO spawned: 'redis-async-broker' with pid 1120
2016-02-06 14:57:36,840 INFO spawned: 'frappe-async-worker' with pid 1121
2016-02-06 14:57:36,841 INFO spawned: 'frappe-longjob-worker' with pid 1122
2016-02-06 14:57:36,842 INFO spawned: 'frappe-worker' with pid 1123
2016-02-06 14:57:36,843 INFO spawned: 'frappe-web' with pid 1124
2016-02-06 14:57:36,856 INFO spawned: 'frappe-workerbeat' with pid 1125
2016-02-06 14:57:36,857 INFO spawned: 'redis-cache' with pid 1126
2016-02-06 14:57:36,872 INFO exited: redis-async-broker (exit status 0; not expected)
2016-02-06 14:57:36,890 INFO exited: redis-cache (exit status 0; not expected)
2016-02-06 14:57:37,640 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 14:57:37,641 INFO exited: frappe-longjob-worker (exit status 1; not expected)
2016-02-06 14:57:37,642 INFO exited: frappe-web (exit status 1; not expected)
2016-02-06 14:57:37,643 INFO exited: frappe-worker (exit status 1; not expected)
2016-02-06 14:57:37,645 INFO exited: frappe-workerbeat (exit status 1; not expected)
2016-02-06 14:57:39,648 INFO spawned: 'frappe-async-worker' with pid 1133
2016-02-06 14:57:44,007 INFO spawned: 'frappe-longjob-worker' with pid 1134
2016-02-06 14:57:44,009 INFO spawned: 'frappe-worker' with pid 1135
2016-02-06 14:57:44,010 INFO spawned: 'frappe-web' with pid 1136
2016-02-06 14:57:44,011 INFO spawned: 'frappe-workerbeat' with pid 1137
2016-02-06 14:57:44,012 INFO spawned: 'redis-cache' with pid 1138
2016-02-06 14:57:44,046 INFO spawned: 'redis-async-broker' with pid 1140
2016-02-06 14:57:44,047 INFO success: frappe-async-worker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2016-02-06 14:57:44,047 INFO exited: redis-cache (exit status 0; not expected)
2016-02-06 14:57:44,074 INFO gave up: redis-cache entered FATAL state, too many start retries too quickly
2016-02-06 14:57:44,074 INFO exited: redis-async-broker (exit status 0; not expected)
2016-02-06 14:57:44,079 INFO gave up: redis-async-broker entered FATAL state, too many start retries too quickly
2016-02-06 14:57:44,097 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 14:57:44,344 INFO spawned: 'frappe-async-worker' with pid 1142
2016-02-06 14:57:44,353 INFO exited: frappe-web (exit status 1; not expected)
2016-02-06 14:57:44,355 INFO exited: frappe-worker (exit status 1; not expected)
2016-02-06 14:57:44,355 INFO exited: frappe-longjob-worker (exit status 1; not expected)
2016-02-06 14:57:44,356 INFO exited: frappe-workerbeat (exit status 1; not expected)
2016-02-06 14:57:44,431 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 14:57:45,433 INFO spawned: 'frappe-async-worker' with pid 1143
2016-02-06 14:57:49,188 INFO spawned: 'frappe-longjob-worker' with pid 1144
2016-02-06 14:57:49,189 INFO spawned: 'frappe-worker' with pid 1145
2016-02-06 14:57:49,190 INFO spawned: 'frappe-web' with pid 1146
2016-02-06 14:57:49,191 INFO spawned: 'frappe-workerbeat' with pid 1147
2016-02-06 14:57:49,283 INFO success: frappe-async-worker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2016-02-06 14:57:49,284 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 14:57:49,573 INFO spawned: 'frappe-async-worker' with pid 1148
2016-02-06 14:57:49,582 INFO exited: frappe-worker (exit status 1; not expected)
2016-02-06 14:57:49,582 INFO gave up: frappe-worker entered FATAL state, too many start retries too quickly
2016-02-06 14:57:49,583 INFO exited: frappe-workerbeat (exit status 1; not expected)
2016-02-06 14:57:49,583 INFO gave up: frappe-workerbeat entered FATAL state, too many start retries too quickly
2016-02-06 14:57:49,583 INFO exited: frappe-web (exit status 1; not expected)
2016-02-06 14:57:49,584 INFO gave up: frappe-web entered FATAL state, too many start retries too quickly
2016-02-06 14:57:49,585 INFO exited: frappe-longjob-worker (exit status 1; not expected)
2016-02-06 14:57:49,665 INFO gave up: frappe-longjob-worker entered FATAL state, too many start retries too quickly
2016-02-06 14:57:49,666 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 14:57:50,668 INFO spawned: 'frappe-async-worker' with pid 1149
2016-02-06 14:57:50,751 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 14:57:52,755 INFO spawned: 'frappe-async-worker' with pid 1150
2016-02-06 14:57:53,272 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 14:57:56,276 INFO spawned: 'frappe-async-worker' with pid 1151
2016-02-06 14:57:56,363 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 14:57:57,364 INFO gave up: frappe-async-worker entered FATAL state, too many start retries too quickly
2016-02-06 16:32:44,652 INFO exited: node-socketio (terminated by SIGKILL; not expected)
2016-02-06 16:32:45,666 INFO spawned: 'node-socketio' with pid 3256
2016-02-06 16:32:47,160 INFO success: node-socketio entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2016-02-06 16:48:54,710 INFO exited: node-socketio (terminated by SIGKILL; not expected)
2016-02-06 16:48:55,712 INFO spawned: 'node-socketio' with pid 4296
2016-02-06 16:48:57,281 INFO success: node-socketio entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2016-02-06 16:49:04,988 WARN received SIGTERM indicating exit request
2016-02-06 16:49:04,988 INFO waiting for node-socketio to die
2016-02-06 16:49:05,060 WARN received SIGTERM indicating exit request
2016-02-06 16:49:05,067 INFO exited: node-socketio (terminated by SIGTERM; not expected)
2016-02-06 16:50:04,652 CRIT Supervisor running as root (no user in config file)
2016-02-06 16:50:04,652 WARN Included extra file "/etc/supervisor/conf.d/frappe.conf" during parsing
2016-02-06 16:50:04,698 INFO RPC interface 'supervisor' initialized
2016-02-06 16:50:04,698 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2016-02-06 16:50:04,702 INFO daemonizing the supervisord process
2016-02-06 16:50:04,702 INFO supervisord started with pid 985
2016-02-06 16:50:05,707 INFO spawned: 'redis-async-broker' with pid 1011
2016-02-06 16:50:05,716 INFO spawned: 'node-socketio' with pid 1015
2016-02-06 16:50:05,727 INFO spawned: 'frappe-async-worker' with pid 1016
2016-02-06 16:50:05,728 INFO spawned: 'frappe-longjob-worker' with pid 1017
2016-02-06 16:50:05,729 INFO spawned: 'frappe-worker' with pid 1018
2016-02-06 16:50:05,731 INFO spawned: 'frappe-web' with pid 1019
2016-02-06 16:50:05,735 INFO spawned: 'frappe-workerbeat' with pid 1020
2016-02-06 16:50:05,747 INFO spawned: 'redis-cache' with pid 1023
2016-02-06 16:50:05,753 INFO exited: redis-async-broker (exit status 0; not expected)
2016-02-06 16:50:05,769 INFO exited: redis-cache (exit status 0; not expected)
2016-02-06 16:50:06,551 INFO exited: frappe-workerbeat (exit status 1; not expected)
2016-02-06 16:50:06,559 INFO exited: frappe-worker (exit status 1; not expected)
2016-02-06 16:50:06,559 INFO exited: frappe-longjob-worker (exit status 1; not expected)
2016-02-06 16:50:06,560 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 16:50:06,561 INFO exited: frappe-web (exit status 1; not expected)
2016-02-06 16:50:07,140 INFO spawned: 'redis-async-broker' with pid 1543
2016-02-06 16:50:07,140 INFO success: node-socketio entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2016-02-06 16:50:07,141 INFO spawned: 'redis-cache' with pid 1544
2016-02-06 16:50:07,167 INFO exited: redis-cache (exit status 0; not expected)
2016-02-06 16:50:07,168 INFO exited: redis-async-broker (exit status 0; not expected)
2016-02-06 16:50:08,171 INFO spawned: 'frappe-async-worker' with pid 1547
2016-02-06 16:50:08,172 INFO spawned: 'frappe-longjob-worker' with pid 1548
2016-02-06 16:50:08,173 INFO spawned: 'frappe-worker' with pid 1549
2016-02-06 16:50:08,174 INFO spawned: 'frappe-web' with pid 1550
2016-02-06 16:50:08,175 INFO spawned: 'frappe-workerbeat' with pid 1551
2016-02-06 16:50:08,576 INFO exited: frappe-worker (exit status 1; not expected)
2016-02-06 16:50:08,576 INFO exited: frappe-longjob-worker (exit status 1; not expected)
2016-02-06 16:50:08,577 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 16:50:08,578 INFO exited: frappe-web (exit status 1; not expected)
2016-02-06 16:50:08,578 INFO exited: frappe-workerbeat (exit status 1; not expected)
2016-02-06 16:50:10,615 INFO spawned: 'redis-async-broker' with pid 1564
2016-02-06 16:50:10,616 INFO spawned: 'frappe-async-worker' with pid 1565
2016-02-06 16:50:10,617 INFO spawned: 'frappe-longjob-worker' with pid 1566
2016-02-06 16:50:10,618 INFO spawned: 'frappe-worker' with pid 1567
2016-02-06 16:50:10,627 INFO spawned: 'frappe-web' with pid 1568
2016-02-06 16:50:10,628 INFO spawned: 'frappe-workerbeat' with pid 1569
2016-02-06 16:50:10,629 INFO spawned: 'redis-cache' with pid 1570
2016-02-06 16:50:10,651 INFO exited: redis-async-broker (exit status 0; not expected)
2016-02-06 16:50:10,665 INFO exited: redis-cache (exit status 0; not expected)
2016-02-06 16:50:11,029 INFO exited: frappe-longjob-worker (exit status 1; not expected)
2016-02-06 16:50:11,031 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 16:50:11,032 INFO exited: frappe-worker (exit status 1; not expected)
2016-02-06 16:50:11,033 INFO exited: frappe-workerbeat (exit status 1; not expected)
2016-02-06 16:50:11,034 INFO exited: frappe-web (exit status 1; not expected)
2016-02-06 16:50:14,038 INFO spawned: 'redis-async-broker' with pid 1574
2016-02-06 16:50:14,039 INFO spawned: 'frappe-async-worker' with pid 1575
2016-02-06 16:50:14,040 INFO spawned: 'frappe-longjob-worker' with pid 1576
2016-02-06 16:50:14,042 INFO spawned: 'frappe-worker' with pid 1577
2016-02-06 16:50:14,043 INFO spawned: 'frappe-web' with pid 1578
2016-02-06 16:50:14,052 INFO spawned: 'frappe-workerbeat' with pid 1579
2016-02-06 16:50:14,053 INFO spawned: 'redis-cache' with pid 1580
2016-02-06 16:50:14,077 INFO exited: redis-async-broker (exit status 0; not expected)
2016-02-06 16:50:14,088 INFO gave up: redis-async-broker entered FATAL state, too many start retries too quickly
2016-02-06 16:50:14,088 INFO exited: redis-cache (exit status 0; not expected)
2016-02-06 16:50:14,449 INFO gave up: redis-cache entered FATAL state, too many start retries too quickly
2016-02-06 16:50:14,454 INFO exited: frappe-longjob-worker (exit status 1; not expected)
2016-02-06 16:50:14,455 INFO gave up: frappe-longjob-worker entered FATAL state, too many start retries too quickly
2016-02-06 16:50:14,455 INFO exited: frappe-async-worker (exit status 1; not expected)
2016-02-06 16:50:14,457 INFO gave up: frappe-async-worker entered FATAL state, too many start retries too quickly
2016-02-06 16:50:14,458 INFO exited: frappe-worker (exit status 1; not expected)
2016-02-06 16:50:14,458 INFO gave up: frappe-worker entered FATAL state, too many start retries too quickly
2016-02-06 16:50:14,459 INFO exited: frappe-web (exit status 1; not expected)
2016-02-06 16:50:14,459 INFO gave up: frappe-web entered FATAL state, too many start retries too quickly
2016-02-06 16:50:14,460 INFO exited: frappe-workerbeat (exit status 1; not expected)
2016-02-06 16:50:15,461 INFO gave up: frappe-workerbeat entered FATAL state, too many start retries too quickly

Any idea?

rmehta · February 8, 2016, 7:11am

@diegoscl weird, seems to be something specific to your setup, what does the supervisor log show?

diegoscl · February 24, 2016, 1:47pm

Hello,

I solve this issue with the help of the bitnami community. This is the thread → GitHub - bitnami/vms: Bitnami Application Catalog VMs

Regards!

superlack · February 26, 2016, 3:53am

I’ll preface this by saying that I don’t have much knowledge on the backend of the system, but it seems as if bitnami has developed their own scripts to serve erpnext. I tried finding that particular file on my system (ubuntu 14) to no avail. I am experiencing the same issue, and have searched tirelessly, and shot blind at a lot of commands, but still am having troubles getting the workers online.

Bench start indicates that there issues with redis_cache