JobHandler_LuaUPnP::Reload: Downloaded Plugin Critical

Plugins & Plugin Development General Plugin Discussion
#1

Often when my Vera3 UI5 restarts, there is a second restart almost exactly 10 minutes later. It looks to me like the “Downloaded Plugin Critical” message indicates a plug-in is to blame, but nearly all of those plug-ins appear to be in the same thread. How can I tell which plug-in caused the restart? Unlike other restarts I don’t see any warnings in the minute or so before the restart…

Log for second restart:

[code]02 12/15/14 13:29:07.104 e[33;1mLOG_CHECK_MEMORY_LEAK pMem start 0x14b4000 now 0x147f000 last 0x1515000 leaked -217088e[0m <0x2b765680>
03 12/15/14 13:29:09.652 JobHandler_LuaUPnP::Reload: Downloaded Plugin Critical 0 m_bCriticalOnly 0 dirty data 0 <0x2b965680>
06 12/15/14 13:29:09.792 Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: e[35;1mNetStatusIDe[0m was: 1 now: 2 #hooks: 0 upnp: 0 v:0xf85278/NONE duplicate:0 <0x2b965680>
06 12/15/14 13:29:09.792 Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: e[35;1mNetStatusTexte[0m was: OK now: Resetting ZWave Network #hooks: 0 upnp: 0 v:0xf87548/NONE duplicate:0 <0x2b965680>
01 12/15/14 13:29:10.218 e[31;1mMongoose XXX-mg_stop1 0xdf3428 1 0e[0m <0x2b032000>
01 12/15/14 13:29:11.219 e[31;1mMongoose XXX-mg_stop2 0xdf3428 2 0e[0m <0x2b032000>
01 12/15/14 13:29:11.219 e[31;1mMongoose XXX-mg_stop3 0xdf3428 2 0e[0m <0x2b032000>
01 12/15/14 13:29:11.219 e[31;1mMongoose XXX-mg_stop4 0xdf3428 19333024 0e[0m <0x2b032000>

e[7;36m2014-12-15 13:29:11 - LuaUPnP Terminated with Exit Code: 250e[1;00m

e[7;36m2014-12-15 13:29:11 - LuaUPnP crashe[1;00m

01 2014-12-15 13:18:59 caught signal 11 <0x2f171680>
01 2014-12-15 13:29:11 caught signal 6 <0x2bd65680>
[/code]

#2

Funny, seeing the same thing on UI7/VeraSecure. Googled and came back to my own post…

#3

And still. If I could figure out what plug-in this is…

|03|04/15/20 10:56:03.197|JobHandler_LuaUPnP::Reload: Downloaded Plugin Critical 0 m_bCriticalOnly 0 dirty data 0 running 1 <0x767fb520>|
|---|---|---|
|06|04/15/20 10:56:03.713|Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: e[35;1mNetStatusIDe[0m was: 1 now: 2 #hooks: 0 upnp: 0 skip: 0 v:0x11367d0/NONE duplicate:0 <0x767fb520>|
|06|04/15/20 10:56:03.714|Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: e[35;1mNetStatusTexte[0m was: OK now: Resetting ZWave Network #hooks: 0 upnp: 0 skip: 0 v:0x11440e0/NONE duplicate:0 <0x767fb520>|
|06|04/15/20 10:56:03.725|Device_Variable::m_szValue_set device: 2 service: urn:micasaverde-com:serviceId:ZigbeeNetwork1 variable: e[35;1mNetStatusIDe[0m was: 0 now: 3 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x767fb520>|
|06|04/15/20 10:56:03.726|Device_Variable::m_szValue_set device: 2 service: urn:micasaverde-com:serviceId:ZigbeeNetwork1 variable: e[35;1mNetStatusTexte[0m was: OK now: GET_LANG(resetting_zigbee_network,Resetting Zigbee Network) #hooks: 0 upnp: 0 skip: 0 v:0xf4ee20/NONE duplicate:0 <0x767fb520>|
|50|04/15/20 10:56:03.985|luup_log:14: DSCAlarmPanel: debug processIncoming:: Command=empty, Data='empty', Checksum=empty <0x6fb9e520>|
|01|04/15/20 10:56:03.985|e[31;1mLuaInterface::CallFunction-2 lu_incoming failed [string "..."]:1102: attempt to concatenate local 'cmd' (a nil value)e[0m <0x6fb9e520>|
|06|04/15/20 10:56:04.737|Device_Variable::m_szValue_set device: 3 service: urn:micasaverde-com:serviceId:BluetoothNetwork1 variable: e[35;1mNetStatusIDe[0m was: 0 now: 3 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x767fb520>|
|06|04/15/20 10:56:04.738|Device_Variable::m_szValue_set device: 3 service: urn:micasaverde-com:serviceId:BluetoothNetwork1 variable: e[35;1mNetStatusTexte[0m was: OK now: GET_LANG(resetting_bluetooth_network,Resetting Bluetooth Network) #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x767fb520>|
|02|04/15/20 10:56:04.939|e[33;1mLPRFJobHandler::m_bQuit_set now 1 for 0x13c9900 ThreadedClass::StopThread ptr 0x13c9900 thread 0x751fb520e[0m <0x767fb520>|
|02|04/15/20 10:56:04.973|e[33;1mLPRFSerial_CSerial::LPRF_ReceiveLoop endinge[0m <0x74dfb520>|
|01|04/15/20 10:56:05.275|e[31;1mUserData::WriteUserData saved--before move File Size: 173177 save size 173177e[0m <0x771d1320>|
|02|04/15/20 10:56:05.275|e[33;1mUserData::TempLogFileSystemFailure start 0e[0m <0x771d1320>|
|02|04/15/20 10:56:05.303|e[33;1mUserData::TempLogFileSystemFailure 5531 res:1|
#6

Hi @wilme2,

The log suggests an issue with the DSC Alarm plugin. There may also be an other plugin that is maybe obsolete or no longer supporting UI5 that gets your Vera trying to download a file no longer there. No hints a bit up in the log file?

Cheers Rene

#7

I agree. the culprit seems to be lu_incoming. it’s fixable, since it’s related to a null value coming into the cmd variable.

#8

Yeah, I saw that (DSC) and focused on it, too, then removed my post because I realized that’s not the message he’s concerned about, apparently?

This one…

|03|04/15/20 10:56:03.197|JobHandler_LuaUPnP::Reload: Downloaded Plugin Critical 0 m_bCriticalOnly 0 dirty data 0 running 1 <0x767fb520>|
|---|---|---|
#9

it’s not the first time that I noticed that something blocking the I/O is crashing the LUUP engine. anyway, I agree the logs are somewhat not useful regarding debugging issue, unless you turn verbose logging on, but it will be very verbose this way.

#10

Yes, it is the :Reload: - Which in theory happened before the DSC error. This only happens a few times a year - and in the past I didn’t see a similar DSC error. I need to fully capture the log the next time it happens and see if I can replicate.

Note the 10 minute timer to (re) try and download plug-ins is still in UI7. I upgraded firmware yesterday, and it was a dumpster fire until I rebooted about the third time. After the normal firmware upgrade and reboot, I had numerous errors in the blue message area about trying to download plug-ins - and that it would try again in 10 minutes.

#11

Hi,

The Mios App market seems very slow again since a few days. Last time that happened it also caused this type of issues. Hopefully they can fix it faster than last time. I did flag it to Sorin in an other thread.

Cheers Rene

#12

Do you have autoupdate enabled? can you disable it? I’ve it disabled and I check manually every now and then for new updates.

#13

I think a slow app store is the likely explanation. After the notices about the downloads, the message bar showed a “Error in Lua for scenes and events” - which it does when startup drags on too long and Startup Lua doesn’t get completely loaded.

#14

Some of the plug-ins I know are out of development or for which I use custom tweaks already have auto-update off, but most of my 15 plug-ins are still enabled (a lot of which is Vera bloatware). I think that is a worth testing - but I would have to undergo a reload for every plug-in as I unchecked it. It would be nice is there was a single switch and no reloading.

#15

I saw my office Vera restart last night, and when I checked it - same error. I only use a few plug-ins on that one.

04/29/20 0:19:19.061 JobHandler_LuaUPnP::Reload: Downloaded Plugin Critical 0 m_bCriticalOnly 0 dirty data 0 running 1 <0x2b5b3680>
06 04/29/20 0:19:19.414 Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: e[35;1mNetStatusIDe[0m was: 1 now: 2 #hooks: 0 upnp: 0 skip: 0 v:0xd3b610/NONE duplicate:0 <0x2b5b3680>
06 04/29/20 0:19:19.416 Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: e[35;1mNetStatusTexte[0m was: OK now: Resetting ZWave Network #hooks: 0 upnp: 0 skip: 0 v:0xd2e0f0/NONE duplicate:

#16

Since this fw is EOL, I think it’ll not be fixed.