Moin Stefan,
ich muss mich auch mal wieder mit einer Frage anschließen:
Kannst du mir helfen, diese Logmeldungen zu deuten und einen Fehler zu finden?
Ich bin der Meinung, dass es anfangs einwandfrei lief - jetzt hab ich immer größere Aussetzer in Fhem - und habe die Updaterate schon verringert...
Grüße,
Stephan
2022.01.28 12:46:19.486 5: alfen_Socket_aussen: ProcessRequestQueue called from Fhem internal timer as queue:alfen_Socket_aussen, qlen 2, request: request: id
1, read fc 3 h1208, len 2, tid 87, master device alfen_Socket_aussen, reading MaxCurrentValidTimeRemaining (getUpdate for MaxCurrentValidTimeRemaining len 2),
queued 6.17 secs ago
2022.01.28 12:46:19.486 5: alfen_Socket_aussen: checkDelays sendDelay, last send to same device was 0.265 secs ago, required delay is 0.1
2022.01.28 12:46:19.486 5: alfen_Socket_aussen: checkDelays commDelay, last communication with same device was 0.115 secs ago, required delay is 0.1
2022.01.28 12:46:19.486 5: alfen_Socket_aussen: checkDelays clientSwitchDelay is not relevant
2022.01.28 12:46:19.486 5: alfen_Socket_aussen: checkDelays busDelayRead, last activity on bus was 0.115 secs ago, required delay is 0
2022.01.28 12:46:19.486 4: alfen_Socket_aussen: ProcessRequestQueue (V4.4.02 - 31.3.2021) qlen 2, sending 005700000006010304b80002 via 192.168.0.49:502, read b
uffer empty,
request: id 1, read fc 3 h1208, len 2, tid 87, master device alfen_Socket_aussen, reading MaxCurrentValidTimeRemaining (getUpdate for MaxCurrentValidTimeRemain
ing len 2), queued 6.17 secs ago
2022.01.28 12:46:19.486 5: alfen_Socket_aussen: Send called from ProcessRequestQueue
2022.01.28 12:46:19.486 5: DevIo_SimpleWrite alfen_Socket_aussen: 005700000006010304b80002
2022.01.28 12:46:19.488 5: alfen_Socket_aussen: StartQueueTimer called from ProcessRequestQueue sets internal timer to process queue in 1.000 seconds
2022.01.28 12:46:19.618 5: alfen_Socket_aussen: readFn buffer: 0057000000070103040000012b
2022.01.28 12:46:19.619 5: alfen_Socket_aussen: ParseFrameStart called from ReadFn protocol TCP expecting id 1
2022.01.28 12:46:19.619 4: alfen_Socket_aussen: ParseFrameStart (TCP, master) extracted id 1, fCode 3, tid 87, dlen 7 and potential data 040000012b
2022.01.28 12:46:19.619 5: alfen_Socket_aussen: HandleResponse called from ReadFn
2022.01.28 12:46:19.619 5: alfen_Socket_aussen: ParseResponse called from HandleResponse
2022.01.28 12:46:19.619 5: alfen_Socket_aussen: now parsing response data objects, master is alfen_Socket_aussen relay is undefined
2022.01.28 12:46:19.619 5: alfen_Socket_aussen: ParseDataString called from HandleResponse with data hex 0000012b, type h, adr 1208, op read
2022.01.28 12:46:19.619 5: alfen_Socket_aussen: SplitDataString called from ParseDataString with data hex 0000012b, type h, adr 1208, valuesLen 2, op read
2022.01.28 12:46:19.619 5: alfen_Socket_aussen: CreateDataObjects called from ParseDataString with objList h1208
2022.01.28 12:46:19.620 5: alfen_Socket_aussen: CreateDataObjects sortedList h1208
2022.01.28 12:46:19.620 5: alfen_Socket_aussen: CreateDataObjects unpacked 0000012b with L> to 299
2022.01.28 12:46:19.620 4: alfen_Socket_aussen: CreateDataObjects assigns value 299 to MaxCurrentValidTimeRemaining
2022.01.28 12:46:19.636 4: alfen_Socket_aussen: set called with Charge_Current (h1210) setVal = 0
2022.01.28 12:46:19.636 5: alfen_Socket_aussen: GetSetChecks with force
2022.01.28 12:46:19.636 4: alfen_Socket_aussen: GetSetChecks calls ReadAnswer to take over async read, still waiting for response, current frame / read buffer:
0057000000070103040000012b, id 1, fCode 3, tid 87,
request: id 1, read fc 3 h1208, len 2, tid 87, master device alfen_Socket_aussen, reading MaxCurrentValidTimeRemaining (getUpdate for MaxCurrentValidTimeRemain
ing len 2), queued 6.32 secs ago, sent 0.15 secs ago,
response: id 1, fc 3, h1208, len 2, values 0000012b
2022.01.28 12:46:19.636 5: alfen_Socket_aussen: ReadAnswer called from GetSetChecks
2022.01.28 12:46:19.636 5: alfen_Socket_aussen: ReadAnswer remaining timeout is 1.84963798522949
2022.01.28 12:46:21.488 3: alfen_Socket_aussen: Timeout in Readanswer, current frame / read buffer: 0057000000070103040000012b, id 1, fCode 3, tid 87,
request: id 1, read fc 3 h1208, len 2, tid 87, master device alfen_Socket_aussen, reading MaxCurrentValidTimeRemaining (getUpdate for MaxCurrentValidTimeRemain
ing len 2), queued 8.17 secs ago, sent 2.00 secs ago,
response: id 1, fc 3, h1208, len 2, values 0000012b
2022.01.28 12:46:21.488 5: alfen_Socket_aussen: DropFrame called from ReadAnswer - drop 0057000000070103040000012b
2022.01.28 12:46:21.489 5: alfen_Socket_aussen: GetSetChecks returns success
2022.01.28 12:46:21.489 5: alfen_Socket_aussen: set packed hex 30 with f> to hex 00000000
2022.01.28 12:46:21.490 4: alfen_Socket_aussen: DoRequest called from SetLDFn created new request, read buffer empty,
request: id 1, write fc 16 h1210, len 2, value 00000000, tid 98, master device alfen_Socket_aussen, reading Charge_Current (set Charge_Current),
response: id 1, fc 3, h1208, len 2, values 0000012b
2022.01.28 12:46:21.490 5: alfen_Socket_aussen: QueueRequest called from DoRequest with h1210, qlen 1 from master alfen_Socket_aussen through io device alfen_Socket_aussen
2022.01.28 12:46:21.490 5: alfen_Socket_aussen: ProcessRequestQueue called from QueueRequest as direct:alfen_Socket_aussen, qlen 2, force, request: request: id 1, write fc 16 h1210, len 2, value 00000000, tid 98, master device alfen_Socket_aussen, reading Charge_Current (set Charge_Current), queued 0.00 secs ago
2022.01.28 12:46:21.490 5: alfen_Socket_aussen: checkDelays clientSwitchDelay is not relevant
2022.01.28 12:46:21.490 5: alfen_Socket_aussen: checkDelays busDelayRead, last activity on bus was 1.871 secs ago, required delay is 0
2022.01.28 12:46:21.490 5: alfen_Socket_aussen: checkDelays commDelay, last communication with same device was 1.871 secs ago, required delay is 0.1
2022.01.28 12:46:21.491 5: alfen_Socket_aussen: checkDelays sendDelay, last send to same device was 2.003 secs ago, required delay is 0.1
2022.01.28 12:46:21.491 4: alfen_Socket_aussen: ProcessRequestQueue (V4.4.02 - 31.3.2021) qlen 2, sending 00620000000b011004ba00020400000000 via 192.168.0.49:502, read buffer empty,
request: id 1, write fc 16 h1210, len 2, value 00000000, tid 98, master device alfen_Socket_aussen, reading Charge_Current (set Charge_Current), queued 0.00 secs ago,
response: id 1, fc 3, h1208, len 2, values 0000012b
2022.01.28 12:46:21.491 5: alfen_Socket_aussen: Send called from ProcessRequestQueue
2022.01.28 12:46:21.491 5: DevIo_SimpleWrite alfen_Socket_aussen: 00620000000b011004ba00020400000000
2022.01.28 12:46:21.493 5: alfen_Socket_aussen: StartQueueTimer called from ProcessRequestQueue sets internal timer to process queue in 1.000 seconds
2022.01.28 12:46:21.493 5: alfen_Socket_aussen: StartQueueTimer called from SetLDFn sets internal timer to process queue in 0.000 seconds
2022.01.28 12:46:21.493 5: alfen_Socket_aussen: ReadAnswer called from SetLDFn
2022.01.28 12:46:21.494 5: alfen_Socket_aussen: ReadAnswer remaining timeout is 1.99603891372681
2022.01.28 12:46:21.593 5: alfen_Socket_aussen: ReadAnswer got: 006200000006011004ba0002
2022.01.28 12:46:21.593 5: alfen_Socket_aussen: ParseFrameStart called from ReadAnswer protocol TCP expecting id 1
2022.01.28 12:46:21.593 4: alfen_Socket_aussen: ParseFrameStart (TCP, master) extracted id 1, fCode 16, tid 98, dlen 6 and potential data 04ba0002
2022.01.28 12:46:21.593 5: alfen_Socket_aussen: HandleResponse called from ReadAnswer
2022.01.28 12:46:21.594 5: alfen_Socket_aussen: ParseResponse called from HandleResponse
2022.01.28 12:46:21.594 4: alfen_Socket_aussen: HandleResponse done, current frame / read buffer: 006200000006011004ba0002, id 1, fCode 16, tid 98,
request: id 1, write fc 16 h1210, len 2, value 00000000, tid 98, master device alfen_Socket_aussen, reading Charge_Current (set Charge_Current), queued 0.10 secs ago, sent 0.10 secs ago,
response: id 1, fc 16, c1210, len 2
2022.01.28 12:46:21.594 5: alfen_Socket_aussen: ResetExpect for HandleResponse from response to idle
2022.01.28 12:46:21.594 5: alfen_Socket_aussen: DropFrame called from ReadAnswer - drop 006200000006011004ba0002
2022.01.28 12:46:21.594 5: alfen_Socket_aussen: set is sending read after write
2022.01.28 12:46:21.595 4: alfen_Socket_aussen: DoRequest called from SetLDFn created new request, read buffer empty,
request: id 1, read fc 3 h1210, len 2, tid 199, master device alfen_Socket_aussen, reading Charge_Current (set Charge_Current Rd),
response: no id, no fcode
2022.01.28 12:46:21.595 5: alfen_Socket_aussen: QueueRequest called from DoRequest with h1210, qlen 1 from master alfen_Socket_aussen through io device alfen_Socket_aussen
2022.01.28 12:46:21.595 5: alfen_Socket_aussen: ProcessRequestQueue called from QueueRequest as direct:alfen_Socket_aussen, qlen 2, force, request: request: id 1, read fc 3 h1210, len 2, tid 199, master device alfen_Socket_aussen, reading Charge_Current (set Charge_Current Rd), queued 0.00 secs ago
2022.01.28 12:46:21.595 5: alfen_Socket_aussen: checkDelays sendDelay, last send to same device was 0.103 secs ago, required delay is 0.1
2022.01.28 12:46:21.595 5: alfen_Socket_aussen: checkDelays clientSwitchDelay is not relevant
2022.01.28 12:46:21.595 5: alfen_Socket_aussen: checkDelays busDelayRead, last activity on bus was 0.002 secs ago, required delay is 0
2022.01.28 12:46:21.595 5: alfen_Socket_aussen: checkDelays commDelay, last communication with same device was 0.002 secs ago, required delay is 0.1
2022.01.28 12:46:21.596 4: alfen_Socket_aussen: checkDelays found commDelay not over, sleep for 0.098 forced
2022.01.28 12:46:21.694 4: alfen_Socket_aussen: checkDelays sleep done, go on with sending
2022.01.28 12:46:21.694 4: alfen_Socket_aussen: ProcessRequestQueue (V4.4.02 - 31.3.2021) qlen 2, sending 00c700000006010304ba0002 via 192.168.0.49:502, read buffer empty,
request: id 1, read fc 3 h1210, len 2, tid 199, master device alfen_Socket_aussen, reading Charge_Current (set Charge_Current Rd), queued 0.10 secs ago,
response: no id, no fcode
2022.01.28 12:46:21.694 5: alfen_Socket_aussen: Send called from ProcessRequestQueue
2022.01.28 12:46:21.694 5: DevIo_SimpleWrite alfen_Socket_aussen: 00c700000006010304ba0002
2022.01.28 12:46:21.696 5: alfen_Socket_aussen: StartQueueTimer called from ProcessRequestQueue sets internal timer to process queue in 1.000 seconds
2022.01.28 12:46:21.697 5: alfen_Socket_aussen: ReadAnswer called from SetLDFn
2022.01.28 12:46:21.697 5: alfen_Socket_aussen: ReadAnswer remaining timeout is 1.89792394638062
2022.01.28 12:46:21.818 5: alfen_Socket_aussen: ReadAnswer got: 00c70000000701030400000000
2022.01.28 12:46:21.818 5: alfen_Socket_aussen: ParseFrameStart called from ReadAnswer protocol TCP expecting id 1
2022.01.28 12:46:21.818 4: alfen_Socket_aussen: ParseFrameStart (TCP, master) extracted id 1, fCode 3, tid 199, dlen 7 and potential data 0400000000
2022.01.28 12:46:21.818 5: alfen_Socket_aussen: HandleResponse called from ReadAnswer
2022.01.28 12:46:21.818 5: alfen_Socket_aussen: ParseResponse called from HandleResponse
2022.01.28 12:46:21.819 5: alfen_Socket_aussen: now parsing response data objects, master is alfen_Socket_aussen relay is undefined
2022.01.28 12:46:21.819 5: alfen_Socket_aussen: ParseDataString called from HandleResponse with data hex 00000000, type h, adr 1210, op read
2022.01.28 12:46:21.819 5: alfen_Socket_aussen: SplitDataString called from ParseDataString with data hex 00000000, type h, adr 1210, valuesLen 2, op read
2022.01.28 12:46:21.819 5: alfen_Socket_aussen: CreateDataObjects called from ParseDataString with objList h1210
2022.01.28 12:46:21.819 5: alfen_Socket_aussen: CreateDataObjects sortedList h1210
2022.01.28 12:46:21.819 5: alfen_Socket_aussen: CreateDataObjects unpacked 00000000 with f> to 0
2022.01.28 12:46:21.820 4: alfen_Socket_aussen: CreateDataObjects assigns value 0 to Charge_Current
2022.01.28 12:46:21.822 5: alfen_Socket_aussen: ParseDataString created 1 readings
edit: Verbose level set to 5