apache2 startet nur wenn ich error.log.1 anschaue

[michaa7]

system: debian/sid(uction), tagesaktuell


Ich hatte letzte woche hier schon einen fehlerbericht verfaßt (noch nicht gepostet), dann startete apache2 plötzlich doch, also habe ich das posting dann doch nicht abgeschickt. Nun aber wieder das gleiche: Obwohl apache die letzten tage sich anstandslos starten ließ (systemctl start apache2) gelang dies heute wieder nicht. Es kam zur wohl allseits bekannten fehlermeldung:

Job for apache2.service failed because the control process exited with error code.
See "systemctl status apache2.service" and "journalctl -xe" for details.

Das error log enthält 0 bytes, der letzte eintrag im error.log.1 stammt von gestern:

[Fri Sep 22 00:03:52.827614 2017] [mpm_event:notice] [pid 5987:tid 140028461839552] AH00491: caught SIGTERM, shutt$

ok, ich habe den rechner herunter gefahren ohne vorher apache2 zu beenden.

Ist das tatsächlich so: Apache2 bekommt mit ob ich (root) error.log.1 angeschaut habe, und wenn nicht startet er nicht?

???

[schwedenmann]

Hallo


was sagt denn:

systemctl status apache2 ?

mfg
schwedenmann

[michaa7]

Ich kann dir "nur" journalctl -xe bieten, das hatte ich noch im terminalemulator:

# journalctl -xe | grep apache
-- Subject: Unit apache2.service has begun start-up
-- Unit apache2.service has begun starting up.
Sep 23 09:56:47 neutower apachectl[682]: AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.0.1. Set the 'ServerName' directive globally to suppress this message
Sep 23 09:56:47 neutower apachectl[682]: (98)Address already in use: AH00072: make_sock: could not bind to address 192.168.2.13:80
Sep 23 09:56:47 neutower apachectl[682]: no listening sockets available, shutting down
Sep 23 09:56:47 neutower apachectl[682]: AH00015: Unable to open logs
Sep 23 09:56:47 neutower apachectl[682]: Action 'start' failed.
Sep 23 09:56:47 neutower apachectl[682]: The Apache error log may have more information.
Sep 23 09:56:47 neutower systemd[1]: apache2.service: Control process exited, code=exited status=1
-- Subject: Unit apache2.service has failed
-- Unit apache2.service has failed.
Sep 23 09:56:47 neutower systemd[1]: apache2.service: Unit entered failed state.
Sep 23 09:56:47 neutower systemd[1]: apache2.service: Failed with result 'exit-code'.
-- Subject: Unit apache-htcacheclean.service has begun start-up
-- Unit apache-htcacheclean.service has begun starting up.
-- Subject: Unit apache-htcacheclean.service has finished start-up
-- Unit apache-htcacheclean.service has finished starting up.
-- Subject: Unit apache2.service has begun start-up
-- Unit apache2.service has begun starting up.
Sep 23 11:53:58 neutower apachectl[16023]: AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.0.1. Set the 'ServerName' directive globally to suppress this message
Sep 23 11:53:58 neutower apachectl[16023]: (98)Address already in use: AH00072: make_sock: could not bind to address 192.168.2.13:80
Sep 23 11:53:58 neutower apachectl[16023]: no listening sockets available, shutting down
Sep 23 11:53:58 neutower apachectl[16023]: AH00015: Unable to open logs
Sep 23 11:53:58 neutower systemd[1]: apache2.service: Control process exited, code=exited status=1
Sep 23 11:53:58 neutower apachectl[16023]: Action 'start' failed.
Sep 23 11:53:58 neutower apachectl[16023]: The Apache error log may have more information.
-- Subject: Unit apache2.service has failed
-- Unit apache2.service has failed.
Sep 23 11:53:58 neutower systemd[1]: apache2.service: Unit entered failed state.
Sep 23 11:53:58 neutower systemd[1]: apache2.service: Failed with result 'exit-code'.
-- Subject: Unit apache2.service has begun start-up
-- Unit apache2.service has begun starting up.
Sep 23 11:54:31 neutower apachectl[16297]: AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.0.1. Set the 'ServerName' directive globally to suppress this message
Sep 23 11:54:31 neutower apachectl[16297]: (98)Address already in use: AH00072: make_sock: could not bind to address 192.168.2.13:80
Sep 23 11:54:31 neutower apachectl[16297]: no listening sockets available, shutting down
Sep 23 11:54:31 neutower apachectl[16297]: AH00015: Unable to open logs
Sep 23 11:54:31 neutower apachectl[16297]: Action 'start' failed.
Sep 23 11:54:31 neutower apachectl[16297]: The Apache error log may have more information.
Sep 23 11:54:31 neutower systemd[1]: apache2.service: Control process exited, code=exited status=1
-- Subject: Unit apache2.service has failed
-- Unit apache2.service has failed.
Sep 23 11:54:31 neutower systemd[1]: apache2.service: Unit entered failed state.
Sep 23 11:54:31 neutower systemd[1]: apache2.service: Failed with result 'exit-code'.
-- Subject: Unit apache2.service has begun start-up
-- Unit apache2.service has begun starting up.
Sep 23 11:54:52 neutower apachectl[16541]: AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.0.1. Set the 'ServerName' directive globally to suppress this message
Sep 23 11:54:52 neutower apachectl[16541]: (98)Address already in use: AH00072: make_sock: could not bind to address 192.168.2.13:80
Sep 23 11:54:52 neutower apachectl[16541]: no listening sockets available, shutting down
Sep 23 11:54:52 neutower apachectl[16541]: AH00015: Unable to open logs
Sep 23 11:54:52 neutower apachectl[16541]: Action 'start' failed.
Sep 23 11:54:52 neutower apachectl[16541]: The Apache error log may have more information.
Sep 23 11:54:52 neutower systemd[1]: apache2.service: Control process exited, code=exited status=1
-- Subject: Unit apache2.service has failed
-- Unit apache2.service has failed.
Sep 23 11:54:52 neutower systemd[1]: apache2.service: Unit entered failed state.
Sep 23 11:54:52 neutower systemd[1]: apache2.service: Failed with result 'exit-code'.
-- Subject: Unit apache2.service has begun start-up
-- Unit apache2.service has begun starting up.
Sep 23 11:55:53 neutower apachectl[17218]: AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.0.1. Set the 'ServerName' directive globally to suppress this message
Sep 23 11:55:53 neutower apachectl[17218]: (98)Address already in use: AH00072: make_sock: could not bind to address 192.168.2.13:80
Sep 23 11:55:53 neutower apachectl[17218]: no listening sockets available, shutting down
Sep 23 11:55:53 neutower apachectl[17218]: AH00015: Unable to open logs
Sep 23 11:55:53 neutower apachectl[17218]: Action 'start' failed.
Sep 23 11:55:53 neutower apachectl[17218]: The Apache error log may have more information.
Sep 23 11:55:53 neutower systemd[1]: apache2.service: Control process exited, code=exited status=1
-- Subject: Unit apache2.service has failed
-- Unit apache2.service has failed.
Sep 23 11:55:53 neutower systemd[1]: apache2.service: Unit entered failed state.
Sep 23 11:55:53 neutower systemd[1]: apache2.service: Failed with result 'exit-code'.

Es lief aber garantiert kein server, wie htop bewies.

In beiden fällen hat das betrachten (nicht bearbeiten/löschen!!!) des apache logs dazu geführt, dass sich der apache wieder starten ließ.

[DeletedUserReAsG]

Wenn dort steht, es könne nicht gestartet werden, weil auf der IP/Port-Kombi schon was liefe, kann man das mit etwa netstat prüfen.

[michaa7]

das werde ich das nächste mal testen mit netstat, aber ich bin sicher, da lief nichts, hätte ich ja auch in htop gesehen. Und der apache ließ sich ja nach betrachten des logs anwerfen, habe ich die letzten zwei male so beobachtet.

[DeletedUserReAsG]

das werde ich das nächste mal testen mit netstat, aber ich bin sicher, da lief nichts, hätte ich ja auch in htop gesehen.

htop zeigt dir nicht an, was auf welcher IP an welchem Port am Netz lauscht. Das lässt sich halt mit z.B. netstat rausfinden.

Dass es nach dem Anschauen der Logs geht, würde ich eher so interpretieren, dass es nach einer gewissen Zeit wieder geht (in der du halt zufällig ins Log geschaut hast). Da ist keiner, der schaut, ob du ins Log guckst und erst dann den Port freigibt.

[michaa7]

Ok, es mag sein wie es will, tatsache ist:

Der rechner läuft nun seit 1,5 stunden, jetzt erst versuche ich den apache zu starten, heute geht es wieder mal nicht.

netstat -tulpn zeigt nichts was an port 80 der LAN Ip horchen würde,

# netstat -tulpn | grep :80
tcp6 0 0 :::80 :::* LISTEN 1/init

"systemctl status apache2.service" zeigt

● apache2.service - The Apache HTTP Server
Loaded: loaded (/lib/systemd/system/apache2.service; enabled; vendor preset: enabled)
Active: failed (Result: exit-code) since Mon 2017-09-25 20:17:56 CEST; 3min 40s ago
Process: 32523 ExecStart=/usr/sbin/apachectl start (code=exited, status=1/FAILURE)

Sep 25 20:17:56 neutower apachectl[32523]: AH00558: apache2: Could not reliably determine the server's fully qualifie$
Sep 25 20:17:56 neutower apachectl[32523]: (98)Address already in use: AH00072: make_sock: could not bind to address $
Sep 25 20:17:56 neutower apachectl[32523]: no listening sockets available, shutting down
Sep 25 20:17:56 neutower apachectl[32523]: AH00015: Unable to open logs
Sep 25 20:17:56 neutower apachectl[32523]: Action 'start' failed.
Sep 25 20:17:56 neutower apachectl[32523]: The Apache error log may have more information.
Sep 25 20:17:56 neutower systemd[1]: ^[[0;1;39mapache2.service: Control process exited, code=exited status=1
Sep 25 20:17:56 neutower systemd[1]: Failed to start The Apache HTTP Server.
Sep 25 20:17:56 neutower systemd[1]: ^[[0;1;39mapache2.service: Unit entered failed state.
Sep 25 20:17:56 neutower systemd[1]: ^[[0;1;39mapache2.service: Failed with result 'exit-code'.

und ja, das betrachten das logs führt auch zu nichts. Merkwürdig jedoch, das other_vhost_access.log (0 byte) hat einen zeitstempel von heute morgen. Da startete ich zwar kurz den rechner bevor ich auf die arbeit ging, startete aber den apache nicht.

Aber wie auch immer, es geht mir ziemlich auf den senkel, dass sich der apache immer wieder nicht starten läßt, ich keinen wirklichen fehler finde, und irgendwann läßt er sich dann starten.

Irgendeine idee wie ich der ursache auf die spur komme? An der apache konfiguration, an meinem netzerk, an meiner hardwarte habe ich nichts geändert, gestern und die letzten tage ließ sich der apache starten, heute geht es selbst nach mehrmaligem reboot nicht.

[Gunman1982]

Schon mal probiert den port in der apache2.conf auf 8000 oder 8080 zu setzen? Nur um mal zu schauen ob apache dann ordentlich startet. Falls dieser dann startet mal schauen ob er nur 8000/8080 belegt oder auch noch 80.

Laut der Ausgabe von netstat sitzt bei dir init auf dem ipv6 port 80.

[michaa7]

soeben habe ich meinen browser, habe versucht die *lokale* webseite aufzurufen, was natgürlich mangel laufendem apache zu einer fehlermeldung im browser führte. Allerdings lies sich jetzt der apache starten, und mit einem reload im browser war die seite erreichbar.

# netstat -tulpn | grep :80
tcp 0 0 192.168.2.13:80 0.0.0.0:* LISTEN 7860/apache2
tcp 0 0 127.0.0.86:80 0.0.0.0:* LISTEN 7773/python

Dieses init dinges ist nun weg.

Kann mir das irgendjemand erklären was da los ist, was dieses init dinges an port 80 v on irgendeiner IP6 adresse zu suchen hat (ich habe das bestimmt nicht eingerichtet. Und wozu gehört dieses python teil, was nun zusätzlich aufgetaucht ist? Ist das üblich so?

Den test mit anderen ports werde ich mir ersparen, denn wie man sieht besteht das problem irgendwie in der grundkonfiguration.

[michaa7]

Laut der Ausgabe von netstat sitzt bei dir init auf dem ipv6 port 80.

Das sehe ich auch, nur warum ist das so und ist das bei dir nicht so?

[michaa7]

Laut der Ausgabe von netstat sitzt bei dir init auf dem ipv6 port 80.

Das sehe ich auch, nur warum ist das so und ist das bei dir nicht so?

EDIT:
Hier wohl die antwort, auch wenn isch sie nicht vollkommen durchblicke:
https://unix.stackexchange.com/question ... on-port-80

[Gunman1982]

Kann mir das irgendjemand erklären was da los ist, was dieses init dinges an port 80 v on irgendeiner IP6 adresse zu suchen hat (ich habe das bestimmt nicht eingerichtet. Und wozu gehört dieses python teil, was nun zusätzlich aufgetaucht ist? Ist das üblich so?

Den test mit anderen ports werde ich mir ersparen, denn wie man sieht besteht das problem irgendwie in der grundkonfiguration.

Hast du an der apache2.service Datei von systemd was geändert, eine eigene erstellt oder in anderen confs speziell was zu notify eingestellt? Ich weiss auch nicht welche mods du installiert hast, was auch zu dem python teil zu sagen ist. Hast du vielleicht irgendwelche addons/mods mit drin die zum beispiel python funktionalität für den apache bieten?

Ich hab nur einen apache2 im lokalen netz laufen mit wenig mods deswegen sieht meiner standard aus:

Code: Alles auswählen

root@XXX:~# netstat -tulpn | grep apache2
tcp6       0      0 :::443                  :::*                    LISTEN      7880/apache2
tcp6       0      0 :::80                   :::*                    LISTEN      7880/apache2

EDIT:
Weil zur gleichen Zeit geschickt und du editiert: das ist wohl einer dieser notify prozesse, der startet erst wenn traffic auf den port kommt und solange steht da init als wartender prozess. Welcher prozess das ist musst du mal schauen über die systemd tools, also welche services hast du laufen, welcher davon hat "Type=notify" in seiner service datei stehen. Die meisten service dateien sind unter /lib/systemd/system zu finden.

[michaa7]

Das problem ist ein sid(uction) problem, weil dort ein kleiner webserver (pywwetha ) mit installiert wird:

[michaa7]

EDIT:
...das ist wohl einer dieser notify prozesse, der startet erst wenn traffic auf den port kommt und solange steht da init als wartender prozess. Welcher prozess das ist musst du mal schauen über die systemd tools, also welche services hast du laufen, welcher davon hat "Type=notify" in seiner service datei stehen. Die meisten service dateien sind unter /lib/systemd/system zu finden.

Ok, ich beginne zu begreifen:

Dürfen sich um diesen socket (IP:port) auch unterschiedliche services balgen ( in diesem fall pywwetha und apache2), der erste der sich meldet gewinnt? Dann müßte ich nämlich nur schauen wie ich dem apachen ein "Type=notify" verpasse. Oder geht das so nicht?

[heisenberg]

Dürfen sich um diesen socket (IP:port) auch unterschiedliche services balgen ( in diesem fall pywwetha und apache2), der erste der sich meldet gewinnt?

Ganz genau, der erste gewinnt und alle anderen, die den gleichen Port haben wollen haben verloren.

Und wie oben zu sehen, hat sich eine Python-Anwendung den 80er Port schon geschnappt.

Wobei: Das Python-Dingens ist oben nur auf einer localnet ip(127.0.0.0/8). Wenn's wirklich nur dort wäre, würde es nicht stören.

[Gunman1982]

Dürfen sich um diesen socket (IP:port) auch unterschiedliche services balgen ( in diesem fall pywwetha und apache2), der erste der sich meldet gewinnt? Dann müßte ich nämlich nur schauen wie ich dem apachen ein "Type=notify" verpasse. Oder geht das so nicht?

Ja und Nein, Ja der erste gewinnt und Nein apache das notify verpassen hilft nicht unbedingt, kann sein das der service dann zufällig vor dem pywwetha kommt, oder vielleicht trotzdem danach. Apache hat default ein fork, das heisst wenn apache vor dem anderen service gestartet wird hat apache den socket und der andere service failed. Es kann sein das die notify bevorzugt behandelt werden was das Belegen des sockets betrifft weil das über init läuft.

AFAIK kann man einen port auch nur mit einem prozess auf LISTEN belegen. Also ip4 den port belegt kann man für ipv6 den port nicht mit einem anderen prozess belegen.

siduction fahre ich nicht, nur standard debian mit SID und da wird standard der apache2 (durch gnome) drauf genagelt von daher keine Ahnung mit dem pywwetha.

[michaa7]

...
Ja und Nein, Ja der erste gewinnt und Nein apache das notify verpassen hilft nicht unbedingt, kann sein das der service dann zufällig vor dem pywwetha kommt, oder vielleicht trotzdem danach. ...

Manchmal muß man eben erst eine dumme frage formulieren um dann aus der antwort zu erkennen, dass man darauf auch selber hätte kommen können:

Dieses init und notify regelwerk besagt ja wohl soetwas wie: kommt irgendwo auf port 80 eine anfrage dann starte mich. Und dann kommt es eben darauf an, wer schneller ist.

Noch eine dumme frage: Es gibt keine möglichkeit dieses regelwerk zu verfeinern? Statt *:80 soetwas wie <zweite-LAN-ip>:80 -> notify?

Naja, vielleicht lege ich einfach pywwetha lahm oder schaue ob pywwetha vhosts kann.

Danke soweit, wenigstens ist die ursache für die startschwierigkeiten nun halbwegs verstanden.

[Gunman1982]

Dieses init und notify regelwerk besagt ja wohl soetwas wie: kommt irgendwo auf port 80 eine anfrage dann starte mich. Und dann kommt es eben darauf an, wer schneller ist.

Nein, vielleicht hab ich mich nicht klar ausgedrückt. Systemd startet die services, sobald einer davon den port 80 nutzen will, egal ob mit notify oder fork ist dieser belegt, das ist der zeitpunkt wo das rennen zwischen den prozessen um den port ist. Wenn notify in der service datei steht dann sitzt ab dann init drauf und horcht, bei fork sitzt da direkt der finale prozess drauf und horcht. Notify is halt nur dafür gedacht das prozesse erst gestartet werden wenn eine anfrage kommt und bis dahin ist da der kleine init drauf der nicht soviele resourcen braucht bzw sowieso da ist.

Noch eine dumme frage: Es gibt keine möglichkeit dieses regelwerk zu verfeinern? Statt *:80 soetwas wie <zweite-LAN-ip>:80 -> notify?

Naja, vielleicht lege ich einfach pywwetha lahm oder schaue ob pywwetha vhosts kann.

Ich habe es selber noch nicht probiert aber sollte möglich sein, natürlich darf dann die 0.0.0.0:80 bzw in ipv6 ::::80 nicht belegt sein.
Wenn du pywwetha eh nicht nutzt würde ich das ding entweder deinstallieren oder den service disablen.

[michaa7]

...
Systemd startet die services, sobald einer davon den port 80 nutzen will, egal ob mit notify oder fork ist dieser belegt, das ist der zeitpunkt wo das rennen zwischen den prozessen um den port ist. ...

Da habe ich gedanklich ein henne und ei problem:
zunächst kommt die anfrage auf port 80 ja von einem klienten (intern oder extern), und davon kann der zu startende prozess noch kaum etwas wissen wenn init/systemd das zunächst abfängt. Und wenn ich zunächst vergeblich mit dem browser die lokale website aufzurufen versuche wird pywwetha offenbar nicht gestarted - zumindest kann ich den apachen nach dieser klientanfrage ohne fehlermeldung starten.

In soweit sorgt deine beschreibung bei mir eher für stirnrunzeln. Danke aber dennoch, mir war bisher überhaupt nicht klar wie sehr systemd mein system im griff hat was daher zu diesem thread geführt hat.

[DeletedUserReAsG]

Die Sache ist: irgendein Service ist so konfiguriert, dass systemd ihn bei Bedarf starten soll. Das ist ansich ’ne gute Sache für seltener benötigte Dienste, früher™ hat man halt den inetd oder sowas genommen. Was es bei dir ist, und warum es so ist, lässt sich aus der Ferne auch nicht sagen – mir ist jedenfalls kein Debianpaket bekannt, das eine solche Konfiguration als Default mitbringt (was nicht heißen muss, dass es keines gäbe – wenngleich mich das etwas wundern würde).

Ich würde den entsprechenden Service umkonfigurieren (oder gleich wegmachen, wenn nicht gebraucht) und das Problem sollte behoben sein.

[Gunman1982]

zunächst vergeblich mit dem browser die lokale website aufzurufen versuche wird pywwetha offenbar nicht gestarted - zumindest kann ich den apachen nach dieser klientanfrage ohne fehlermeldung starten.

Ich gehe stark davon aus das, wenn es pywwetha ist, init versucht den zu starten und aus mir unbekannten gründen dieser nicht hoch kommt. Hast du denn mal nach dem service geschaut, ob der auf enable ist? Und den dann mal auf disable setzen das dieser bei einem neustart nicht gestartet wird. Ich habe kein Siduction deswegen kann ich das hier nicht testen.