search

alexreinert / piVCCU

piVCCU is a project to install the original Homematic CCU3 firmware inside a virtualized container (lxc) on ARM based single board computers.
Apache License 2.0
302 stars 64 forks source link

100% Java usage #54

Closed Noranius closed 6 years ago

Noranius commented 6 years ago

Hello, I've recognized several times that my Pi (Model 3 b+) overheats. Today I've checked the CPU-Usage. Java has 100% of one CPU. Is there some Java-Code in piVCCU?

UPDATE: Just killed Java and tried the Web Interface: No devices except the virtual remote.

Kind Regards Noranius

alexreinert commented 6 years ago

piVCCU itself does not use Java. But the hmserver inside the CCU firmware bases on Java.

alexreinert commented 6 years ago

Maybe you can see the cause of the 100% usage in the logfile of the hmserver: sudo pivccu-attach cat /var/log/hmserver.log

Noranius commented 6 years ago

Ok. I Just restarted the PI and again all is up. But this Problem occurs after several days repeatingly.

I'll have new information not later than next week.

Regards Noranius

alexreinert commented 6 years ago

Any news on this?

Noranius commented 6 years ago

Last week the piVccu software seems not to respond, because i didn't got any measurements. But the log doesnt show anything. I hope it will occur again... some bugs are really shy...

Noranius commented 6 years ago

Today there was another bahviour: neither the pivccu website respond nor Sensorvalues were transceived. The log is below.

I didn't restart it untill now.

Jun 20 09:10:47 de.eq3.lib.util.dynamics.GenericFactory INFO  [main] @GenericFactory 
Jun 20 09:10:47 de.eq3.lib.util.dynamics.GenericFactory INFO  [main] creating instance of HMServerConfiguration with no-arg constructor 
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [HMIPTRXWriterWorker] (1) *worker 
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [KeyServerWorker] (1) *worker 
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [KryoPersistenceWorker] (1) *worker 
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [TransactionSubsystemHandler] (1) *worker 
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [FirmwareLoaderFileSystem] (1) *worker 
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [LocalServerPersistentDataLoader] (1)  
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [LocalServerAdapterInitialization] (1)  
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [BackendCommandHandler] (1)  
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [DeviceInclusionAcceptHandler] (1)  
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [IncomingHMIPFrameHandler] (1)  
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [DeviceBackgroundUpdateSubsystem] (1)  
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [DeviceInclusionDefaultConfigurationChanger] (1)  
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [CyclicSmokeDetectorAwakening] (1)  
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [LocalServerFirmwareUpdateInitialization] (1)  
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [LegacyNotificationHandler] (1) *worker 
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [LegacyAPIWorker] (1) *worker 
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [LegacyBackendNotificationHandler] (3) *worker 
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [LegacyBlindLevelCorrectionHandler] (1) *worker 
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: added for deployment [LegacyInitializion] (1)  
Jun 20 09:10:53 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: deploying 19 classes to Vert.x 
Jun 20 09:10:54 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: 19 VertxDeployers initialized 
Jun 20 09:10:54 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-3] SYSTEM: start of CyclicSmokeDetectorAwakening succeeded (fcb2a3ec-bbf7-4e4c-ab4f-7a5467ab70b4) 
Jun 20 09:10:54 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-1] SYSTEM: start of LegacyBlindLevelCorrectionHandler succeeded (4bc7ec57-2319-4311-bcb3-59f9de1e7758) 
Jun 20 09:10:54 de.eq3.cbcs.server.core.vertx.KeyServerWorker ERROR [vert.x-worker-thread-2] Missing key server configuration parameter (Network.Key) for  mode: KEYSERVER_LOCAL 
Jun 20 09:10:54 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-2] SYSTEM: start of HMIPTRXWriterWorker succeeded (8bb1708d-d6d1-4e2c-8e18-9b960b4fc255) 
Jun 20 09:10:54 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-1] SYSTEM: start of TransactionSubsystemHandler succeeded (aa40bfcf-f42f-476f-b3de-acd610ac0ae1) 
Jun 20 09:10:54 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-1] SYSTEM: start of DeviceInclusionDefaultConfigurationChanger succeeded (42093e90-96e7-4a1a-89b7-94125c5e8032) 
Jun 20 09:10:54 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-0] SYSTEM: start of KeyServerWorker succeeded (bc886fa3-5293-463f-b228-eac4d18b81bb) 
Jun 20 09:10:55 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-3] SYSTEM: start of DeviceBackgroundUpdateSubsystem succeeded (1eaa3168-254f-408e-8c35-11d217c6b6bf) 
Jun 20 09:10:55 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-0] SYSTEM: start of KryoPersistenceWorker succeeded (428bd31c-3c8e-4072-a30d-f1fe75c797b4) 
Jun 20 09:10:55 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-4] SYSTEM: start of LocalServerPersistentDataLoader succeeded (66187e70-f3de-49be-b8de-12432099af3c) 
Jun 20 09:10:56 de.eq3.cbcs.server.core.otau.util.FirmwareLoaderFileSystem INFO  [vert.x-worker-thread-1] SYSTEM: Firmware update directory is set to /etc/config/firmware 
Jun 20 09:10:56 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-6] SYSTEM: start of FirmwareLoaderFileSystem succeeded (4e74295c-0f1d-4ea7-b931-660a65770660) 
Jun 20 09:10:57 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-3] SYSTEM: start of DeviceInclusionAcceptHandler succeeded (8c08df7a-23a0-4ade-b2e4-29ab26b88346) 
Jun 20 09:10:57 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-6] SYSTEM: start of IncomingHMIPFrameHandler succeeded (752a3bf2-5983-43d7-88e8-56f9ec338d4b) 
Jun 20 09:10:57 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-7] SYSTEM: start of BackendCommandHandler succeeded (c0d2e1d0-88d6-4495-83eb-620b0f5f84b0) 
Jun 20 09:10:57 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-4] SYSTEM: start of LegacyNotificationHandler succeeded (852e0666-79d4-4b2c-9660-40b3330be329) 
Jun 20 09:10:57 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-4] SYSTEM: start of LegacyBackendNotificationHandler succeeded (5231d311-1964-4ee0-94f9-07bd3f2ed869) 
Jun 20 09:10:57 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-1] SYSTEM: start of LegacyAPIWorker succeeded (49190c29-366d-4a4b-8468-64eb8ce9770a) 
Jun 20 09:10:57 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-0] SYSTEM: start of LocalServerAdapterInitialization succeeded (b468e747-c9e5-4115-ade8-9381e0c20791) 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] TRX adapter state 1: HMIP_TRX_App 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] TRX adapter application is already running 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] No NWK, try to set address ... 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] Try to set radio address 12178086... 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] Set max send attempts for 3014F5AC94000416FB53307B to 3 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] Try to get application version... 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] Application version 2.8.4 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] Bootloader version 1.0.12 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] hmos version 1.18.5 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] MCU type: EFM32G200F64_CM3 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] Duty Cycle: 0.0 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] set DutyCycle limit to ffffffc8 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] Set Duty Cycle Limit 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] Current Security Counter: 25006594 
Jun 20 09:10:57 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] Update security counter to calculation: 25572522 
Jun 20 09:10:58 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] TRX adapter has 27 link partners 
Jun 20 09:10:58 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] Adapter with Access Point id 3014F5AC94000416FB53307B initialized 
Jun 20 09:10:58 de.eq3.cbcs.server.local.base.internal.LocalServerAdapterInitialization INFO  [Thread-6] HMIPTRXInitialResponseListener said that Adapter was initialized 
Jun 20 09:10:58 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-2] SYSTEM: start of LocalServerFirmwareUpdateInitialization succeeded (6e750511-6d7e-45ff-896d-246696ab4607) 
Jun 20 09:10:58 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-5] SYSTEM: start of LegacyInitializion succeeded (d4c498cd-37ef-4d9a-997e-467a30d82364) 
Jun 20 09:10:58 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO  [vert.x-eventloop-thread-2] SYSTEM: Checking all devices on all accesspoints for updates 
Jun 20 09:10:58 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO  [vert.x-eventloop-thread-2] SYSTEM: There are 1 APs queued with updatable devices 
Jun 20 09:10:58 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-0] SYSTEM: initial deployment complete _____________________________________________________ 
Jun 20 09:11:02 de.eq3.ccu.server.HMServer INFO  [Thread-2] Default MaxEventLoopExecuteTime: 2000000000 
Jun 20 09:11:02 de.eq3.ccu.server.HMServer INFO  [Thread-2] Default BlockedThreadCheckInterval: 1000 
Jun 20 09:11:02 de.eq3.ccu.server.HMServer INFO  [Thread-2] Default MaxWorkerExecuteTime: 60000000000 
Jun 20 09:11:02 de.eq3.ccu.server.HMServer INFO  [Thread-2] Default EventLoopPoolSize: 8 
Jun 20 09:11:02 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-2] SYSTEM: added for deployment [BackendWorker] (1) *worker 
Jun 20 09:11:02 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-2] SYSTEM: added for deployment [GroupRequestWorker] (1) *worker 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-2] SYSTEM: added for deployment [DiagramRequestWorker] (1) *worker 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-2] SYSTEM: added for deployment [StorageRequestWorker] (1) *worker 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-2] SYSTEM: added for deployment [DeviceFirmwareRequestWorker] (1) *worker 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-2] SYSTEM: added for deployment [EnergyPriceRequestWorker] (1) *worker 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-2] SYSTEM: added for deployment [CouplingRequestWorker] (1) *worker 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-2] SYSTEM: deploying 7 classes to Vert.x 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-2] SYSTEM: 7 VertxDeployers initialized 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-3] SYSTEM: start of BackendWorker succeeded (31130c76-910f-43b3-ab6a-32a8eef53df9) 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-3] SYSTEM: start of CouplingRequestWorker succeeded (0cc669ff-3f2e-40a8-9c87-f0a2afa8f985) 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-0] SYSTEM: start of EnergyPriceRequestWorker succeeded (3ddd851e-77ab-4950-b979-0275181e72cc) 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-4] SYSTEM: start of StorageRequestWorker succeeded (66e1e9b2-7b70-4737-aace-8196728c74d5) 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-4] SYSTEM: start of DiagramRequestWorker succeeded (2530c9da-b325-45e4-845b-63728d988779) 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-1] SYSTEM: start of DeviceFirmwareRequestWorker succeeded (6d0eed27-655b-4b67-b927-155e4a2d69b8) 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [vert.x-eventloop-thread-5] SYSTEM: start of GroupRequestWorker succeeded (1bac51b9-70ad-44b2-bafe-343089d60bc0) 
Jun 20 09:11:03 de.eq3.cbcs.vertx.management.VertxManager INFO  [Thread-2] SYSTEM: initial deployment complete _____________________________________________________ 
Jun 20 09:11:03 de.eq3.ccu.server.HMServer INFO  [Thread-2] Starting HMServer at 127.0.0.1:9292 
Jun 20 09:11:03 de.eq3.ccu.server.HMServer INFO  [Thread-2] Read Configuration 
Jun 20 09:11:03 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create Bidcos Dispatcher 
Jun 20 09:11:03 de.eq3.ccu.server.HMServer INFO  [Thread-2] InitBidCosCache 
Jun 20 09:11:04 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher ERROR [Thread-2] BidCosCache could not be initialized 
Jun 20 09:11:04 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher ERROR [Thread-2] java.net.ConnectException: Connection refused (Connection refused) 
Jun 20 09:11:04 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create groupDefinitionProvider 
Jun 20 09:11:05 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create VirtualDeviceHolder 
Jun 20 09:11:05 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create VirtualDeviceHandlerRega 
Jun 20 09:11:05 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create GroupAdministrationService 
Jun 20 09:11:05 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create GroupDeviceDispatcher 
Jun 20 09:11:05 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create GroupDeviceHandler 
Jun 20 09:11:05 de.eq3.ccu.groupdevice.service.GroupDeviceHandler INFO  [Thread-2] @GroupDeviceHandler - initializing... 
Jun 20 09:11:05 de.eq3.ccu.groupdevice.service.GroupDeviceHandler INFO  [Thread-2] --> created groupDeviceDispatcher (GroupDeviceService to BidCoS (via Dispatcher)) 
Jun 20 09:11:05 de.eq3.ccu.groupdevice.service.GroupDeviceHandler INFO  [Thread-2] --> created virtualDeviceHandler (GroupDeviceService to ReGa) 
Jun 20 09:11:05 de.eq3.ccu.groupdevice.service.GroupDeviceHandler INFO  [Thread-2] --> got groupDefinitionProvider 
Jun 20 09:11:05 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create BidCosGroupMemberProvider 
Jun 20 09:11:05 de.eq3.ccu.server.HMServer INFO  [Thread-2] Init groupAdministrationService 
Jun 20 09:11:05 de.eq3.ccu.server.HMServer INFO  [Thread-2] Init Virtual OS Device 
Jun 20 09:11:05 de.eq3.ccu.server.HMServer INFO  [Thread-2] Init ESHLight Bridge 
Jun 20 09:11:06 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create RrdDatalogging 
Jun 20 09:11:06 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create MeasurementService 
Jun 20 09:11:06 de.eq3.ccu.server.HMServer INFO  [Thread-2] Init MeasurementService 
Jun 20 09:11:06 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create HTTP Server 
Jun 20 09:11:10 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO  [vert.x-eventloop-thread-2] AP 3014F5AC94000416FB53307B: OTAU Handler e63d648d-d7ea-4c3a-8932-84b38ddaaa25 continues for device(s) [3014F711A0000A1709ACBC3F] 
Jun 20 09:11:20 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create BidCos context and start handler 
Jun 20 09:11:20 de.eq3.ccu.server.HMServer INFO  [Thread-2] Create group context and start handler 
Jun 20 09:11:20 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-0] (un)registerCallback on LegacyServiceHandler called from url: http://127.0.0.1:9292/bidcos 
Jun 20 09:11:20 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-0] init finished 
Jun 20 09:11:20 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer INFO  [vert.x-worker-thread-3] Added InterfaceId: HmIP-RF_java 
Jun 20 09:11:21 de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil INFO  [vert.x-worker-thread-3] updateDevicesForClient HmIP-RF_java -> 225 device addresses will be added 
Jun 20 09:11:21 de.eq3.ccu.server.HMServer INFO  [Thread-2] Starting HMServer done 
Jun 20 09:11:40 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO  [vert.x-eventloop-thread-1] (un)registerCallback on VirtualDeviceHandlerRega called from url: xmlrpc_bin://127.0.0.1:1999 
Jun 20 09:11:40 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO  [vert.x-eventloop-thread-1] Added InterfaceId: 1008 
Jun 20 09:11:40 de.eq3.ccu.virtualdevice.service.internal.rega.BackendWorker INFO  [vert.x-worker-thread-7] Execute BackendCommand: de.eq3.ccu.virtualdevice.service.internal.rega.BackendUpdateDevicesCommand 
Jun 20 09:11:50 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-2] (un)registerCallback on LegacyServiceHandler called from url: xmlrpc_bin://127.0.0.1:1999 
Jun 20 09:11:50 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-2] init finished 
Jun 20 09:11:50 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer INFO  [vert.x-worker-thread-4] Added InterfaceId: 1009 
Jun 20 09:11:50 de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil INFO  [vert.x-worker-thread-4] updateDevicesForClient 1009 -> 6 device addresses will be deleted 
Jun 20 09:12:28 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO  [vert.x-eventloop-thread-2] AP 3014F5AC94000416FB53307B: OTAU Handler e63d648d-d7ea-4c3a-8932-84b38ddaaa25 aborted for device(s) [3014F711A0000A1709ACBC3F] 
Jun 20 09:28:32 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-3] (un)registerCallback on LegacyServiceHandler called from url: http://192.168.253.1:7420/fh2010 
Jun 20 09:28:32 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-3] init finished 
Jun 20 09:29:52 de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil INFO  [vert.x-worker-thread-4] updateDevicesForClient 1009 -> 6 device addresses will be added 
Jun 20 09:29:53 org.apache.http.impl.client.DefaultHttpClient INFO  [vert.x-worker-thread-3] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) 
Jun 20 09:29:53 org.apache.http.impl.client.DefaultHttpClient INFO  [vert.x-worker-thread-3] Retrying request to {}->http://127.0.0.1:9292 
Jun 20 09:30:08 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-2] (un)registerCallback on LegacyServiceHandler called from url: http://192.168.253.1:7420/fh2010 
Jun 20 09:30:08 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-2] Removed InterfaceId: CB2010 
Jun 20 09:30:08 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-2] init finished 
Jun 20 09:30:28 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-1] (un)registerCallback on LegacyServiceHandler called from url: http://192.168.253.1:7420/fh2010 
Jun 20 09:30:28 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-1] init finished
alexreinert commented 6 years ago

This is the more or less normal log of a startup, which was yesterday at 09:20. Can you please provide other informations?

sudo pivccu-attach cat /var/log/hmserver.log
sudo pivccu-attach ps aux
sudo dmesg | tail -40
sudo cat /proc/meminfo
Noranius commented 6 years ago

Good Morning It seems like the USB-Transceiver wasn't recognized?!

I had an additional USB drive attached. Maybe this lead to the Problem?

pi@ITD-S-001:~ $ sudo dmesg | tail -40

[ 16.943659] usbcore: registered new interface driver cp210x [ 16.943772] usbserial: USB Serial support registered for cp210x [ 17.075362] cp210x 1-1.2:1.0: cp210x converter detected [ 17.085501] usb 1-1.2: cp210x converter now attached to ttyUSB0 [ 19.612545] Adding 102396k swap on /var/swap. Priority:-1 extents:1 across:102396k SSFS [ 19.631015] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready [ 22.770577] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 26.393797] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. [ 26.897046] Started plat_eq3ccu2 [ 28.732849] br0: port 1(vethpivccu) entered blocking state [ 28.732858] br0: port 1(vethpivccu) entered disabled state [ 28.733115] device vethpivccu entered promiscuous mode [ 28.733420] IPv6: ADDRCONF(NETDEV_UP): vethpivccu: link is not ready [ 28.817272] eth0: renamed from vethEJBMR3 [ 28.902395] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready [ 28.904594] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 28.904695] IPv6: ADDRCONF(NETDEV_CHANGE): vethpivccu: link becomes ready [ 28.904738] br0: port 1(vethpivccu) entered blocking state [ 28.904741] br0: port 1(vethpivccu) entered forwarding state [ 33.732059] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. [ 33.811280] EXT4-fs (mmcblk0p5): mounted filesystem with ordered data mode. Opts: (null) [ 92.842559] Bluetooth: Core ver 2.22 [ 92.842608] NET: Registered protocol family 31 [ 92.842610] Bluetooth: HCI device and connection manager initialized [ 92.842622] Bluetooth: HCI socket layer initialized [ 92.842637] Bluetooth: L2CAP socket layer initialized [ 92.842655] Bluetooth: SCO socket layer initialized [ 124.153683] eq3loop: created slave ttyS0 [ 124.153937] eq3loop: created slave mmd_bidcos [ 124.939904] eq3loop: eq3loop_open_slave() ttyS0 [ 125.144731] eq3loop: eq3loop_close_slave() ttyS0 [ 126.221732] eq3loop: eq3loop_open_slave() mmd_bidcos [ 126.813399] Bluetooth: BNEP (Ethernet Emulation) ver 1.3 [ 126.813405] Bluetooth: BNEP filters: protocol multicast [ 126.813418] Bluetooth: BNEP socket layer initialized [ 1179.988922] eq3loop: eq3loop_open_slave() ttyS0 [ 1180.197479] eq3loop: eq3loop_close_slave() ttyS0 [ 1302.151409] eq3loop: eq3loop_open_slave() ttyS0 [ 1302.356196] eq3loop: eq3loop_close_slave() ttyS0 [99193.690007] usb 1-1.3: USB disconnect, device number 6

alexreinert commented 6 years ago

Hi,

sorry for the late response:

have you checked your power adapter? An undervoltage can lead to a disconnect of the USB ports and the GPIO. And this could cause all of your problems.

alexreinert commented 6 years ago

Any news on this?

Noranius commented 6 years ago

Good Morning, sorry i dindn't recognized the answer. Today the RPI wasn't accessable by the attached monitor. I took a ssh-connection to get out the Data. Used power supply: 2.5A at 5V. Attached HW: Ethernet, Keyboard, Mouse, HDMI, HMIP-RF-USB.

The logs are below.

Kind regards Noran

sudo pivccu-attach cat /var/log/hmserver.log Jun 29 09:51:57 de.eq3.lib.util.dynamics.GenericFactory INFO [main] @GenericFactory Jun 29 09:51:57 de.eq3.lib.util.dynamics.GenericFactory INFO [main] creating instance of HMServerConfiguration with no-arg constructor Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [HMIPTRXWriterWorker] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [KeyServerWorker] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [KryoPersistenceWorker] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [TransactionSubsystemHandler] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [FirmwareLoaderFileSystem] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LocalServerPersistentDataLoader] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LocalServerAdapterInitialization] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [BackendCommandHandler] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [DeviceInclusionAcceptHandler] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [IncomingHMIPFrameHandler] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [DeviceBackgroundUpdateSubsystem] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [DeviceInclusionDefaultConfigurationChanger] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [CyclicSmokeDetectorAwakening] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LocalServerFirmwareUpdateInitialization] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LegacyNotificationHandler] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LegacyAPIWorker] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LegacyBackendNotificationHandler] (3) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LegacyBlindLevelCorrectionHandler] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LegacyInitializion] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: deploying 19 classes to Vert.x Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: 19 VertxDeployers initialized Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-5] SYSTEM: start of CyclicSmokeDetectorAwakening succeeded (f663cf39-b1c1-42bb-92d6-2eff94cbe1dd) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-7] SYSTEM: start of DeviceInclusionDefaultConfigurationChanger succeeded (ecd8e160-4581-4d41-ab64-7e3becfee935) Jun 29 09:52:01 de.eq3.cbcs.server.core.vertx.KeyServerWorker ERROR [vert.x-worker-thread-0] Missing key server configuration parameter (Network.Key) for mode: KEYSERVER_LOCAL Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-1] SYSTEM: start of HMIPTRXWriterWorker succeeded (c0b4ba13-5d22-4a6b-9d4d-e452e66f9ab9) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-6] SYSTEM: start of LegacyBlindLevelCorrectionHandler succeeded (86b89a3b-82df-4abb-b192-cc6e824bc97a) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-3] SYSTEM: start of KeyServerWorker succeeded (2d1acaa1-54d1-45f2-ac87-72873db1e21f) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-2] SYSTEM: start of TransactionSubsystemHandler succeeded (c9dceea8-fdae-4f36-bbc9-d5963172231c) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-0] SYSTEM: start of DeviceBackgroundUpdateSubsystem succeeded (669c202c-24e4-4620-b9f0-452b5f5d79de) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-1] SYSTEM: start of KryoPersistenceWorker succeeded (8fd0a37e-b53f-45b2-8395-9f05f0e44310) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-4] SYSTEM: start of LocalServerPersistentDataLoader succeeded (1707a4aa-cf3f-4582-9dde-c3114541e4a1) Jun 29 09:52:02 de.eq3.cbcs.server.core.otau.util.FirmwareLoaderFileSystem INFO [vert.x-worker-thread-2] SYSTEM: Firmware update directory is set to /etc/config/firmware Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-6] SYSTEM: start of FirmwareLoaderFileSystem succeeded (214b563b-b9b0-4d25-951a-add9cc51cedf) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-4] SYSTEM: start of DeviceInclusionAcceptHandler succeeded (3be2daa4-aded-4d1c-b201-9e64d7814653) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-6] SYSTEM: start of IncomingHMIPFrameHandler succeeded (93d79b84-04b8-4fbf-b7c1-6b3b6ae832dc) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-7] SYSTEM: start of LegacyBackendNotificationHandler succeeded (82e69191-9e67-47eb-8352-2e1dca0e07e4) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-1] SYSTEM: start of BackendCommandHandler succeeded (4fd660e2-c39a-4eff-a605-1c48d9fc6590) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-5] SYSTEM: start of LegacyNotificationHandler succeeded (40bdda4f-249d-4e7a-a561-9102d56f00ca) Jun 29 09:52:03 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-6] SYSTEM: start of LocalServerAdapterInitialization succeeded (aea305ee-b6cc-436c-a047-a987da70339b) Jun 29 09:52:03 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-7] SYSTEM: start of LegacyAPIWorker succeeded (54fb6469-ed18-49ed-898c-afdb28bcb288) Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] TRX adapter state 1: HMIP_TRX_App Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] TRX adapter application is already running Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] No NWK, try to set address ... Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Try to set radio address 12178086... Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Set max send attempts for 3014F5AC94000416FB53307B to 3 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Try to get application version... Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Application version 2.8.4 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Bootloader version 1.0.12 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] hmos version 1.18.5 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] MCU type: EFM32G200F64_CM3 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Duty Cycle: 0.0 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] set DutyCycle limit to ffffffc8 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Set Duty Cycle Limit Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Current Security Counter: 26202626 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Update security counter to calculation: 28172741 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] TRX adapter has 27 link partners Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Adapter with Access Point id 3014F5AC94000416FB53307B initialized Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.LocalServerAdapterInitialization INFO [Thread-6] HMIPTRXInitialResponseListener said that Adapter was initialized Jun 29 09:52:04 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-3] SYSTEM: start of LegacyInitializion succeeded (2395eb73-892f-4bc2-a3d0-a0ea29027f74) Jun 29 09:52:04 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-5] SYSTEM: start of LocalServerFirmwareUpdateInitialization succeeded (0d66a547-d05c-40ef-a0dd-c235e0bca3ed) Jun 29 09:52:04 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: initial deployment complete _____________________________________________________ Jun 29 09:52:04 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO [vert.x-eventloop-thread-2] SYSTEM: Checking all devices on all accesspoints for updates Jun 29 09:52:04 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO [vert.x-eventloop-thread-2] SYSTEM: There are 1 APs queued with updatable devices Jun 29 09:52:07 de.eq3.ccu.server.HMServer INFO [Thread-2] Default MaxEventLoopExecuteTime: 2000000000 Jun 29 09:52:07 de.eq3.ccu.server.HMServer INFO [Thread-2] Default BlockedThreadCheckInterval: 1000 Jun 29 09:52:07 de.eq3.ccu.server.HMServer INFO [Thread-2] Default MaxWorkerExecuteTime: 60000000000 Jun 29 09:52:07 de.eq3.ccu.server.HMServer INFO [Thread-2] Default EventLoopPoolSize: 8 Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [BackendWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [GroupRequestWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [DiagramRequestWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [StorageRequestWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [DeviceFirmwareRequestWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [EnergyPriceRequestWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [CouplingRequestWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: deploying 7 classes to Vert.x Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: 7 VertxDeployers initialized Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-2] SYSTEM: start of BackendWorker succeeded (3047ba84-008c-41e7-960f-089c5fef7684) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-0] SYSTEM: start of CouplingRequestWorker succeeded (c39432e9-4091-4fd8-9e55-7ea51ba80d01) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-4] SYSTEM: start of EnergyPriceRequestWorker succeeded (3bde3435-9988-4a2e-98b9-736c26b1051e) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-1] SYSTEM: start of StorageRequestWorker succeeded (75d70f2e-abb0-4657-8cb0-5102e5e6b921) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-0] SYSTEM: start of GroupRequestWorker succeeded (0a0aeedd-a8dd-469c-b22c-aa8d1d5ecdd6) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-1] SYSTEM: start of DiagramRequestWorker succeeded (c3e8fe41-362f-4817-9db2-b99a9e334f91) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-4] SYSTEM: start of DeviceFirmwareRequestWorker succeeded (9d52aa5a-720c-403e-bb6f-5ad4a8958d3e) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: initial deployment complete _____________________________________________________ Jun 29 09:52:07 de.eq3.ccu.server.HMServer INFO [Thread-2] Starting HMServer at 127.0.0.1:9292 Jun 29 09:52:07 de.eq3.ccu.server.HMServer INFO [Thread-2] Read Configuration Jun 29 09:52:08 de.eq3.ccu.server.HMServer INFO [Thread-2] Create Bidcos Dispatcher Jun 29 09:52:08 de.eq3.ccu.server.HMServer INFO [Thread-2] InitBidCosCache Jun 29 09:52:08 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher ERROR [Thread-2] BidCosCache could not be initialized Jun 29 09:52:08 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher ERROR [Thread-2] java.net.ConnectException: Connection refused (Connection refused) Jun 29 09:52:08 de.eq3.ccu.server.HMServer INFO [Thread-2] Create groupDefinitionProvider Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Create VirtualDeviceHolder Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Create VirtualDeviceHandlerRega Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Create GroupAdministrationService Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Create GroupDeviceDispatcher Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Create GroupDeviceHandler Jun 29 09:52:09 de.eq3.ccu.groupdevice.service.GroupDeviceHandler INFO [Thread-2] @GroupDeviceHandler - initializing... Jun 29 09:52:09 de.eq3.ccu.groupdevice.service.GroupDeviceHandler INFO [Thread-2] --> created groupDeviceDispatcher (GroupDeviceService to BidCoS (via Dispatcher)) Jun 29 09:52:09 de.eq3.ccu.groupdevice.service.GroupDeviceHandler INFO [Thread-2] --> created virtualDeviceHandler (GroupDeviceService to ReGa) Jun 29 09:52:09 de.eq3.ccu.groupdevice.service.GroupDeviceHandler INFO [Thread-2] --> got groupDefinitionProvider Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Create BidCosGroupMemberProvider Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Init groupAdministrationService Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Init Virtual OS Device Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Init ESHLight Bridge Jun 29 09:52:10 de.eq3.ccu.server.HMServer INFO [Thread-2] Create RrdDatalogging Jun 29 09:52:10 de.eq3.ccu.server.HMServer INFO [Thread-2] Create MeasurementService Jun 29 09:52:10 de.eq3.ccu.server.HMServer INFO [Thread-2] Init MeasurementService Jun 29 09:52:10 de.eq3.ccu.server.HMServer INFO [Thread-2] Create HTTP Server Jun 29 09:52:17 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO [vert.x-eventloop-thread-2] AP 3014F5AC94000416FB53307B: OTAU Handler d678b3d1-a60d-47cc-8858-10f8e03439d0 continues for device(s) [3014F711A0000A1709ACBC3F] Jun 29 09:52:25 de.eq3.ccu.server.HMServer INFO [Thread-2] Create BidCos context and start handler Jun 29 09:52:25 de.eq3.ccu.server.HMServer INFO [Thread-2] Create group context and start handler Jun 29 09:52:25 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher ERROR [Timer-1] Could not register HmIP-RF_java Jun 29 09:52:26 de.eq3.ccu.server.HMServer INFO [Thread-2] Starting HMServer done Jun 29 09:52:30 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO [vert.x-worker-thread-3] (un)registerCallback on LegacyServiceHandler called from url: http://127.0.0.1:9292/bidcos Jun 29 09:52:30 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO [vert.x-worker-thread-3] init finished Jun 29 09:52:30 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer INFO [vert.x-worker-thread-2] Added InterfaceId: HmIP-RF_java Jun 29 09:52:30 de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil INFO [vert.x-worker-thread-2] updateDevicesForClient HmIP-RF_java -> 225 device addresses will be added Jun 29 09:52:45 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO [vert.x-eventloop-thread-1] (un)registerCallback on VirtualDeviceHandlerRega called from url: xmlrpc_bin://127.0.0.1:1999 Jun 29 09:52:45 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO [vert.x-eventloop-thread-1] Added InterfaceId: 1008 Jun 29 09:52:45 de.eq3.ccu.virtualdevice.service.internal.rega.BackendWorker INFO [vert.x-worker-thread-7] Execute BackendCommand: de.eq3.ccu.virtualdevice.service.internal.rega.BackendUpdateDevicesCommand Jun 29 09:52:55 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO [vert.x-worker-thread-4] (un)registerCallback on LegacyServiceHandler called from url: xmlrpc_bin://127.0.0.1:1999 Jun 29 09:52:55 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO [vert.x-worker-thread-4] init finished Jun 29 09:52:55 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer INFO [vert.x-worker-thread-3] Added InterfaceId: 1009 Jun 29 09:53:37 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO [vert.x-eventloop-thread-2] AP 3014F5AC94000416FB53307B: OTAU Handler d678b3d1-a60d-47cc-8858-10f8e03439d0 aborted for device(s) [3014F711A0000A1709ACBC3F] Jun 29 09:55:01 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 09:55:01 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] Retrying request to {}->http://127.0.0.1:9292 Jun 29 09:57:01 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 09:57:01 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] Retrying request to {}->http://127.0.0.1:9292 Jun 29 09:57:46 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 09:57:46 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:01:46 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:01:46 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:04:44 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO [vert.x-worker-thread-2] (un)registerCallback on LegacyServiceHandler called from url: http://192.168.253.1:7420/fh2010 Jun 29 10:04:44 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO [vert.x-worker-thread-2] init finished Jun 29 10:04:44 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer INFO [vert.x-worker-thread-1] Added InterfaceId: CB2010 Jun 29 10:04:44 de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil INFO [vert.x-worker-thread-1] updateDevicesForClient CB2010 -> 225 device addresses will be added Jun 29 10:10:32 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:10:32 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:25:48 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:25:48 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:31:21 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:31:21 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:37:17 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:37:17 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:39:28 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:39:28 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:39:59 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:39:59 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] Retrying request to {}->http://127.0.0.1:9292 Jun 29 11:06:27 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 11:06:27 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] Retrying request to {}->http://127.0.0.1:9292 Jun 29 11:13:50 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 11:13:50 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] Retrying request to {}->http://127.0.0.1:9292 Jun 29 11:33:45 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 11:33:45 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 12:16:39 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 12:16:39 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 12:28:00 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 12:28:00 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 12:34:24 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 12:34:24 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] Retrying request to {}->http://127.0.0.1:9292 Jun 29 12:51:44 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 12:51:44 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] Retrying request to {}->http://127.0.0.1:9292 Jun 29 13:16:43 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 13:16:43 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 13:34:51 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 13:34:51 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292 Jun 29 13:47:21 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 13:47:21 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292 Jun 29 14:00:25 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 14:00:25 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] Retrying request to {}->http://127.0.0.1:9292 Jun 29 14:17:37 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 14:17:37 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 14:25:20 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 14:25:20 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] Retrying request to {}->http://127.0.0.1:9292 Jun 29 20:50:29 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 20:50:29 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 21:16:11 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 21:16:11 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] Retrying request to {}->http://127.0.0.1:9292 Jun 30 05:26:52 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 30 05:26:52 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] Retrying request to {}->http://127.0.0.1:9292 Jun 30 06:28:05 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 30 06:28:05 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292 Jun 30 11:11:26 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 30 11:11:26 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] Retrying request to {}->http://127.0.0.1:9292 Jul 1 03:56:16 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jul 1 03:56:16 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292 Jul 2 08:05:56 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jul 2 08:05:56 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292

pi@ITD-S-001:~ $ sudo pivccu-attach cat /var/log/hmserver.log Jun 29 09:51:57 de.eq3.lib.util.dynamics.GenericFactory INFO [main] @GenericFactory Jun 29 09:51:57 de.eq3.lib.util.dynamics.GenericFactory INFO [main] creating instance of HMServerConfiguration with no-arg constructor Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [HMIPTRXWriterWorker] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [KeyServerWorker] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [KryoPersistenceWorker] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [TransactionSubsystemHandler] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [FirmwareLoaderFileSystem] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LocalServerPersistentDataLoader] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LocalServerAdapterInitialization] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [BackendCommandHandler] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [DeviceInclusionAcceptHandler] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [IncomingHMIPFrameHandler] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [DeviceBackgroundUpdateSubsystem] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [DeviceInclusionDefaultConfigurationChanger] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [CyclicSmokeDetectorAwakening] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LocalServerFirmwareUpdateInitialization] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LegacyNotificationHandler] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LegacyAPIWorker] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LegacyBackendNotificationHandler] (3) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LegacyBlindLevelCorrectionHandler] (1) *worker Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: added for deployment [LegacyInitializion] (1) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: deploying 19 classes to Vert.x Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: 19 VertxDeployers initialized Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-5] SYSTEM: start of CyclicSmokeDetectorAwakening succeeded (f663cf39-b1c1-42bb-92d6-2eff94cbe1dd) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-7] SYSTEM: start of DeviceInclusionDefaultConfigurationChanger succeeded (ecd8e160-4581-4d41-ab64-7e3becfee935) Jun 29 09:52:01 de.eq3.cbcs.server.core.vertx.KeyServerWorker ERROR [vert.x-worker-thread-0] Missing key server configuration parameter (Network.Key) for mode: KEYSERVER_LOCAL Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-1] SYSTEM: start of HMIPTRXWriterWorker succeeded (c0b4ba13-5d22-4a6b-9d4d-e452e66f9ab9) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-6] SYSTEM: start of LegacyBlindLevelCorrectionHandler succeeded (86b89a3b-82df-4abb-b192-cc6e824bc97a) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-3] SYSTEM: start of KeyServerWorker succeeded (2d1acaa1-54d1-45f2-ac87-72873db1e21f) Jun 29 09:52:01 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-2] SYSTEM: start of TransactionSubsystemHandler succeeded (c9dceea8-fdae-4f36-bbc9-d5963172231c) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-0] SYSTEM: start of DeviceBackgroundUpdateSubsystem succeeded (669c202c-24e4-4620-b9f0-452b5f5d79de) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-1] SYSTEM: start of KryoPersistenceWorker succeeded (8fd0a37e-b53f-45b2-8395-9f05f0e44310) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-4] SYSTEM: start of LocalServerPersistentDataLoader succeeded (1707a4aa-cf3f-4582-9dde-c3114541e4a1) Jun 29 09:52:02 de.eq3.cbcs.server.core.otau.util.FirmwareLoaderFileSystem INFO [vert.x-worker-thread-2] SYSTEM: Firmware update directory is set to /etc/config/firmware Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-6] SYSTEM: start of FirmwareLoaderFileSystem succeeded (214b563b-b9b0-4d25-951a-add9cc51cedf) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-4] SYSTEM: start of DeviceInclusionAcceptHandler succeeded (3be2daa4-aded-4d1c-b201-9e64d7814653) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-6] SYSTEM: start of IncomingHMIPFrameHandler succeeded (93d79b84-04b8-4fbf-b7c1-6b3b6ae832dc) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-7] SYSTEM: start of LegacyBackendNotificationHandler succeeded (82e69191-9e67-47eb-8352-2e1dca0e07e4) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-1] SYSTEM: start of BackendCommandHandler succeeded (4fd660e2-c39a-4eff-a605-1c48d9fc6590) Jun 29 09:52:02 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-5] SYSTEM: start of LegacyNotificationHandler succeeded (40bdda4f-249d-4e7a-a561-9102d56f00ca) Jun 29 09:52:03 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-6] SYSTEM: start of LocalServerAdapterInitialization succeeded (aea305ee-b6cc-436c-a047-a987da70339b) Jun 29 09:52:03 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-7] SYSTEM: start of LegacyAPIWorker succeeded (54fb6469-ed18-49ed-898c-afdb28bcb288) Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] TRX adapter state 1: HMIP_TRX_App Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] TRX adapter application is already running Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] No NWK, try to set address ... Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Try to set radio address 12178086... Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Set max send attempts for 3014F5AC94000416FB53307B to 3 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Try to get application version... Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Application version 2.8.4 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Bootloader version 1.0.12 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] hmos version 1.18.5 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] MCU type: EFM32G200F64_CM3 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Duty Cycle: 0.0 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] set DutyCycle limit to ffffffc8 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Set Duty Cycle Limit Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Current Security Counter: 26202626 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Update security counter to calculation: 28172741 Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] TRX adapter has 27 link partners Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO [Thread-6] Adapter with Access Point id 3014F5AC94000416FB53307B initialized Jun 29 09:52:03 de.eq3.cbcs.server.local.base.internal.LocalServerAdapterInitialization INFO [Thread-6] HMIPTRXInitialResponseListener said that Adapter was initialized Jun 29 09:52:04 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-3] SYSTEM: start of LegacyInitializion succeeded (2395eb73-892f-4bc2-a3d0-a0ea29027f74) Jun 29 09:52:04 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-5] SYSTEM: start of LocalServerFirmwareUpdateInitialization succeeded (0d66a547-d05c-40ef-a0dd-c235e0bca3ed) Jun 29 09:52:04 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-0] SYSTEM: initial deployment complete _____________________________________________________ Jun 29 09:52:04 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO [vert.x-eventloop-thread-2] SYSTEM: Checking all devices on all accesspoints for updates Jun 29 09:52:04 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO [vert.x-eventloop-thread-2] SYSTEM: There are 1 APs queued with updatable devices Jun 29 09:52:07 de.eq3.ccu.server.HMServer INFO [Thread-2] Default MaxEventLoopExecuteTime: 2000000000 Jun 29 09:52:07 de.eq3.ccu.server.HMServer INFO [Thread-2] Default BlockedThreadCheckInterval: 1000 Jun 29 09:52:07 de.eq3.ccu.server.HMServer INFO [Thread-2] Default MaxWorkerExecuteTime: 60000000000 Jun 29 09:52:07 de.eq3.ccu.server.HMServer INFO [Thread-2] Default EventLoopPoolSize: 8 Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [BackendWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [GroupRequestWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [DiagramRequestWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [StorageRequestWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [DeviceFirmwareRequestWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [EnergyPriceRequestWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: added for deployment [CouplingRequestWorker] (1) *worker Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: deploying 7 classes to Vert.x Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: 7 VertxDeployers initialized Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-2] SYSTEM: start of BackendWorker succeeded (3047ba84-008c-41e7-960f-089c5fef7684) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-0] SYSTEM: start of CouplingRequestWorker succeeded (c39432e9-4091-4fd8-9e55-7ea51ba80d01) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-4] SYSTEM: start of EnergyPriceRequestWorker succeeded (3bde3435-9988-4a2e-98b9-736c26b1051e) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-1] SYSTEM: start of StorageRequestWorker succeeded (75d70f2e-abb0-4657-8cb0-5102e5e6b921) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-0] SYSTEM: start of GroupRequestWorker succeeded (0a0aeedd-a8dd-469c-b22c-aa8d1d5ecdd6) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-1] SYSTEM: start of DiagramRequestWorker succeeded (c3e8fe41-362f-4817-9db2-b99a9e334f91) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [vert.x-eventloop-thread-4] SYSTEM: start of DeviceFirmwareRequestWorker succeeded (9d52aa5a-720c-403e-bb6f-5ad4a8958d3e) Jun 29 09:52:07 de.eq3.cbcs.vertx.management.VertxManager INFO [Thread-2] SYSTEM: initial deployment complete _____________________________________________________ Jun 29 09:52:07 de.eq3.ccu.server.HMServer INFO [Thread-2] Starting HMServer at 127.0.0.1:9292 Jun 29 09:52:07 de.eq3.ccu.server.HMServer INFO [Thread-2] Read Configuration Jun 29 09:52:08 de.eq3.ccu.server.HMServer INFO [Thread-2] Create Bidcos Dispatcher Jun 29 09:52:08 de.eq3.ccu.server.HMServer INFO [Thread-2] InitBidCosCache Jun 29 09:52:08 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher ERROR [Thread-2] BidCosCache could not be initialized Jun 29 09:52:08 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher ERROR [Thread-2] java.net.ConnectException: Connection refused (Connection refused) Jun 29 09:52:08 de.eq3.ccu.server.HMServer INFO [Thread-2] Create groupDefinitionProvider Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Create VirtualDeviceHolder Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Create VirtualDeviceHandlerRega Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Create GroupAdministrationService Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Create GroupDeviceDispatcher Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Create GroupDeviceHandler Jun 29 09:52:09 de.eq3.ccu.groupdevice.service.GroupDeviceHandler INFO [Thread-2] @GroupDeviceHandler - initializing... Jun 29 09:52:09 de.eq3.ccu.groupdevice.service.GroupDeviceHandler INFO [Thread-2] --> created groupDeviceDispatcher (GroupDeviceService to BidCoS (via Dispatcher)) Jun 29 09:52:09 de.eq3.ccu.groupdevice.service.GroupDeviceHandler INFO [Thread-2] --> created virtualDeviceHandler (GroupDeviceService to ReGa) Jun 29 09:52:09 de.eq3.ccu.groupdevice.service.GroupDeviceHandler INFO [Thread-2] --> got groupDefinitionProvider Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Create BidCosGroupMemberProvider Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Init groupAdministrationService Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Init Virtual OS Device Jun 29 09:52:09 de.eq3.ccu.server.HMServer INFO [Thread-2] Init ESHLight Bridge Jun 29 09:52:10 de.eq3.ccu.server.HMServer INFO [Thread-2] Create RrdDatalogging Jun 29 09:52:10 de.eq3.ccu.server.HMServer INFO [Thread-2] Create MeasurementService Jun 29 09:52:10 de.eq3.ccu.server.HMServer INFO [Thread-2] Init MeasurementService Jun 29 09:52:10 de.eq3.ccu.server.HMServer INFO [Thread-2] Create HTTP Server Jun 29 09:52:17 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO [vert.x-eventloop-thread-2] AP 3014F5AC94000416FB53307B: OTAU Handler d678b3d1-a60d-47cc-8858-10f8e03439d0 continues for device(s) [3014F711A0000A1709ACBC3F] Jun 29 09:52:25 de.eq3.ccu.server.HMServer INFO [Thread-2] Create BidCos context and start handler Jun 29 09:52:25 de.eq3.ccu.server.HMServer INFO [Thread-2] Create group context and start handler Jun 29 09:52:25 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher ERROR [Timer-1] Could not register HmIP-RF_java Jun 29 09:52:26 de.eq3.ccu.server.HMServer INFO [Thread-2] Starting HMServer done Jun 29 09:52:30 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO [vert.x-worker-thread-3] (un)registerCallback on LegacyServiceHandler called from url: http://127.0.0.1:9292/bidcos Jun 29 09:52:30 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO [vert.x-worker-thread-3] init finished Jun 29 09:52:30 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer INFO [vert.x-worker-thread-2] Added InterfaceId: HmIP-RF_java Jun 29 09:52:30 de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil INFO [vert.x-worker-thread-2] updateDevicesForClient HmIP-RF_java -> 225 device addresses will be added Jun 29 09:52:45 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO [vert.x-eventloop-thread-1] (un)registerCallback on VirtualDeviceHandlerRega called from url: xmlrpc_bin://127.0.0.1:1999 Jun 29 09:52:45 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO [vert.x-eventloop-thread-1] Added InterfaceId: 1008 Jun 29 09:52:45 de.eq3.ccu.virtualdevice.service.internal.rega.BackendWorker INFO [vert.x-worker-thread-7] Execute BackendCommand: de.eq3.ccu.virtualdevice.service.internal.rega.BackendUpdateDevicesCommand Jun 29 09:52:55 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO [vert.x-worker-thread-4] (un)registerCallback on LegacyServiceHandler called from url: xmlrpc_bin://127.0.0.1:1999 Jun 29 09:52:55 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO [vert.x-worker-thread-4] init finished Jun 29 09:52:55 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer INFO [vert.x-worker-thread-3] Added InterfaceId: 1009 Jun 29 09:53:37 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO [vert.x-eventloop-thread-2] AP 3014F5AC94000416FB53307B: OTAU Handler d678b3d1-a60d-47cc-8858-10f8e03439d0 aborted for device(s) [3014F711A0000A1709ACBC3F] Jun 29 09:55:01 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 09:55:01 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] Retrying request to {}->http://127.0.0.1:9292 Jun 29 09:57:01 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 09:57:01 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] Retrying request to {}->http://127.0.0.1:9292 Jun 29 09:57:46 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 09:57:46 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:01:46 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:01:46 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:04:44 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO [vert.x-worker-thread-2] (un)registerCallback on LegacyServiceHandler called from url: http://192.168.253.1:7420/fh2010 Jun 29 10:04:44 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO [vert.x-worker-thread-2] init finished Jun 29 10:04:44 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer INFO [vert.x-worker-thread-1] Added InterfaceId: CB2010 Jun 29 10:04:44 de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil INFO [vert.x-worker-thread-1] updateDevicesForClient CB2010 -> 225 device addresses will be added Jun 29 10:10:32 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:10:32 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:25:48 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:25:48 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:31:21 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:31:21 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:37:17 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:37:17 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:39:28 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:39:28 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] Retrying request to {}->http://127.0.0.1:9292 Jun 29 10:39:59 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 10:39:59 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] Retrying request to {}->http://127.0.0.1:9292 Jun 29 11:06:27 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 11:06:27 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] Retrying request to {}->http://127.0.0.1:9292 Jun 29 11:13:50 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 11:13:50 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] Retrying request to {}->http://127.0.0.1:9292 Jun 29 11:33:45 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 11:33:45 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 12:16:39 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 12:16:39 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 12:28:00 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 12:28:00 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 12:34:24 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 12:34:24 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] Retrying request to {}->http://127.0.0.1:9292 Jun 29 12:51:44 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 12:51:44 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] Retrying request to {}->http://127.0.0.1:9292 Jun 29 13:16:43 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 13:16:43 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 13:34:51 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 13:34:51 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292 Jun 29 13:47:21 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 13:47:21 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292 Jun 29 14:00:25 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 14:00:25 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] Retrying request to {}->http://127.0.0.1:9292 Jun 29 14:17:37 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 14:17:37 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 14:25:20 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 14:25:20 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-1] Retrying request to {}->http://127.0.0.1:9292 Jun 29 20:50:29 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 20:50:29 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-2] Retrying request to {}->http://127.0.0.1:9292 Jun 29 21:16:11 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 29 21:16:11 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] Retrying request to {}->http://127.0.0.1:9292 Jun 30 05:26:52 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 30 05:26:52 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-0] Retrying request to {}->http://127.0.0.1:9292 Jun 30 06:28:05 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 30 06:28:05 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292 Jun 30 11:11:26 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jun 30 11:11:26 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-3] Retrying request to {}->http://127.0.0.1:9292 Jul 1 03:56:16 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jul 1 03:56:16 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292 Jul 2 08:05:56 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:9292: Broken pipe (Write failed) Jul 2 08:05:56 org.apache.http.impl.client.DefaultHttpClient INFO [vert.x-worker-thread-4] Retrying request to {}->http://127.0.0.1:9292

pi@ITD-S-001:~ $ sudo pivccu-attach ps aux PID USER COMMAND 1 root init 71 root /usr/sbin/crond 75 root /sbin/syslogd -m 0 77 root /sbin/klogd 117 root /usr/sbin/ifplugd -i eth0 -fI -u0 -d10 161 root {setclock} /bin/sh /bin/setclock 176 root /bin/eq3configd 177 root /bin/ssdpd 182 root /usr/sbin/lighttpd -f /etc/lighttpd/lighttpd.conf 225 root /bin/multimacd -f /etc/config/multimacd.conf -l 5 246 root /bin/rfd -f /etc/config/rfd.conf -l 5 261 root java -Xmx64m -Dlog4j.configuration=file:///etc/config/log4j.xml -Dfile.encoding=ISO-8859-1 -jar /opt/HMServer/HMIPServer.jar /etc/crRFD.conf 354 root /bin/ReGaHss.normal -f /etc/rega.conf -l 2 28553 root sleep 60 28554 root ps aux pi@ITD-S-001:~ $ sudo dmesg | tail -40 [251657.454628] [<80284720>] (SyS_ioctl) from [<801080c0>] (ret_fast_syscall+0x0/0x1c) [251657.454720] INFO: task kworker/2:0:30053 blocked for more than 120 seconds. [251657.454724] Tainted: G O 4.9.80-v7+ #1098 [251657.454727] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [251657.454735] kworker/2:0 D 0 30053 2 0x00000000 [251657.454750] Workqueue: events dbs_work_handler [251657.454765] [<8072252c>] (__schedule) from [<80722a54>] (schedule+0x50/0xa8) [251657.454780] [<80722a54>] (schedule) from [<80722e48>] (schedule_preempt_disabled+0x18/0x1c) [251657.454796] [<80722e48>] (schedule_preempt_disabled) from [<80724564>] (__mutex_lock_slowpath+0xac/0x164) [251657.454811] [<80724564>] (__mutex_lock_slowpath) from [<8072467c>] (mutex_lock+0x60/0x64) [251657.454825] [<8072467c>] (mutex_lock) from [<805e6108>] (rpi_firmware_transaction+0x44/0xac) [251657.454837] [<805e6108>] (rpi_firmware_transaction) from [<805e6268>] (rpi_firmware_property_list+0xf8/0x220) [251657.454850] [<805e6268>] (rpi_firmware_property_list) from [<805e63f4>] (rpi_firmware_property+0x64/0x84) [251657.454865] [<805e63f4>] (rpi_firmware_property) from [<805c1660>] (bcm2835_cpufreq_clock_property.constprop.1+0x48/0x5c) [251657.454883] [<805c1660>] (bcm2835_cpufreq_clock_property.constprop.1) from [<805c16c0>] (bcm2835_cpufreq_driver_target_index+0x4c/0xc0) [251657.454899] [<805c16c0>] (bcm2835_cpufreq_driver_target_index) from [<805bb8c4>] (__cpufreq_driver_target+0x250/0x580) [251657.454913] [<805bb8c4>] (__cpufreq_driver_target) from [<805bfe0c>] (od_dbs_timer+0xa8/0x174) [251657.454927] [<805bfe0c>] (od_dbs_timer) from [<805c0a84>] (dbs_work_handler+0x3c/0x68) [251657.454944] [<805c0a84>] (dbs_work_handler) from [<801367f8>] (process_one_work+0x158/0x454) [251657.454961] [<801367f8>] (process_one_work) from [<80136b58>] (worker_thread+0x64/0x5b8) [251657.454976] [<80136b58>] (worker_thread) from [<8013ca74>] (kthread+0x10c/0x124) [251657.454989] [<8013ca74>] (kthread) from [<80108154>] (ret_from_fork+0x14/0x20) [251780.335076] INFO: task Xorg:644 blocked for more than 120 seconds. [251780.335083] Tainted: G O 4.9.80-v7+ #1098 [251780.335086] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [251780.335097] Xorg D 0 644 597 0x00000000 [251780.335131] [<8072252c>] (__schedule) from [<80722a54>] (schedule+0x50/0xa8) [251780.335145] [<80722a54>] (schedule) from [<80725c8c>] (schedule_timeout+0x1e8/0x41c) [251780.335160] [<80725c8c>] (schedule_timeout) from [<807235c8>] (wait_for_common+0xbc/0x17c) [251780.335175] [<807235c8>] (wait_for_common) from [<807236a8>] (wait_for_completion+0x20/0x24) [251780.335191] [<807236a8>] (wait_for_completion) from [<805e612c>] (rpi_firmware_transaction+0x68/0xac) [251780.335205] [<805e612c>] (rpi_firmware_transaction) from [<805e6268>] (rpi_firmware_property_list+0xf8/0x220) [251780.335217] [<805e6268>] (rpi_firmware_property_list) from [<805e63f4>] (rpi_firmware_property+0x64/0x84) [251780.335234] [<805e63f4>] (rpi_firmware_property) from [<804a489c>] (bcm2708_fb_blank+0x50/0x9c) [251780.335251] [<804a489c>] (bcm2708_fb_blank) from [<8049ae20>] (fb_blank+0x64/0xb8) [251780.335265] [<8049ae20>] (fb_blank) from [<8049b804>] (do_fb_ioctl+0x45c/0x770) [251780.335278] [<8049b804>] (do_fb_ioctl) from [<8049bb68>] (fb_ioctl+0x50/0x5c) [251780.335294] [<8049bb68>] (fb_ioctl) from [<80283f68>] (do_vfs_ioctl+0xac/0x820) [251780.335311] [<80283f68>] (do_vfs_ioctl) from [<80284720>] (SyS_ioctl+0x44/0x6c) [251780.335327] [<80284720>] (SyS_ioctl) from [<801080c0>] (ret_fast_syscall+0x0/0x1c) pi@ITD-S-001:~ $ sudo cat /proc/meminfo MemTotal: 949580 kB MemFree: 99636 kB MemAvailable: 625092 kB Buffers: 159772 kB Cached: 407620 kB SwapCached: 2424 kB Active: 532108 kB Inactive: 262600 kB Active(anon): 163084 kB Inactive(anon): 73716 kB Active(file): 369024 kB Inactive(file): 188884 kB Unevictable: 0 kB Mlocked: 0 kB SwapTotal: 102396 kB SwapFree: 97268 kB Dirty: 0 kB Writeback: 0 kB AnonPages: 224896 kB Mapped: 82652 kB Shmem: 9488 kB Slab: 39244 kB SReclaimable: 25208 kB SUnreclaim: 14036 kB KernelStack: 2312 kB PageTables: 3344 kB NFS_Unstable: 0 kB Bounce: 0 kB WritebackTmp: 0 kB CommitLimit: 577184 kB Committed_AS: 1029116 kB VmallocTotal: 1114112 kB VmallocUsed: 0 kB VmallocChunk: 0 kB CmaTotal: 8192 kB CmaFree: 6792 kB

alexreinert commented 6 years ago

Ok,

interessting new information: You are using the HmIP-RF-USB, together with the other USB issue you had, I'm suggesting to try a different power supply. The Raspberry foundation suggests a 5.1V power supply because of some voltage drop between power supply and raspberry itself. If you use a bus powered hard disk, a power supply with 2.5A could be to small.

Also I saw a "sleep 60" in the log. Are you using this inside scripts? This could lead to issues, too, as the logic part of the CCU is single threaded.

Noranius commented 6 years ago

No i didn't wrote scripts inside pivccu. I only use it for communicating with HomeMatic IP via FHEM.

After your statement I thought it could be like this. I'll try to get a more powerfull Supply.

Kind regards and thanks for your help Noran

Noranius commented 6 years ago

Hello, today we switched the power supply to this one: https://www.amazon.de/Ladekabel-Ladegerät-Raspberry-Soundlink-Smartphones/dp/B06XKYSQSD/ref=cm_cr_arp_d_product_top?ie=UTF8 We will see if it gets better now.

Regards Noran

Noranius commented 6 years ago

Good Morning, after 1 week the Raspberry is still running. I found a blog with 3 advices for suplies. I took this one: HKY

Thank you for your help. By the way, thats the purpose for what we use pivccu: Bauhaus Universität Weimar: Digital ITD Twin. The last link is a detailed description.

Kind regards Noran

alexreinert commented 6 years ago

Hi,

thanks for the info. In that case I close the issue as it is most likely, that the power supply was the cause of the issue.

Alex