FHEM Forum

Hallo zusammen,

ähnliche Fehlermeldungen gab es schon im Dezember, die aber gefixt sein sollen. Mein fhem ist aktuell und ich bekomme folgende Meldungen:

2021.04.07 18:16:49 1: ERROR: addToWritebuffer for WEB_192.168.6.10_59956 without FD
2021.04.07 18:16:49 1: callstack: addToWritebuffer:731 FW_addToWritebuffer:761 FW_AsyncOutput:3847 CallFn:2023 asyncOutput:5395 ZWave_Parse:4043 Dispatch:982 ZWDongle_Parse:877 ZWDongle_Read:3847 CallFn:773
2021.04.07 18:16:57 1: ERROR: addToWritebuffer for WEB_192.168.6.10_59956 without FD
2021.04.07 18:16:57 1: callstack: addToWritebuffer:731 FW_addToWritebuffer:761 FW_AsyncOutput:3847 CallFn:2023 asyncOutput:5395 ZWave_Parse:4043 Dispatch:982 ZWDongle_Parse:877 ZWDongle_Read:3847 CallFn:773


Woran kann das liegen?

VG
Torsten

Danke fuer den Hinweis, habs gefixt.

Hallo,
mit dem gestrigen Update der Version /24251/ bekomme ich wieder die folgenden Fehler:



2021.04.15 08:55:39 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:55:39 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:55:39 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:55:39 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:55:39 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:55:39 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:55:39 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD



Grüße
Fabian

Merkwuerdig.

Die aktuelle Version von fhem.pl gibt bei diesem Problem mindestens eine weitere Zeile auf verbose 1 aus, normalerweise sogar zwei.
Ich vermute "cherry-picking", d.h. 01_FHEMWEB.pm ist aktuell, fhem.pl aber nicht.
Apropos: TcpServerUtils.pm muss auch aktualisiert werden. Eigentlich alles, bevor man hier ein Problem meldet.

Ich habe heute morgen alles per ,,Update" aktualisiert und dann genau diese genannte Meldung erhalten und FHEM startete nicht mehr.
Erst nach rückspielen der alten 01_FHEMWEB.pm konnte das Problem gelöst werden!

Entweder wurde das gezeigte Log gefiltert, oder ist fhem.pl nicht aktuell.
Wurde nach dem update FHEM neu gestartet?
Ist evtl. "attr global exclude_from_update fhem.pl" gesetzt?

Die genannten Einträge hatte ich zu hunderten nach dem heutigen Update und einem Neustart von FHEM.
Und erst nachdem ich die 01_FHEMWEB.pm 24176 2021-04-07 zurückgespielt habe, startete FHEM wieder sauber.
Nein, attr global exclude_from_update fhem.pl ist nicht gesetzt = fhem.pl 23904 2021-03-07 09:20:31Z

Dann muss ein Wunder vorliegen, da laut aktuellen Code:
    Log 1, "ERROR: addToWritebuffer for $n without FD";
    Log 1, "callstack:".stacktraceAsString(1);
    Log 1, "FD closed in ".$hash->{stacktrace} if($hash->{stacktrace});

diese Zeile nie alleine im Log erscheint.

Tatsächlich hat sich zwischen den hunderten oder tausenden Logzeilen noch mehr versteckt:

2021.04.15 08:54:00 1: Downloading https://fhem.de/fhemupdate/controls_fhem.txt
2021.04.15 08:54:00 1:
2021.04.15 08:54:00 1: fhem
2021.04.15 08:54:00 1: RMDIR: ./restoreDir/update/2021-01-07
2021.04.15 08:54:00 1: UPD ./CHANGED
2021.04.15 08:54:00 1: UPD FHEM/01_FHEMWEB.pm
2021.04.15 08:54:00 1: UPD FHEM/47_OBIS.pm
2021.04.15 08:54:00 1: UPD FHEM/69_SoftliqCloud.pm
2021.04.15 08:54:00 1: UPD FHEM/70_BOTVAC.pm
2021.04.15 08:54:00 1: UPD FHEM/73_DoorBird.pm
2021.04.15 08:54:00 1: UPD FHEM/73_ElectricityCalculator.pm
2021.04.15 08:54:00 1: UPD FHEM/73_GasCalculator.pm
2021.04.15 08:54:00 1: UPD FHEM/73_WaterCalculator.pm
2021.04.15 08:54:00 1: UPD FHEM/98_DOIF.pm
2021.04.15 08:54:01 1: UPD FHEM/99_SUNRISE_EL.pm
2021.04.15 08:54:01 1: UPD FHEM/lib/fhem_zwave_deviceconfig.xml.gz
2021.04.15 08:54:01 1: UPD FHEM/lib/openzwave_manufacturer_specific.xml
2021.04.15 08:54:01 1: saving fhem.cfg
2021.04.15 08:54:01 1: saving ./log/fhem.save
2021.04.15 08:54:01 1:
2021.04.15 08:54:01 1: New entries in the CHANGED file:
2021.04.15 08:54:01 1:  - bugfix:  70_BOTVAC: transient map cache
2021.04.15 08:54:01 1:  - bugfix:  73_DoorBird: Event Video Routine
2021.04.15 08:54:01 1:  - bugfix:  73_ElectricityCalculator: Bugfix - Midnight-Crash
2021.04.15 08:54:01 1:  - bugfix:  73_WaterCalculator:       Bugfix - Midnight-Crash
2021.04.15 08:54:01 1:  - bugfix:  73_GasCalculator:         Bugfix - Midnight-Crash
2021.04.15 08:54:01 1:
2021.04.15 08:54:01 1: Downloading https://raw.githubusercontent.com/knowthelist/fhem-tablet-ui/master/controls_fhemtabletui.txt
2021.04.15 08:54:01 1:
2021.04.15 08:54:01 1: fhemtabletui
2021.04.15 08:54:01 1: nothing to do...
2021.04.15 08:54:01 1: Calling /usr/bin/perl ./contrib/commandref_join.pl -noWarnings, this may take a while
2021.04.15 08:54:09 1:
2021.04.15 08:54:09 1: update finished, "shutdown restart" is needed to activate the changes.
2021.04.15 08:54:09 1:
2021.04.15 08:54:09 1: Please consider using the global attribute sendStatistics
2021.04.15 08:54:24 1: HMCCU: [myHmCCU : 10323] Graceful shutdown in 8 seconds
2021.04.15 08:54:24 1: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10323] Stopping RPC server CB2001001006001013
2021.04.15 08:54:24 1: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10323] Deregistering RPC server http://192.168.1.6:7411/fh2001 with ID CB2001001006001013 at http://192.168.1.13:2001
2021.04.15 08:54:24 1: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10323] Callback for RPC server CB2001001006001013 deregistered
2021.04.15 08:54:24 2: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10323] Sending signal INT to RPC server process CB2001001006001013 with PID=10371
2021.04.15 08:54:24 2: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10323] Cleaning up immediately
2021.04.15 08:54:24 1: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10323] Housekeeping called. Cleaning up RPC environment
2021.04.15 08:54:24 2: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10371] CB2001001006001013 received signal INT
2021.04.15 08:54:24 2: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10371] CB2001001006001013 received signal INT
2021.04.15 08:54:24 1: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10371] RPC server CB2001001006001013 stopped handling connections. PID=10371
2021.04.15 08:54:24 2: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10371] Number of I/O errors = 0
2021.04.15 08:54:26 2: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10323] RPC server process CB2001001006001013 deleted
2021.04.15 08:54:26 2: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10323] Stop I/O handling
2021.04.15 08:54:26 2: HMCCURPCPROC: [d_rpc001013BidCos_RF : 10323] RPC server stopped. Cancel delayed shutdown.
2021.04.15 08:54:27 1: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10323] Stopping RPC server CB2010001006001013
2021.04.15 08:54:27 1: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10323] Deregistering RPC server http://192.168.1.6:7420/fh2010 with ID CB2010001006001013 at http://192.168.1.13:2010
2021.04.15 08:54:27 1: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10323] Callback for RPC server CB2010001006001013 deregistered
2021.04.15 08:54:27 2: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10323] Sending signal INT to RPC server process CB2010001006001013 with PID=10372
2021.04.15 08:54:27 2: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10323] Cleaning up immediately
2021.04.15 08:54:27 1: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10323] Housekeeping called. Cleaning up RPC environment
2021.04.15 08:54:27 2: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10372] CB2010001006001013 received signal INT
2021.04.15 08:54:27 2: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10372] CB2010001006001013 received signal INT
2021.04.15 08:54:27 1: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10372] RPC server CB2010001006001013 stopped handling connections. PID=10372
2021.04.15 08:54:27 2: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10372] Number of I/O errors = 0
2021.04.15 08:54:29 2: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10323] RPC server process CB2010001006001013 deleted
2021.04.15 08:54:29 1: HMCCU: [myHmCCU : 10323] All RPC servers inactive
2021.04.15 08:54:29 2: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10323] Stop I/O handling
2021.04.15 08:54:29 2: HMCCURPCPROC: [d_rpc001013HmIP_RF : 10323] RPC server stopped. Cancel delayed shutdown.
2021.04.15 08:54:30 1: Server shutdown delayed due to d_rpc001013HmIP_RF,alexa,myHmCCU,d_rpc001013BidCos_RF for max 10 sec
2021.04.15 08:54:30 1: [Freezemon] freezemon: possible freeze starting at 08:54:25, delay is 5.798 possibly caused by: no bad guy found :-(
2021.04.15 08:54:30 3: alexa: stopped
2021.04.15 08:54:31 1: FHEMWEB SSL/HTTPS error:  SSL accept attempt failed (peer: 192.168.1.6)
2021.04.15 08:54:31 1: FHEMWEB SSL/HTTPS error:  SSL accept attempt failed (peer: 192.168.1.6)
2021.04.15 08:54:40 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:54:40 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:54:40 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:54:40 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:54:40 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
.........

.........

2021.04.15 08:54:40 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:54:40 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
Deep recursion on subroutine "main::Log" at fhem.pl line 3517.
Deep recursion on subroutine "main::Log3" at fhem.pl line 1029.
2021.04.15 08:54:40 1: PERL WARNING: Deep recursion on subroutine "main::FW_addToWritebuffer" at ./FHEM/01_FHEMWEB.pm line 3085.
Deep recursion on subroutine "main::FW_logInform" at fhem.pl line 1014.
Deep recursion on subroutine "main::addToWritebuffer" at ./FHEM/01_FHEMWEB.pm line 731.
.....
2021.04.15 08:54:40 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:54:40 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:55:39 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:55:39 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:55:39 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:55:39 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
2021.04.15 08:55:39 1: ERROR: addToWritebuffer for WEB_192.168.1.113_55835 without FD
.....
Out of memory!


Zitat von: rudolfkoenig am 15 April 2021, 19:00:22
Dann muss ein Wunder vorliegen, da laut aktuellen Code:

Code Auswählen Erweitern

    Log 1, "ERROR: addToWritebuffer for $n without FD";
    Log 1, "callstack:".stacktraceAsString(1);
    Log 1, "FD closed in ".$hash->{stacktrace} if($hash->{stacktrace});

diese Zeile nie alleine im Log erscheint.

Hallo Rudi,

anbei mein update check

fhem
List of new / modified files since last update:
UPD ./CHANGED
UPD FHEM/00_SONOS.pm (excluded from update)
UPD FHEM/01_FHEMWEB.pm
UPD FHEM/10_CUL_HM.pm
UPD FHEM/21_SONOSPLAYER.pm (excluded from update)
UPD FHEM/36_Shelly.pm
UPD FHEM/47_OBIS.pm
UPD FHEM/49_IPCAM.pm
UPD FHEM/69_SoftliqCloud.pm
UPD FHEM/70_BOTVAC.pm
UPD FHEM/70_BRAVIA.pm
UPD FHEM/73_DoorBird.pm
UPD FHEM/73_ElectricityCalculator.pm
UPD FHEM/73_GasCalculator.pm
UPD FHEM/73_WaterCalculator.pm
UPD FHEM/98_DOIF.pm
UPD FHEM/99_SUNRISE_EL.pm
UPD FHEM/HttpUtils.pm
UPD FHEM/lib/AttrTemplate/ipcam.template
UPD FHEM/lib/UPnP/ControlPoint.pm (excluded from update)
UPD FHEM/lib/fhem_zwave_deviceconfig.xml.gz
UPD FHEM/lib/openzwave_manufacturer_specific.xml

New entries in the CHANGED file:
- bugfix:  70_BOTVAC: transient map cache
- bugfix:  73_DoorBird: Event Video Routine
- bugfix:  73_ElectricityCalculator: Bugfix - Midnight-Crash
- bugfix:  73_WaterCalculator:       Bugfix - Midnight-Crash
- bugfix:  73_GasCalculator:         Bugfix - Midnight-Crash
- bugfix:  70_BRAVIA: fix registration renewal
- change:  49_IPCAM: imageWithCallback wrapped in internalTimer with 0 delay
Downloading https://raw.githubusercontent.com/nagel86/fhem-flex/master/controls_fhem-flex.txt


Ich sehe kein fhem.pl oder TcpServerUtils.pm.

fhem.pl vom 07.03.2021
TcpServerUtils.pm vom 19.01.2021

Passt das dann so zur aktuellen 01_FHEMWEB.pm? Besser einmal gefragt, bevor ich update.

Grüße Jörg

@JoWiemann:

ZitatTcpServerUtils.pm vom 19.01.2021

Meine Version vom TcpServerUtils.pm ist vom 2021-01-04. Staun.
Sonst: einfach update machen, dann funktioniert das, wie bei den hundert anderen freiwilligen FHEM-Tester auch, die taeglich updaten.

@webdandy:
die deep recursion Zeilen sind sehr suspekt, ich habe den Code daraufhin untersucht, diverse Theorien aufgestellt, getestet, verworfen: ich habe keine Ahnung, wie das entstehen koennte. Auch in diesem Log fehlen wundersamerweise die von mir bemaengelten stacktrace Zeilen, dafuer habe ich auch keine Erklaerung. Es sei denn, die "Platte" ist korrupt, was natuerlich immer alles erklaeren kann.

Zitat von: rudolfkoenig am 16 April 2021, 18:54:07
@JoWiemann:Meine Version vom TcpServerUtils.pm ist vom 2021-01-04. Staun.
Sonst: einfach update machen, dann funktioniert das, wie bei den hundert anderen freiwilligen FHEM-Tester auch, die taeglich updaten.

Sorry mein Fehler. War das Dateidatum. Also Zeitpunkt des updates. Auf meinem Testsystem alles Ok. Morgen geht es dann auf das Prod-System.

Grüße Jörg

Hallo,
das Thema ist schon über ein Jahr alt, hoffe das ist kein Problem das ich es noch mal hochhole.

Habe folgende Meldung:
2022.05.07 01:34:34.238 1: ERROR: addToWritebuffer for WEB_127.0.0.1_44246 without FD
2022.05.07 01:34:34.238 1: callstack: addToWritebuffer:749 FW_addToWritebuffer:1240 readingsGroup_Update:1490 readingsGroup_Notify:3932 CallFn:3844 DoTrigger:4947 readingsEndUpdate:2018 HUEDevice_Parse:2854 HUEBridge_dispatch:720 __ANON__:778

Was kann ich tun?

Danke und VG
Dieter

Moin,

ich schliesse mich der Frage an. Was kann ich tun?
2022.05.07 08:59:57 1: ERROR: addToWritebuffer for PDA_192.168.1.108_60234 without FD
2022.05.07 08:59:57 1: callstack: addToWritebuffer:749 FW_addToWritebuffer:1240 readingsGroup_Update:1547 readingsGroup_Notify:3932 CallFn:3844 DoTrigger:4229 Dispatch:566 MQTT2_SERVER_doPublish:446 MQTT2_SERVER_Read:3932 CallFn:781


Gruss
  Enno

ZitatWas kann ich tun?

- diese Fehlermeldung ignorieren
- den Browserfenster, wo ein readingsGroup anzeigt wird, nicht schliessen
- readingsGroup Modul-Maintainer bitten, den zweiten FW_addToWritebuffer nur dann aufzurufen, wenn nach dem ersten die Verbindung nicht geschlossen wurde.

Hallo,

ich habe seit kurzem auch das Phänomen, dass ich den Fehler erhalte. Die einzige Änderung war, dass ich ein Shelly 1pm hinzugefügt habe.

2022.07.08 15:45:55 1: ERROR: addToWritebuffer for fhemapp_192.168.216.102_53550 without FD
2022.07.08 15:45:55 1: callstack: addToWritebuffer:749 FW_addToWritebuffer:707 FW_initInform:576 FW_Read:3950 CallFn:781
2022.07.08 15:45:55 1: FD closed in  TcpServer_Close:579 TcpServer_WriteBlocking:560 FW_Read:3950 CallFn:781



2022.07.08 15:45:56 1: ERROR: addToWritebuffer for WEB_192.168.216.102_53552 without FD
2022.07.08 15:45:56 1: callstack: addToWritebuffer:749 FW_addToWritebuffer:707 FW_initInform:576 FW_Read:3950 CallFn:781
2022.07.08 15:45:56 1: FD closed in  TcpServer_Close:579 TcpServer_WriteBlocking:560 FW_Read:3950 CallFn:781


Gibt es irgendwas, wie ich den Fehler beheben kann??

VG Felix

2022.07.09 07:46:08 1: ERROR: addToWritebuffer for WEB_192.168.1.53_50190 without FD
2022.07.09 07:46:08 1: callstack: addToWritebuffer:749 FW_addToWritebuffer:1240 readingsGroup_Update:1547 readingsGroup_Notify:3950 CallFn:3862 DoTrigger:4247 Dispatch:1642 ESPEasy_dispatch:1109 ESPEasy_Read:3950 CallFn:781
2022.07.09 08:23:06 1: ERROR: addToWritebuffer for WEB_192.168.1.53_50196 without FD
2022.07.09 08:23:06 1: callstack: addToWritebuffer:749 FW_addToWritebuffer:1240 readingsGroup_Update:1547 readingsGroup_Notify:3950 CallFn:3862 DoTrigger:4247 Dispatch:1642 ESPEasy_dispatch:1109 ESPEasy_Read:3950 CallFn:781
ich das gleiche, die IP Adresse stammt von einem PI. Im Browser ( Chrom ) wir  Fhem angezeigt.

Zitat von: rudolfkoenig am 07 Mai 2022, 11:15:02

- readingsGroup Modul-Maintainer bitten, den zweiten FW_addToWritebuffer nur dann aufzurufen, wenn nach dem ersten die Verbindung nicht geschlossen wurde.

Ich weiss nicht was ich da machen soll :-\

Ich habe jetzt in FW_addToWriteBuffer das Schreiben ohne FD blockiert.
Das ist ein bisschen unter dem Teppich kehren, allerdings glaube ich, dass man race-condition lieber hier, und nicht in jedem Aufrufer pruefen soll.

Damit sollte sich auch die readingsGroup Meldung erledigt haben.
@Jonny1957: auch wenn das jetzt zwecklos geworden ist: neues Thema aufmachen im readingsGroup Abschnitt (siehe https://fhem.de/MAINTAINER.txt) mit passenden Ueberschrift und Beschreibung.

Danke!