Logs füllen SD-Karte voll

[ic14m001]

Nö, absolut nichts - System lief problemlos und wie heißts so schön: never change a running system ;-)

Ja, 1.4.2 läuft auf dem Raspi, hab auch keine OS-Updates oder ähnliches gemacht. Ich werde jetzt wirklich ALLE FakeSensoren deaktiveren und das System mal zwei Wochen quasi im Leerlauf betreiben. Parallel dazu setze ich auf einen zweiten RPi das ganze nochmals auf MIT den FakeSensoren von 1Wire - mal sehen ob ich irgendwelche Unterschiede feststellen kann ......

BG
David

[bmx]

Du kannst mal bei der logging.yaml etwas reinschreiben um die maximale Größe eines Logfiles zu begrenzen:

  file:
    class: logging.handlers.TimedRotatingFileHandler
    formatter: simple
    filters: [loggerfilter]
    when: midnight
[B]    maxBytes: 104857600 # 100MB[/B]
    backupCount: 7
    ....

Probier mal aus ob Dir das wenigstens die Karte dann nicht zumüllt. Es gibt auch noch die Möglichkeit doppelte Meldungen rauszuwerfen aber dazu müßte man jetzt mehr ändern und ich denke das ist dann was für SHNG 1.5

[ic14m001]

Danke für den Tipp, werd ich gleich noch einstellen :-)

Bedeutet dies, dass nach 100MB eine neue Datei angelegt wird oder dass nach 100MB nichts mehr für den jeweiligen Tag protokolliert wird?

Das mit den doppelten Logeinträgen klingt gut .... Wie gesagt, in der 4,4GB großen Logdatei steht immer das gleiche drinnen .....
BG

[bmx]

Das bedeutet, das nach 100MB eine neue Datei angelegt wird. Wenn Du natürlich backupCount auf 40 setzt, dann sind die 4GB auch wieder voll...

Geht übrigens erst ab Python 3.5.5 Mit Python 3.4 gibt es einen Fehler, das er den Parameter nicht kennt. Also Debian Jessie und leider auch Standardmäßig Debian Stretch würden so nicht funktionieren, für den Fall das das jemand auch nutzen möchte ...

[schloessl]

Bei mir hat es auch wieder zugeschlagen!
Die Speicherkarte war voll, das System abgestürzt.
Die Log-Datei zeigte 4.427.032 KB, leider zu groß für normale Editoren.
Aber Google half. In eine .tar einlesen und anzeigen lassen.Aber zwischendrin eine Nacht geschlafen, am Morgen gab es tatsächlich eine editierbare Anzeige.

Innerhalb der Zeiten 1:44 - 1:59 knallte dasSystem die Logdatei zu und stürzte ab.

Nachfolgend der Logauszug ab der Fehlerquelle.
Ich hoffe die Kundigen können den Fehler erkennen und beseitigen!!

Bitte, bitte seit 1.4.2 schon 3 mal "Speicher voll"

2018-02-07 01:40:28 INFO plugins.wunderground_wetter_rb _get_item_fromwugdata: wug_matchstring split len=6, content=['forecast', 'simpleforecast', 'forecastday', '3', 'avewind', 'dir'] -> 'WNW'
2018-02-07 01:40:28 INFO plugins.wunderground_wetter_rb Item wgwetter.rb.vorhersage3.avgwinddir = WNW via Wunderground None None
2018-02-07 01:40:28 INFO plugins.wunderground_wetter_rb _get_item_fromwugdata: wug_matchstring split len=6, content=['forecast', 'simpleforecast', 'forecastday', '3', 'avewind', 'degrees'] -> '300'
2018-02-07 01:40:28 INFO plugins.wunderground_wetter_rb Item wgwetter.rb.vorhersage3.avgwinddegrees = 300 via Wunderground None None
2018-02-07 01:40:31 INFO plugins.avm_fritzbox_7490.update Item avm.uptime_7490 = 918966 via Logic None None
2018-02-07 01:40:32 INFO plugins.avm_fritzbox_7490.update Item avm.wan.uptime = 54858 via Logic None None
2018-02-07 01:40:32 INFO plugins.avm_fritzbox_7490.update Item avm.wan.total_packets_sent = 1410376 via Logic None None
2018-02-07 01:40:33 INFO plugins.avm_fritzbox_7490.update Item avm.wan.total_packets_received = 923303 via Logic None None
2018-02-07 01:40:33 INFO plugins.avm_fritzbox_7490.update Item avm.wan.total_bytes_sent = 237964254 via Logic None None
2018-02-07 01:40:33 INFO plugins.avm_fritzbox_7490.update Item avm.wan.total_bytes_received = 983320547 via Logic None None
2018-02-07 01:40:33 INFO plugins.avm_fritzbox_7490.update Item avm.wan.current_bytes_sent = 75 via Logic None None
2018-02-07 01:40:33 INFO plugins.avm_fritzbox_7490.update Item avm.wan.current_bytes_received = 2799 via Logic None None
2018-02-07 01:40:35 ERROR plugins.avm_fritzbox_7490.update Attribute aha_device not available on the FritzDevice
2018-02-07 01:40:35 ERROR plugins.avm_fritzbox_7490.update Attribute aha_device not available on the FritzDevice
2018-02-07 01:40:39 INFO IMAP Ignoring mail. xxx.de => alarm@yyy.de: AW: TEST ALARM TYP A - DEACTIVATED
2018-02-07 01:40:39 INFO IMAP Ignoring mail. xxx.de => alarm@yyy.de: TEST ALARM TYP B - DEACTIVATED
2018-02-07 01:40:39 INFO IMAP Ignoring mail. xxx.de => alarm@yyy.de: : AW: TEST ALARM TYP B - DEACTIVATED
2018-02-07 01:40:48 INFO logics.env_stat Item env.system.load = 0.26 via Logic None None
2018-02-07 01:40:48 INFO logics.env_stat Item env.system.diskfree = 4531113984 via Logic None None
2018-02-07 01:40:48 INFO logics.env_stat Item env.system.diskusage = 2989338624 via Logic None None
2018-02-07 01:44:27 ERROR Main Connection polling failed: [Errno 9] Ungültiger Dateideskriptor
Traceback (most recent call last):
File "/usr/local/smarthome/bin/smarthome.py", line 493, in start
self.connections.poll()
File "/usr/local/smarthome/lib/connection.py", line 106, in poll
self._epoll.modify(fileno, self._ro)
OSError: [Errno 9] Ungültiger Dateideskriptor
2018-02-07 01:44:27 ERROR Main Connection polling failed: [Errno 9] Ungültiger Dateideskriptor
Traceback (most recent call last):
File "/usr/local/smarthome/bin/smarthome.py", line 493, in start
self.connections.poll()
File "/usr/local/smarthome/lib/connection.py", line 106, in poll
self._epoll.modify(fileno, self._ro)
OSError: [Errno 9] Ungültiger Dateideskriptor
2018-02-07 01:44:27 ERROR Main Connection polling failed: [Errno 9] Ungültiger Dateideskriptor
Traceback (most recent call last):
File "/usr/local/smarthome/bin/smarthome.py", line 493, in start
self.connections.poll()
File "/usr/local/smarthome/lib/connection.py", line 106, in poll
self._epoll.modify(fileno, self._ro)
OSError: [Errno 9] Ungültiger Dateideskriptor
2018-02-07 01:44:27 ERROR Main Connection polling failed: [Errno 9] Ungültiger Dateideskriptor
Traceback (most recent call last):
File "/usr/local/smarthome/bin/smarthome.py", line 493, in start
self.connections.poll()
File "/usr/local/smarthome/lib/connection.py", line 106, in poll
self._epoll.modify(fileno, self._ro)
OSError: [Errno 9] Ungültiger Dateideskriptor

... und das ganze so weiter und so weiter ...

2018-02-07 01:44:27 ERROR Main Connection polling failed: [Errno 9] Ungültiger Dateideskriptor
Traceback (most recent call last):
File "/usr/local/smarthome/bin/smarthome.py", line 493, in start
self.connections.poll()
File "/usr/local/smarthome/lib/connection.py", line 106, in poll
self._epoll.modify(fileno, self._ro)
OSError: [Errno 9] Ungültiger Dateideskriptor

[ic14m001]

Genau so schauts bei mir auch aus ....

[psilo]

an eurer stelle würde ich erstmal allgemein das logging nur noch auf error schalten... da sind infos und vermutlich debugs dabei... da wird das schon mal einiges..

wie sehen die jew. logging.yaml's aus?

[ic14m001]

Hab gestern das akutelle Image von Onkelandy heruntergeladenn und auf einen zweiten RPi installiert. Und auch hier füllte das Log die gesamte SD-Karte über Nacht ....

Laut Backend ist die Python-Version 3.5.3 final installiert - jedoch bekomme ich eine Fehlermeldung, ich smarthomeng neu starte, wenn die Begrenzung der Loggröße in der logging.yaml hinterlegt ist:

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

Hier mal meine aktuelle logging.yaml (original wie im Image):

version: 1
disable_existing_loggers: False
formatters:
busmonitor_format:
format: '%(asctime)s;%(message)s;'
datefmt: '%Y-%m-%d;%H:%M:%S'
simple:
format: '%(asctime)s %(levelname)-8s %(threadName)-12s %(message)s'
datefmt: '%Y-%m-%d %H:%M:%S'
detail:
format: '%(asctime)s %(levelname)-8s %(module)-12s %(threadName)-12s %(message)s -- %(filename)s:%(funcName)s:%(lineno)d'
datefmt: '%Y-%m-%d %H:%M:%S'
filters:
loggerfilter:
'()': lib.logutils.Filter
name: 'knx_busmonitor'
handlers:
console:
class: logging.StreamHandler
formatter: detail
stream: ext://sys.stdout
file:
class: logging.handlers.TimedRotatingFileHandler
formatter: simple
filters: [loggerfilter]
when: midnight
backupCount: 7
encoding: utf8
filename: ./var/log/smarthome.log
busmonitor_file:
class: logging.handlers.TimedRotatingFileHandler
formatter: busmonitor_format
when: midnight
backupCount: 7
encoding: utf8
filename: ./var/log/knx_busmonitor.log
loggers:
knx_busmonitor:
level: INFO
handlers: [busmonitor_file ]
# plugins.knx:
# level: INFO
# lib.scheduler:
# level: DEBUG
# plugins.cli:
# level: DEBUG

root:
level: INFO
handlers: [file, console]

[Lonie]

Ich hatte ebenfalls schon mehrfach eine gefüllte Partition aufgrund der "ungültiger Dateideskriptor" Logeinträge. Als Lösung für mich habe ich das Logging komplett deaktiviert. Man kann natürlich eine eigene Partition für die Logfiles erstellen, dann läuft das System zumindest weiter. Ein Logrotate welches auf die Filesize aufbaut existiert nach meiner Recherche leider nicht.

[ic14m001]

Jetzt noch zwei abschließende Fragen (von einem "Nicht-Linux-Guru"): Wie deaktiviere ich das Logging bzw. wie kann ich die LogFiles z.B. auf einen USB-Stick "umleiten"?

[schloessl]

Und wieder war die SD-Karte (fast) voll.
Im Log-Verzeichnis fand ich : smarthome.log 4.425.032 KB

Per Putty war das Systemnoch erreichbar, also schnell stoppen, (/usr/local/smarthome/bin/smarthome.py --stop) , große Log-Datei sichern und im Log löschen.
Nachfolgend zeige ich die Anzeigen im Putty. Hie tauchen einige Fehler auf. Vielleicht hilft es das Problem zu umzingeln.
Weitere Angaben kann ich lederzeit lösen!
Künnen wir nicht eine Debug-Zeile einbauen und den Dateideskriptor loggen ?

-------------------- Init SmartHomeNG 1.4.2.master (0dff0244) ---

SmartHome Raspi running for: 3 days, 22h55m32s

Hier meine Versuche::

[smarthome@SmartHomeNG ~]$ /usr/local/smarthome/bin/smarthome.py --start
--- Logging error ---
Traceback (most recent call last):
File "/usr/lib/python3.5/logging/__init__.py", line 985, in emit
self.flush()
File "/usr/lib/python3.5/logging/__init__.py", line 965, in flush
self.stream.flush()
OSError: [Errno 28] Auf dem Gerät ist kein Speicherplatz mehr verfügbar
Call stack:
File "/usr/local/smarthome/bin/smarthome.py", line 1051, in <module>
sh = SmartHome(extern_conf_dir=extern_conf_dir)
File "/usr/local/smarthome/bin/smarthome.py", line 196, in __init__
self._logger.info("Using config dir: {}".format(self._extern_conf_dir))
Message: 'Using config dir: /usr/local/smarthome'
Arguments: ()
2018-02-15 12:41:07 INFO smarthome Main Using config dir: /usr/local/smarthome -- smarthome.py:__init__:196
Daemon PID 23359
fork #2 failed: 28 (Auf dem Gerät ist kein Speicherplatz mehr verfügbar)

/usr/local/smarthome/bin/smarthome.py --stop -> keine Reaktion

Versuch Start:
[smarthome@SmartHomeNG ~]$ /usr/local/smarthome/bin/smarthome.py --start
Traceback (most recent call last):
File "/usr/local/smarthome/bin/smarthome.py", line 1044, in <module>
if lib.daemon.check_sh_is_running(PIDFILE):
File "/usr/local/smarthome/lib/daemon.py", line 148, in check_sh_is_running
pid = read_pidfile(pidfile)
File "/usr/local/smarthome/lib/daemon.py", line 133, in read_pidfile
return int(line)
ValueError: invalid literal for int() with base 10: ''
[smarthome@SmartHomeNG ~]$ [smarthome@SmartHomeNG ~]$ /usr/local/smarthome/bin/smarthome.py --start
-bash: [smarthome@SmartHomeNG: Kommando nicht gefunden.
[smarthome@SmartHomeNG ~]$ Traceback (most recent call last):
-bash: Syntaxfehler beim unerwarteten Wort `most'
[smarthome@SmartHomeNG ~]$ File "/usr/local/smarthome/bin/smarthome.py", line 1044, in <module>
-bash: Syntaxfehler beim unerwarteten Wort `newline'
[smarthome@SmartHomeNG ~]$ if lib.daemon.check_sh_is_running(PIDFILE):
-bash: Syntaxfehler beim unerwarteten Wort `PIDFILE'
[smarthome@SmartHomeNG ~]$ File "/usr/local/smarthome/lib/daemon.py", line 148, in check_sh_is_running
-bash: File: Kommando nicht gefunden.
[smarthome@SmartHomeNG ~]$ pid = read_pidfile(pidfile)
-bash: Syntaxfehler beim unerwarteten Wort `('
[smarthome@SmartHomeNG ~]$ File "/usr/local/smarthome/lib/daemon.py", line 133, in read_pidfile
-bash: File: Kommando nicht gefunden.
[smarthome@SmartHomeNG ~]$ return int(line)
-bash: Syntaxfehler beim unerwarteten Wort `('
[smarthome@SmartHomeNG ~]$ ValueError: invalid literal for int() with base 10: ''
-bash: Syntaxfehler beim unerwarteten Wort `('
[smarthome@SmartHomeNG ~]$ /usr/local/smarthome/bin/smarthome.py --stop [smarthome@SmartHomeNG ~]$
usage: smarthome.py [-h] [-v | -d | -i | -l | -s | -q | -V | --start]
[-c CONFIG_DIR]
smarthome.py: error: unrecognized arguments: [smarthome@SmartHomeNG ~]$

dann
ps -aux | grep smarthome
kill 23359

Neuer Start ging dann!

Es ist sicherlich kein Hinweis auf das eigentliche Problem. Evtl eine Hilfe.

[heckmannju]

ich denke der logger muss gewechselt werden in Pyhton 3.5 gibt es die zwei..

logging.handlers.RotatingFileHandler([I]filename[/I], [I]mode='a'[/I], [I]maxBytes=0[/I], [I]backupCount=0[/I], [I]encoding=None[/I], [I]delay=False[/I])[URL="https://docs.python.org/3.5/library/logging.handlers.html#logging.handlers.RotatingFileHandler"]¶[/URL]
logging.handlers.TimedRotatingFileHandler([I]filename[/I], [I]when='h'[/I], [I]interval=1[/I], [I]backupCount=0[/I], [I]encoding=None[/I], [I]delay=False[/I], [I]utc=False[/I], [I]atTime=None[/I])[URL="https://docs.python.org/3.5/library/logging.handlers.html#logging.handlers.TimedRotatingFileHandler"]¶[/URL]

Wenn der TimedRotatingFileHandler keine maxBytes hat würde ich aus robustheitsgründen immer den

file:
class: logging.handlers.RotatingFileHandler
formatter: simple
filters: [loggerfilter]
[B]maxBytes: 104857600 # 100MB[/B]
backupCount: 3
....

Ich habe das noch nicht ausprobiert weil ich noch nicht das problem hatte. Ich will aber auf jedenfall das die grösse der Logs limitiert ist.

[schloessl]

Hallo heckmannju,

diese Lösung ist weiter oben schon einmal aufgezeigt worden. Leider ohne Erfolg.

Mein Stand:

rpi1.jpg

das Testergebnis:

Traceback (most recent call last):
File "/usr/lib/python3.5/logging/config.py", line 558, in configure
handler = self.configure_handler(handlers[name])
File "/usr/lib/python3.5/logging/config.py", line 731, in configure_handler
result = factory(**kwargs)
TypeError: __init__() got an unexpected keyword argument 'maxBytes'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/usr/local/smarthome/bin/smarthome.py", line 1051, in &lt;module&gt;
sh = SmartHome(extern_conf_dir=extern_conf_dir)
File "/usr/local/smarthome/bin/smarthome.py", line 195, in __init__
self.initLogging()
File "/usr/local/smarthome/bin/smarthome.py", line 367, in initLogging
logging.config.dictConfig(doc)
File "/usr/lib/python3.5/logging/config.py", line 795, in dictConfig
dictConfigClass(config).configure()
File "/usr/lib/python3.5/logging/config.py", line 566, in configure
'%r: %s' % (name, e))
ValueError: Unable to configure handler 'file': __init__() got an unexpected keyword argument 'maxBytes'

Getestet auf Raspi-IMG. Hier wird python 3.5 angezeigt, obwohl laut backend 3.5.3 installiert ist. Auf Unix-Rechner scheint es zu laufen.

[heckmannju]

kannst du mal deine log config zeigen. (logging.yaml )
VG
Jürgen

Also ich habe es heute mal auf meinem Raspi mit dem neuesten image getestet.

[heckmannju]

Hier mal meine config...damit ich nicht so lange warten muss ist es auf 10k grosse logs gestellt.

  file:
    #logging.handlers.RotatingFileHandler(filename, mode='a', maxBytes=0, backupCount=0, encoding=None, delay=False)
    #class: logging.handlers.TimedRotatingFileHandler
    class: logging.handlers.RotatingFileHandler
    formatter: simple
    filters: [loggerfilter]
    maxBytes: 10480
    #when: midnight
    backupCount: 7
    encoding: utf8
    filename: ./var/log/smarthome.log

-rw-rw-rw- 1 smarthome users      20K Feb 17 11:15 smarthome.log.7
-rw-rw-rw- 1 smarthome users      11K Feb 17 11:16 smarthome.log.6
-rw-rw-rw- 1 smarthome users      11K Feb 17 11:16 smarthome.log.5
-rw-rw-rw- 1 smarthome users     2,7K Feb 17 11:16 smarthome.log.4
-rw-rw-rw- 1 smarthome users      20K Feb 17 11:16 smarthome.log.3
-rw-rw-rw- 1 smarthome users      20K Feb 17 11:16 smarthome.log.2
-rw-rw-rw- 1 smarthome users      11K Feb 17 12:22 smarthome.log.1
-rw-rw-rw- 1 smarthome users      11K Feb 17 12:22 smarthome.log