freez durch readingsgroup

Begonnen von iamandy, 08 April 2018, 13:47:47

Vorheriges Thema - Nächstes Thema

iamandy

Sonnige Grüße!

Ich habe ein Phänomen mit readingsGroup das ich nicht verstehe!

Mein System hängt immer mal (teilweise 552 Sekunden)! Seit Freezemon versuche ich das ganze einzugrenzen, komme aber immer noch nicht recht weiter. Ich weiß nur, dass wenn ich meine readingsGroup disable sind die freezes weg.

Jetzt habe ich einen einfachen Test gemacht und selbst hier hängt mein fhem.

Ich habe ein readingsGroup und ein dummy, beide verwende ich in keinem anderem Device. Ungewöhnlich ist vielleicht, dass ich dem Dummy 3 statt 2 Zustände gebe und das ich mit commands im readingsGroup arbeite.

Wenn ich jetzt zwischen den Zuständen hin und her schalte, habe ich bis zu 5 Sekunden freezes. Auch wenn ich im dummy und nicht im readingsGroup hin und her schalte hängt das System...

Das ist doch nicht normal, oder?

define test2.rg readingsGroup Test.dum:state,<One>,<On>,<Off>
attr test2.rg commands {\
'test2.rg.On'  => 'set $DEVICE on',\
'test2.rg.Off' => 'set $DEVICE off',\
'test2.rg.One' => 'set $DEVICE one',\
}
attr test2.rg room Test
attr test2.rg valueIcon {\
'Test.dum.state.on'  => 'general_an@green',\
'Test.dum.state.off' => 'general_aus@dimgrey',\
'Test.dum.state.one' => 'general_an@yellowgreen',\
}


define Test.dum dummy
attr Test.dum webCmd one:on:off




mumpitzstuff

Vermutlich eine Schleife? Du schaltest, dann wird deine Readingsgroup getriggert, diese schaltet wieder und triggert erneut deine Readingsgroup usw.

iamandy

Wo ist diese Schleife? Es gibt doch keine Devices die auf test2.rg oder Test.dum zugreifen.

BTW: Ich habe herausgefunden, dass wenn ich das Attr valueIcon lösche, dann ist das freez weg!

Auch bei allen anderen readingsGroup habe ich keine Probleme mehr, sobald ich das Attr valueIcon lösche...

KernSani

Ich habe das gerade mal in meinem Testsystem nachgebaut und kann es nicht nachvollziehen... Schaltet auch mit valueIcon ohne Verzögerung...
Wie sieht denn dein verbose 5 Log vom Freeze aus?

RasPi: RFXTRX, HM, zigbee2mqtt, mySensors, JeeLink, miLight, squeezbox, Alexa, Siri, ...

iamandy

Es schaltet bei mir auch, es dauert nur ein paar Sekunden und in der zeit gibt es einen freez. Man bemerkt sofort den Geschwindigkeitsunterschied mit und ohne valueIcon....

Ich habe auch ein test System, aber auf meinem habe ich den Fehler auch. Ich nutze das stylesheet ios7, kann es daher kommen? Ich habe es leicht modifiziert...

Ich habe kurz verbose 5 laufen lassen und zwei mal umgeschaltet, denke der folgende Log Teil sollte der richtige sein.

2018.04.08 22:09:28 5: [Freezemon] Freezemon: ----------- Ending Freeze handling at 2018.04.08 22:09:28.120 after 0.031693 --------
2018.04.08 22:09:28 5: End notify loop for Freezemon
2018.04.08 22:09:28 5: battStatus: not on any display, ignoring notify
2018.04.08 22:09:28 5: Starting notify loop for Freezemon, 5 event(s), first is s:22:09:27 e:22:09:28 f:1.088 d:no bad guy found :-(
2018.04.08 22:09:28 1: [Freezemon] Freezemon: possible freeze starting at 22:09:27, delay is 1.088 possibly caused by: no bad guy found :-(
2018.04.08 22:09:28 5: [Freezemon] Freezemon: ----------- Starting Freeze handling at 2018.04.08 22:09:28.088 ---------------------
/
2018.04.08 22:09:28 4: WEB: /fhem?XHR=1&cmd=set%20Test.dum%20one&fwcsrf=csrf_792019021940299&fw_id=457986 / RL:20 / text/plain; charset=UTF-8 / Content-Encoding: gzip
2018.04.08 22:09:28 5: End notify loop for Test.dum
2018.04.08 22:09:28 5: End notify loop for test2.rg
2018.04.08 22:09:26 5: Starting notify loop for test2.rg, 1 event(s), first is Test.dum.state: <html><svg class="icon general_an yellowgreen" data-txt="one"    xmlns:dc="http://purl.org/dc/elements/1.1/"    xmlns:cc="http://creativecommons.org/ns#"    xmlns:rdf="http://www.w3.org/1999/02/22-rdf-syntax-ns#"    xmlns:svg="http://www.w3.org/2000/svg"    xmlns="http://www.w3.org/2000/svg"    xmlns:sodipodi="http://sodipodi.sourceforge.net/DTD/sodipodi-0.dtd"    xmlns:inkscape="http://www.inkscape.org/namespaces/inkscape"    version="1.0"    width="468pt"    height="468pt"    viewBox="0 0 468 468"    id="svg2"    inkscape:version="0.48.4 r9939"    sodipodi:docname="general_an.svg">   <sodipodi:namedview      pagecolor="#ffffff"      bordercolor="#666666"      borderopacity="1"      objecttolerance="10"      gridtolerance="10"      guidetolerance="10"      inkscape:pageopacity="0"      inkscape:pageshadow="2"      inkscape:window-width="795"      inkscape:window-height="480"      id="namedview10"      showgrid="false"      inkscape:zoom="0.4034188"      inkscape:cx="787.02331"      inkscape:cy="292.5"      inkscape:window-x="504"      inkscape:window-y="110"      inkscape:window-maximized="0"      inkscape:current-layer="layer1" />   <defs      id="defs12" />   <metadata      id="metadata4"> Created by potrace 1.8, written by Peter Selinger 2001-2007 <rdf:RDF>   <cc:Work      rdf:about="">     <dc:format>image/svg+xml</dc:format>     <dc:type        rdf:resource="http://purl.org/dc/dcmitype/StillImage" />     <dc:title></dc:title>   </cc:Work> </rdf:RDF> </metadata>   <g      transform="matrix(0.189474,0,0,-0.189474,0,468)"      id="g6"      fill="yellowgreen"      stroke="none">     <path        d="M 395,2455 C 244,2422 112,2322 57,2200 5,2083 6,2112 2,1260 0,702 2,446 10,400 43,208 198,52 398,11 c 71,-15 1628,-15 1692,0 174,40 322,190 365,370 22,94 22,1579 0,1683 -21,98 -66,187 -127,252 -61,64 -113,98 -201,128 -61,21 -75,21 -867,23 -640,1 -817,-1 -865,-12 z m 1737,-163 c 74,-36 132,-95 170,-170 l 23,-47 0,-840 0,-840 -28,-57 c -37,-76 -96,-134 -171,-169 l -63,-29 -839,2 -839,3 -50,27 C 273,204 196,285 167,348 l -22,47 0,840 0,840 27,52 c 53,100 128,162 227,189 35,10 236,12 856,11 l 810,-2 67,-33 z"        id="path8" />   </g>      <g        transform="scale(0.92809982,1.0774703)"        id="text2990" \t   fill="yellowgreen"  \t   stroke="none">       <path          d="m 133.53428,276.73193 45.10187,-117.44109 16.74297,0 48.06593,117.44109 -17.70429,0 -13.69879,-35.56879 -49.10736,0 -12.89769,35.56879 z m 33.88648,-48.22615 39.81462,0 -12.25681,-32.52461 c -3.73852,-9.88013 -6.51566,-17.99792 -8.33143,-24.35341 -1.49544,7.53043 -3.605,15.00734 -6.32868,22.43077 z"          id="path2988" />       <path          d="m 255.86208,276.73193 0,-117.44109 15.94187,0 61.68461,92.20648 0,-92.20648 14.90044,0 0,117.44109 -15.94187,0 -61.68461,-92.28659 0,92.28659 z"          id="path2990" />     </g>  </svg></html>
2018.04.08 22:09:26 5: battStatus: no longer visible, ignoring notify
2018.04.08 22:09:26 5: Starting notify loop for Test.dum, 1 event(s), first is one
2018.04.08 22:09:26 4: dummy set Test.dum one
2018.04.08 22:09:26 5: Cmd: >set Test.dum one<
2018.04.08 22:09:26 4: WEB_192.168.178.58_58969 POST /fhem?XHR=1&cmd=set%20Test.dum%20one&fwcsrf=csrf_792019021940299&fw_id=457986; BUFLEN:0


2018.04.08 22:09:28 1: [Freezemon] Freezemon: possible freeze starting at 22:09:27, delay is 1.088 possibly caused by: no bad guy found :-(
2018.04.08 22:09:28 5: [Freezemon] Freezemon: ----------- Starting Freeze handling at 2018.04.08 22:09:28.088 ---------------------
/
2018.04.08 22:09:28 4: WEB: /fhem?XHR=1&cmd=set%20Test.dum%20one&fwcsrf=csrf_792019021940299&fw_id=457986 / RL:20 / text/plain; charset=UTF-8 / Content-Encoding: gzip
2018.04.08 22:09:28 5: End notify loop for Test.dum
2018.04.08 22:09:28 5: End notify loop for test2.rg
2018.04.08 22:09:26 5: Starting notify loop for test2.rg, 1 event(s), first is Test.dum.state: <html><svg class="icon general_an yellowgreen" data-txt="one"    xmlns:dc="http://purl.org/dc/elements/1.1/"    xmlns:cc="http://creativecommons.org/ns#"    xmlns:rdf="http://www.w3.org/1999/02/22-rdf-syntax-ns#"    xmlns:svg="http://www.w3.org/2000/svg"    xmlns="http://www.w3.org/2000/svg"    xmlns:sodipodi="http://sodipodi.sourceforge.net/DTD/sodipodi-0.dtd"    xmlns:inkscape="http://www.inkscape.org/namespaces/inkscape"    version="1.0"    width="468pt"    height="468pt"    viewBox="0 0 468 468"    id="svg2"    inkscape:version="0.48.4 r9939"    sodipodi:docname="general_an.svg">   <sodipodi:namedview      pagecolor="#ffffff"      bordercolor="#666666"      borderopacity="1"      objecttolerance="10"      gridtolerance="10"      guidetolerance="10"      inkscape:pageopacity="0"      inkscape:pageshadow="2"      inkscape:window-width="795"      inkscape:window-height="480"      id="namedview10"      showgrid="false"      inkscape:zoom="0.4034188"      inkscape:cx="787.02331"      inkscape:cy="292.5"      inkscape:window-x="504"      inkscape:window-y="110"      inkscape:window-maximized="0"      inkscape:current-layer="layer1" />   <defs      id="defs12" />   <metadata      id="metadata4"> Created by potrace 1.8, written by Peter Selinger 2001-2007 <rdf:RDF>   <cc:Work      rdf:about="">     <dc:format>image/svg+xml</dc:format>     <dc:type        rdf:resource="http://purl.org/dc/dcmitype/StillImage" />     <dc:title></dc:title>   </cc:Work> </rdf:RDF> </metadata>   <g      transform="matrix(0.189474,0,0,-0.189474,0,468)"      id="g6"      fill="yellowgreen"      stroke="none">     <path        d="M 395,2455 C 244,2422 112,2322 57,2200 5,2083 6,2112 2,1260 0,702 2,446 10,400 43,208 198,52 398,11 c 71,-15 1628,-15 1692,0 174,40 322,190 365,370 22,94 22,1579 0,1683 -21,98 -66,187 -127,252 -61,64 -113,98 -201,128 -61,21 -75,21 -867,23 -640,1 -817,-1 -865,-12 z m 1737,-163 c 74,-36 132,-95 170,-170 l 23,-47 0,-840 0,-840 -28,-57 c -37,-76 -96,-134 -171,-169 l -63,-29 -839,2 -839,3 -50,27 C 273,204 196,285 167,348 l -22,47 0,840 0,840 27,52 c 53,100 128,162 227,189 35,10 236,12 856,11 l 810,-2 67,-33 z"        id="path8" />   </g>      <g        transform="scale(0.92809982,1.0774703)"        id="text2990" \t   fill="yellowgreen"  \t   stroke="none">       <path          d="m 133.53428,276.73193 45.10187,-117.44109 16.74297,0 48.06593,117.44109 -17.70429,0 -13.69879,-35.56879 -49.10736,0 -12.89769,35.56879 z m 33.88648,-48.22615 39.81462,0 -12.25681,-32.52461 c -3.73852,-9.88013 -6.51566,-17.99792 -8.33143,-24.35341 -1.49544,7.53043 -3.605,15.00734 -6.32868,22.43077 z"          id="path2988" />       <path          d="m 255.86208,276.73193 0,-117.44109 15.94187,0 61.68461,92.20648 0,-92.20648 14.90044,0 0,117.44109 -15.94187,0 -61.68461,-92.28659 0,92.28659 z"          id="path2990" />     </g>  </svg></html>
2018.04.08 22:09:26 5: battStatus: no longer visible, ignoring notify
2018.04.08 22:09:26 5: Starting notify loop for Test.dum, 1 event(s), first is one
2018.04.08 22:09:26 4: dummy set Test.dum one
2018.04.08 22:09:26 5: Cmd: >set Test.dum one<
2018.04.08 22:09:26 4: WEB_192.168.178.58_58969 POST /fhem?XHR=1&cmd=set%20Test.dum%20one&fwcsrf=csrf_792019021940299&fw_id=457986; BUFLEN:0

KernSani

der Log-Auszug ist zu spät, da ist der freeze schon vorbei. Setz mal das fm_logFile-Attribut im freeze device, dann wird dir ein verbose 5 log vom Zeitpunkt des Freezes (und davor) erzeugt (unabhängig vom global verbose level).
RasPi: RFXTRX, HM, zigbee2mqtt, mySensors, JeeLink, miLight, squeezbox, Alexa, Siri, ...

iamandy

Viel mehr ist da aber nicht. Ich habe es jetzt mit fm_log gemacht...:

jump to the end

=========================================================

[Freezemon] Freezemon: possible freeze starting at 22:51:00, delay is 3.412 possibly caused by: no bad guy found :-(

2018.04.08 22:50:59.243 5: JeeLink/RAW: /OK 9 0 1 4 146 54



2018.04.08 22:50:59.448 4: Connection accepted from telnetPort_127.0.0.1_34972

2018.04.08 22:50:59.450 5: Cmd: >exit<

2018.04.08 22:50:59.468 4: WEB_192.168.178.58_59236 POST /fhem?XHR=1&cmd=set%20Test.dum%20off&fwcsrf=csrf_792019021940299&fw_id=460563; BUFLEN:0

2018.04.08 22:50:59.469 5: Cmd: >set Test.dum off<

2018.04.08 22:50:59.470 4: dummy set Test.dum off

2018.04.08 22:50:59.483 5: battStatus: not on any display, ignoring notify

--- log skips     3.927 secs.

2018.04.08 22:51:03.410 5: End notify loop for test2.rg

2018.04.08 22:51:03.411 5: End notify loop for Test.dum

2018.04.08 22:51:03.411 4: WEB: /fhem?XHR=1&cmd=set%20Test.dum%20off&fwcsrf=csrf_792019021940299&fw_id=460563 / RL:20 / text/plain; charset=UTF-8 / Content-Encoding: gzip

/

[Freezemon] Freezemon: possible freeze starting at 22:51:00, delay is 3.412 possibly caused by: no bad guy found :-(


jump to the top

KernSani

Hmmm... schade... readingsgroup scheint an der Stelle nicht sehr gesprächig zu sein. Da kann dann vermutlich nur noch Andre selbst helfen...
RasPi: RFXTRX, HM, zigbee2mqtt, mySensors, JeeLink, miLight, squeezbox, Alexa, Siri, ...

iamandy

Ich habe heute angefangen mein komplettes FHEM (ich habe vorher ein Backup gemacht) device für device zu löschen. Wie es der Zufall so will, musste ich 95% löschen, bis ich das Problem mit gelöscht und damit eingekreist habe....

Auch wenn ich es nicht verstehe, es war die folgende Zeile, die alles ausgelöst hat und eine extrem Wirkung auf readingsGroup zu haben scheint:

define FileLog_Doif FileLog /run/fhem/Doif-%Y-%m.log .*Doif:cmd_nr:.*|.*Doif:error:.*|.*Doif:wait_timer:.*|Display.Flur.dum:.*|Motion.Flur:.*|Motion.Flur_Btn_01:.*|Motion.Flur_Btn_02:.*|Motion.Flur_Motion:.*|Schalter.Flur.Doif:motion-on:.*|SchalterFlur1:.*|Test_Doif:.*|pushandy:lastMessage:.*|pushmsg:lastMessage:.*


Die Regexp parts im FileLog die mit einem .* beginnen musste ich löschen (also die ersten 3). Jetzt sieht es so aus als würde alles laufen wie es soll.

Warum dieses auf meine readingsGroup mit den Attributen valueIcon und commands und nur auf die, so krasse Wirkung zeigt verstehe ich nicht. Vielleicht kann es mir jemand erklären?  :-[