luapnp won't start can't get into system

Moxified · January 11, 2015, 2:09pm

My vera lite seems to have pooched over the night. It was controlling devices when I went to sleep but when I got up it is not working. I haven’t changed anything in several weeks.

The power light is good, network is good but the orange lua light is out. I have tried unplugging it several times and it won’t come up. I can’t get into the portal as it says “Luup engine is taking longer to reload.”

I SSHed into the thing and linux appears to be happily running. log.sh?Device=LuaUPnP from a browser shows the luaupnp engine crashing over and over. Looking at that log it fails to load d_automator.xml. My guess is that is causing the crash but I don’t know how to remove that.

Full log snippet which gets repeated rapidly:

---------------after sleep-------------
PID USER VSZ STAT COMMAND
1 root 1684 S init
2 root 0 SW [kthreadd]
3 root 0 SW [ksoftirqd/0]
4 root 0 SW [kworker/0:0]
5 root 0 SW [kworker/u:0]
6 root 0 SW< [khelper]
7 root 0 SW [kworker/u:1]
39 root 0 SW [sync_supers]
41 root 0 SW [bdi-default]
43 root 0 SW< [kblockd]
68 root 0 SW [kswapd0]
132 root 0 SW [mtdblock0]
137 root 0 SW [mtdblock1]
142 root 0 SW [mtdblock2]
147 root 0 SW [mtdblock3]
152 root 0 SW [mtdblock4]
157 root 0 SW [mtdblock5]
162 root 0 SW [mtdblock6]
167 root 0 SW [mtdblock7]
172 root 0 SW [mtdblock8]
177 root 0 SW [mtdblock9]
200 root 0 SW [kworker/0:1]
307 root 0 SW< [ipolldevd]
374 root 0 SWN [jffs2_gcd_mtd7]
402 root 1684 S init
437 root 1928 S syslogd -C256
439 root 1672 S klogd
453 root 784 S /sbin/hotplug2 --override --persistent --set-worker /lib/hotplug2/worker_fork.so --set-rules-file /etc/hotplug2.rules --max
580 root 0 SW< [cfg80211]
632 root 0 SW [khubd]
1067 root 0 SW [flush-mtd-unmap]
1538 root 1684 S crond -c /etc/crontabs -l 5
1588 root 1128 S /usr/sbin/dropbear -P /var/run/dropbear.1.pid -p 22
1748 nobody 916 S /usr/sbin/dnsmasq -D -y -Z -b -E -s lan -S /lan/ -l /tmp/dhcp.leases -r /tmp/resolv.conf.auto --stop-dns-rebind --rebind-lo
1805 root 748 S /usr/bin/luci-bwc -d
1843 root 1680 S watchdog -t 5 /dev/watchdog
1903 root 1688 S /bin/ash /usr/bin/Start_LuaUPnP.sh
1926 root 1676 S /bin/ash /usr/bin/Start_serproxy.sh
2006 root 1680 S /bin/ash /usr/bin/Start_NetworkMonitor.sh
2023 root 1792 S /bin/ash /usr/bin/cmh-ra-daemon.sh
2072 root 1192 S ssh -p 232 -T -y -i /etc/cmh-ra/keys/cmh-ra-key.priv -R 44439:127.0.0.1:80 cmh-ra@fwd4.mios.com
2083 root 6648 S /usr/bin/NetworkMonitor
2085 root 3740 S lighttpd -f /etc/lighttpd.conf
2520 root 768 S /usr/bin/haserl /www/cgi-bin/cmh/log.sh
2530 root 1688 S /bin/sh
2614 root 1676 S tail -f /var/log/cmh/LuaUPnP.log
2615 root 1692 S /bin/sh
3831 root 1668 S sleep 15
4323 root 1668 S sleep 5
4768 root 1676 R ps axf
---------------after kill -9-------------
PID USER VSZ STAT COMMAND
1 root 1684 S init
2 root 0 SW [kthreadd]
3 root 0 SW [ksoftirqd/0]
4 root 0 SW [kworker/0:0]
5 root 0 SW [kworker/u:0]
6 root 0 SW< [khelper]
7 root 0 SW [kworker/u:1]
39 root 0 SW [sync_supers]
41 root 0 SW [bdi-default]
43 root 0 SW< [kblockd]
68 root 0 SW [kswapd0]
132 root 0 SW [mtdblock0]
137 root 0 SW [mtdblock1]
142 root 0 SW [mtdblock2]
147 root 0 SW [mtdblock3]
152 root 0 SW [mtdblock4]
157 root 0 SW [mtdblock5]
162 root 0 SW [mtdblock6]
167 root 0 SW [mtdblock7]
172 root 0 SW [mtdblock8]
177 root 0 SW [mtdblock9]
200 root 0 SW [kworker/0:1]
307 root 0 SW< [ipolldevd]
374 root 0 SWN [jffs2_gcd_mtd7]
402 root 1684 S init
437 root 1928 S syslogd -C256
439 root 1672 S klogd
453 root 784 S /sbin/hotplug2 --override --persistent --set-worker /lib/hotplug2/worker_fork.so --set-rules-file /etc/hotplug2.rules --max
580 root 0 SW< [cfg80211]
632 root 0 SW [khubd]
1067 root 0 SW [flush-mtd-unmap]
1538 root 1684 S crond -c /etc/crontabs -l 5
1588 root 1128 S /usr/sbin/dropbear -P /var/run/dropbear.1.pid -p 22
1748 nobody 916 S /usr/sbin/dnsmasq -D -y -Z -b -E -s lan -S /lan/ -l /tmp/dhcp.leases -r /tmp/resolv.conf.auto --stop-dns-rebind --rebind-lo
1805 root 748 S /usr/bin/luci-bwc -d
1843 root 1680 S watchdog -t 5 /dev/watchdog
1903 root 1688 S /bin/ash /usr/bin/Start_LuaUPnP.sh
1926 root 1676 S /bin/ash /usr/bin/Start_serproxy.sh
2006 root 1680 S /bin/ash /usr/bin/Start_NetworkMonitor.sh
2023 root 1792 S /bin/ash /usr/bin/cmh-ra-daemon.sh
2072 root 1192 S ssh -p 232 -T -y -i /etc/cmh-ra/keys/cmh-ra-key.priv -R 44439:127.0.0.1:80 cmh-ra@fwd4.mios.com
2083 root 6648 S /usr/bin/NetworkMonitor
2085 root 3740 S lighttpd -f /etc/lighttpd.conf
2520 root 768 S /usr/bin/haserl /www/cgi-bin/cmh/log.sh
2530 root 1688 S /bin/sh
2614 root 1676 S tail -f /var/log/cmh/LuaUPnP.log
2615 root 1692 S /bin/sh
3831 root 1668 S sleep 15
4323 root 1668 S sleep 5
4770 root 1676 R ps axf
4771 root 1680 S /bin/ash /usr/bin/GetNetworkState.sh wifi
03 01/11/15 8:41:42.969 LuaUPNP: starting bLogUPnP 0 <0x2b908000>
02 01/11/15 8:41:42.999 JobHandler_LuaUPnP::Run: pid 4348 didn’t exit <0x2b908000>
02 01/11/15 8:41:43.560 UserData::LoadUserData previous: 0 from 1.5.622 <0x2b908000>
09 01/11/15 8:41:43.561 UserData::ParseRooms 1 Garage <0x2b908000>
09 01/11/15 8:41:43.561 UserData::ParseRooms 2 Living Room <0x2b908000>
09 01/11/15 8:41:43.561 UserData::ParseRooms 3 Kitchen <0x2b908000>
09 01/11/15 8:41:43.562 UserData::ParseRooms 4 Dining Room <0x2b908000>
09 01/11/15 8:41:43.562 UserData::ParseRooms 5 Basement <0x2b908000>
09 01/11/15 8:41:43.562 UserData::ParseRooms 6 Master Bedroom <0x2b908000>
09 01/11/15 8:41:43.562 UserData::ParseRooms 7 Guest Bedroom <0x2b908000>
09 01/11/15 8:41:43.563 UserData::ParseRooms 8 Study <0x2b908000>
09 01/11/15 8:41:43.563 UserData::ParseRooms 9 Attic <0x2b908000>
09 01/11/15 8:41:43.563 UserData::ParseRooms 10 Outside <0x2b908000>
09 01/11/15 8:41:43.563 UserData::ParseRooms 11 zzz <0x2b908000>
09 01/11/15 8:41:43.564 UserData::ParseRooms 12 Halls <0x2b908000>
09 01/11/15 8:41:43.564 UserData::ParseRooms 13 A House <0x2b908000>
03 01/11/15 8:41:43.633 UserData::LoadUserData BuildVersion: 1.5.622 SvnVersion: 7546 Model: 33 MiCasaVerde VeraLite flush: 0 changed: 0 resync: 8249 syncdevice:1 <0x2b908000>
01 01/11/15 8:41:43.852 Device_LuaUPnP::LoadDeviceDoc can’t load /etc/cmh-lu//D_Automator.xml <0x2b908000>
02 01/11/15 8:41:43.852 JobHandler_LuaUPnP::m_sMissingFile_set /etc/cmh-lu//D_Automator.xml <0x2b908000>
01 01/11/15 8:41:43.853 JobHandler_LuaUPnP::CreateDevice_LuaUPnP failed to load 67/D_Automator.xml so device 67 is offline <0x2b908000>
01 01/11/15 8:41:44.340 Device_LuaUPnP::CreateServices Aborting device 67 because the topmost device has no interface <0x2b908000>
01 01/11/15 8:41:44.340 JobHandler_LuaUPnP::CreateAllServices failed to create 67 <0x2b908000>
01 01/11/15 8:41:44.422 UPnPAction_Send::ParseState can’t find name <0x2b908000>
02 01/11/15 8:41:44.461 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x2b908000>
02 01/11/15 8:41:44.468 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:DSCAlarmPartition1 <0x2b908000>
02 01/11/15 8:41:44.477 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x2b908000>
02 01/11/15 8:41:44.481 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x2b908000>
02 01/11/15 8:41:44.482 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:GenericSensor1 <0x2b908000>
02 01/11/15 8:41:44.500 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x2b908000>
02 01/11/15 8:41:44.511 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x2b908000>
02 01/11/15 8:41:44.512 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:GenericSensor1 <0x2b908000>
02 01/11/15 8:41:44.515 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x2b908000>
02 01/11/15 8:41:44.518 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x2b908000>
02 01/11/15 8:41:44.521 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x2b908000>
02 01/11/15 8:41:44.527 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x2b908000>
02 01/11/15 8:41:44.530 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1 <0x2b908000>
02 01/11/15 8:41:44.533 Device_Service::MatchupUpnpServices no upnp service for urn:micasaverde-com:serviceId:ZWaveDevice1

2015-01-11 08:41:44 - LuaUPnP Terminated with Exit Code: 139

2015-01-11 08:41:44 - LuaUPnP crash

---------------exited-------------
PID USER VSZ STAT COMMAND
1 root 1684 S init
2 root 0 SW [kthreadd]
3 root 0 SW [ksoftirqd/0]
4 root 0 SW [kworker/0:0]
5 root 0 SW [kworker/u:0]
6 root 0 SW< [khelper]
7 root 0 SW [kworker/u:1]
39 root 0 SW [sync_supers]
41 root 0 SW [bdi-default]
43 root 0 SW< [kblockd]
68 root 0 SW [kswapd0]
132 root 0 SW [mtdblock0]
137 root 0 SW [mtdblock1]
142 root 0 SW [mtdblock2]
147 root 0 SW [mtdblock3]
152 root 0 SW [mtdblock4]
157 root 0 SW [mtdblock5]
162 root 0 SW [mtdblock6]
167 root 0 SW [mtdblock7]
172 root 0 SW [mtdblock8]
177 root 0 SW [mtdblock9]
200 root 0 SW [kworker/0:1]
307 root 0 SW< [ipolldevd]
374 root 0 SWN [jffs2_gcd_mtd7]
402 root 1684 S init
437 root 1928 S syslogd -C256
439 root 1672 S klogd
453 root 784 S /sbin/hotplug2 --override --persistent --set-worker /lib/hotplug2/worker_fork.so --set-rules-file /etc/hotplug2.rules --max
580 root 0 SW< [cfg80211]
632 root 0 SW [khubd]
1067 root 0 SW [flush-mtd-unmap]
1538 root 1684 S crond -c /etc/crontabs -l 5
1588 root 1128 S /usr/sbin/dropbear -P /var/run/dropbear.1.pid -p 22
1748 nobody 916 S /usr/sbin/dnsmasq -D -y -Z -b -E -s lan -S /lan/ -l /tmp/dhcp.leases -r /tmp/resolv.conf.auto --stop-dns-rebind --rebind-lo
1805 root 748 S /usr/bin/luci-bwc -d
1843 root 1680 S watchdog -t 5 /dev/watchdog
1903 root 1688 S /bin/ash /usr/bin/Start_LuaUPnP.sh
1926 root 1676 S /bin/ash /usr/bin/Start_serproxy.sh
2006 root 1680 S /bin/ash /usr/bin/Start_NetworkMonitor.sh
2023 root 1792 S /bin/ash /usr/bin/cmh-ra-daemon.sh
2072 root 1192 S ssh -p 232 -T -y -i /etc/cmh-ra/keys/cmh-ra-key.priv -R 44439:127.0.0.1:80 cmh-ra@fwd4.mios.com
2083 root 6648 S /usr/bin/NetworkMonitor
2085 root 3740 S lighttpd -f /etc/lighttpd.conf
2520 root 768 S /usr/bin/haserl /www/cgi-bin/cmh/log.sh
2530 root 1688 S /bin/sh
2614 root 1676 S tail -f /var/log/cmh/LuaUPnP.log
2615 root 1692 S /bin/sh
3831 root 1668 S sleep 15
5078 root 1668 S sleep 1
5089 root 1676 R ps axf

Z-Waver · January 11, 2015, 2:27pm

Do you have an X10 serial device attached? See here: http://forum.micasaverde.com/index.php/topic,11484.0.html

If not, there is a remote possibility that the /etc/cmh/user_data.json.lzo might have become corrupted. Try backing it up and then renaming/copying in one of its numbered backups.

If you still got nothing, I’d try reflashing the firmware and restoring from backup or going the tech support route.

Moxified · January 11, 2015, 2:36pm

I do not have an X-10 adapter.

I would try the backup restore route but I can’t back it up cause I can’t get into the dashboard. It probably has auto-backups but I can’t see those either and the last backup I saved to my computer is very out of date… I know, my fault.

I tried doing the dance with user_data.json.lzo but it reacts the same.

Anybody have a copy of D_Automator.xml? I could try putting it in the location it is looking for.

Z-Waver · January 11, 2015, 3:53pm

Sorry, I don’t have that file. Perhaps someone else can provide it.

Your backups should have been occurring automatically each night. The procedure you would use is:

Flash firmware(same major UI version) onto your Vera.

Login to newly flashed/defaulted Vera using your usual MCV account. Go to the backups tab and download a backup from last night or the night before.

Restore backup.

Moxified · January 13, 2015, 12:37pm

Ended up being that plugin. Like most other app’s, automator.app seems to be dead so I just uninstalled it. I was able to get my system running again after a restore.

Z-Waver · January 13, 2015, 1:01pm

How did you uninstall it, when you couldn’t login/connect to the UI?

Moxified · January 13, 2015, 1:05pm

Good point, I didn’t clarify.

I finally got into the backup restore section. I think there were some browser cache issues that were keeping me out of there.

Once I got into the backup restore section, I was able to pull down a backup and restore it. That part worked fine. I had to try several backups to find one that didn’t have the same issue. I ended up going with 1/1/15 if I remember right. Then I deleted the plugin.