apache error.log

 ( spgabor | 2018. szeptember 3., hétfő - 10:02 )

Sziasztok!

Debian 8-on minden nap az error.log-ot az Apache frissítés előtt/után rögzíti a következő üzeneteket. Mindig ugyan azokat a hibákat azonos időpontban. Az SSL hiba már frissítés előtt is jelen volt, viszont a
[mpm_prefork:warn] [pid 31023] AH00167: long lost child came home!
üzenet biztos, hogy az óta jött elő. A többiben már nem vagyok biztos.
Ezekkel kell szerintetek foglalkoznom? Mit tudok tenni velük, hogy ne okozzanak problémát?


[Sun Sep 02 07:35:02.204182 2018] [:notice] [pid 2732] FastCGI: process manager initialized (pid 2732)
[ 2018-09-02 07:35:02.2142 2734/7fb6c8a39740 agents/Watchdog/Main.cpp:538 ]: Options: { 'analytics_log_user' => 'nobody', 'default_group' => 'nogroup', 'default_python' => 'python', 'default_ruby' => '/usr/bin/ruby', 'default_user' => 'nobody', 'log_level' => '0', 'max_pool_size' => '6', 'passenger_root' => '/usr/lib/ruby/vendor_ruby/phusion_passenger/locations.ini', 'passenger_version' => '4.0.53', 'pool_idle_time' => '300', 'temp_dir' => '/tmp', 'union_station_gateway_address' => 'gateway.unionstationapp.com', 'union_station_gateway_port' => '443', 'user_switching' => 'true', 'web_server_passenger_version' => '4.0.53', 'web_server_pid' => '31023', 'web_server_type' => 'apache', 'web_server_worker_gid' => '33', 'web_server_worker_uid' => '33' }
[ 2018-09-02 07:35:02.2275 2737/7fee0b973740 agents/HelperAgent/Main.cpp:650 ]: PassengerHelperAgent online, listening at unix:/tmp/passenger.1.0.31023/generation-3/request
[ 2018-09-02 07:35:02.2433 2747/7f5894e3e780 agents/LoggingAgent/Main.cpp:321 ]: PassengerLoggingAgent online, listening at unix:/tmp/passenger.1.0.31023/generation-3/logging
[ 2018-09-02 07:35:02.2434 2734/7fb6c8a39740 agents/Watchdog/Main.cpp:728 ]: All Phusion Passenger agents started!
[Sun Sep 02 07:35:02.278629 2018] [ssl:warn] [pid 31023] AH01906: levelezo_cime:8080:0 server certificate is a CA certificate (BasicConstraints: CA == TRUE !?)
[Sun Sep 02 07:35:02.278653 2018] [ssl:warn] [pid 31023] AH01909: levelezo_cime:8080:0 server certificate does NOT include an ID which matches the server name
[Sun Sep 02 07:35:02.278698 2018] [ssl:error] [pid 31023] AH02217: ssl_stapling_init_cert: can't retrieve issuer certificate! [subject: emailAddress=postmaster@levelezo.hu,CN=mail.levelezo.hu,OU=IT,O=Ceg Kft,L=Telepules,ST=Megye,C=HU / issuer: emailAddress=postmaster@levelezo.hu,CN=mail.levelezo.hu,OU=IT,O=Ceg,L=Telepules,ST=Megye,C=HU / serial: E90118B9F3D4B5D2 / notbefore: May 1 05:20:35 2016 GMT / notafter: Apr 29 05:20:35 2026 GMT]
[Sun Sep 02 07:35:02.278704 2018] [ssl:error] [pid 31023] AH02567: Unable to configure certificate levelezo_cime:8080:0 for stapling
[Sun Sep 02 07:35:02.278973 2018] [mpm_prefork:notice] [pid 31023] AH00163: Apache/2.4.10 (Debian) mod_fastcgi/mod_fastcgi-SNAP-0910052141 mod_fcgid/2.3.9 Phusion_Passenger/4.0.53 OpenSSL/1.0.1t mod_wsgi/4.3.0 Python/3.4.2 configured -- resuming normal operations
[Sun Sep 02 07:35:02.278986 2018] [core:notice] [pid 31023] AH00094: Command line: '/usr/sbin/apache2'
[Sun Sep 02 07:35:02.279017 2018] [mpm_prefork:warn] [pid 31023] AH00167: long lost child came home! (pid 12683)
[Mon Sep 03 07:35:02.848270 2018] [mpm_prefork:notice] [pid 31023] AH00171: Graceful restart requested, doing restart

Köszönöm a segítséget előre is!

Üdv:
spgabor

Hozzászólás megjelenítési lehetőségek

A választott hozzászólás megjelenítési mód a „Beállítás” gombbal rögzíthető.

Gondolom napi logrotate inditja ujra mindig ilyenkor, jo esellyel egy reload is eleg lenne annak, szoval nezd meg /etc/logrotate.d/apache* konfigokat.

Igen, a logrotate indítja. Amikor észrevettem a hibát, akkor fórumokon azt olvastam, hogy Apache újraindítás. De ez múlt héten volt. Az óta is minden reggel megjelenik az üzenet.

Gondolom logrotate konfig szerint naponta rotalja a logokat, amihez daily cron altalaban 6:25-kor szokott lefutni rendszerekben (nalad gondolom timezone elteres okozhatja hogy 7:35-kori log vna rola), jo esellyel eleg lenne atirni logrotete apache konfigjat reload-ra, de lehet egyszerubb ha bemasolod hogy nez ki most az a konfig.

Ez az apache logrotate:


/var/log/apache2/*.log {
daily
missingok
rotate 14
compress
delaycompress
notifempty
create 666 root adm
sharedscripts
postrotate
if /etc/init.d/apache2 status > /dev/null ; then \
/etc/init.d/apache2 reload > /dev/null; \
fi;
endscript
prerotate
if [ -d /etc/logrotate.d/httpd-prerotate ]; then \
run-parts /etc/logrotate.d/httpd-prerotate; \
fi; \
endscript
}

Pedig ez meg nem indokolja az apache restartot, nezd meg esetleg /etc/logrotate.d/httpd-prerotate letezik-e es ha igen mi van benne.
Masik lehetoseg amire gondolni tudok hogy ottmaradt korabbrol valami mas logrotate ami szinten lefut, nezd meg tobbi logrotate konfigban lehet-e ami apache-ot erinti.
Esetleg meg azt nezd meg milyen cronjob-ok futnak le, hatha oda kerult be valami ami okozza, azokban van-e ami apache-ot erinti: /etc/cron.daily/ , /etc/cron.d/, crontab
Netan automata csomag frissites ami lefut cron-bol es ha frissul apache (es/vagy php es tarsai) akkor inditja ujra, logokban nezd meg csomagfrissitesek voltak-e reggelente amikor megjelent apache ujrainditas a logokban.

Szia,

/etc/logrotate.d/httpd-prerotate fájl nincsen, illetve a tbbi logrotate-ban nem láttam apache újraindítás sort.
A /etc/cron.daily/-ben van egy apache2 fájl, aminek ez a tartalma, de ebben sem látok olyat, hogy újraindítaná:


#!/bin/sh

# run htcacheclean

set -e
set -u

type htcacheclean > /dev/null 2>&1 || exit 0
[ -e /etc/default/apache2 ] || exit 0

# edit /etc/default/apache2 to change this
HTCACHECLEAN_MODE=daemon
HTCACHECLEAN_RUN=auto
HTCACHECLEAN_SIZE=300M
HTCACHECLEAN_PATH=/var/cache/apache2/mod_cache_disk
HTCACHECLEAN_OPTIONS=""

. /etc/default/apache2

[ "$HTCACHECLEAN_MODE" = "cron" ] || exit 0

[ "$HTCACHECLEAN_RUN" = "yes" ] ||
( [ "$HTCACHECLEAN_RUN" = "auto" ] && \
[ -e /etc/apache2/mods-enabled/cache_disk.load ] ) || exit 0

htcacheclean ${HTCACHECLEAN_OPTIONS} \
-p${HTCACHECLEAN_PATH} \
-l${HTCACHECLEAN_SIZE}

crontab pedig a következőket tartalmazza csak:

# /etc/crontab: system-wide crontab
# Unlike any other crontab you don't have to run the `crontab'
# command to install the new version when you edit this file
# and files in /etc/cron.d. These files also have username fields,
# that none of the other crontabs do.

SHELL=/bin/sh
PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin

# m h dom mon dow user command
17 * * * * root cd / && run-parts --report /etc/cron.hourly
25 6 * * * root test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
47 6 * * 7 root test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.weekly )
52 6 1 * * root test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.monthly )
#

A frissítés után Roundcube lett telepítve a szerverre a következő leírás alapján:
https://www.howtoforge.com/tutorial/perfect-server-debian-8-4-jessie-apache-bind-dovecot-ispconfig-3-1/3/

Nem tudom, hogy ez kavarta-e meg, de elötte leklónoztam a szervert és csináltam egy próbát a frissítésekkel és a Roundcube telepítéssel, de ott nem volt ez a probléma a log szerint. A két szervernek elvileg megegyezik, mert a teszt alapján írtam egy doksit és úgy csináltam vég az élesen is.

Esetleg valakinek van ötlete?
Néztem a napokban hogy mi indítja újra az apache-ot, és arra jöttem rá, hogy mégis csak a logrotate csinálja. Mivel mint fent is látható az apache logrotate-ban, van benne egy vizsgálat a postrotate alatt. Itt az if-ben lévő feltételbe minden reggel belefut. Ezt abból következtetem, hogy a postrotate if feltételébe tettem egy plusz sort, ami minden alkalommal reload előtt a pontos időpontot beleírja egy fájlba. Már csak azt nem értem, hogy miért igaz minden alkalommal az if feltétele? Ha jól értelmezem, a feltétel azt vizsgálja, hogy az apache2 fut-e, de nem látok olyan naplóbejegyzést, hogy ne így lenne. Akkor mégis miért fut bele? Vagy rosszul értelmezem?

Nezd meg mit tartalmaz a /etc/init.d/apache2 reload resze, hatha az restart-ot csinal valojaban, vagy futtasd le kezzel es logban mi latszik.
Egyebkent le lehetne cserelni azt a reszt hogy systemctl -el hivja meg aminek megadhatod reload-or-restart vagy try-reload-or-restart -al meghivni:
systemctl reload-or-restart apache2

reload-or-restart NAME... Reload one or more units if possible,
otherwise start or restart
try-reload-or-restart NAME... If active, reload one or more units,
if supported, otherwise restart

Vagy azzal lekerdezni hogy fut-e:
systemctl is-active apache2
De esetleg apachectl vagy apache2ctl-el is megnezheted, talan abban is van reload vagy statust lekerdezni.

Szia!

/etc/init.d/apache2-ben lévő reload bejegyzéseket a következőket találtam:

do_reload() {
if apache_conftest; then
if ! pidofproc -p $PIDFILE "$DAEMON" > /dev/null 2>&1 ; then
APACHE2_INIT_MESSAGE="Apache2 is not running"
return 2
fi
$APACHE2CTL graceful > /dev/null 2>&1
return $?
else
APACHE2_INIT_MESSAGE="The apache2$DIR_SUFFIX configtest failed. Not doing anything."
return 2
fi
}

illetve egy case függvényen belül a következők:


reload|force-reload|graceful)
log_daemon_msg "Reloading $DESC" "$NAME"
do_reload
RET_STATUS=$?
case "$RET_STATUS" in
0|1)
log_success_msg
[ "$VERBOSE" != no ] && [ $RET_STATUS = 1 ] && log_warning_msg "Server was already running"
;;
2)
log_failure_msg
print_error_msg
exit 1
;;
esac
print_error_msg
;;

A systemctl lecserélését nem tudom hol értetted. Ezt tudnád pontosítani? Viszont ha kézzel futtatom az apache2 reload parancsot, akkor ugyanaz történik az error.log szerint, mint korábban. Ugyan az a log kerül bele. Illetve amit írtál, a systemctl reload-or-restart apache2 parancsot futtatva is az eddigivel azonos tartalom kerül be az error.log-ba.
A systemctl is-active apache2-vel lekérdezve active válasz jön vissza ettől függetlenül. Illetve ha /etc/init-d/apache2 status-ra is az jön vissza, hogy fut.

Akkor reload eseten is elojon ez, systemctl-re cserelesre annyira gondoltam hogy logoratete-be /etc/init.d/apache2 reload helyett systemctl reload apache2 -t irni, de ha kezzel futtatva is ugyanaz akkor felesleges.

Ugy remlett, lehet valami massal kevertem hogy apachectl/apache2ctl-ben van reload is, nem csak restart (graceful is lenyegeben restart csak meglevo kapcsolatokat megtartja).

Viszont igy akkor aligha azzal van gond hogy ott nem reload tortenik valojaban, az fut le, csak az ad ilyen hibat.

Gyorsan keresgelve a hibara lehet megoldas lehet restart-ra cserelni (probald ha azzal futtatod kezzel akkor is ott-e a hibauzenet, persze ez azt takarja hogy akkor megszakadnak aktualis kapcsolatok, vagy elfogadod ezt a hibauzenetet (bar ezt 2.0-s apachenal irjak de hatha tobbire is ervenyes csak lemaradt a doksibol):
http://httpd.apache.org/docs/2.0/stopping.html

"Architectures that use an on-disk ScoreBoardFile can potentially have their scoreboards corrupted. This can result in the "bind: Address already in use" (after HUP) or "long lost child came home!" (after USR1). The former is a fatal error, while the latter just causes the server to lose a scoreboard slot. So it may be advisable to use graceful restarts, with an occasional hard restart. These problems are very difficult to work around, but fortunately most architectures do not require a scoreboard file. See the ScoreBoardFile documentation for architecture which uses it."

Restart-ra nem jön a hibaüzenet utolsó sora. Viszont ha utána egyből reload-ot is próbálok, ismét jön a hibaüzenet.
Nézegettem a ScoreBoard-ot a neten, hogy mit is csinál, de nem ismerem a pontos működését. Okozhatja ez a problémát? Lehet vele kezdeni valamit?

Ma reggel logrotate előtt kivettem a fájlbol a prerotate opciót. Így az újraindítás nem történt meg.


● apache2.service - LSB: Apache2 web server
Loaded: loaded (/etc/init.d/apache2)
Drop-In: /lib/systemd/system/apache2.service.d
└─forking.conf
Active: active (running) since cs 2018-08-30 13:43:11 CEST; 2 weeks 4 days ago
Process: 30960 ExecStop=/etc/init.d/apache2 stop (code=exited, status=0/SUCCESS)
Process: 1704 ExecReload=/etc/init.d/apache2 reload (code=exited, status=0/SUCCESS)
Process: 30987 ExecStart=/etc/init.d/apache2 start (code=exited, status=0/SUCCESS)
CGroup: /system.slice/apache2.service
├─ 1729 vlogger (access log
├─ 1730 /usr/sbin/fcgi-pm -k start
├─ 1731 /usr/sbin/apache2 -k start
├─ 1732 PassengerWatchdog
├─ 1735 PassengerHelperAgent
├─ 1743 PassengerLoggingAgent
├─ 1755 /usr/sbin/apache2 -k start
├─ 1756 /usr/sbin/apache2 -k start
├─ 1757 /usr/sbin/apache2 -k start
├─ 1758 /usr/sbin/apache2 -k start
├─ 1759 /usr/sbin/apache2 -k start
├─ 6439 /usr/sbin/apache2 -k start
├─22964 /usr/sbin/apache2 -k start
├─24047 /usr/sbin/apache2 -k start
├─24048 /usr/sbin/apache2 -k start
├─24053 /usr/sbin/apache2 -k start
├─24056 /usr/sbin/apache2 -k start
└─31023 /usr/sbin/apache2 -k start

szept 14 07:35:02 mailstylhu systemd[1]: Reloaded LSB: Apache2 web server.
szept 15 07:35:01 mailstylhu systemd[1]: Reloading LSB: Apache2 web server.
szept 15 07:35:02 mailstylhu apache2[21184]: Reloading web server: apache2.
szept 15 07:35:02 mailstylhu systemd[1]: Reloaded LSB: Apache2 web server.
szept 16 07:35:02 mailstylhu systemd[1]: Reloading LSB: Apache2 web server.
szept 16 07:35:02 mailstylhu apache2[11297]: Reloading web server: apache2.
szept 16 07:35:02 mailstylhu systemd[1]: Reloaded LSB: Apache2 web server.
szept 17 07:35:02 mailstylhu systemd[1]: Reloading LSB: Apache2 web server.
szept 17 07:35:02 mailstylhu apache2[1704]: Reloading web server: apache2.
szept 17 07:35:02 mailstylhu systemd[1]: Reloaded LSB: Apache2 web server.

Most kicsit több task-ban fut, de remélem ez nem okoz hosszú távon problémát.