anaigini
Computer
- Dec 25, 2019
- 1
Hi,
I created a customized script to start httpd :
I can reload the service after applying the changes :
, however I get errors when I attempt to restart the service :
This is the error logged in journalctl -xe :
This is the errors logged in httpd error logs :
This is in the httpd access logs :
This is in /var/log/messages :
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 :
And these are the outputs :
Please help me debug the error, as I am not sure where and how to start.
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
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 -debugAnd 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 timeoutPlease help me debug the error, as I am not sure where and how to start.
