Eng-Tips is the largest engineering community on the Internet

Intelligent Work Forums for Engineering Professionals

Problem starting service with systemd scripts

Status
Not open for further replies.

anaigini

Computer
Dec 25, 2019
1
0
0
MY
Hi,

I created a customized script to start httpd :

Code:
[root@dev1-myeg system]# cat httpd.service
[Unit]
Description=The Apache HTTP Server
After=network.target remote-fs.target nss-lookup.target

[Service]
Type=notify
#EnvironmentFile=/opt/rh/httpd24/root/etc/sysconfig/httpd
#ExecStart=/usr/local/apache-2.4.33/bin/httpd $OPTIONS -DFOREGROUND
ExecStart=/usr/local/apache-2.4.33/bin/httpd -k start
ExecReload=/usr/local/apache-2.4.33/bin/httpd $OPTIONS -k graceful
ExecStop=/bin/kill -WINCH ${MAINPID}

# We want systemd to give httpd some time to finish gracefully, but still want
# it to kill httpd after TimeoutStopSec if something went wrong during the
# graceful stop. Normally, Systemd sends SIGTERM signal right after the
# ExecStop, which would kill httpd. We are sending useless SIGCONT here to give
# httpd time to finish.
KillSignal=SIGCONT
PrivateTmp=true

[Install]
WantedBy=multi-user.target
[root@dev1-myeg system]#

I can reload the service after applying the changes :
Code:
systemctl reload httpd
, however I get errors when I attempt to restart the service :

Code:
[root@dev1-myeg logs]# systemctl status httpd
● httpd.service - The Apache HTTP Server
   Loaded: loaded (/usr/lib/systemd/system/httpd.service; disabled; vendor preset: disabled)
   Active: failed (Result: timeout) since Thu 2019-12-19 15:16:38 +08; 1h 30min ago
  Process: 29026 ExecStop=/bin/kill -WINCH ${MAINPID} (code=exited, status=1/FAILURE)
  Process: 29022 ExecStart=/usr/local/apache-2.4.33/bin/httpd -k start (code=exited, status=0/SUCCESS)
 Main PID: 29022 (code=exited, status=0/SUCCESS)

Dec 19 15:15:08 dev1-myeg.int.myeg.com.my systemd[1]: Starting The Apache HTTP Server...
Dec 19 15:15:08 dev1-myeg.int.myeg.com.my kill[29026]: kill: cannot find process ""
Dec 19 15:15:08 dev1-myeg.int.myeg.com.my systemd[1]: httpd.service: control process exited, code=exited status=1
Dec 19 15:16:38 dev1-myeg.int.myeg.com.my systemd[1]: httpd.service stop-sigterm timed out. Killing.
Dec 19 15:16:38 dev1-myeg.int.myeg.com.my systemd[1]: Failed to start The Apache HTTP Server.
Dec 19 15:16:38 dev1-myeg.int.myeg.com.my systemd[1]: Unit httpd.service entered failed state.
Dec 19 15:16:38 dev1-myeg.int.myeg.com.my systemd[1]: httpd.service failed.
[root@dev1-myeg logs]#

This is the error logged in journalctl -xe :

Code:
Dec 19 15:14:02 dev1-myeg.int.myeg.com.my postfix/bounce[28209]: 79383479D7F: sender non-delivery notification: 89A5C47C211
Dec 19 15:14:02 dev1-myeg.int.myeg.com.my postfix/qmgr[5740]: 79383479D7F: removed
Dec 19 15:14:02 dev1-myeg.int.myeg.com.my postfix/local[28208]: 89A5C47C211: to=<root@dev1-myeg.int.myeg.com.my>, relay=local, delay=0.02, delays=0.01/0/0/0.01, dsn=5.2.2, status=bounced (c
Dec 19 15:14:02 dev1-myeg.int.myeg.com.my postfix/qmgr[5740]: 89A5C47C211: removed
Dec 19 15:14:09 dev1-myeg.int.myeg.com.my graylog-collector-sidecar[3251]: time="2019-12-19T15:14:09+08:00" level=error msg="[UpdateRegistration] Failed to report collector status to server
Dec 19 15:14:38 dev1-myeg.int.myeg.com.my graylog-collector-sidecar[3251]: time="2019-12-19T15:14:38+08:00" level=error msg="[RequestConfiguration] Fetching configuration failed: Get http:/
Dec 19 15:14:49 dev1-myeg.int.myeg.com.my graylog-collector-sidecar[3251]: time="2019-12-19T15:14:49+08:00" level=error msg="[UpdateRegistration] Failed to report collector status to server
Dec 19 15:14:50 dev1-myeg.int.myeg.com.my polkitd[3254]: Registered Authentication Agent for unix-process:28967:805245139 (system bus name :1.277996 [/usr/bin/pkttyagent --notify-fd 5 --fal
Dec 19 15:14:50 dev1-myeg.int.myeg.com.my systemd[1]: Reloading.
Dec 19 15:14:51 dev1-myeg.int.myeg.com.my polkitd[3254]: Unregistered Authentication Agent for unix-process:28967:805245139 (system bus name :1.277996, object path /org/freedesktop/PolicyKi
Dec 19 15:15:01 dev1-myeg.int.myeg.com.my systemd[1]: Started Session 137606 of user root.
-- Subject: Unit session-137606.scope has finished start-up
-- Defined-By: systemd
-- Support: [URL unfurl="true"]http://lists.freedesktop.org/mailman/listinfo/systemd-devel[/URL]
--
-- Unit session-137606.scope has finished starting up.
--
-- The start-up result is done.
Dec 19 15:15:01 dev1-myeg.int.myeg.com.my CROND[28999]: (root) CMD (cd /usr/local/apache31-MYEG/htdocs/myeg_new_ui && php artisan get:survey > /usr/local/apache31-MYEG/logs/getsurvey-cron.l
Dec 19 15:15:02 dev1-myeg.int.myeg.com.my postfix/pickup[25832]: 801D8479D7F: uid=0 from=<root>
Dec 19 15:15:02 dev1-myeg.int.myeg.com.my postfix/cleanup[28206]: 801D8479D7F: message-id=<20191219071502.801D8479D7F@dev1-myeg.int.myeg.com.my>
Dec 19 15:15:02 dev1-myeg.int.myeg.com.my postfix/qmgr[5740]: 801D8479D7F: from=<root@dev1-myeg.int.myeg.com.my>, size=2539, nrcpt=1 (queue active)
Dec 19 15:15:02 dev1-myeg.int.myeg.com.my postfix/local[28208]: 801D8479D7F: to=<root@dev1-myeg.int.myeg.com.my>, orig_to=<root>, relay=local, delay=0.43, delays=0.41/0/0/0.02, dsn=5.2.2, s
Dec 19 15:15:02 dev1-myeg.int.myeg.com.my postfix/cleanup[28206]: 889D247C211: message-id=<20191219071502.889D247C211@dev1-myeg.int.myeg.com.my>
Dec 19 15:15:02 dev1-myeg.int.myeg.com.my postfix/qmgr[5740]: 889D247C211: from=<>, size=4538, nrcpt=1 (queue active)
Dec 19 15:15:02 dev1-myeg.int.myeg.com.my postfix/bounce[28209]: 801D8479D7F: sender non-delivery notification: 889D247C211
Dec 19 15:15:02 dev1-myeg.int.myeg.com.my postfix/qmgr[5740]: 801D8479D7F: removed
Dec 19 15:15:02 dev1-myeg.int.myeg.com.my postfix/local[28208]: 889D247C211: to=<root@dev1-myeg.int.myeg.com.my>, relay=local, delay=0.02, delays=0.01/0/0/0.01, dsn=5.2.2, status=bounced (c
Dec 19 15:15:02 dev1-myeg.int.myeg.com.my postfix/qmgr[5740]: 889D247C211: removed
Dec 19 15:15:08 dev1-myeg.int.myeg.com.my polkitd[3254]: Registered Authentication Agent for unix-process:29016:805246855 (system bus name :1.277999 [/usr/bin/pkttyagent --notify-fd 5 --fal
Dec 19 15:15:08 dev1-myeg.int.myeg.com.my systemd[1]: Starting The Apache HTTP Server...
-- Subject: Unit httpd.service has begun start-up
-- Defined-By: systemd
-- Support: [URL unfurl="true"]http://lists.freedesktop.org/mailman/listinfo/systemd-devel[/URL]
--
-- Unit httpd.service has begun starting up.
Dec 19 15:15:08 dev1-myeg.int.myeg.com.my kill[29026]: kill: cannot find process ""
Dec 19 15:15:08 dev1-myeg.int.myeg.com.my systemd[1]: httpd.service: control process exited, code=exited status=1
Dec 19 15:15:18 dev1-myeg.int.myeg.com.my graylog-collector-sidecar[3251]: time="2019-12-19T15:15:18+08:00" level=error msg="[RequestConfiguration] Fetching configuration failed: Get http:/
Dec 19 15:15:29 dev1-myeg.int.myeg.com.my userhelper[29136]: pam_succeed_if(ovirt-container-list:auth): requirement "user = ovirtagent" was met by user "ovirtagent"
Dec 19 15:15:29 dev1-myeg.int.myeg.com.my userhelper[29136]: running '/usr/share/ovirt-guest-agent/container-list' with root privileges on behalf of 'ovirtagent'
Dec 19 15:15:29 dev1-myeg.int.myeg.com.my graylog-collector-sidecar[3251]: time="2019-12-19T15:15:29+08:00" level=error msg="[UpdateRegistration] Failed to report collector status to server
Dec 19 15:15:58 dev1-myeg.int.myeg.com.my graylog-collector-sidecar[3251]: time="2019-12-19T15:15:58+08:00" level=error msg="[RequestConfiguration] Fetching configuration failed: Get http:/
Dec 19 15:16:01 dev1-myeg.int.myeg.com.my systemd[1]: Started Session 137607 of user root.
-- Subject: Unit session-137607.scope has finished start-up
-- Defined-By: systemd
-- Support: [URL unfurl="true"]http://lists.freedesktop.org/mailman/listinfo/systemd-devel[/URL]
--
-- Unit session-137607.scope has finished starting up.
lines 1410-1458/1515 96%

This is the errors logged in httpd error logs :

Code:
[Thu Dec 19 15:15:08.522704 2019] [ssl:warn] [pid 29022:tid 140066466289472] AH01906: dev1.myeg.com.my:443:0 server certificate is a CA certificate (BasicConstraints: CA == TRUE !?)
[Thu Dec 19 15:15:08.532567 2019] [jk:warn] [pid 29022:tid 140066466289472] No JkShmFile defined in httpd.conf. Using default /usr/local/apache-2.4.33/logs/jk-runtime-status
[Thu Dec 19 15:15:08.556561 2019] [jk:error] [pid 29022] [Thu Dec 19 15:15:08 2019][29022:140066466289472] [debug] jk_shm_close::jk_shm.c (745): Closed shared memory /usr/local/apache-2.4.33/logs/jk-runtime-status.29022 childs=1
[Thu Dec 19 15:15:08.861044 2019] [ssl:warn] [pid 29025:tid 140066466289472] AH01906: dev1.myeg.com.my:443:0 server certificate is a CA certificate (BasicConstraints: CA == TRUE !?)
[Thu Dec 19 15:15:09.104449 2019] [jk:warn] [pid 29025:tid 140066466289472] No JkShmFile defined in httpd.conf. Using default /usr/local/apache-2.4.33/logs/jk-runtime-status
[Thu Dec 19 15:15:09.142371 2019] [mpm_event:notice] [pid 29025:tid 140066466289472] AH00489: Apache/2.4.33 (Unix) OpenSSL/1.0.2o PHP/5.6.36 mod_jk/1.2.43 configured -- resuming normal operations
[Thu Dec 19 15:15:09.142464 2019] [core:notice] [pid 29025:tid 140066466289472] AH00094: Command line: '/usr/local/apache-2.4.33/bin/httpd'
(END)

This is in the httpd access logs :

Code:
46.229.168.161 - - [19/Dec/2019:14:04:03 +0800] "GET /robots.txt HTTP/1.1" 200 24 "-" "Mozilla/5.0 (compatible; SemrushBot/6~bl; +[URL unfurl="true"]http://www.semrush.com/bot.html)"[/URL] TLSv1.2 ECDHE-RSA-AES128-GCM-SHA256
46.229.168.163 - - [19/Dec/2019:14:04:05 +0800] "GET /career/mymotor HTTP/1.1" 200 5341 "-" "Mozilla/5.0 (compatible; SemrushBot/6~bl; +[URL unfurl="true"]http://www.semrush.com/bot.html)"[/URL] TLSv1.2 ECDHE-RSA-AES128-GCM-SHA256
45.56.78.64 - - [19/Dec/2019:14:24:15 +0800] "GET /?0628182016134805143312 HTTP/1.1" 400 226
64.233.172.106 - - [19/Dec/2019:15:03:04 +0800] "GET /eservices/ HTTP/1.1" 200 1607
64.233.172.108 - - [19/Dec/2019:15:03:04 +0800] "GET /common/img/favicon.ico HTTP/1.1" 200 32942
(END)

This is in /var/log/messages :

Code:
Dec 19 15:14:50 dev1-myeg systemd: Reloading.
Dec 19 15:15:01 dev1-myeg systemd: Started Session 137606 of user root.
Dec 19 15:15:08 dev1-myeg systemd: Starting The Apache HTTP Server...
Dec 19 15:15:08 dev1-myeg kill: kill: cannot find process ""
Dec 19 15:15:08 dev1-myeg systemd: httpd.service: control process exited, code=exited status=1
Dec 19 15:15:18 dev1-myeg graylog-collector-sidecar: time="2019-12-19T15:15:18+08:00" level=error msg="[RequestConfiguration] Fetching configuration failed: Get [URL unfurl="true"]http://13.228.178.92:9000/ap[/URL]
i/plugins/org.graylog.plugins.collector/3fb08426-6b4b-4928-969f-913cb690dc3f?tags=%5B%22laravel%22%2C%22apache%22%5D: dial tcp 13.228.178.92:9000: i/o timeout"
Dec 19 15:15:29 dev1-myeg graylog-collector-sidecar: time="2019-12-19T15:15:29+08:00" level=error msg="[UpdateRegistration] Failed to report collector status to server: Put [URL unfurl="true"]http://13.228.17[/URL]
8.92:9000/api/plugins/org.graylog.plugins.collector/collectors/3fb08426-6b4b-4928-969f-913cb690dc3f: dial tcp 13.228.178.92:9000: i/o timeout"
Dec 19 15:15:58 dev1-myeg graylog-collector-sidecar: time="2019-12-19T15:15:58+08:00" level=error msg="[RequestConfiguration] Fetching configuration failed: Get [URL unfurl="true"]http://13.228.178.92:9000/ap[/URL]
i/plugins/org.graylog.plugins.collector/3fb08426-6b4b-4928-969f-913cb690dc3f?tags=%5B%22laravel%22%2C%22apache%22%5D: dial tcp 13.228.178.92:9000: i/o timeout"
Dec 19 15:16:01 dev1-myeg systemd: Started Session 137607 of user root.
Dec 19 15:16:09 dev1-myeg graylog-collector-sidecar: time="2019-12-19T15:16:09+08:00" level=error msg="[UpdateRegistration] Failed to report collector status to server: Put [URL unfurl="true"]http://13.228.17[/URL]
8.92:9000/api/plugins/org.graylog.plugins.collector/collectors/3fb08426-6b4b-4928-969f-913cb690dc3f: dial tcp 13.228.178.92:9000: i/o timeout"
Dec 19 15:16:38 dev1-myeg graylog-collector-sidecar: time="2019-12-19T15:16:38+08:00" level=error msg="[RequestConfiguration] Fetching configuration failed: Get [URL unfurl="true"]http://13.228.178.92:9000/ap[/URL]
i/plugins/org.graylog.plugins.collector/3fb08426-6b4b-4928-969f-913cb690dc3f?tags=%5B%22laravel%22%2C%22apache%22%5D: dial tcp 13.228.178.92:9000: i/o timeout"
Dec 19 15:16:38 dev1-myeg systemd: httpd.service stop-sigterm timed out. Killing.
Dec 19 15:16:38 dev1-myeg systemd: Failed to start The Apache HTTP Server.
Dec 19 15:16:38 dev1-myeg systemd: Unit httpd.service entered failed state.
Dec 19 15:16:38 dev1-myeg systemd: httpd.service failed.
Dec 19 15:16:49 dev1-myeg graylog-collector-sidecar: time="2019-12-19T15:16:49+08:00" level=error msg="[UpdateRegistration] Failed to report collector status to server: Put [URL unfurl="true"]http://13.228.178.92:9000/api/plugins/org.graylog.plugins.collector/collectors/3fb08426-6b4b-4928-969f-913cb690dc3f:[/URL] dial tcp 13.228.178.92:9000: i/o timeout"
Dec 19 15:17:01 dev1-myeg systemd: Started Session 137608 of user root.
Dec 19 15:17:18 dev1-myeg graylog-collector-sidecar: time="2019-12-19T15:17:18+08:00" level=error msg="[RequestConfiguration] Fetching configuration failed: Get [URL unfurl="true"]http://13.228.178.92:9000/api/plugins/org.graylog.plugins.collector/3fb08426-6b4b-4928-969f-913cb690dc3f?tags=%5B%22laravel%22%2C%22apache%22%5D:[/URL] dial tcp 13.228.178.92:9000: i/o timeout"
Dec 19 15:17:29 dev1-myeg graylog-collector-sidecar: time="2019-12-19T15:17:29+08:00" level=error msg="[UpdateRegistration] Failed to report collector status to server: Put [URL unfurl="true"]http://13.228.178.92:9000/api/plugins/org.graylog.plugins.collector/collectors/3fb08426-6b4b-4928-969f-913cb690dc3f:[/URL] dial tcp 13.228.178.92:9000: i/o timeout"
Dec 19 15:17:58 dev1-myeg graylog-collector-sidecar: time="2019-12-19T15:17:58+08:00" level=error msg="[RequestConfiguration] Fetching configuration failed: Get [URL unfurl="true"]http://13.228.178.92:9000/api/plugins/org.graylog.plugins.collector/3fb08426-6b4b-4928-969f-913cb690dc3f?tags=%5B%22laravel%22%2C%22apache%22%5D:[/URL] dial tcp 13.228.178.92:9000: i/o timeout"
Dec 19 15:18:01 dev1-myeg systemd: Started Session 137609 of user root.
Dec 19 15:18:09 dev1-myeg graylog-collector-sidecar: time="2019-12-19T15:18:09+08:00" level=error msg="[UpdateRegistration] Failed to report collector status to server: Put [URL unfurl="true"]http://13.228.178.92:9000/api/plugins/org.graylog.plugins.collector/collectors/3fb08426-6b4b-4928-969f-913cb690dc3f:[/URL] dial tcp 13.228.178.92:9000: i/o timeout"
Dec 19 15:18:38 dev1-myeg graylog-collector-sidecar: time="2019-12-19T15:18:38+08:00" level=error msg="[RequestConfiguration] Fetching configuration failed: Get [URL unfurl="true"]http://13.228.178.92:9000/ap:[/URL]

I notice that somehow the graylog-collector-sidecar errors also show after the httpd failures, and also a lot of messages on "ovirt" appear together with them too. How are all of these related?

I ran the command :

Code:
# /usr/bin/graylog-collector-sidecar -debug

And these are the outputs :

Code:
[root@dev1-myeg collector-sidecar]# /usr/bin/graylog-collector-sidecar -debug
INFO[0000] Using collector-id: 3fb08426-6b4b-4928-969f-913cb690dc3f
INFO[0000] No node-id was configured, falling back to hostname
INFO[0000] Fetching configurations tagged by: [laravel apache]
DEBU[0000] Creating rotated log writer for: /var/log/graylog/collector-sidecar/collector_sidecar.log.%Y%m%d%H%M
DEBU[0000] Add collector backend: filebeat
INFO[0000] Starting signal distributor
DEBU[0000] [signal-processor] (seq=1) handling cmd: restart
INFO[0000] [filebeat] Starting (exec driver)
DEBU[0000] Creating rotated log writer for: /var/log/graylog/collector-sidecar/filebeat_stderr.log.%Y%m%d%H%M
DEBU[0000] Creating rotated log writer for: /var/log/graylog/collector-sidecar/filebeat_stderr.log.%Y%m%d%H%M
DEBU[0000] [signal-processor] (seq=1) cmd done: restart
ERRO[0001] [filebeat] Backend finished unexpectedly, trying to restart 1/3.
DEBU[0001] [signal-processor] (seq=2) handling cmd: restart
INFO[0001] [filebeat] Stopping
DEBU[0003] [filebeat] SIGHUP ignored, killing process
DEBU[0003] [filebeat] Failed to kill process os: process already finished
INFO[0003] [filebeat] Starting (exec driver)
DEBU[0003] Creating rotated log writer for: /var/log/graylog/collector-sidecar/filebeat_stderr.log.%Y%m%d%H%M
DEBU[0003] Creating rotated log writer for: /var/log/graylog/collector-sidecar/filebeat_stderr.log.%Y%m%d%H%M
DEBU[0003] [signal-processor] (seq=2) cmd done: restart
ERRO[0004] [filebeat] Backend finished unexpectedly, trying to restart 2/3.
DEBU[0004] [signal-processor] (seq=3) handling cmd: restart
INFO[0004] [filebeat] Stopping
DEBU[0006] [filebeat] SIGHUP ignored, killing process
DEBU[0006] [filebeat] Failed to kill process os: process already finished
INFO[0006] [filebeat] Starting (exec driver)
DEBU[0006] Creating rotated log writer for: /var/log/graylog/collector-sidecar/filebeat_stderr.log.%Y%m%d%H%M
DEBU[0006] Creating rotated log writer for: /var/log/graylog/collector-sidecar/filebeat_stderr.log.%Y%m%d%H%M
DEBU[0006] [signal-processor] (seq=3) cmd done: restart
ERRO[0007] [filebeat] Backend finished unexpectedly, trying to restart 3/3.
DEBU[0007] [signal-processor] (seq=4) handling cmd: restart
INFO[0007] [filebeat] Stopping
DEBU[0009] [filebeat] SIGHUP ignored, killing process
DEBU[0009] [filebeat] Failed to kill process os: process already finished
INFO[0009] [filebeat] Starting (exec driver)
DEBU[0009] Creating rotated log writer for: /var/log/graylog/collector-sidecar/filebeat_stderr.log.%Y%m%d%H%M
DEBU[0009] Creating rotated log writer for: /var/log/graylog/collector-sidecar/filebeat_stderr.log.%Y%m%d%H%M
DEBU[0009] [signal-processor] (seq=4) cmd done: restart
ERRO[0010] [filebeat] Unable to start collector after 3 tries, giving up!







ERRO[1800] [RequestConfiguration] Fetching configuration failed: Get [URL unfurl="true"]http://13.228.178.92:9000/api/plugins/org.graylog.plugins.collector/3fb08426-6b4b-4928-969f-913cb690dc3f?tags=%5B%22laravel%22%2C%22apache%22%5D:[/URL] dial tcp 13.228.178.92:9000: i/o timeout
ERRO[1800] [UpdateRegistration] Failed to report collector status to server: Put [URL unfurl="true"]http://13.228.178.92:9000/api/plugins/org.graylog.plugins.collector/collectors/3fb08426-6b4b-4928-969f-913cb690dc3f:[/URL] dial tcp 13.228.178.92:9000: i/o timeout

Please help me debug the error, as I am not sure where and how to start.
 
Status
Not open for further replies.
Back
Top