Ja wo loggt er denn bloß hin?

Vom einfachen Programm zum fertigen Debian-Paket, Fragen rund um Programmiersprachen, Scripting und Lizenzierung.
Antworten
Benutzeravatar
seep
Beiträge: 544
Registriert: 31.10.2004 14:21:08
Lizenz eigener Beiträge: GNU Free Documentation License
Wohnort: HSK

Ja wo loggt er denn bloß hin?

Beitrag von seep » 19.09.2017 10:13:46

Ich habe ein Perl-Script, sagen wir mal endlos.pl, das macht endlos etwas und unterrichtet mich darüber per Ausgabe auf die Standardfehlerausgabe (STDERR).

Dieses Perl-Script starte ich per Bash-Script (start.sh) per nohup in den Hintergrund.

nohup endlos.pl &

Rufe ich ./start.sh auf, werden die Fehleraushaben von endlos.pl in nohup.out geschrieben. Soweit so erwartbar so gut.

nohup endlos.pl >> nohup.log &

Rufe ich nun ./start.sh auf, werden die Fehlerausgaben von endlos.pl an nohup.log angehängt. Soweit so erwartbar so gut. nohup meldet auch brav, dass es stderr auf stdout umleitet, sprich es landet alles im nohup.log. (In Wirklichkeit heißt die Datei anders, aber um Euch nicht zu verwirren und zu zeigen, dass ja nohup diese Datei anlegt, nenne ich sie hier so).

Per cronjob soll nun das Bash-Script morgens gestartet und abends abgeschossen werden:

0 5 * * * cd /home/seep/scripts && ./start.sh

Problem: Es erfolgen überhaupt keine Ausgaben ins Logfile. Ein lsof | nohup.log zeigt, dass die Datei zum Schreiben geöffnet wurde, aber es kommt nichts hinein.

Ich bin verwirrt. Wo versickern die Ausgaben und was muss ich tun, damit sie dort landen, wo ich sie erwarte?

Benutzeravatar
MSfree
Beiträge: 10686
Registriert: 25.09.2007 19:59:30

Re: Ja wo loggt er denn bloß hin?

Beitrag von MSfree » 19.09.2017 10:45:41

seep hat geschrieben: ↑ zum Beitrag ↑
19.09.2017 10:13:46
nohup endlos.pl >> nohup.log &
das >> nohup.log legt die Datei nohup.log im aktuellen Verzeichnis an.
Per cronjob...
Problem: Es erfolgen überhaupt keine Ausgaben ins Logfile.
Logisch! Das aktuelle Verzeichnis, in dem cron seine Jobs startet, ist üblicherweise /dev/null.

Du mußt die Dateiumleitung mit einem absoluten Pfad versehen, z.B.:

Code: Alles auswählen

nohup endlos.pl >> /home/username/logs/nohup.log &
oder

Code: Alles auswählen

nohup endlos.pl >> /var/log/nohup.log &

Benutzeravatar
seep
Beiträge: 544
Registriert: 31.10.2004 14:21:08
Lizenz eigener Beiträge: GNU Free Documentation License
Wohnort: HSK

Re: Ja wo loggt er denn bloß hin?

Beitrag von seep » 19.09.2017 11:01:49

Negativ. Ich verwende einen absoluten Pfad (nur das Beispiel oben wollte ich kurz halten), schließlich wird die Datei ja auch mit 0 Byte angelegt, sobald der Cronjob gestartet und dann also nohup gestartet wird, die Datei aber nicht mit Log-Ausgaben gefüllt. Die Jobs laufen alle, nur die Logausgaben versickern irgendwo.

Benutzeravatar
seep
Beiträge: 544
Registriert: 31.10.2004 14:21:08
Lizenz eigener Beiträge: GNU Free Documentation License
Wohnort: HSK

Re: Ja wo loggt er denn bloß hin?

Beitrag von seep » 19.09.2017 11:11:08

MSfree hat geschrieben: ↑ zum Beitrag ↑
19.09.2017 10:45:41
Das aktuelle Verzeichnis, in dem cron seine Jobs startet, ist üblicherweise /dev/null.
Noch dazu: Durch das "cd /home/seep/" in der crontab liefert ein "pwd" direkt vor dem "nohup" brav ein "/home/seep/". Selbst wenn ein relativer Pfad verwendet worden wäre, hätte es gepasst.

Benutzeravatar
seep
Beiträge: 544
Registriert: 31.10.2004 14:21:08
Lizenz eigener Beiträge: GNU Free Documentation License
Wohnort: HSK

Re: Ja wo loggt er denn bloß hin?

Beitrag von seep » 19.09.2017 11:48:07

Ich habe zwar keine Antwort auf meine Frage gefunden, jedoch eine Lösung für mein Problem, immerhin:

Ersetze ich in meinem von cron aufgerufenem Startscript diesen Aufruf

nohup endlos.pl >> /home/seep/log/nohup.log &

durch

exec endlos.pl >> /home/seep/log/nohup.log 2>&1 &

dann funktioniert alles wie gewünscht und die Ausgaben landen auch sichtbar dort, wo ich sie vermute.

Warum es mit nohup nicht funktioniert, bleibt dennoch rätselhaft.

r4pt0r
Beiträge: 1237
Registriert: 30.04.2007 13:32:44
Lizenz eigener Beiträge: MIT Lizenz

Re: Ja wo loggt er denn bloß hin?

Beitrag von r4pt0r » 19.09.2017 20:11:41

Alternativ und einigermaßen portabel (zumindest alle optionen gemäß IEEE 1003.2/POSIX.2) kann man auch "logger" verwenden um Nachrichten an das jeweilige syslog zu senden.

Recht praktisch in scripten die i.d.r. nicht interaktiv ausgeführt werden ist ein override für echo:

Code: Alles auswählen

echo() {
    logger -t "scriptname" "$@"
}
Im code kann dann einfach "echo" verwendet werden. Für debugging wird die Funktion "echo" auskommentiert (oder man baut nen switch für -v ein), dann landet die Ausgabe wie gewohnt in STDOUT.

Anstatt ein zusätzliches shellscript nur zur Umleitung der messages zu verwenden, wäre es aber wesentlich sauberer, einfach direkt Sys::Syslog im Perlscript zu verwenden - das ist ein direktes interface zu UNIX syslog calls und damit _wirklich_ portabel.
https://metacpan.org/pod/Sys::Syslog

Im Falle von debian >jessie musst du dich in beiden Fällen dann eben mit dem systemd binärlog rumschlagen und deine logs wieder aus dem journal holen. Für alle vernünftigen Systeme landen die Nachrichten in /var/log/messages oder /var/log/syslog bzw kann das gewünschte Ziel einfach per eintrag in /etc/syslog.conf eingestellt werden.

guennid

Re: Ja wo loggt er denn bloß hin?

Beitrag von guennid » 19.09.2017 20:26:22

r4pt0r hat geschrieben:Im Falle von debian >jessie musst du dich in beiden Fällen dann eben mit dem systemd binärlog rumschlagen und deine logs wieder aus dem journal holen. Für alle vernünftigen Systeme landen die Nachrichten in /var/log/messages oder /var/log/syslog
:wink:

Zum Generieren dieses Eintrags wurde kein Schlaufon benutzt. :wink:

Benutzeravatar
seep
Beiträge: 544
Registriert: 31.10.2004 14:21:08
Lizenz eigener Beiträge: GNU Free Documentation License
Wohnort: HSK

Re: Ja wo loggt er denn bloß hin?

Beitrag von seep » 19.09.2017 22:25:12

r4pt0r hat geschrieben: ↑ zum Beitrag ↑
19.09.2017 20:11:41
kann man auch "logger"
Danke für den Tipp mit logger, ich werde mir das mal anschauen. Natürlich könnte ich auch (ohne logger) direkt vom Perl-Script in eine Datei statt auf STDERR loggen, oder auch direkt ins Syslog.

Es beantwortet dennoch nicht die Frage, warum bei der Verwendung von nohup nicht umgeleitet wird und in der Logdatei landet. Wenn ich mal eine Erklärung finde, werde ich berichten.

uname
Beiträge: 12046
Registriert: 03.06.2008 09:33:02

Re: Ja wo loggt er denn bloß hin?

Beitrag von uname » 20.09.2017 10:23:08

Zwei Anmerkungen:

2.) Cron

Code: Alles auswählen

0 5 * * * cd /home/seep/scripts && ./start.sh
An dieser Stelle "cd" zu verwenden ist ganz schlechte Programmierung.
Dann lieber dem Perl-Script einen Pfad als Zielpfad mitgeben (Übergabe Variable). Damit verschwinden vielleicht auch deine Probleme.

2.) nohup
Anstatt nohup verwende ich nur noch Debianscreen oder Debiantmux. Da treten die Probleme von nohup erst gar nicht auf.
Mittlerweile empfehle ich lieber Debiantmux mit dem immer gleichen Aufruf (falls immer die identische tmux-Sitzung aufgerufen werden soll):

Code: Alles auswählen

tmux attach || tmux new
In der tmux-Sitzung dann das Programm ./start.sh ohne nohup aufrufen und tmux detachen und bei Bedarf mit obiger Befehlskombination wieder attachen. Falls du dir die Tastenkombination zum detachen (C-b d) nicht merken kannst, kannst du einfach das Terminal schließen. Bei mehreren Programmen im Hintergrund kannst du sowohl mehrere Tmux-Sitzungen als auch mehrere virtuelle Terminals innerhalb einer oder mehrerer Tmux-Sitzungen verwenden.

rendegast
Beiträge: 15041
Registriert: 27.02.2006 16:50:33
Lizenz eigener Beiträge: MIT Lizenz

Re: Ja wo loggt er denn bloß hin?

Beitrag von rendegast » 20.09.2017 12:03:53

uname hat geschrieben:
0 5 * * * cd /home/seep/scripts && ./start.sh
An dieser Stelle "cd" zu verwenden ist ganz schlechte Programmierung.
<->
Standard-/etc/crontab:

Code: Alles auswählen

...
# m h dom mon dow user	command
17 *	* * *	root    cd / && run-parts --report /etc/cron.hourly
...
mfg rendegast
-----------------------
Viel Eifer, viel Irrtum; weniger Eifer, weniger Irrtum; kein Eifer, kein Irrtum.
(Lin Yutang "Moment in Peking")

Benutzeravatar
seep
Beiträge: 544
Registriert: 31.10.2004 14:21:08
Lizenz eigener Beiträge: GNU Free Documentation License
Wohnort: HSK

Re: Ja wo loggt er denn bloß hin?

Beitrag von seep » 20.09.2017 12:25:15

uname hat geschrieben: ↑ zum Beitrag ↑
20.09.2017 10:23:08
An dieser Stelle "cd" zu verwenden ist ganz schlechte Programmierung.
Begründung?
uname hat geschrieben: ↑ zum Beitrag ↑
20.09.2017 10:23:08
Damit verschwinden vielleicht auch deine Probleme.
Halte ich für unwahrscheinlich. Werde ich aber gerne am Wochenende mal durchspielen.
uname hat geschrieben: ↑ zum Beitrag ↑
20.09.2017 10:23:08
Anstatt nohup verwende ich nur noch Debianscreen oder Debiantmux. Da treten die Probleme von nohup erst gar nicht auf.
Klingt spannend, ist für eine nicht interaktiven Job aber wohl keine Lösung. :D

Benutzeravatar
seep
Beiträge: 544
Registriert: 31.10.2004 14:21:08
Lizenz eigener Beiträge: GNU Free Documentation License
Wohnort: HSK

Re: Ja wo loggt er denn bloß hin?

Beitrag von seep » 20.09.2017 15:41:03

Vorab: man nohup sagt:

If standard input is a terminal, redirect it from /dev/null. If standard output is a terminal, append output to 'nohup.out' if possible, '$HOME/nohup.out' otherwise. If standard error is a terminal, redirect it to standard output. To save output to FILE, use 'nohup COMMAND > FILE'.

Es werden keine Aussagen dazu gemacht, wie die Ausgaben umgeleitet werden, wenn (wie im Falle von cron) kein "terminal" involviert ist. Dies nur vorab.

Ich habe nun ein kleines Shell-Script gebaut, was mir ein paar Ausgaben auf stdout und stderr auswirft:

Code: Alles auswählen

#!/bin/bash
for i in $(seq 23 42 )
do
	date "+%Y-%m-%d %H:%M:%S ($i) hello, stdout"
	date "+%Y-%m-%d %H:%M:%S ($i) hello, stderr" >&2
	sleep 1
done
Dazu zwei Scripte, die es per nohup starten, einmal mit expliziter Angabe eines Logfiles und einmal ohne:

nohup-hello-to-log.sh

Code: Alles auswählen

#!/bin/bash
date "+%Y-%m-%d %H:%M:%S $0 started" >> /tmp/nohup-hello-to-log.log
nohup ./hello.sh > /tmp/nohup.log &
date "+%Y-%m-%d %H:%M:%S $0 Ready." >> /tmp/nohup-hello-to-log.log
nohup-hello-no-log.sh

Code: Alles auswählen

#!/bin/bash
date "+%Y-%m-%d %H:%M:%S $0 started" >> /tmp/nohup-hello-no-log.log
nohup ./hello.sh &
date "+%Y-%m-%d %H:%M:%S $0 Ready." >> /tmp/nohup-hello-no-log.log
Beide Scripte starte ich mit Abstand per crontab-Eintrag:
17 15 * * * cd ~/Source/bash/ && ./nohup-hello-no-log.sh
18 15 * * * cd ~/Source/bash/ && ./nohup-hello-to-log.sh
Ergebnisse:
  • Beim nohup-hello-no-log.sh wird keine nohup.out erzeugt, weder im aktuellen Pfad noch im User-Homeverzeichnis noch sonstwo. Alle Ausgaben des per nohup gestarteten hello.sh auf stdout und stderr verschwinden im Nirvana.
  • Beim nohup-hello-to-log.sh werden wie gewünscht die Ausgaben auf stdout ins /tmp/nohup.log umgeleitet. nohup leitet stderr nicht selbständig auf stdout um, die Ausgaben auf stderr landen daher nicht im /tmp/nohup.log sondern verschwinden im Nirvana.
  • Um auch die Ausgaben auf stderr zu sehen, muss man sich wie sonst auch selber um die Umleitung kümmern:

Code: Alles auswählen

#!/bin/bash
date "+%Y-%m-%d %H:%M:%S $0 started" >> /tmp/nohup-hello-to-log.log
nohup ./hello.sh > /tmp/nohup.log 2>&1 &
date "+%Y-%m-%d %H:%M:%S $0 Ready." >> /tmp/nohup-hello-to-log.log
Insofern ist der Einsatz von nohup zusammen mit cron wohl eher Quatsch. Und wenn man mal darüber nachdenkt, wofür nohup eigentlich gedacht ist (Hangup-Signale zu ignorieren, die im cron-Umfeld afaik eh nicht auftreten), dann hätte ich da auch früher drauf kommen können.

Notiz an mich selbst: nohup und cron nicht zusammen nutzen.

Antworten