Service startup errors - Githubissues

realies commented 5 years ago

Upon booting the container up via docker-composer there is errors until something fully initializes:

$ docker-compose up
Starting alpine-sqs ... done
Attaching to alpine-sqs
alpine-sqs    | 2018-11-23 05:07:57,782 INFO Included extra file "/etc/supervisor/conf.d/elasticmq.conf" during parsing
alpine-sqs    | 2018-11-23 05:07:57,782 INFO Included extra file "/etc/supervisor/conf.d/insight.conf" during parsing
alpine-sqs    | 2018-11-23 05:07:57,782 INFO Included extra file "/etc/supervisor/conf.d/sqs-init.conf" during parsing
alpine-sqs    | 2018-11-23 05:07:57,782 INFO Set uid to user 0 succeeded
alpine-sqs    | 2018-11-23 05:07:57,790 INFO RPC interface 'supervisor' initialized
alpine-sqs    | 2018-11-23 05:07:57,791 CRIT Server 'unix_http_server' running without any HTTP authentication checking
alpine-sqs    | 2018-11-23 05:07:57,791 INFO supervisord started with pid 1
alpine-sqs    | 2018-11-23 05:07:58,793 INFO spawned: 'sqs-init' with pid 9
alpine-sqs    | 2018-11-23 05:07:58,794 INFO spawned: 'elasticmq' with pid 10
alpine-sqs    | 2018-11-23 05:07:58,796 INFO spawned: 'insight' with pid 11
alpine-sqs    | cp: can't stat '/opt/custom/*.conf': No such file or directory
alpine-sqs    | 
alpine-sqs    | > sqs-insight@0.3.0 start /opt/sqs-insight
alpine-sqs    | > node index.js
alpine-sqs    | 
alpine-sqs    | 2018-11-23 05:07:59,803 INFO success: sqs-init entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
alpine-sqs    | 2018-11-23 05:07:59,803 INFO success: elasticmq entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
alpine-sqs    | 2018-11-23 05:07:59,803 INFO success: insight entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
alpine-sqs    | 2018-11-23 05:07:59,803 INFO exited: sqs-init (exit status 0; expected)
alpine-sqs    | Loading config file from "/opt/sqs-insight/lib/../config/config_local.json"
alpine-sqs    | 05:08:00.080 [main] INFO  org.elasticmq.server.Main$ - Starting ElasticMQ server (0.14.6) ...
alpine-sqs    | Unable to load queues for  undefined
alpine-sqs    | Error: No endpoints configured
alpine-sqs    |     at /opt/sqs-insight/lib/index.js:61:15
alpine-sqs    |     at _fulfilled (/opt/sqs-insight/node_modules/q/q.js:854:54)
alpine-sqs    |     at self.promiseDispatch.done (/opt/sqs-insight/node_modules/q/q.js:883:30)
alpine-sqs    |     at Promise.promise.promiseDispatch (/opt/sqs-insight/node_modules/q/q.js:816:13)
alpine-sqs    |     at /opt/sqs-insight/node_modules/q/q.js:624:44
alpine-sqs    |     at runSingle (/opt/sqs-insight/node_modules/q/q.js:137:13)
alpine-sqs    |     at flush (/opt/sqs-insight/node_modules/q/q.js:125:13)
alpine-sqs    |     at _combinedTickCallback (internal/process/next_tick.js:131:7)
alpine-sqs    |     at process._tickDomainCallback (internal/process/next_tick.js:218:9)
alpine-sqs    | bye bye.
alpine-sqs    | npm ERR! code ELIFECYCLE
alpine-sqs    | npm ERR! errno 1
alpine-sqs    | npm ERR! sqs-insight@0.3.0 start: `node index.js`
alpine-sqs    | npm ERR! Exit status 1
alpine-sqs    | npm ERR! 
alpine-sqs    | npm ERR! Failed at the sqs-insight@0.3.0 start script.
alpine-sqs    | npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
alpine-sqs    | 
alpine-sqs    | npm ERR! A complete log of this run can be found in:
alpine-sqs    | npm ERR!     /root/.npm/_logs/2018-11-23T05_08_00_389Z-debug.log
alpine-sqs    | 2018-11-23 05:08:00,413 INFO exited: insight (exit status 1; not expected)
alpine-sqs    | 05:08:01.327 [elasticmq-akka.actor.default-dispatcher-4] INFO  akka.event.slf4j.Slf4jLogger - Slf4jLogger started
alpine-sqs    | 2018-11-23 05:08:01,329 INFO spawned: 'insight' with pid 64
alpine-sqs    | 
alpine-sqs    | > sqs-insight@0.3.0 start /opt/sqs-insight
alpine-sqs    | > node index.js
alpine-sqs    | 
alpine-sqs    | Loading config file from "/opt/sqs-insight/lib/../config/config_local.json"
alpine-sqs    | 2018-11-23 05:08:02,509 INFO success: insight entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
alpine-sqs    | Unable to load queues for  undefined
alpine-sqs    | Error: No endpoints configured
alpine-sqs    |     at /opt/sqs-insight/lib/index.js:61:15
alpine-sqs    |     at _fulfilled (/opt/sqs-insight/node_modules/q/q.js:854:54)
alpine-sqs    |     at self.promiseDispatch.done (/opt/sqs-insight/node_modules/q/q.js:883:30)
alpine-sqs    |     at Promise.promise.promiseDispatch (/opt/sqs-insight/node_modules/q/q.js:816:13)
alpine-sqs    |     at /opt/sqs-insight/node_modules/q/q.js:624:44
alpine-sqs    |     at runSingle (/opt/sqs-insight/node_modules/q/q.js:137:13)
alpine-sqs    |     at flush (/opt/sqs-insight/node_modules/q/q.js:125:13)
alpine-sqs    |     at _combinedTickCallback (internal/process/next_tick.js:131:7)
alpine-sqs    |     at process._tickDomainCallback (internal/process/next_tick.js:218:9)
alpine-sqs    | bye bye.
alpine-sqs    | npm ERR! code ELIFECYCLE
alpine-sqs    | npm ERR! errno 1
alpine-sqs    | npm ERR! sqs-insight@0.3.0 start: `node index.js`
alpine-sqs    | npm ERR! Exit status 1
alpine-sqs    | npm ERR! 
alpine-sqs    | npm ERR! Failed at the sqs-insight@0.3.0 start script.
alpine-sqs    | npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
alpine-sqs    | 
alpine-sqs    | npm ERR! A complete log of this run can be found in:
alpine-sqs    | npm ERR!     /root/.npm/_logs/2018-11-23T05_08_02_956Z-debug.log
alpine-sqs    | 2018-11-23 05:08:02,978 INFO exited: insight (exit status 1; not expected)
alpine-sqs    | 05:08:03.341 [elasticmq-akka.actor.default-dispatcher-3] INFO  o.e.rest.sqs.TheSQSRestServerBuilder - Started SQS rest server, bind address 0.0.0.0:9324, visible server address * (depends on incoming request path) 
alpine-sqs    | 2018-11-23 05:08:03,343 INFO spawned: 'insight' with pid 86
alpine-sqs    | 05:08:03.445 [elasticmq-akka.actor.default-dispatcher-3] INFO  o.elasticmq.actor.QueueManagerActor - Creating queue QueueData(default,MillisVisibilityTimeout(10000),PT5S,PT0S,2018-11-23T05:08:03.359Z,2018-11-23T05:08:03.359Z,None,false,false,None,None,Map())
alpine-sqs    | 05:08:03.489 [main] INFO  org.elasticmq.server.Main$ - === ElasticMQ server (0.14.6) started in 4451 ms ===
alpine-sqs    | 
alpine-sqs    | > sqs-insight@0.3.0 start /opt/sqs-insight
alpine-sqs    | > node index.js
alpine-sqs    | 
alpine-sqs    | Loading config file from "/opt/sqs-insight/lib/../config/config_local.json"
alpine-sqs    | 2018-11-23 05:08:04,375 INFO success: insight entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
alpine-sqs    | Config contains 1 queues.
alpine-sqs    | Adding consumer for default
alpine-sqs    | listening on port 9325

roribio commented 5 years ago

Hi,

Thank you for reporting this.

~I know npm has had some issues this past week but I don't know if this could be related to that.~ Definitely not related to the npm issues this week. It looks like it has to do with sqs-insight loading much quicker than elasticmq. This was probably introduced by the use of dynamic endpoints.

I'll investigate 🕵️ 👀

roribio commented 5 years ago

Supervisord doesn't support process dependencies with the autostart feature;

See supervisor bug #122.

Workaround: https://github.com/bendikro/supervisord-dependent-startup

Example: https://github.com/bendikro/supervisord-dependent-startup/blob/master/example.md

I'll work on implementing this shortly.

JackWCollins commented 5 years ago

@roribio This is perhaps a stupid question, but I haven't worked with python much. How do I implement that workaround? I've spent some time with the supervisord-dependent-startup package and I'm trying to build a new image of alpine-sqs with that package included. I've tried copying that full directory under /etc/supervisor and adding the following to supervisord.conf:

[eventlistener:dependentstartup]
command=python /etc/supervisor/supervisord_dependent_startup/supervisord_dependent_startup.py -c /etc/supervisor/supervisord.conf
autostart=true
events=PROCESS_STATE

However that doesn't seem to work. When I run this as a local_sqs container via docker-compose I get:

local_sqs_1  | 2019-02-21 06:22:46,611 INFO spawned: 'dependentstartup' with pid 13
local_sqs_1  | 2019-02-21 06:22:46,658 INFO exited: dependentstartup (exit status 1; not expected)

I'll be happy to submit a PR to fix this issue once I can figure out how to include this package. Do you have any advice?

roribio commented 5 years ago

Hey @JackWCollins,

Thanks for picking this up! I don't think it's a stupid question at all, I'm not a Python expert either.

I did some research and found a project that's using this same plugin, here. It's structured similarly as this project. Upon inspection, I conclude/assume the following:

You can install the plugin using pip. See example here.

For non-editable installs, the project is built locally in a temp dir and then installed normally. Note that if a satisfactory version of the package is already installed, the VCS source will not overwrite it without an –upgrade flag. VCS requirements pin the package version (specified in the setup.py file) of the target commit, not necessarily the commit itself.

-- Reference: PIP User Manual - VCS Support.

Apparently, pip is included with the alpine-base distribution and no further installation is required. I would double-check this is the case though.
It seems pip installs binaries to /usr/local/bin on Alpine Linux. See example here.
Once the plugin is installed and you configure the event listener, you can configure the startup order for services. There's an example for that, here.

I hope this helps! If you can get it to work, I'm glad to merge your changes and update the image on Docker Hub.

Thanks again, Ronald

roribio / alpine-sqs

Service startup errors #21