Neues Modul: Performance Monitor

Begonnen von herrmannj, 10 November 2013, 12:49:13

Vorheriges Thema - Nächstes Thema

Spezialtrick

Hallo Jörg.

Ich habe das Verbose auf 5 hoch gesetzt. Leider finde ich nicht so recht woran es liegen könnte. Findest du was?

2014.07.09 13:22:39 1: Perfmon: possible freeze starting at 13:22:36, delay is 3.012
2014.07.09 13:22:39 5: Triggering rr_Miro (2 changes)
2014.07.09 13:22:39 5: Notify loop for rr_Miro durTimerPresence_cr: 9686
2014.07.09 13:22:39 4: eventTypes: ROOMMATE rr_Miro durTimerPresence_cr: 9686 -> durTimerPresence_cr: .*
2014.07.09 13:22:39 4: eventTypes: ROOMMATE rr_Miro durTimerPresence: 161:25:57 -> durTimerPresence: .*:.*:.*
2014.07.09 13:22:39 5: Triggering rr_Angie (2 changes)
2014.07.09 13:22:39 5: Notify loop for rr_Angie durTimerAbsence_cr: 34236
2014.07.09 13:22:39 4: eventTypes: ROOMMATE rr_Angie durTimerAbsence_cr: 34236 -> durTimerAbsence_cr: .*
2014.07.09 13:22:39 4: eventTypes: ROOMMATE rr_Angie durTimerAbsence: 570:35:46 -> durTimerAbsence: .*:.*:.*
2014.07.09 13:22:39 5: SYSMON Update
2014.07.09 13:22:39 5: SYSMON SYSMON_getNetworkInfo get eth0:eth0:Ethernet
2014.07.09 13:22:39 5: SYSMON SYSMON_getNetworkInfo get wlan0:wlan0:WiFi
2014.07.09 13:22:39 5: Triggering sysmon (6 changes)
2014.07.09 13:22:39 5: Notify loop for sysmon cpu_freq: 700
2014.07.09 13:22:39 4: eventTypes: SYSMON sysmon cpu_freq: 700 -> cpu_freq: .*
2014.07.09 13:22:39 4: eventTypes: SYSMON sysmon eth0_diff: RX: 0.01 MB, TX: 0.05 MB, Total: 0.06 MB -> eth0_diff: RX: .* MB, TX: .* MB, Total: .* MB
2014.07.09 13:22:39 4: eventTypes: SYSMON sysmon cpu_temp_avg: 48.3 -> cpu_temp_avg: .*
2014.07.09 13:22:39 4: eventTypes: SYSMON sysmon cpu_temp: 48.15 -> cpu_temp: .*
2014.07.09 13:22:39 4: eventTypes: SYSMON sysmon loadavg: 0.06 0.11 0.13 -> loadavg: .* .* .*
2014.07.09 13:22:39 4: eventTypes: SYSMON sysmon ram: Total: 485.24 MB, Used: 88.16 MB, 18.17 %, Free: 397.08 MB -> ram: Total: .* MB, Used: .* MB, .* %, Free: .* MB
2014.07.09 13:22:43 5: FHEMduino/RAW: /K3
2014.07.09 13:22:43 5: FHEMduino/RAW: K3/5000+1
2014.07.09 13:22:43 5: FHEMduino/RAW: K35000+1/3789
2014.07.09 13:22:43 5: FHEMduino/RAW: K35000+13789
/

2014.07.09 13:22:43 5: FHEMduino: K35000+13789
2014.07.09 13:22:43 5: FHEMduino dispatch K35000+13789
2014.07.09 13:22:43 5: FingerprintFn Message: Name: FHEMduino  und Message: K35000+13789
2014.07.09 13:22:43 4: FHEMduino_KW9010 FHEMduino_KW9010_35: T 13.7 H 89
2014.07.09 13:22:44 5: FHEMduino/RAW: /K
2014.07.09 13:22:44 5: FHEMduino/RAW: K/35000+1378
2014.07.09 13:22:44 5: FHEMduino/RAW: K35000+1378/9

2014.07.09 13:22:44 5: FHEMduino: K35000+13789
2014.07.09 13:22:44 5: FHEMduino dispatch K35000+13789
2014.07.09 13:22:44 5: FingerprintFn Message: Name: FHEMduino  und Message: K35000+13789
2014.07.09 13:22:44 4: FHEMduino_KW9010 FHEMduino_KW9010_35: T 13.7 H 89
2014.07.09 13:22:44 5: FHEMduino/RAW: /K3
2014.07.09 13:22:44 5: FHEMduino/RAW: K3/5000+1
2014.07.09 13:22:44 5: FHEMduino/RAW: K35000+1/3789
2014.07.09 13:22:44 5: FHEMduino/RAW: K35000+13789/

2014.07.09 13:22:44 5: FHEMduino: K35000+13789
2014.07.09 13:22:44 5: FHEMduino dispatch K35000+13789
2014.07.09 13:22:44 5: FingerprintFn Message: Name: FHEMduino  und Message: K35000+13789
2014.07.09 13:22:44 4: FHEMduino_KW9010 FHEMduino_KW9010_35: T 13.7 H 89
2014.07.09 13:23:00 5: exec at command tickHeartbeat
2014.07.09 13:23:00 5: Cmd: >{tickHeartbeat('Server_Heartbeat');}<
2014.07.09 13:23:00 5: Cmd: >set Server_Heartbeat 5<
2014.07.09 13:23:00 4: dummy set Server_Heartbeat 5
2014.07.09 13:23:00 5: Triggering Server_Heartbeat (2 changes)
2014.07.09 13:23:00 5: Notify loop for Server_Heartbeat 5
2014.07.09 13:23:00 4: eventTypes: dummy Server_Heartbeat 5 -> .*
2014.07.09 13:23:00 4: eventTypes: dummy Server_Heartbeat lastChange: 13:23:00 -> lastChange: .*:.*:.*
2014.07.09 13:23:00 4: eventTypes: dummy Server_Heartbeat state: 5 -> state: .*
2014.07.09 13:23:00 5: redefine at command tickHeartbeat as +*00:01:00 {tickHeartbeat('Server_Heartbeat');}
2014.07.09 13:23:01 4: Connection accepted from FHEMWEB:127.0.0.1:40464
2014.07.09 13:23:02 4: Connection accepted from FHEMWEB:127.0.0.1:40465
2014.07.09 13:23:02 4: Connection closed for FHEMWEB:127.0.0.1:40464
2014.07.09 13:23:02 4: HTTP FHEMWEB:127.0.0.1:40465 GET /fhem/rss/FrameRSS.jpg
2014.07.09 13:23:02 4: /fhem/rss/FrameRSS.jpg / RL:10127 / image/jpeg; charset=utf-8 /  /
2014.07.09 13:23:02 4: Connection accepted from FHEMWEB:127.0.0.1:40466
2014.07.09 13:23:02 4: Connection closed for FHEMWEB:127.0.0.1:40465
2014.07.09 13:23:02 4: HTTP FHEMWEB:127.0.0.1:40466 GET /fhem/rss/FrameRSS.jpg
2014.07.09 13:23:02 4: /fhem/rss/FrameRSS.jpg / RL:10127 / image/jpeg; charset=utf-8 /  /
2014.07.09 13:23:02 4: Connection closed for FHEMWEB:127.0.0.1:40466
2014.07.09 13:23:15 5: FHEMduino/RAW: /K3
2014.07.09 13:23:15 5: FHEMduino/RAW: K3/5000+1
2014.07.09 13:23:15 5: FHEMduino/RAW: K35000+1/3789
2014.07.09 13:23:15 5: FHEMduino/RAW: K35000+13789/

2014.07.09 13:23:15 5: FHEMduino: K35000+13789
2014.07.09 13:23:15 5: FHEMduino dispatch K35000+13789
2014.07.09 13:23:15 5: FingerprintFn Message: Name: FHEMduino  und Message: K35000+13789
2014.07.09 13:23:15 4: FHEMduino_KW9010 FHEMduino_KW9010_35: T 13.7 H 89
2014.07.09 13:23:16 5: FHEMduino/RAW: /K
2014.07.09 13:23:16 5: FHEMduino/RAW: K/35000+
2014.07.09 13:23:16 5: FHEMduino/RAW: K35000+/1378
2014.07.09 13:23:16 5: FHEMduino/RAW: K35000+1378/9

2014.07.09 13:23:16 5: FHEMduino: K35000+13789
2014.07.09 13:23:16 5: FHEMduino dispatch K35000+13789
2014.07.09 13:23:16 5: FingerprintFn Message: Name: FHEMduino  und Message: K35000+13789
2014.07.09 13:23:16 4: FHEMduino_KW9010 FHEMduino_KW9010_35: T 13.7 H 89
2014.07.09 13:23:16 5: FHEMduino/RAW: /K3
2014.07.09 13:23:16 5: FHEMduino/RAW: K3/5000+1
2014.07.09 13:23:16 5: FHEMduino/RAW: K35000+1/378
2014.07.09 13:23:16 5: FHEMduino/RAW: K35000+1378/9

2014.07.09 13:23:16 5: FHEMduino: K35000+13789
2014.07.09 13:23:16 5: FHEMduino dispatch K35000+13789
2014.07.09 13:23:16 5: FingerprintFn Message: Name: FHEMduino  und Message: K35000+13789
2014.07.09 13:23:16 4: FHEMduino_KW9010 FHEMduino_KW9010_35: T 13.7 H 89
2014.07.09 13:23:22 5: Cmd: >{fhem("set Druckauftrag ".`/opt/fhem/cups.sh`)}<
2014.07.09 13:23:22 5: Cmd: >set Druckauftrag abgeschlossen
<
2014.07.09 13:23:22 5: Triggering Druckauftrag (1 changes)
2014.07.09 13:23:22 5: Notify loop for Druckauftrag abgeschlossen

2014.07.09 13:23:22 4: eventTypes: dummy Druckauftrag abgeschlossen
-> abgeschlossen

2014.07.09 13:23:22 4: eventTypes: dummy Druckauftrag state: abgeschlossen
-> state: abgeschlossen

2014.07.09 13:23:27 5: FHEMduino/RAW: /K
2014.07.09 13:23:27 5: FHEMduino/RAW: K/fc100+
2014.07.09 13:23:27 5: FHEMduino/RAW: Kfc100+/2551
2014.07.09 13:23:27 5: FHEMduino/RAW: Kfc100+2551/27

2014.07.09 13:23:27 5: FHEMduino: Kfc100+255127
2014.07.09 13:23:27 5: FHEMduino dispatch Kfc100+255127
2014.07.09 13:23:27 5: FingerprintFn Message: Name: FHEMduino  und Message: Kfc100+255127
2014.07.09 13:23:27 5: Triggering FHEMduino (1 changes)
2014.07.09 13:23:27 5: Notify loop for FHEMduino UNKNOWNCODE Kfc100+255127
2014.07.09 13:23:27 4: eventTypes: FHEMduino FHEMduino UNKNOWNCODE Kfc100+255127 -> UNKNOWNCODE Kfc100+.*
2014.07.09 13:23:27 3: FHEMduino: Unknown code Kfc100+255127, help me!
2014.07.09 13:23:27 5: FHEMduino/RAW: /K
2014.07.09 13:23:27 5: FHEMduino/RAW: K/fc100+
2014.07.09 13:23:27 5: FHEMduino/RAW: Kfc100+/2551
2014.07.09 13:23:27 5: FHEMduino/RAW: Kfc100+2551/27

2014.07.09 13:23:27 5: FHEMduino: Kfc100+255127
2014.07.09 13:23:27 5: FHEMduino dispatch Kfc100+255127
2014.07.09 13:23:27 5: FingerprintFn Message: Name: FHEMduino  und Message: Kfc100+255127
2014.07.09 13:23:27 5: Triggering FHEMduino (1 changes)
2014.07.09 13:23:27 5: Notify loop for FHEMduino UNKNOWNCODE Kfc100+255127
2014.07.09 13:23:27 4: eventTypes: FHEMduino FHEMduino UNKNOWNCODE Kfc100+255127 -> UNKNOWNCODE Kfc100+.*
2014.07.09 13:23:27 3: FHEMduino: Unknown code Kfc100+255127, help me!
2014.07.09 13:23:27 5: FHEMduino/RAW: /K
2014.07.09 13:23:27 5: FHEMduino/RAW: K/fc100+255
2014.07.09 13:23:27 5: FHEMduino/RAW: Kfc100+255/127

2014.07.09 13:23:27 5: FHEMduino: Kfc100+255127
2014.07.09 13:23:27 5: FHEMduino dispatch Kfc100+255127
2014.07.09 13:23:27 5: FingerprintFn Message: Name: FHEMduino  und Message: Kfc100+255127
2014.07.09 13:23:27 5: Triggering FHEMduino (1 changes)
2014.07.09 13:23:27 5: Notify loop for FHEMduino UNKNOWNCODE Kfc100+255127
2014.07.09 13:23:27 4: eventTypes: FHEMduino FHEMduino UNKNOWNCODE Kfc100+255127 -> UNKNOWNCODE Kfc100+.*
2014.07.09 13:23:27 3: FHEMduino: Unknown code Kfc100+255127, help me!
2014.07.09 13:23:42 1: Perfmon: possible freeze starting at 13:23:39, delay is 3.012
FHEM - Debmatic - Zigbee2MQTT - Homekit

herrmannj

Hi,

ne - leider nicht. Im fraglichen Zeitraum ist im log nichts zu sehen:
2014.07.09 13:23:27 3: FHEMduino: Unknown code Kfc100+255127, help me!
2014.07.09 13:23:42 1: Perfmon: possible freeze starting at 13:23:39, delay is 3.012

Grundsätzlich erscheint aber eben auch nur das im log was die dazugehörigen Module reinschreiben.

Also #3; Module deaktivieren ....

vg
Jörg

Spezialtrick

Ich habe nun nach und nach alle Module bzw die Definition dazu aus meiner fhem.cfg gelöscht, anschließend das Log kontrolliert und wieder eingefügt. Leider komme ich nicht weiter. Die Freezes tauchen immer noch auf. Würde Dir meine hem.cfg Datei helfen das Problem zu finden?

Ein weiterer Auszug:

2014.07.09 17:27:03 4: HTTP FHEMWEB:192.168.178.21:62476 GET /fhem/pgm2/svg.js
2014.07.09 17:27:03 4: HTTP FHEMWEB:192.168.178.21:62482 GET /fhem/pgm2/fhemweb_noArg.js
2014.07.09 17:27:03 4: HTTP FHEMWEB:192.168.178.21:62400 GET /fhem/pgm2/fhemweb_readingsHistory.js
2014.07.09 17:27:03 4: HTTP FHEMWEB:192.168.178.21:62458 GET /fhem/pgm2/fhemweb_slider.js
2014.07.09 17:27:03 4: HTTP FHEMWEB:192.168.178.21:62439 GET /fhem/pgm2/fhemweb_svg.js
2014.07.09 17:27:03 4: HTTP FHEMWEB:192.168.178.21:62476 GET /fhem/pgm2/fhemweb_textField.js
2014.07.09 17:27:03 4: HTTP FHEMWEB:192.168.178.21:62482 GET /fhem/pgm2/fhemweb_time.js
2014.07.09 17:27:03 4: HTTP FHEMWEB:192.168.178.21:62400 GET /fhem/images/default/icoEverything.png
2014.07.09 17:27:03 4: Connection accepted from FHEMWEB:127.0.0.1:41511
2014.07.09 17:27:03 4: Connection closed for FHEMWEB:127.0.0.1:41510
2014.07.09 17:27:03 4: HTTP FHEMWEB:127.0.0.1:41511 GET /fhem/rss/FrameRSS.jpg
2014.07.09 17:27:03 4: /fhem/rss/FrameRSS.jpg / RL:9753 / image/jpeg; charset=utf-8 /  /
2014.07.09 17:27:03 4: Connection closed for FHEMWEB:127.0.0.1:41511
2014.07.09 17:27:03 4: Connection accepted from FHEMWEB:127.0.0.1:41512
2014.07.09 17:27:03 4: HTTP FHEMWEB:127.0.0.1:41512 GET /fhem/rss/FrameRSS.jpg
2014.07.09 17:27:04 4: /fhem/rss/FrameRSS.jpg / RL:9753 / image/jpeg; charset=utf-8 /  /
2014.07.09 17:27:04 4: Connection closed for FHEMWEB:127.0.0.1:41512
2014.07.09 17:27:04 4: HTTP FHEMWEB:192.168.178.21:62400 GET /fhem/FileLog_logWrapper?XHR=1&inform=type=status;filter=×tamp=1404919624489
2014.07.09 17:27:04 4: HTTP FHEMWEB:192.168.178.21:62482 GET /fhem/icons/favicon
2014.07.09 17:27:08 5: [Tageslichtsteuerung] Original weather readings
2014.07.09 17:27:08 5: Triggering Tageslichtsteuerung (5 changes)
2014.07.09 17:27:08 5: Notify loop for Tageslichtsteuerung azimuth: 258.83
2014.07.09 17:27:08 4: eventTypes: Twilight Tageslichtsteuerung azimuth: 258.83 -> azimuth: .*
2014.07.09 17:27:08 4: eventTypes: Twilight Tageslichtsteuerung elevation: 37.19 -> elevation: .*
2014.07.09 17:27:08 4: eventTypes: Twilight Tageslichtsteuerung twilight: 100 -> twilight: .*
2014.07.09 17:27:08 4: eventTypes: Twilight Tageslichtsteuerung twilight_weather: 100 -> twilight_weather: .*
2014.07.09 17:27:08 4: eventTypes: Twilight Tageslichtsteuerung compasspoint: west-southwest -> compasspoint: west-southwest
2014.07.09 17:27:08 5: [Tageslichtsteuerung] removing Timer: Tageslichtsteuerung_sunpos
2014.07.09 17:27:08 5: [Tageslichtsteuerung] setting  Timer: Tageslichtsteuerung_sunpos 09.07.2014  17:32:08
2014.07.09 17:27:09 5: SYSMON Update
2014.07.09 17:27:09 5: SYSMON SYSMON_getNetworkInfo get eth0:eth0:Ethernet
2014.07.09 17:27:09 5: SYSMON SYSMON_getNetworkInfo get wlan0:wlan0:WiFi
2014.07.09 17:27:09 5: Triggering sysmon (6 changes)
2014.07.09 17:27:09 5: Notify loop for sysmon cpu_freq: 700
2014.07.09 17:27:09 4: eventTypes: SYSMON sysmon cpu_freq: 700 -> cpu_freq: .*
2014.07.09 17:27:09 4: eventTypes: SYSMON sysmon eth0_diff: RX: 0.04 MB, TX: 0.85 MB, Total: 0.89 MB -> eth0_diff: RX: .* MB, TX: .* MB, Total: .* MB
2014.07.09 17:27:09 4: eventTypes: SYSMON sysmon cpu_temp_avg: 48.5 -> cpu_temp_avg: .*
2014.07.09 17:27:09 4: eventTypes: SYSMON sysmon cpu_temp: 48.69 -> cpu_temp: .*
2014.07.09 17:27:09 4: eventTypes: SYSMON sysmon loadavg: 0.21 0.26 0.32 -> loadavg: .* .* .*
2014.07.09 17:27:09 4: eventTypes: SYSMON sysmon ram: Total: 485.24 MB, Used: 87.21 MB, 17.97 %, Free: 398.03 MB -> ram: Total: .* MB, Used: .* MB, .* %, Free: .* MB
2014.07.09 17:27:09 5: Cmd: >{fhem("set Druckauftrag ".`/opt/fhem/cups.sh`)}<
2014.07.09 17:27:09 5: Cmd: >set Druckauftrag abgeschlossen
<
2014.07.09 17:27:09 5: Triggering Druckauftrag (1 changes)
2014.07.09 17:27:09 5: Notify loop for Druckauftrag abgeschlossen

2014.07.09 17:27:09 4: eventTypes: dummy Druckauftrag abgeschlossen
-> abgeschlossen

2014.07.09 17:27:09 4: eventTypes: dummy Druckauftrag state: abgeschlossen
-> state: abgeschlossen

2014.07.09 17:27:12 5: SW: ORb
2014.07.09 17:27:12 5: CUL/RAW (ReadAnswer): OK:1

2014.07.09 17:27:16 5: I2C_TSL2561_Enable: start
2014.07.09 17:27:16 5: I2C_TSL2561_ReadByte: start
2014.07.09 17:27:16 5: I2C_TSL2561_ReadByte: 3
2014.07.09 17:27:16 5: I2C_TSL2561_Enable: is enabled
2014.07.09 17:27:16 5: I2C_TSL2561_Enable: end
2014.07.09 17:27:16 5: I2C_TSL2561_Disable: start
2014.07.09 17:27:16 5: I2C_TSL2561_Disable: end
2014.07.09 17:27:16 5: Triggering Luminosity (3 changes)
2014.07.09 17:27:16 5: Notify loop for Luminosity luminosity: 14
2014.07.09 17:27:16 4: eventTypes: I2C_TSL2561 Luminosity luminosity: 14 -> luminosity: .*
2014.07.09 17:27:16 4: eventTypes: I2C_TSL2561 Luminosity broadband: 1 -> broadband: .*
2014.07.09 17:27:16 4: eventTypes: I2C_TSL2561 Luminosity ir: 0 -> ir: .*
2014.07.09 17:27:16 5: Pressure empfangen: 125 240
2014.07.09 17:27:16 5: Pressure empfangen: 153 39 64
2014.07.09 17:27:16 5: Triggering Pressure (4 changes)
2014.07.09 17:27:16 5: Notify loop for Pressure T: 37.2 P: 993 P-NN: 1003
2014.07.09 17:27:16 4: eventTypes: I2C_BMP180 Pressure T: 37.2 P: 993 P-NN: 1003 -> T: .* P: .* P-NN: .*
2014.07.09 17:27:16 4: eventTypes: I2C_BMP180 Pressure temperature: 37.2 -> temperature: .*
2014.07.09 17:27:16 4: eventTypes: I2C_BMP180 Pressure pressure: 993 -> pressure: .*
2014.07.09 17:27:16 4: eventTypes: I2C_BMP180 Pressure pressure-nn: 1003 -> pressure-nn: .*
2014.07.09 17:27:16 4: eventTypes: I2C_BMP180 Pressure state: T: 37.2 P: 993 P-NN: 1003 -> state: T: .* P: .* P-NN: .*
2014.07.09 17:27:16 5: Triggering Server (1 changes)
2014.07.09 17:27:16 5: Notify loop for Server isRunning: true
2014.07.09 17:27:16 4: eventTypes: WOL Server isRunning: true -> isRunning: true
2014.07.09 17:27:19 5: SW: ORb
2014.07.09 17:27:19 5: CUL/RAW (ReadAnswer): OK:1

2014.07.09 17:27:19 5: SW: OmD000000558C41328
2014.07.09 17:27:19 5: CUL/RAW (ReadAnswer): m:D00000
2014.07.09 17:27:19 5: CUL/RAW (ReadAnswer): 0558C413
2014.07.09 17:27:19 5: CUL/RAW (ReadAnswer): 28

2014.07.09 17:27:19 5: SW: OwB44
2014.07.09 17:27:19 5: SW: ORb
2014.07.09 17:27:19 5: CUL/RAW (ReadAnswer): OK:1

2014.07.09 17:27:19 5: SW: OmD000000558C41328
2014.07.09 17:27:19 5: CUL/RAW (ReadAnswer): m:D00000
2014.07.09 17:27:19 5: CUL/RAW (ReadAnswer): 0558C413
2014.07.09 17:27:19 5: CUL/RAW (ReadAnswer): 28

2014.07.09 17:27:19 5: SW: OwBbe
2014.07.09 17:27:19 5: SW: OrB
2014.07.09 17:27:19 5: CUL/RAW (ReadAnswer): 6C

2014.07.09 17:27:19 5: SW: OrB
2014.07.09 17:27:19 5: CUL/RAW (ReadAnswer): 01

2014.07.09 17:27:19 5: SW: OrB
2014.07.09 17:27:19 5: CUL/RAW (ReadAnswer): 4B

2014.07.09 17:27:19 5: SW: OrB
2014.07.09 17:27:20 5: CUL/RAW (ReadAnswer): 46

2014.07.09 17:27:20 5: SW: OrB
2014.07.09 17:27:20 5: CUL/RAW (ReadAnswer): 7F

2014.07.09 17:27:20 5: SW: OrB
2014.07.09 17:27:20 5: CUL/RAW (ReadAnswer): FF

2014.07.09 17:27:20 5: SW: OrB
2014.07.09 17:27:20 5: CUL/RAW (ReadAnswer): 04

2014.07.09 17:27:20 5: SW: OrB
2014.07.09 17:27:20 5: CUL/RAW (ReadAnswer): 10

2014.07.09 17:27:20 5: SW: OrB
2014.07.09 17:27:20 5: CUL/RAW (ReadAnswer): 5D

2014.07.09 17:27:20 5: Triggering OWX_28_13C458050000 (2 changes)
2014.07.09 17:27:20 5: Notify loop for OWX_28_13C458050000 temperature: 22.75
2014.07.09 17:27:20 4: eventTypes: OWTHERM OWX_28_13C458050000 temperature: 22.75 -> temperature: .*
2014.07.09 17:27:20 4: eventTypes: OWTHERM OWX_28_13C458050000 T: 22.75 °C ▾ -> T: .* °C ▾
2014.07.09 17:27:20 4: eventTypes: OWTHERM OWX_28_13C458050000 state: T: 22.75 °C ▾ -> state: T: .* °C ▾
2014.07.09 17:27:20 5: T: 22.75 °C ▾
2014.07.09 17:27:20 5: SW: ORb
2014.07.09 17:27:20 5: CUL/RAW (ReadAnswer): OK:1

2014.07.09 17:27:20 5: SW: OmF6000005589C5828
2014.07.09 17:27:20 5: CUL/RAW (ReadAnswer): m:F60000
2014.07.09 17:27:20 5: CUL/RAW (ReadAnswer): 05589C58
2014.07.09 17:27:20 5: CUL/RAW (ReadAnswer): 28

2014.07.09 17:27:20 5: SW: OwB44
2014.07.09 17:27:21 5: SW: ORb
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): OK:1

2014.07.09 17:27:21 5: SW: OmF6000005589C5828
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): m:F60000
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): 05589C58
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): 28

2014.07.09 17:27:21 5: SW: OwBbe
2014.07.09 17:27:21 5: SW: OrB
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): 6D

2014.07.09 17:27:21 5: SW: OrB
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): 01

2014.07.09 17:27:21 5: SW: OrB
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): 4B

2014.07.09 17:27:21 5: SW: OrB
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): 46

2014.07.09 17:27:21 5: SW: OrB
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): 7F

2014.07.09 17:27:21 5: SW: OrB
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): FF

2014.07.09 17:27:21 5: SW: OrB
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): 03

2014.07.09 17:27:21 5: SW: OrB
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): 10

2014.07.09 17:27:21 5: SW: OrB
2014.07.09 17:27:21 5: CUL/RAW (ReadAnswer): 70

2014.07.09 17:27:21 5: Triggering OWX_28_589C58050000 (2 changes)
2014.07.09 17:27:21 5: Notify loop for OWX_28_589C58050000 temperature: 22.8125
2014.07.09 17:27:21 4: eventTypes: OWTHERM OWX_28_589C58050000 temperature: 22.8125 -> temperature: .*
2014.07.09 17:27:21 4: eventTypes: OWTHERM OWX_28_589C58050000 T: 22.81 °C ▾ -> T: .* °C ▾
2014.07.09 17:27:21 4: eventTypes: OWTHERM OWX_28_589C58050000 state: T: 22.81 °C ▾ -> state: T: .* °C ▾
2014.07.09 17:27:21 5: T: 22.81 °C ▾
2014.07.09 17:27:21 1: Perfmon: possible freeze starting at 17:27:20, delay is 1.348


Danke schonmal für deine Hilfe!
FHEM - Debmatic - Zigbee2MQTT - Homekit

herrmannj

Hi,

ZitatIch habe nun nach und nach alle Module bzw die Definition dazu aus meiner fhem.cfg gelöscht, anschließend das Log kontrolliert und wieder eingefügt. Leider komme ich nicht weiter. Die Freezes tauchen immer noch auf.
Da stimmt dann was nicht.

Wenn Du eine leere cfg hast (bzw die Democonfig) wüsste ich keinen plausiblen Grund warum die freeze auftauchen sollten.

Im "normalen" Betrieb musst Du unterscheiden: kleine (und seltene) freeze (1..2 Sekunden) können vorkommen, liegt in der Art wie fhem aufgebaut ist, je schneller die Hardware desto seltener.

In Deinem Beispiel von heute morgen hast Du regelmäßig, einmal pro Minute, für 3 Sekunden Stillstand. Das wird sich ganz sicher auf ein einzelnes Modul zurückführen lassen welches einmal aller 60 Sekunden einen Task ausführt. 
ZitatWürde Dir meine hem.cfg Datei helfen das Problem zu finden?
Leider nein. Daran sehe ich nur welche Module Du verwendest, nicht jedoch welches blockiert.

Schau Dir mal parallel "apptime" (siehe commandref) an. Perfmon ist gut darin einzelne "Hänger" und deren Zeitpunkt aufzuzeigen. "Apptime" zeigt an welche Module wieviel Rechenzeit insgesamt brauchen. Beides kombiniert macht ein gutes Gesamtbild.

Poste gerne mal den Output von apptime.

vg
Jörg

Spezialtrick

Ich habe es heute Nachmittag mal mit der FHEM.cfg.demo ausprobiert. Da gabs keine Hänger.

Das gibt mir Apptime aus (als Bild damit die Tabelle erhalten bleibt. :) ):



FHEM - Debmatic - Zigbee2MQTT - Homekit

herrmannj

ZitatIch habe es heute Nachmittag mal mit der FHEM.cfg.demo ausprobiert. Da gabs keine Hänger.
alles andere wäre verrückt  8)

Der screenshot von apptime sieht erstmal recht unspektakulär aus - allerdings weiß ich auch nicht über welchen Zeitraum der erstellt wurde.

Gedankenspiel:
wenn Du jeweils aller 60 Sekunden einen freeze hast müsste doch nach einer apptime-daten-sammelzeit von 10x60 + 10x3 Sekunden = 10m30s die verursachende Funktion genau 10 mal im apptime auftauchen...

vg
Jörg

Spezialtrick

#66
Gesagt, getan. ^^ Habe Apptime ungefähr 10 min 30 sec laufen lassen. Parallel dazu der Auszug aus dem Log:

2014.07.09 20:13:57 1: Perfmon: possible freeze starting at 20:13:56, delay is 1.559
2014.07.09 20:14:13 1: FHEMduino_KW9010 77 Temperature jump too large
2014.07.09 20:14:27 1: FHEMduino_KW9010 35 Temperature jump too large
2014.07.09 20:14:45 1: KindleDisplay aktualisiert
2014.07.09 20:15:45 1: KindleDisplay aktualisiert
2014.07.09 20:16:35 1: FHEMduino_KW9010 35 Temperature jump too large
2014.07.09 20:16:35 1: FHEMduino_KW9010 35 Temperature jump too large
2014.07.09 20:16:36 1: FHEMduino_KW9010 UNDEFINED sensor detected, code 34
2014.07.09 20:16:45 1: KindleDisplay aktualisiert
2014.07.09 20:17:39 1: FHEMduino_KW9010 35 Temperature jump too large
2014.07.09 20:17:45 1: KindleDisplay aktualisiert
2014.07.09 20:18:11 1: FHEMduino_KW9010 35 Temperature jump too large
2014.07.09 20:18:12 1: FHEMduino_KW9010 35 Temperature jump too large
2014.07.09 20:18:29 1: FHEMduino_KW9010 UNDEFINED sensor detected, code 1b
2014.07.09 20:18:45 1: KindleDisplay aktualisiert
2014.07.09 20:18:56 1: Perfmon: possible freeze starting at 20:18:55, delay is 1.284
2014.07.09 20:19:45 1: KindleDisplay aktualisiert
2014.07.09 20:20:32 1: FHEMduino_KW9010 UNDEFINED sensor detected, code b5
2014.07.09 20:20:45 1: KindleDisplay aktualisiert
2014.07.09 20:21:45 1: KindleDisplay aktualisiert
2014.07.09 20:21:56 1: FHEMduino_KW9010 35 Temperature jump too large
2014.07.09 20:22:13 1: FHEMduino_KW9010 77 Temperature jump too large
2014.07.09 20:22:39 1: FHEMduino_KW9010 UNDEFINED sensor detected, code b5
2014.07.09 20:22:45 1: KindleDisplay aktualisiert
2014.07.09 20:23:45 1: KindleDisplay aktualisiert
2014.07.09 20:23:56 1: Perfmon: possible freeze starting at 20:23:55, delay is 1.285
2014.07.09 20:24:03 1: FHEMduino_KW9010 35 Temperature jump too large
2014.07.09 20:24:36 1: FHEMduino_KW9010 UNDEFINED sensor detected, code 34
2014.07.09 20:24:45 1: KindleDisplay aktualisiert
2014.07.09 20:25:20 1: FHEMduino_KW9010 UNDEFINED sensor detected, code b5
2014.07.09 20:25:49 1: Perfmon: possible freeze starting at 20:25:44, delay is 5.612


Komischerweise sind nur noch vier Freezes vorhanden.  ???

Edit: Ich sehe gerade, dass meine Drucker Automatisierung nicht in der hem.cfg abgespeichert war. Habe diese hier nachgebaut:

http://forum.fhem.de/index.php/topic,22942.15.html

Können die Hänger daraus resultieren?
FHEM - Debmatic - Zigbee2MQTT - Homekit

herrmannj

ZitatKomischerweise sind nur noch vier Freezes vorhanden
ja, die haben auch einen ganz anderen Fingerprint als die von heute morgen. verbose scheint wieder auf 1 zu stehen. Vielleicht (!) hats was mit dem owtherm zu tun - ich meine das es da eine asynchrone Version gibt.

Die 5 Sekunden am Ende tauchen im apptime leider nicht auf - vermutlich sind die 5 Sekunden also die Summe von mehreren Einzel-Aufrufen. (?)

Versuch Module einzeln zu deaktivieren. (save und Neustart!). Sorry - mehr kann ich von hier aus vermutlich nicht beitragen...

vg
Jörg


Spezialtrick

Ich habe nun alles aus meiner fhem.cfg gelöscht. Verblieben sind nur die Standardeinträge:

attr global altitude 85
attr global autoload_undefined_devices 1
attr global logfile ./log/fhem-%Y-%m.log
attr global modpath .
attr global statefile ./log/fhem.save
attr global updateInBackground 0
attr global userattr devStateIcon devStateStyle fm_type icon lightSceneParamsToSave lightSceneRestoreOnlyIfChanged:1,0 sortby webCmd widgetOverride
attr global verbose 3

#attr global mseclog 1

define WEB FHEMWEB 8083 global
attr WEB basicAuth XXXXXXXXXX
attr WEB menuEntries restart,cmd=shutdown+restart,update,cmd=update,updatecheck,cmd=update+check
attr WEB ploteditor always
attr WEB roomIcons Alarmanlage:building_security Anwesenheit:status_available Flur:control_building_empty Küche:scene_dinner Bad:scene_bath Wohnzimmer:scene_livingroom Schlafzimmer:scene_baby Umwelt:scene_day System:edit_settings RaspberryPi:RPi Logs:edit_copy
attr WEB sortRooms Alarmanlage Anwesenheit Flur Küche Bad Wohnzimmer Schlafzimmer Umwelt System RaspberryPi Logs Everything Unsorted
attr WEB stylesheetPrefix bright

define WEBphone FHEMWEB 8084 global
attr WEBphone basicAuth XXXXXXXXXX
attr WEBphone hiddenroom DashboardRoom
attr WEBphone stylesheetPrefix smallscreen

define WEBtablet FHEMWEB 8085 global
attr WEBtablet basicAuth XXXXXXXXXX
attr WEBtablet hiddenroom DashboardRoom
attr WEBtablet stylesheetPrefix touchpad

define telnetPort telnet 7072
attr telnetPort SSL 1
attr telnetPort password XXXXXXXXXX

# Fake FileLog entry, to access the fhem log from FHEMWEB
define Logfile FileLog ./log/fhem-%Y-%m.log fakelog
attr Logfile room Logs

#define autocreate autocreate
#attr autocreate filelog ./log/%NAME-%Y.log
#attr autocreate room Unsorted

define eventTypes eventTypes ./log/eventTypes.txt

# Disable this to avoid looking for new USB devices on startup
define initialUsbCheck notify global:INITIALIZED usb create


Eigentlich dürften jetzt doch keine Freezes mehr auftreten. Leider ist das aber nicht der Fall... -.-

2014.07.13 15:50:05 0: Server shutdown
2014.07.13 15:50:09 2: Perfmon: ready to watch out for delays greater than one second
2014.07.13 15:50:10 1: Including fhem.cfg
2014.07.13 15:50:11 3: WEB: port 8083 opened
2014.07.13 15:50:11 3: WEBphone: port 8084 opened
2014.07.13 15:50:11 3: WEBtablet: port 8085 opened
2014.07.13 15:50:11 3: telnetPort: port 7072 opened
2014.07.13 15:50:12 2: eventTypes: loaded 1195 events from ./log/eventTypes.txt
2014.07.13 15:50:12 1: Including ./log/fhem.save
2014.07.13 15:50:12 3: initialUsbCheck return value: Unknown command usb, try help.
2014.07.13 15:50:12 0: Server started with 8 defined entities (version $Id: fhem.pl 6080 2014-06-07 16:12:09Z rudolfkoenig $, os linux, user fhem, pid 13741)
2014.07.13 15:50:12 1: Perfmon: possible freeze starting at 15:50:10, delay is 2.344
2014.07.13 15:51:03 1: Perfmon: possible freeze starting at 15:51:02, delay is 1.033
2014.07.13 15:51:17 1: Perfmon: possible freeze starting at 15:51:12, delay is 5.116
2014.07.13 15:57:08 1: Perfmon: possible freeze starting at 15:57:03, delay is 5.213


Hast du noch irgendeine Idee?  :(
FHEM - Debmatic - Zigbee2MQTT - Homekit

herrmannj

ZitatHast du noch irgendeine Idee?
Immer  :)

Wenn das wirklich die komplette cfg ist dann prüfe bitte nochmal die 99_xxx.pm dateien (und nimm sie kurz aus dem Verzeichnis). Für die 99er gibt es einen autoload Mechanismus unabhängig von der cfg.

Wenn es dann immer noch auftritt bleibt nur fhem (mit pgm2) als quelle. pgm2 ist auch definitiv buggy (!!!) - ggf  ssl abschalten und beobachten.

vg
jörg

Spezialtrick

Ich habe mir grad dazu entschlossen, einfach alles nochmals neu aufzusetzen. Hoffentlich ist danach alles so wie es sein soll.

Vielen Dank für deine Hilfe! :)
FHEM - Debmatic - Zigbee2MQTT - Homekit

Navigator

#71
Mir ist bei meiner FHEM Installation und einer, die ich betreue aufgefallen, das man oft diese Freezes erhält, wenn man  seine Plots anzeigen lässt. Besonders über die externe Adresse. Kann man das irgendwie optimieren?

justme1968

Schau dir plotfork an.

gruss
  andre
hue, tradfri, alexa-fhem, homebridge-fhem, LightScene, readingsGroup, ...

https://github.com/sponsors/justme-1968

Navigator

#73
danke, mach ich.

Edit: Schon besser... ;D

Harald

#74
Hallo zusammen,

ich versuche gerade die die Ursachen der Verzögerungen in meinem FHEM mittels des Performace Monitors zu ermitteln. Dabei wäre es für mich hilfreich, wenn ich erst die großen Brocken beseitigte und dann die kleineren. Ich denke, es wäre hilfreich, wenn ich die Schwelle im Modul anpassen könnte.

Kann mir jemand sagen, ob das überhaupt möglich ist und wenn ja, wo ich was im Modul muss. Eigentlich besteht es ja "nur" aus ein paar Zeilen aber leider verstehe ich die Funktionen nicht ganz.

Viele Grüße und schönes Wochenende

Harald

Nachtrag: Ich hab's gefunden: Zeile 31  if ($freeze > 1). Vergrößert man den Wert ( hier 1), wird die Schwelle auch vergrößert.
Router:AVM7590 1&1 FW:FRITZ!OS 07.56 Anbindung:1&1 50/10 Mb/s, WLAN-Repeater 300E
ELV MAX!Cube, 7xThermostat, ECO, RasPi 4B mit bullseye auf Festplatte,
CUL V 1.67, JeeLink v3_10.1c, nanoCUL, 1xS300TH, 4xHMS100T, 4xELRO, 1xTFA, 2xMAX_FK
ELV MAX!1.4.5, FHEM 5.7 auf RasPi, Kostal PIKO plus