I see the problem. You’re setting that in the Bash shell and that’s why is not working.
You need to change the logging in the OpenHAB console. Info on how to do it is available here: https://www.openhab.org/docs/administration/console.html
Regarding the inverter id, make sure it’s a 10 digit number.
I will use tomorrow the console and then copy the log info again here
Thanks
good morning, still the same, only this logging in the file
2023-09-05 09:32:19.382 [ERROR] [arman.internal.SolarmanLoggerHandler] - Response frame has invalid starting byte
2023-09-05 09:32:19.384 [ERROR] [arman.internal.SolarmanLoggerHandler] - Modbus frame is too short or empty
2023-09-05 09:33:19.399 [ERROR] [arman.internal.SolarmanLoggerHandler] - Response frame has invalid starting byte
2023-09-05 09:33:19.401 [ERROR] [arman.internal.SolarmanLoggerHandler] - Modbus frame is too short or empty
2023-09-05 09:34:19.426 [ERROR] [arman.internal.SolarmanLoggerHandler] - Response frame has invalid starting byte
2023-09-05 09:34:19.428 [ERROR] [arman.internal.SolarmanLoggerHandler] - Modbus frame is too short or empty
2023-09-05 09:34:19.430 [INFO ] [arman.internal.SolarmanLoggerHandler] - Assuming logger is OFFLINE after 3 failed requests. Disabling connection error logging until it becomes available again
now I changed from trace command to debug and get more messages. And back to trace. Same
i can see now the trace in the list:
2023-09-05 10:09:35.157 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F6020000000000000000000000000000010300030057F4344415
2023-09-05 10:09:35.265 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: 41542B595A434D505645523D4D57335F3136555F353430365F322E32370D0A0D0A
2023-09-05 10:09:35.267 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F602000000000000000000000000000001030202002D25AFC715
2023-09-05 10:09:35.367 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: AA1000E1003089F0
2023-09-05 10:09:35.370 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F60200000000000000000000000000000103024A0006E5A69F15
2023-09-05 10:09:35.868 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: AA1003E8001459AD
2023-09-05 10:09:35.871 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F6020000000000000000000000000000010302560027E4789D15
2023-09-05 10:09:37.063 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: AA03260004010002013232303831313035363800010000120C0700000001140211000017700000020186A8
2023-09-05 10:09:37.066 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F602000000000000000000000000000001030284000A845C3215
2023-09-05 10:09:37.471 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: A510001015004AB0B3F7F602014D6F7B0012070000F4727B6405006C15
2023-09-05 10:09:37.472 [ERROR] [arman.internal.SolarmanLoggerHandler] - Unexpected control code in error response frame
2023-09-05 10:09:37.475 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F6020000000000000000000000000000010302A0000845964715
2023-09-05 10:09:37.652 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: AA030A00000000000000000000BE9C
2023-09-05 10:10:35.150 [DEBUG] [ernal.updater.SolarmanChannelUpdater] - Fetching data from logger
2023-09-05 10:10:35.160 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F6020000000000000000000000000000010300030057F4344415
2023-09-05 10:10:35.263 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: 41542B595A434D505645523D4D57335F3136555F353430365F322E32370D0A0D0A
2023-09-05 10:10:35.265 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F602000000000000000000000000000001030202002D25AFC715
2023-09-05 10:10:35.599 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: A5C1001015004EB0B3F7F60201876F7B004C070000F4727B640103AE3232303831313035363800010000120C07000000011402110000177000000201004B0000003C1709050A0A1C000000000ABE0726141E128E000000000000139C002C0000000000000000007800000000000100000000000100000000000100000000000A000000000000000000000000000400000000000006F8000000000000000000000367000003470000090600000000000300000000138800000000000000000000000002D0000000000000CB537115
2023-09-05 10:10:35.601 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F60200000000000000000000000000000103024A0006E5A69F15
2023-09-05 10:10:35.853 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: AA030A00000000000000000000BE9C
2023-09-05 10:10:35.856 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F6020000000000000000000000000000010302560027E4789D15
2023-09-05 10:10:36.452 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: AA030A00000000000000000000BE9C
2023-09-05 10:10:36.454 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F602000000000000000000000000000001030284000A845C3215
2023-09-05 10:10:37.052 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: AA0306C9BF87120001E771
2023-09-05 10:10:37.054 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F6020000000000000000000000000000010302A0000845964715
2023-09-05 10:10:37.659 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: AA1000C800145823
2023-09-05 10:11:35.150 [DEBUG] [ernal.updater.SolarmanChannelUpdater] - Fetching data from logger
2023-09-05 10:11:35.158 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F6020000000000000000000000000000010300030057F4344415
2023-09-05 10:11:35.262 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: 41542B595A434D505645523D4D57335F3136555F353430365F322E32370D0A0D0A
2023-09-05 10:11:35.263 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F602000000000000000000000000000001030202002D25AFC715
2023-09-05 10:11:35.608 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: A5C10010150050B0B3F7F60201C36F7B0088070000F4727B640103AE3232303831313035363800010000120C07000000011402110000177000000201004B0000003C1709050A0A1C000000000ABE0726141E128E000000000000139C002C0000000000000000007800000000000100000000000100000000000100000000000A000000000000000000000000000400000000000006F8000000000000000000000367000003470000090600000000000300000000138800000000000000000000000002D0000000000000CB53EB15
2023-09-05 10:11:35.609 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F60200000000000000000000000000000103024A0006E5A69F15
2023-09-05 10:11:36.453 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: AA03260004010002013232303831313035363800010000120C0700000001140211000017700000020186A8
2023-09-05 10:11:36.454 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F6020000000000000000000000000000010302560027E4789D15
2023-09-05 10:11:37.052 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: AA030A00000000000000000000BE9C
2023-09-05 10:11:37.053 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F602000000000000000000000000000001030284000A845C3215
2023-09-05 10:11:37.652 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: AA030A00000000000000000000BE9C
2023-09-05 10:11:37.653 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F6020000000000000000000000000000010302A0000845964715
2023-09-05 10:11:37.717 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: A5100010150051B0B3F7F60201C56F7B008A070000F4727B6405006315
2023-09-05 10:11:37.717 [ERROR] [arman.internal.SolarmanLoggerHandler] - Unexpected control code in error response frame
From disable to enable the thing I get this messages now
2023-09-05 10:22:24.875 [DEBUG] [arman.internal.SolarmanLoggerHandler] - Found definition for deye_2mppt
2023-09-05 10:22:24.914 [DEBUG] [arman.internal.SolarmanLoggerHandler] - Updated thing with id solarman:logger and 12 channels
2023-09-05 10:22:24.915 [DEBUG] [ernal.updater.SolarmanChannelUpdater] - Fetching data from logger
2023-09-05 10:22:24.923 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F602000000000000000000000000000001030003007E35EA6215
2023-09-05 10:22:25.030 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: 41542B595A434D505645523D4D57335F3136555F353430365F322E32370D0A0D0A
2023-09-05 10:22:25.031 [ERROR] [arman.internal.SolarmanLoggerHandler] - Response frame has invalid starting byte
2023-09-05 10:22:25.032 [ERROR] [arman.internal.SolarmanLoggerHandler] - Modbus frame is too short or empty
2023-09-05 10:23:24.916 [DEBUG] [ernal.updater.SolarmanChannelUpdater] - Fetching data from logger
2023-09-05 10:23:24.925 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Request frame: A5170010450000B0B3F7F602000000000000000000000000000001030003007E35EA6215
2023-09-05 10:23:25.028 [DEBUG] [rnal.modbus.SolarmanLoggerConnection] - Response frame: 41542B595A434D505645523D4D57335F3136555F353430365F322E32370D0A0D0A
2023-09-05 10:23:25.030 [ERROR] [arman.internal.SolarmanLoggerHandler] - Response frame has invalid starting byte
2023-09-05 10:23:25.031 [ERROR] [arman.internal.SolarmanLoggerHandler] - Modbus frame is too short or empty
Hey @Frankinho ,
You seem to either have the wrong inverter type for the Solarman thing, or you have multiple Solarman things, some of which with the wrong inverter type.
I’m saying this because in your logs I see requests that when decoded look like
Request was from: 0x0003 to 0x0059 for logger with ID: 41434XXXXX
which should not be sent for the deye_2mppt inverter type, but for the deye_sg04lp3.
Even with the wrong inverter type some requests are succeeding because the registers overlap between inverters, see the one from 2023-09-05 10:11:35.608, which when decoded looks like this:
Request was from: 0x0202 to 0x022E for logger with ID: 41434XXXXX
Response was from logger with ID: 41434XXXXX
[0x0202]: 0x3232 (12850)
[0x0203]: 0x3038 (12344)
[0x0204]: 0x3131 (12593)
[0x0205]: 0x3035 (12341)
[0x0206]: 0x3638 (13880)
[0x0207]: 0x0001 (1)
[0x0208]: 0x0000 (0)
[0x0209]: 0x120C (4620)
[0x020A]: 0x0700 (1792)
[0x020B]: 0x0000 (0)
[0x020C]: 0x0114 (276)
[0x020D]: 0x0211 (529)
[0x020E]: 0x0000 (0)
[0x020F]: 0x1770 (6000)
[0x0210]: 0x0000 (0)
[0x0211]: 0x0201 (513)
[0x0212]: 0x004B (75)
[0x0213]: 0x0000 (0)
[0x0214]: 0x003C (60)
[0x0215]: 0x1709 (5897)
[0x0216]: 0x050A (1290)
[0x0217]: 0x0A1C (2588)
[0x0218]: 0x0000 (0)
[0x0219]: 0x0000 (0)
[0x021A]: 0x09BE (2494)
[0x021B]: 0x0726 (1830)
[0x021C]: 0x141E (5150)
[0x021D]: 0x118E (4494)
[0x021E]: 0x0000 (0)
[0x021F]: 0x0000 (0)
[0x0220]: 0x0000 (0)
[0x0221]: 0x129C (4764)
[0x0222]: 0x002C (44)
[0x0223]: 0x0000 (0)
[0x0224]: 0x0000 (0)
[0x0225]: 0x0000 (0)
[0x0226]: 0x0000 (0)
[0x0227]: 0x0078 (120)
[0x0228]: 0x0000 (0)
[0x0229]: 0x0000 (0)
[0x022A]: 0x0001 (1)
[0x022B]: 0x0000 (0)
[0x022C]: 0x0000 (0)
[0x022D]: 0x0001 (1)
[0x022E]: 0x0000 (0)
So I think you are on the right track.
Hi Catalin,
hope you are well and thanks for all your work on this.
Would you consider making your binding become an official part of openHAB i.e. contribute it as a PR?
Hello @mstormi ,
Sure, my pleasure. As soon as I can find some free time I’ll reformat a bit the code to pass the style checks and submit a PR.
Regards,
Catalin