anthonywebb / homebridge-cbus

CBus plugin for homebridge
MIT License
35 stars 20 forks source link

What causes 'unparseable line ... Error: database access before initialisation'? #98

Closed sgraystar closed 4 years ago

sgraystar commented 4 years ago

@anthonywebb Thanks for your efforts on this, it is one of my more fun items being able to summon our teenage son with flashing lights (and voiceover via jishi/node-sonos-http-api).

You may have seen on cbusforums that I have been investigating the reason for a failure the first time I use Siri & homebridge-cbus after a long delay. I am not sure if it is at all related but the homebridge.log file shows that after some period every command generates an error, even if the action is executed successfuly.

The extract below shows me opening the IOS Home app and turning a single light on & off, with errors.

Cheers

2020-02-13T22:51:17.181Z cbus:client sent command '[129] get //DENDY4/254/56/3 level # getOn' 2020-02-13T22:51:17.181Z cbus:client sent command '[130] get //DENDY4/254/56/39 level # getOn' 2020-02-13T22:51:17.181Z cbus:client sent command '[131] get //DENDY4/254/56/74 level # getOn' 2020-02-13T22:51:17.181Z cbus:client sent command '[132] get //DENDY4/254/56/57 level # getOn' 2020-02-13T22:51:17.181Z cbus:client sent command '[133] get //DENDY4/254/56/38 level # getOn' 2020-02-13T22:51:17.181Z cbus:client sent command '[134] get //DENDY4/254/56/42 level # getOn' 2020-02-13T22:51:17.182Z cbus:client sent command '[135] get //DENDY4/254/56/40 level # getOn' 2020-02-13T22:51:17.182Z cbus:client sent command '[136] get //DENDY4/254/56/31 level # getOn' 2020-02-13T22:51:17.182Z cbus:client sent command '[137] get //DENDY4/254/56/32 level # getOn' 2020-02-13T22:51:17.182Z cbus:client sent command '[138] get //DENDY4/254/56/2 level # getOn' 2020-02-13T22:51:17.182Z cbus:client sent command '[139] get //DENDY4/254/56/24 level # getOn' 2020-02-13T22:51:17.182Z cbus:client sent command '[140] get //DENDY4/254/56/24 level # getBrightness' 2020-02-13T22:51:17.182Z cbus:client sent command '[141] get //DENDY4/254/56/0 level # getOn' 2020-02-13T22:51:17.182Z cbus:client sent command '[142] get //DENDY4/254/56/47 level # getOn' 2020-02-13T22:51:17.182Z cbus:client sent command '[143] get //DENDY4/254/56/41 level # getOn' 2020-02-13T22:51:17.182Z cbus:client sent command '[144] get //DENDY4/254/56/37 level # getOn' 2020-02-13T22:51:17.182Z cbus:client sent command '[145] get //DENDY4/254/56/30 level # getOn' 2020-02-13T22:51:17.182Z cbus:client sent command '[146] get //DENDY4/254/56/36 level # getOn' 2020-02-13T22:51:17.182Z cbus:client sent command '[147] get //DENDY4/254/56/46 level # getOn' 2020-02-13T22:51:17.183Z cbus:client sent command '[148] get //DENDY4/254/56/75 level # getOn' 2020-02-13T22:51:17.183Z cbus:client rx response { commandId: 129, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 3 }, level: 0, type: 'response', raw: '[129] 300 //DENDY4/254/56/3: level=0' } 2020-02-13T22:51:17.183Z cbus:client matched request '[129] get //DENDY4/254/56/3 level # getOn' with response '[129] 300 //DENDY4/254/56/3: level=0' (19 pending requests) 2020-02-13T22:51:17.185Z cbus:client rx response { commandId: 130, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 39 }, level: 0, type: 'response', raw: '[130] 300 //DENDY4/254/56/39: level=0' } 2020-02-13T22:51:17.185Z cbus:client matched request '[130] get //DENDY4/254/56/39 level # getOn' with response '[130] 300 //DENDY4/254/56/39: level=0' (18 pending requests) 2020-02-13T22:51:17.185Z cbus:client rx response { commandId: 131, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 74 }, level: 0, type: 'response', raw: '[131] 300 //DENDY4/254/56/74: level=0' } 2020-02-13T22:51:17.185Z cbus:client matched request '[131] get //DENDY4/254/56/74 level # getOn' with response '[131] 300 //DENDY4/254/56/74: level=0' (17 pending requests) 2020-02-13T22:51:17.186Z cbus:client rx response { commandId: 132, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 57 }, level: 0, type: 'response', raw: '[132] 300 //DENDY4/254/56/57: level=0' } 2020-02-13T22:51:17.186Z cbus:client matched request '[132] get //DENDY4/254/56/57 level # getOn' with response '[132] 300 //DENDY4/254/56/57: level=0' (16 pending requests) 2020-02-13T22:51:17.186Z cbus:client rx response { commandId: 133, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 38 }, level: 0, type: 'response', raw: '[133] 300 //DENDY4/254/56/38: level=0' } 2020-02-13T22:51:17.186Z cbus:client matched request '[133] get //DENDY4/254/56/38 level # getOn' with response '[133] 300 //DENDY4/254/56/38: level=0' (15 pending requests) 2020-02-13T22:51:17.187Z cbus:client rx response { commandId: 134, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 42 }, level: 0, type: 'response', raw: '[134] 300 //DENDY4/254/56/42: level=0' } 2020-02-13T22:51:17.188Z cbus:client matched request '[134] get //DENDY4/254/56/42 level # getOn' with response '[134] 300 //DENDY4/254/56/42: level=0' (14 pending requests) 2020-02-13T22:51:17.188Z cbus:client rx response { commandId: 135, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 40 }, level: 0, type: 'response', raw: '[135] 300 //DENDY4/254/56/40: level=0' } 2020-02-13T22:51:17.188Z cbus:client matched request '[135] get //DENDY4/254/56/40 level # getOn' with response '[135] 300 //DENDY4/254/56/40: level=0' (13 pending requests) 2020-02-13T22:51:17.188Z cbus:client rx response { commandId: 136, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 31 }, level: 0, type: 'response', raw: '[136] 300 //DENDY4/254/56/31: level=0' } 2020-02-13T22:51:17.189Z cbus:client matched request '[136] get //DENDY4/254/56/31 level # getOn' with response '[136] 300 //DENDY4/254/56/31: level=0' (12 pending requests) 2020-02-13T22:51:17.189Z cbus:client rx response { commandId: 137, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 32 }, level: 0, type: 'response', raw: '[137] 300 //DENDY4/254/56/32: level=0' } 2020-02-13T22:51:17.189Z cbus:client matched request '[137] get //DENDY4/254/56/32 level # getOn' with response '[137] 300 //DENDY4/254/56/32: level=0' (11 pending requests) 2020-02-13T22:51:17.189Z cbus:client rx response { commandId: 138, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 2 }, level: 0, type: 'response', raw: '[138] 300 //DENDY4/254/56/2: level=0' } 2020-02-13T22:51:17.189Z cbus:client matched request '[138] get //DENDY4/254/56/2 level # getOn' with response '[138] 300 //DENDY4/254/56/2: level=0' (10 pending requests) 2020-02-13T22:51:17.190Z cbus:client rx response { commandId: 139, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 24 }, level: 0, type: 'response', raw: '[139] 300 //DENDY4/254/56/24: level=0' } 2020-02-13T22:51:17.191Z cbus:client matched request '[139] get //DENDY4/254/56/24 level # getOn' with response '[139] 300 //DENDY4/254/56/24: level=0' (9 pending requests) 2020-02-13T22:51:17.191Z cbus:client rx response { commandId: 140, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 24 }, level: 0, type: 'response', raw: '[140] 300 //DENDY4/254/56/24: level=0' } 2020-02-13T22:51:17.191Z cbus:client matched request '[140] get //DENDY4/254/56/24 level # getBrightness' with response '[140] 300 //DENDY4/254/56/24: level=0' (8 pending requests) 2020-02-13T22:51:17.192Z cbus:client rx response { commandId: 141, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 0 }, level: 0, type: 'response', raw: '[141] 300 //DENDY4/254/56/0: level=0' } 2020-02-13T22:51:17.192Z cbus:client matched request '[141] get //DENDY4/254/56/0 level # getOn' with response '[141] 300 //DENDY4/254/56/0: level=0' (7 pending requests) 2020-02-13T22:51:17.193Z cbus:client rx response { commandId: 142, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 47 }, level: 0, type: 'response', raw: '[142] 300 //DENDY4/254/56/47: level=0' } 2020-02-13T22:51:17.193Z cbus:client matched request '[142] get //DENDY4/254/56/47 level # getOn' with response '[142] 300 //DENDY4/254/56/47: level=0' (6 pending requests) 2020-02-13T22:51:17.194Z cbus:client rx response { commandId: 143, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 41 }, level: 0, type: 'response', raw: '[143] 300 //DENDY4/254/56/41: level=0' } 2020-02-13T22:51:17.194Z cbus:client matched request '[143] get //DENDY4/254/56/41 level # getOn' with response '[143] 300 //DENDY4/254/56/41: level=0' (5 pending requests) 2020-02-13T22:51:17.194Z cbus:client rx response { commandId: 144, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 37 }, level: 0, type: 'response', raw: '[144] 300 //DENDY4/254/56/37: level=0' } 2020-02-13T22:51:17.194Z cbus:client matched request '[144] get //DENDY4/254/56/37 level # getOn' with response '[144] 300 //DENDY4/254/56/37: level=0' (4 pending requests) 2020-02-13T22:51:17.195Z cbus:client rx response { commandId: 145, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 30 }, level: 0, type: 'response', raw: '[145] 300 //DENDY4/254/56/30: level=0' } 2020-02-13T22:51:17.195Z cbus:client matched request '[145] get //DENDY4/254/56/30 level # getOn' with response '[145] 300 //DENDY4/254/56/30: level=0' (3 pending requests) 2020-02-13T22:51:17.195Z cbus:client rx response { commandId: 146, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 36 }, level: 0, type: 'response', raw: '[146] 300 //DENDY4/254/56/36: level=0' } 2020-02-13T22:51:17.195Z cbus:client matched request '[146] get //DENDY4/254/56/36 level # getOn' with response '[146] 300 //DENDY4/254/56/36: level=0' (2 pending requests) 2020-02-13T22:51:17.195Z cbus:client rx response { commandId: 147, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 46 }, level: 0, type: 'response', raw: '[147] 300 //DENDY4/254/56/46: level=0' } 2020-02-13T22:51:17.196Z cbus:client matched request '[147] get //DENDY4/254/56/46 level # getOn' with response '[147] 300 //DENDY4/254/56/46: level=0' (1 pending requests) 2020-02-13T22:51:17.196Z cbus:client rx response { commandId: 148, code: 300, matched: false, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 75 }, level: 0, type: 'response', raw: '[148] 300 //DENDY4/254/56/75: level=0' } 2020-02-13T22:51:17.196Z cbus:client matched request '[148] get //DENDY4/254/56/75 level # getOn' with response '[148] 300 //DENDY4/254/56/75: level=0' (0 pending requests) 2020-02-13T22:51:23.930Z cbus:client sent command '[149] ramp //DENDY4/254/56/24 100% # setBrightness' 2020-02-13T22:51:23.931Z cbus:client rx response { commandId: 149, code: 200, matched: false, processed: true, type: 'response', raw: '[149] 200 OK: //DENDY4/254/56/24' } 2020-02-13T22:51:23.931Z cbus:client matched request '[149] ramp //DENDY4/254/56/24 100% # setBrightness' with response '[149] 200 OK: //DENDY4/254/56/24' (0 pending requests) 2020-02-13T22:51:24.002Z cbus:client rx event { time: '20200214-095124', code: 730, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 24 }, level: 100, sourceunit: 54, ramptime: 0, sessionId: 'cmd3', commandId: 149, type: 'event', raw: '#e# 20200214-095124 730 //DENDY4/254/56/24 62437af0-303b-1038-8aca-bf9d5af0de0e new level=255 sourceunit=54 ramptime=0 sessionId=cmd3 commandId=149' } 2020-02-13T22:51:24.003Z cbus:client rx unparsable line: '#e# 20200214-095124 730 //DENDY4/254/56/24 62437af0-303b-1038-8aca-bf9d5af0de0e new level=255 sourceunit=54 ramptime=0 sessionId=cmd3 commandId=149', error: Error: database access before initialisation at CGateDatabase.getNetworkEntity (C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\lib\cgate-database.js:337:9) at CGateDatabase.getTag (C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\lib\cgate-database.js:323:21) at CBusPlatform._processEvent (C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\index.js:111:45) at CBusPlatform.<anonymous> (C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\index.js:153:8) at CBusClient.emit (events.js:223:5) at CBusClient._socketReceivedLine (C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\lib\cgate-client.js:641:10) at Carrier.<anonymous> (C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\lib\cgate-client.js:175:9) at Carrier.emit (events.js:223:5) at C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\node_modules\carrier\lib\carrier.js:24:12 at processTicksAndRejections (internal/process/task_queues.js:76:11) 2020-02-13T22:51:27.480Z cbus:client sent command '[150] ramp //DENDY4/254/56/24 0% # setOn (off)' 2020-02-13T22:51:27.481Z cbus:client rx response { commandId: 150, code: 200, matched: false, processed: true, type: 'response', raw: '[150] 200 OK: //DENDY4/254/56/24' } 2020-02-13T22:51:27.481Z cbus:client matched request '[150] ramp //DENDY4/254/56/24 0% # setOn (off)' with response '[150] 200 OK: //DENDY4/254/56/24' (0 pending requests) 2020-02-13T22:51:27.537Z cbus:client rx event { time: '20200214-095127', code: 730, processed: true, netId: CBusNetId { project: 'DENDY4', network: 254, application: 56, group: 24 }, level: 0, sourceunit: 54, ramptime: 0, sessionId: 'cmd3', commandId: 150, type: 'event', raw: '#e# 20200214-095127 730 //DENDY4/254/56/24 62437af0-303b-1038-8aca-bf9d5af0de0e new level=0 sourceunit=54 ramptime=0 sessionId=cmd3 commandId=150' } 2020-02-13T22:51:27.538Z cbus:client rx unparsable line: '#e# 20200214-095127 730 //DENDY4/254/56/24 62437af0-303b-1038-8aca-bf9d5af0de0e new level=0 sourceunit=54 ramptime=0 sessionId=cmd3 commandId=150', error: Error: database access before initialisation at CGateDatabase.getNetworkEntity (C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\lib\cgate-database.js:337:9) at CGateDatabase.getTag (C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\lib\cgate-database.js:323:21) at CBusPlatform._processEvent (C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\index.js:111:45) at CBusPlatform.<anonymous> (C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\index.js:153:8) at CBusClient.emit (events.js:223:5) at CBusClient._socketReceivedLine (C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\lib\cgate-client.js:641:10) at Carrier.<anonymous> (C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\lib\cgate-client.js:175:9) at Carrier.emit (events.js:223:5) at C:\Users\Touch\AppData\Roaming\npm\node_modules\homebridge-cbus\node_modules\carrier\lib\carrier.js:24:12 at processTicksAndRejections (internal/process/task_queues.js:76:11)

sgraystar commented 4 years ago

Never mind, removing homebridge-config-ui-x seems to have stopped the errors.