Debmatic und RPI-RF-MOD, Led dunkel, debmatic startet, Webinterface unerreichbar

[thomas.z]

Moin zusammen,

auf meinem ASUS-Tinkerboard (R-Pi kompatibel)laufen seit langem FHEM und Debmatic gut zusammen. Seit gestern hat jedoch Debmatic ein Problem. Es wurde von einem Elektriker an der Hausverteilung garbeitet. Danach wollte ich beide Dienste neue starten (funktioniert wohl wg. timing nach dem Reboot nicht automatisch, keine Verbindung). Das schien auch zu funktionieren, jedoch war das Webinterface der Debmatic nicht zu erreichen. Ich habe dann nachgeschaut und die Signal-Led des RPI-RF-MOD oben auf dem ELV-Gehäuse war dunkel.

Neustart, wiederholt neu laden etc. brachte nichts. Da während der Elektroarbeiten ein Fehler gemacht wurde, könnte es zu einer Überspannung gekommen sein. Da die Stromversorgung für das system über die 5V-Buchse des RPI-RF-MOD board (wie empfohlen) versorgt wird, hatte ich den Verdacht, dass das board hinüber ist, aber die Stromversorgung des Tinkerboards noch funktionert, weil das auch noch normal funktioniert (zumindest über die Konsole und für FHEM.

Ich habe ein neues RPI-RF-MOD bestellt und eingebaut, aber das zeigt auch eine dunkle LED, Debmatic lässt sich starten (mit Fehlermeldungen) und das Webinterface ist nicht zu erreichen.

Offensichtlich macht der hmserver (? oder wer immer) auch keinen Port auf:

Code Auswählen Erweitern

Nmap scan report for tinkerboard.fritz.box (192.168.25.56)
Host is up (0.0026s latency).
Not shown: 996 closed tcp ports (reset)
PORT     STATE SERVICE
22/tcp   open  ssh
53/tcp   open  domain
8083/tcp open  us-srv
8084/tcp open  websnp
debmatic-info liefert:

Code Auswählen Erweitern

debmatic version: 3.61.7-90
Kernel modules: Available
Raw UART dev:   Available
HMRF Hardware:  RPI-RF-MOD
 Connected via: GPIO@ff190000.serial (/dev/raw-uart)
 Board serial:  5F298D807A
 Radio MAC:     0xFF807A
HMIP Hardware:  RPI-RF-MOD
 Connected via: GPIO@ff190000.serial (/dev/raw-uart)
 SGTIN:         3014F711A0001F5F298D807A
 Radio MAC:     0xB659E9
Damit scheint auch ein defekter GPIO ausgeschlossen zu sein.

Ein Sequenz aus "systemctl stop debmatic" und danach gleich wieder starten liefert folgendes in /var/log/syslog:

Code Auswählen Erweitern

Jun 16 12:00:00 localhost systemd[1]: Starting debmatic set interface clock...
Jun 16 12:00:00 localhost systemd[1]: debmatic-setinterfaceclock.service: Succeeded.
Jun 16 12:00:00 localhost systemd[1]: Started debmatic set interface clock.
Jun 16 12:00:00 localhost systemd[1]: debmatic-setinterfaceclock.timer: Succeeded.
Jun 16 12:00:00 localhost systemd[1]: Stopped debmatic set interface clock timer.
Jun 16 12:00:00 localhost systemd[1]: debmatic-startupfinished.service: Succeeded.
Jun 16 12:00:00 localhost systemd[1]: Stopped debmatic startup finished.
Jun 16 12:00:00 localhost systemd[1]: Stopping debmatic eq3configd...
Jun 16 12:00:00 localhost systemd[1]: Stopping debmatic rega...
Jun 16 12:00:00 localhost systemd[1]: Stopping debmatic ssdpd...
Jun 16 12:00:00 localhost systemd[1]: Stopping debmatic HssLED...
Jun 16 12:00:00 localhost systemd[1]: debmatic-ssdpd.service: Main process exited, code=killed, status=15/TERM
Jun 16 12:00:00 localhost systemd[1]: debmatic-eq3configd.service: Main process exited, code=killed, status=15/TERM
Jun 16 12:00:00 localhost systemd[1]: debmatic-hssled.service: Main process exited, code=killed, status=15/TERM
Jun 16 12:00:00 localhost systemd[1]: debmatic-ssdpd.service: Succeeded.
Jun 16 12:00:00 localhost systemd[1]: Stopped debmatic ssdpd.
Jun 16 12:00:00 localhost systemd[1]: debmatic-eq3configd.service: Succeeded.
Jun 16 12:00:00 localhost systemd[1]: Stopped debmatic eq3configd.
Jun 16 12:00:01 localhost rmmod[3867]: rmmod: ERROR: Module ledtrig_timer is builtin.
Jun 16 12:00:01 localhost systemd[1]: debmatic-hssled.service: Succeeded.
Jun 16 12:00:01 localhost systemd[1]: Stopped debmatic HssLED.
Jun 16 12:00:01 localhost CRON[3871]: (root) CMD (/usr/lib/armbian/armbian-truncate-logs)
Jun 16 12:00:04 localhost start_rega.sh[2680]: SIGTERM received: Halting...
Jun 16 12:00:04 localhost ReGaHss: SIGTERM: ReGaHss Halting
Jun 16 12:00:09 localhost systemd[1]: debmatic-rega.service: Main process exited, code=exited, status=1/FAILURE
Jun 16 12:00:09 localhost systemd[1]: debmatic-rega.service: Failed with result 'exit-code'.
Jun 16 12:00:09 localhost systemd[1]: Stopped debmatic rega.
Jun 16 12:00:09 localhost systemd[1]: xml-api.service: Succeeded.
Jun 16 12:00:09 localhost systemd[1]: Stopped XML-API.
Jun 16 12:00:09 localhost systemd[1]: Stopping debmatic hmserver...
Jun 16 12:00:09 localhost kernel: [ 2428.817383] eq3loop: eq3loop_close_slave() mmd_hmip
Jun 16 12:00:09 localhost systemd[1]: debmatic-hmserver.service: Main process exited, code=exited, status=143/n/a
Jun 16 12:00:09 localhost systemd[1]: debmatic-hmserver.service: Failed with result 'exit-code'.
Jun 16 12:00:09 localhost systemd[1]: Stopped debmatic hmserver.
Jun 16 12:00:09 localhost systemd[1]: Stopping debmatic rfd...
Jun 16 12:00:09 localhost kernel: [ 2428.945078] eq3loop: eq3loop_close_slave() mmd_bidcos
Jun 16 12:00:09 localhost systemd[1]: debmatic-rfd.service: Main process exited, code=killed, status=15/TERM
Jun 16 12:00:09 localhost systemd[1]: debmatic-rfd.service: Succeeded.
Jun 16 12:00:09 localhost systemd[1]: Stopped debmatic rfd.
Jun 16 12:00:09 localhost systemd[1]: debmatic-updatelgwkey.service: Succeeded.
Jun 16 12:00:09 localhost systemd[1]: Stopped debmatic update lgw key.
Jun 16 12:00:09 localhost systemd[1]: debmatic-updatelgwfirmware.service: Succeeded.
Jun 16 12:00:09 localhost systemd[1]: Stopped debmatic update lgw firmware.
Jun 16 12:00:09 localhost systemd[1]: debmatic-prepareinterfaceslist.service: Succeeded.
Jun 16 12:00:09 localhost systemd[1]: Stopped debmatic prepare InterfacesList.xml.
Jun 16 12:00:09 localhost kernel: [ 2429.013769] eq3loop: eq3loop_close_master() mmd_bidcos
Jun 16 12:00:09 localhost kernel: [ 2429.013775] eq3loop: eq3loop_close_master() mmd_bidcos destroy device
Jun 16 12:00:09 localhost kernel: [ 2429.013939] eq3loop: eq3loop_close_master() mmd_hmip
Jun 16 12:00:09 localhost kernel: [ 2429.013943] eq3loop: eq3loop_close_master() mmd_hmip destroy device
Jun 16 12:00:09 localhost systemd[1]: Stopping debmatic multimacd...
Jun 16 12:00:14 localhost systemd[1]: debmatic-multimacd.service: Succeeded.
Jun 16 12:00:14 localhost systemd[1]: Stopped debmatic multimacd.
Jun 16 12:00:14 localhost systemd[1]: debmatic-updaterffirmware.service: Succeeded.
Jun 16 12:00:14 localhost systemd[1]: Stopped debmatic update rf firmware.
Jun 16 12:00:14 localhost systemd[1]: Stopping debmatic...
Jun 16 12:00:14 localhost echo[3917]: - > /sys/module/hb_rf_eth/parameters/connect
Jun 16 12:00:14 localhost rmmod[3918]: rmmod: ERROR: Module hb_rf_eth is not currently loaded
Jun 16 12:00:14 localhost systemd[1]: debmatic.service: Succeeded.
Jun 16 12:00:14 localhost systemd[1]: Stopped debmatic.
Jun 16 12:00:22 localhost systemd[1]: Starting Lighttpd Daemon...
Jun 16 12:00:22 localhost systemd[1]: Starting piVCCU DKMS Modules...
Jun 16 12:00:22 localhost systemd[1]: pivccu-dkms.service: Succeeded.
Jun 16 12:00:22 localhost systemd[1]: Started piVCCU DKMS Modules.
Jun 16 12:00:22 localhost systemd[1]: Starting debmatic...
Jun 16 12:00:22 localhost kernel: [ 2442.090941] raw-uart raw-uart: Reset radio module
Jun 16 12:00:22 localhost kernel: [ 2442.093360] raw-uart raw-uart: Reset radio module
Jun 16 12:00:22 localhost systemd[1]: Started Lighttpd Daemon.
Jun 16 12:00:23 localhost lighttpd[3957]: 2023-06-16 12:00:22: (server.c.750) opening errorlog '/var/log/lighttpd/error.log' failed: Permission denied
Jun 16 12:00:23 localhost lighttpd[3957]: 2023-06-16 12:00:22: (server.c.1461) Opening errorlog failed. Going down.
Jun 16 12:00:23 localhost systemd[1]: lighttpd.service: Main process exited, code=exited, status=255/EXCEPTION
Jun 16 12:00:23 localhost systemd[1]: lighttpd.service: Failed with result 'exit-code'.
Jun 16 12:00:23 localhost systemd[1]: lighttpd.service: Service RestartSec=100ms expired, scheduling restart.
Jun 16 12:00:23 localhost systemd[1]: lighttpd.service: Scheduled restart job, restart counter is at 1.
Jun 16 12:00:23 localhost systemd[1]: Stopped Lighttpd Daemon.
Jun 16 12:00:23 localhost systemd[1]: Starting Lighttpd Daemon...
Jun 16 12:00:23 localhost systemd[1]: Started Lighttpd Daemon.
Jun 16 12:00:23 localhost lighttpd[3967]: 2023-06-16 12:00:23: (server.c.750) opening errorlog '/var/log/lighttpd/error.log' failed: Permission denied
Jun 16 12:00:23 localhost lighttpd[3967]: 2023-06-16 12:00:23: (server.c.1461) Opening errorlog failed. Going down.
Jun 16 12:00:23 localhost systemd[1]: lighttpd.service: Main process exited, code=exited, status=255/EXCEPTION
Jun 16 12:00:23 localhost systemd[1]: lighttpd.service: Failed with result 'exit-code'.
Jun 16 12:00:23 localhost systemd[1]: lighttpd.service: Service RestartSec=100ms expired, scheduling restart.
Jun 16 12:00:23 localhost systemd[1]: lighttpd.service: Scheduled restart job, restart counter is at 2.
Jun 16 12:00:23 localhost systemd[1]: Stopped Lighttpd Daemon.
Jun 16 12:00:23 localhost systemd[1]: Starting Lighttpd Daemon...
Jun 16 12:00:24 localhost systemd[1]: Started Lighttpd Daemon.
Jun 16 12:00:24 localhost lighttpd[3977]: 2023-06-16 12:00:24: (server.c.750) opening errorlog '/var/log/lighttpd/error.log' failed: Permission denied
Jun 16 12:00:24 localhost lighttpd[3977]: 2023-06-16 12:00:24: (server.c.1461) Opening errorlog failed. Going down.
Jun 16 12:00:24 localhost systemd[1]: lighttpd.service: Main process exited, code=exited, status=255/EXCEPTION
Jun 16 12:00:24 localhost systemd[1]: lighttpd.service: Failed with result 'exit-code'.
Jun 16 12:00:24 localhost systemd[1]: lighttpd.service: Service RestartSec=100ms expired, scheduling restart.
Jun 16 12:00:24 localhost systemd[1]: lighttpd.service: Scheduled restart job, restart counter is at 3.
Jun 16 12:00:24 localhost systemd[1]: Stopped Lighttpd Daemon.
Jun 16 12:00:24 localhost systemd[1]: Starting Lighttpd Daemon...
Jun 16 12:00:24 localhost systemd[1]: Started Lighttpd Daemon.
Jun 16 12:00:24 localhost lighttpd[3987]: 2023-06-16 12:00:24: (server.c.750) opening errorlog '/var/log/lighttpd/error.log' failed: Permission denied
Jun 16 12:00:24 localhost lighttpd[3987]: 2023-06-16 12:00:24: (server.c.1461) Opening errorlog failed. Going down.
Jun 16 12:00:24 localhost systemd[1]: lighttpd.service: Main process exited, code=exited, status=255/EXCEPTION
Jun 16 12:00:24 localhost systemd[1]: lighttpd.service: Failed with result 'exit-code'.
Jun 16 12:00:24 localhost systemd[1]: lighttpd.service: Service RestartSec=100ms expired, scheduling restart.
Jun 16 12:00:24 localhost systemd[1]: lighttpd.service: Scheduled restart job, restart counter is at 4.
Jun 16 12:00:24 localhost systemd[1]: Stopped Lighttpd Daemon.
Jun 16 12:00:24 localhost systemd[1]: Starting Lighttpd Daemon...
Jun 16 12:00:25 localhost systemd[1]: Started Lighttpd Daemon.
Jun 16 12:00:25 localhost kernel: [ 2444.511136] raw-uart raw-uart: Reset radio module
Jun 16 12:00:25 localhost lighttpd[3997]: 2023-06-16 12:00:25: (server.c.750) opening errorlog '/var/log/lighttpd/error.log' failed: Permission denied
Jun 16 12:00:25 localhost lighttpd[3997]: 2023-06-16 12:00:25: (server.c.1461) Opening errorlog failed. Going down.
Jun 16 12:00:25 localhost systemd[1]: lighttpd.service: Main process exited, code=exited, status=255/EXCEPTION
Jun 16 12:00:25 localhost systemd[1]: lighttpd.service: Failed with result 'exit-code'.
Jun 16 12:00:25 localhost initsystem.sh[3927]: cat: /sys/class/net/dummy0/carrier: Invalid argument
Jun 16 12:00:25 localhost systemd[1]: lighttpd.service: Service RestartSec=100ms expired, scheduling restart.
Jun 16 12:00:25 localhost systemd[1]: lighttpd.service: Scheduled restart job, restart counter is at 5.
Jun 16 12:00:25 localhost systemd[1]: Stopped Lighttpd Daemon.
Jun 16 12:00:25 localhost systemd[1]: lighttpd.service: Start request repeated too quickly.
Jun 16 12:00:25 localhost systemd[1]: lighttpd.service: Failed with result 'exit-code'.
Jun 16 12:00:25 localhost systemd[1]: Failed to start Lighttpd Daemon.
Jun 16 12:00:25 localhost systemd[1]: Dependency failed for debmatic lighttpd.
Jun 16 12:00:25 localhost systemd[1]: debmatic-lighttpd.service: Job debmatic-lighttpd.service/start failed with result 'dependency'.
Jun 16 12:00:25 localhost systemd[1]: Started debmatic.
Jun 16 12:00:25 localhost systemd[1]: Starting debmatic update rf firmware...
Jun 16 12:00:25 localhost systemd[1]: Condition check resulted in debmatic hs485d being skipped.
Jun 16 12:00:25 localhost systemd[1]: Starting debmatic HssLED...
Jun 16 12:00:25 localhost systemd[1]: Starting debmatic ssdpd...
Jun 16 12:00:25 localhost systemd[1]: Starting debmatic prepare InterfacesList.xml...
Jun 16 12:00:25 localhost systemd[1]: Starting debmatic eq3configd...
Jun 16 12:00:26 localhost update_rf_firmware.sh[4095]: RPI-RF-MOD has already desired version 4.4.12...
Jun 16 12:00:26 localhost systemd[1]: Started debmatic update rf firmware.
Jun 16 12:00:26 localhost systemd[1]: Starting debmatic multimacd...
Jun 16 12:00:26 localhost systemd[1]: Started debmatic HssLED.
Jun 16 12:00:26 localhost systemd[1]: Started debmatic ssdpd.
Jun 16 12:00:26 localhost systemd[1]: Started debmatic prepare InterfacesList.xml.
Jun 16 12:00:26 localhost systemd[1]: Started debmatic eq3configd.
Jun 16 12:00:26 localhost systemd[1]: Starting debmatic update lgw firmware...
Jun 16 12:00:26 localhost systemd[1]: Starting XML-API...
Jun 16 12:00:26 localhost start_multimacd.sh[4147]: kernel.sched_rt_runtime_us = -1
Jun 16 12:00:26 localhost systemd[1]: Started XML-API.
Jun 16 12:00:26 localhost start_multimacd.sh[4147]: Daemonizing to background
Jun 16 12:00:26 localhost kernel: [ 2445.317314] eq3loop: created slave mmd_hmip
Jun 16 12:00:26 localhost kernel: [ 2445.317786] eq3loop: created slave mmd_bidcos
Jun 16 12:00:26 localhost systemd[1]: Started debmatic update lgw firmware.
Jun 16 12:00:26 localhost systemd[1]: Starting debmatic update lgw key...
Jun 16 12:00:26 localhost update_lgw_key.sh[4184]: ls: cannot access '/etc/config/*.keychange': No such file or directory
Jun 16 12:00:26 localhost systemd[1]: Started debmatic update lgw key.
Jun 16 12:00:28 localhost systemd[1]: Started debmatic multimacd.
Jun 16 12:00:28 localhost systemd[1]: Starting debmatic rfd...
Jun 16 12:00:28 localhost start_rfd.sh[4195]: Daemonizing to background
Jun 16 12:00:28 localhost kernel: [ 2447.426395] eq3loop: eq3loop_open_slave() mmd_bidcos
Jun 16 12:00:30 localhost systemd[1]: Started debmatic rfd.
Jun 16 12:00:30 localhost systemd[1]: Starting debmatic hmserver...
Jun 16 12:00:31 localhost start_hmserver.sh[4219]: Init Hardware Info
Jun 16 12:00:31 localhost start_hmserver.sh[4219]: WARNING: An illegal reflective access operation has occurred
Jun 16 12:00:31 localhost start_hmserver.sh[4219]: WARNING: Illegal reflective access by io.netty.util.internal.PlatformDependent0$1 (file:/opt/HMServer/HMIPServer.jar) to field java.nio.Buffer.address
Jun 16 12:00:31 localhost start_hmserver.sh[4219]: WARNING: Please consider reporting this to the maintainers of io.netty.util.internal.PlatformDependent0$1
Jun 16 12:00:31 localhost start_hmserver.sh[4219]: WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
Jun 16 12:00:31 localhost start_hmserver.sh[4219]: WARNING: All illegal access operations will be denied in a future release
Jun 16 12:00:42 localhost start_hmserver.sh[4219]: RXTX Warning:  Removing stale lock file. /var/lock/LCK..mmd_hmip
Jun 16 12:00:42 localhost kernel: [ 2461.689878] eq3loop: eq3loop_open_slave() mmd_hmip
Jun 16 12:00:42 localhost kernel: [ 2461.690086] eq3loop: eq3loop_close_slave() mmd_hmip
Jun 16 12:00:42 localhost kernel: [ 2461.693072] eq3loop: eq3loop_open_slave() mmd_hmip
Jun 16 12:00:42 localhost kernel: [ 2461.693265] eq3loop: eq3loop_close_slave() mmd_hmip
Jun 16 12:00:42 localhost kernel: [ 2461.694943] eq3loop: eq3loop_open_slave() mmd_hmip
Jun 16 12:00:42 localhost kernel: [ 2461.695107] eq3loop: eq3loop_close_slave() mmd_hmip
Jun 16 12:00:42 localhost kernel: [ 2461.703287] eq3loop: eq3loop_open_slave() mmd_hmip
Jun 16 12:00:52 localhost systemd[1]: Started debmatic hmserver.
Jun 16 12:00:52 localhost systemd[1]: Starting debmatic rega...
Jun 16 12:00:55 localhost start_rega.sh[4382]: successfully loaded "/etc/config/homematic.regadom"
Jun 16 12:00:55 localhost start_rega.sh[4382]: Load interfaces from file
Jun 16 12:00:55 localhost start_rega.sh[4382]: HTTP server started successfully (6 workers)
Jun 16 12:00:55 localhost start_rega.sh[4382]: Waiting for child to finish
Jun 16 12:00:55 localhost start_rega.sh[4382]: Executing /bin/hm_startup in child 4395
Jun 16 12:00:57 localhost wait_sysvar_creation.tcl[4384]: Waiting for ReGa startup . Done
Jun 16 12:00:57 localhost systemd[1]: Started debmatic rega.
Jun 16 12:00:57 localhost systemd[1]: Starting debmatic startup finished...
Jun 16 12:00:57 localhost systemd[1]: Started debmatic startup finished.
Jun 16 12:00:57 localhost systemd[1]: Condition check resulted in debmatic Monitor HB-RF-ETH being skipped.
Jun 16 12:00:57 localhost systemd[1]: Started debmatic set interface clock timer.
Jun 16 12:01:02 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"00085A498DAA30:7","ENERGY_COUNTER"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: ENERGY_COUNTER"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:02 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"00085A498DAA30:7","ENERGY_COUNTER"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:02 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0.000000 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:02 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","ACTIVE_PROFILE"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: ACTIVE_PROFILE"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:02 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","ACTIVE_PROFILE"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:02 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:02 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"00085A498DAA30:7","ENERGY_COUNTER_OVERFLOW"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: ENERGY_COUNTER_OVERFLOW"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:02 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"00085A498DAA30:7","ENERGY_COUNTER_OVERFLOW"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:02 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:02 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","ACTUAL_TEMPERATURE"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: ACTUAL_TEMPERATURE"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:02 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","ACTUAL_TEMPERATURE"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:02 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0.000000 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:02 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","ACTUAL_TEMPERATURE_STATUS"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: ACTUAL_TEMPERATURE_STATUS"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:02 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","ACTUAL_TEMPERATURE_STATUS"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:02 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:02 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","BOOST_TIME"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: BOOST_TIME"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:02 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","BOOST_TIME"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:02 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:02 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","FROST_PROTECTION"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: FROST_PROTECTION"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:02 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","FROST_PROTECTION"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:02 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:02 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","HEATING_COOLING"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: HEATING_COOLING"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:02 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","HEATING_COOLING"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:02 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:02 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","HUMIDITY"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: HUMIDITY"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:02 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","HUMIDITY"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:02 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:02 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","HUMIDITY_STATUS"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: HUMIDITY_STATUS"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:02 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","HUMIDITY_STATUS"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:02 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:02 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","PARTY_MODE"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: PARTY_MODE"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:02 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","PARTY_MODE"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:02 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:03 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","PARTY_SET_POINT_TEMPERATURE"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: PARTY_SET_POINT_TEMPERATURE"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:03 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","PARTY_SET_POINT_TEMPERATURE"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:03 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0.000000 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:03 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","PARTY_TIME_END"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: PARTY_TIME_END"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:03 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","PARTY_TIME_END"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:03 localhost ReGaHss: ERROR: CallGetValue failed; sVal =  [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:03 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","PARTY_TIME_START"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: PARTY_TIME_START"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:03 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","PARTY_TIME_START"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:03 localhost ReGaHss: ERROR: CallGetValue failed; sVal =  [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:03 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","QUICK_VETO_TIME"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: QUICK_VETO_TIME"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:03 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","QUICK_VETO_TIME"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:03 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:03 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","SET_POINT_MODE"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: SET_POINT_MODE"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:03 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","SET_POINT_MODE"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:03 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:03 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","SET_POINT_TEMPERATURE"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: SET_POINT_TEMPERATURE"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:03 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","SET_POINT_TEMPERATURE"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:03 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0.000000 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:03 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","SWITCH_POINT_OCCURED"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: SWITCH_POINT_OCCURED"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:03 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","SWITCH_POINT_OCCURED"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:03 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:03 localhost ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000A9A49A2CACD:1","WINDOW_STATE"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: WINDOW_STATE"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Jun 16 12:01:03 localhost ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 1009, params: {"000A9A49A2CACD:1","WINDOW_STATE"}) [CallGetValue():iseXmlRpc.cpp:1435]
Jun 16 12:01:03 localhost ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Jun 16 12:01:05 localhost start_hmserver.sh[4219]: Jun 16, 2023 12:01:05 PM io.vertx.core.impl.BlockedThreadChecker
Jun 16 12:01:05 localhost start_hmserver.sh[4219]: WARNING: Thread Thread[vert.x-eventloop-thread-3,5,main] has been blocked for 2723 ms, time limit is 2000
Jun 16 12:01:06 localhost start_hmserver.sh[4219]: Jun 16, 2023 12:01:06 PM io.vertx.core.impl.BlockedThreadChecker
Jun 16 12:01:06 localhost start_hmserver.sh[4219]: WARNING: Thread Thread[vert.x-eventloop-thread-3,5,main] has been blocked for 3723 ms, time limit is 2000
Jun 16 12:01:07 localhost start_hmserver.sh[4219]: Jun 16, 2023 12:01:07 PM io.vertx.core.impl.BlockedThreadChecker
Jun 16 12:01:07 localhost start_hmserver.sh[4219]: WARNING: Thread Thread[vert.x-eventloop-thread-3,5,main] has been blocked for 4724 ms, time limit is 2000
Jun 16 12:01:07 localhost start_rega.sh[4382]: ReGa entering normal operation
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: Jun 16, 2023 12:01:08 PM io.vertx.core.impl.BlockedThreadChecker
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: WARNING: Thread Thread[vert.x-eventloop-thread-3,5,main] has been blocked for 5723 ms, time limit is 2000
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: io.vertx.core.VertxException: Thread blocked
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.misc.Unsafe.park(Native Method)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:458)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega.registerCallback(VirtualDeviceHandlerRega.java:99)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.lang.reflect.Method.invoke(Method.java:566)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//de.eq3.cbcs.legacy.communication.rpc.internal.rpc.AnnotationAwareRpcHandler.execute(AnnotationAwareRpcHandler.java:80)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.server.internal.RpcMessageHandler.handle(RpcMessageHandler.java:70)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.server.internal.RpcMessageHandler.handle(RpcMessageHandler.java:24)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.HandlerRegistration.deliver(HandlerRegistration.java:212)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.HandlerRegistration.handle(HandlerRegistration.java:191)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.EventBusImpl.lambda$deliverToHandler$3(EventBusImpl.java:505)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.EventBusImpl$$Lambda$95/0xa6543e28.handle(Unknown Source)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.impl.ContextImpl.lambda$wrapTask$2(ContextImpl.java:337)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.impl.ContextImpl$$Lambda$83/0xa879f428.run(Unknown Source)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:403)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:445)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
Jun 16 12:01:08 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.lang.Thread.run(Thread.java:829)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: Jun 16, 2023 12:01:09 PM io.vertx.core.impl.BlockedThreadChecker
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: WARNING: Thread Thread[vert.x-eventloop-thread-3,5,main] has been blocked for 6723 ms, time limit is 2000
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: io.vertx.core.VertxException: Thread blocked
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.misc.Unsafe.park(Native Method)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:458)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega.registerCallback(VirtualDeviceHandlerRega.java:99)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.lang.reflect.Method.invoke(Method.java:566)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//de.eq3.cbcs.legacy.communication.rpc.internal.rpc.AnnotationAwareRpcHandler.execute(AnnotationAwareRpcHandler.java:80)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.server.internal.RpcMessageHandler.handle(RpcMessageHandler.java:70)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.server.internal.RpcMessageHandler.handle(RpcMessageHandler.java:24)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.HandlerRegistration.deliver(HandlerRegistration.java:212)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.HandlerRegistration.handle(HandlerRegistration.java:191)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.EventBusImpl.lambda$deliverToHandler$3(EventBusImpl.java:505)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.EventBusImpl$$Lambda$95/0xa6543e28.handle(Unknown Source)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.impl.ContextImpl.lambda$wrapTask$2(ContextImpl.java:337)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.impl.ContextImpl$$Lambda$83/0xa879f428.run(Unknown Source)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:403)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:445)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
Jun 16 12:01:09 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.lang.Thread.run(Thread.java:829)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: Jun 16, 2023 12:01:10 PM io.vertx.core.impl.BlockedThreadChecker
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: WARNING: Thread Thread[vert.x-eventloop-thread-3,5,main] has been blocked for 7724 ms, time limit is 2000
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: io.vertx.core.VertxException: Thread blocked
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.misc.Unsafe.park(Native Method)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:458)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega.registerCallback(VirtualDeviceHandlerRega.java:99)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.lang.reflect.Method.invoke(Method.java:566)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//de.eq3.cbcs.legacy.communication.rpc.internal.rpc.AnnotationAwareRpcHandler.execute(AnnotationAwareRpcHandler.java:80)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.server.internal.RpcMessageHandler.handle(RpcMessageHandler.java:70)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.server.internal.RpcMessageHandler.handle(RpcMessageHandler.java:24)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.HandlerRegistration.deliver(HandlerRegistration.java:212)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.HandlerRegistration.handle(HandlerRegistration.java:191)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.EventBusImpl.lambda$deliverToHandler$3(EventBusImpl.java:505)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.EventBusImpl$$Lambda$95/0xa6543e28.handle(Unknown Source)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.impl.ContextImpl.lambda$wrapTask$2(ContextImpl.java:337)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.impl.ContextImpl$$Lambda$83/0xa879f428.run(Unknown Source)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:403)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:445)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
Jun 16 12:01:10 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.lang.Thread.run(Thread.java:829)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: Jun 16, 2023 12:01:11 PM io.vertx.core.impl.BlockedThreadChecker
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: WARNING: Thread Thread[vert.x-eventloop-thread-3,5,main] has been blocked for 8724 ms, time limit is 2000
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: io.vertx.core.VertxException: Thread blocked
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.misc.Unsafe.park(Native Method)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:458)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega.registerCallback(VirtualDeviceHandlerRega.java:99)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.lang.reflect.Method.invoke(Method.java:566)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//de.eq3.cbcs.legacy.communication.rpc.internal.rpc.AnnotationAwareRpcHandler.execute(AnnotationAwareRpcHandler.java:80)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.server.internal.RpcMessageHandler.handle(RpcMessageHandler.java:70)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.server.internal.RpcMessageHandler.handle(RpcMessageHandler.java:24)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.HandlerRegistration.deliver(HandlerRegistration.java:212)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.HandlerRegistration.handle(HandlerRegistration.java:191)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.EventBusImpl.lambda$deliverToHandler$3(EventBusImpl.java:505)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.EventBusImpl$$Lambda$95/0xa6543e28.handle(Unknown Source)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.impl.ContextImpl.lambda$wrapTask$2(ContextImpl.java:337)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.impl.ContextImpl$$Lambda$83/0xa879f428.run(Unknown Source)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:403)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:445)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
Jun 16 12:01:11 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.lang.Thread.run(Thread.java:829)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: Jun 16, 2023 12:01:12 PM io.vertx.core.impl.BlockedThreadChecker
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: WARNING: Thread Thread[vert.x-eventloop-thread-3,5,main] has been blocked for 9724 ms, time limit is 2000
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: io.vertx.core.VertxException: Thread blocked
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.misc.Unsafe.park(Native Method)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:458)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega.registerCallback(VirtualDeviceHandlerRega.java:99)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.lang.reflect.Method.invoke(Method.java:566)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//de.eq3.cbcs.legacy.communication.rpc.internal.rpc.AnnotationAwareRpcHandler.execute(AnnotationAwareRpcHandler.java:80)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.server.internal.RpcMessageHandler.handle(RpcMessageHandler.java:70)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//de.eq3.ccu.server.internal.RpcMessageHandler.handle(RpcMessageHandler.java:24)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.HandlerRegistration.deliver(HandlerRegistration.java:212)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.HandlerRegistration.handle(HandlerRegistration.java:191)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.EventBusImpl.lambda$deliverToHandler$3(EventBusImpl.java:505)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.eventbus.impl.EventBusImpl$$Lambda$95/0xa6543e28.handle(Unknown Source)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.impl.ContextImpl.lambda$wrapTask$2(ContextImpl.java:337)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//io.vertx.core.impl.ContextImpl$$Lambda$83/0xa879f428.run(Unknown Source)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:403)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:445)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at app//io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
Jun 16 12:01:12 localhost start_hmserver.sh[4219]: #011at java.base@11.0.18/java.lang.Thread.run(Thread.java:829)
FHEM meldet für das ccu-device "RPCState inactive".

Nach dem letzten apt update (einige Wochen her) lief debmatic noch. Ich konnte allerdings damal die neues Version nicht installieren, weil eine Abhängigkeit (ich meine es war ein zur C++-Lib) nicht aufgelöst werden konnte.

Nun hoffe ich auf erhellende Hinweise der Debmatic-Spezialisten .

Gruß

Thomas

[thomas.z]

Das Problem ist behoben. Es lag an einer nicht geeigneten Kombination der apt Pakete debmatic und pivccu-modules-dkms nach dem update.