Basic Event Logging Problems - TempLogFileSystemFailure

konstsch · June 9, 2015, 8:29pm

I have similar trouble. I use flash-drive as well.
My z-wave net include only two fibaro’s devices.

ssubo · August 11, 2015, 4:28pm

I’m also seeing the “cannot write user data” message every 6 minutes. Any updates on this issue?

hmspain · August 11, 2015, 4:37pm

Knowing how EXTREMELY limited the disk space is on Vera, I would recommend logging into the Vera as “root” and “df -h” to check the partition utilization. You don’t want ANY of your partitions to be reading Use% 100% :-).

Putting you log files on a USB drive might cause as many problems as it tries to solve, but (if it works) is a step in the right direction keeping those partitions free for upgrades and other Vera processes.

ssubo · August 14, 2015, 3:43am

I did that and I have 2 100% rows… Any way to fix this? Take a look:

Filesystem Size Used Available Use% Mounted on
/dev/root 4.5M 4.5M 0 100% /rom
tmpfs 30.5M 4.2M 26.3M 14% /tmp
tmpfs 512.0K 0 512.0K 0% /dev
/dev/mtdblock7 11.0M 7.3M 3.7M 66% /overlay
overlayfs:/overlay 11.0M 7.3M 3.7M 66% /
/dev/mtdblock8 4.4M 4.4M 0 100% /mios

RichardTSchaefer · August 14, 2015, 7:11am

Those two are OK … they are read-only partitions that contain the Vera Software.

hmspain · August 14, 2015, 12:03pm

“Those two” reading 100% full; good point Richard, thank you!

That /overlay partition is used (among other things I’m sure) for upgrades (my understanding). A little tight for my taste, but just so you know :-).

hmspain · August 15, 2015, 3:02am

I was feeling smug not getting this error… until tonight LOL. Something to do with my USB thumb drive?

root@MiOS_30013035:~# df -h
Filesystem Size Used Available Use% Mounted on
/dev/root 4.5M 4.5M 0 100% /rom
tmpfs 62.2M 1.9M 60.3M 3% /tmp
tmpfs 512.0K 0 512.0K 0% /dev
/dev/mtdblock7 11.0M 8.0M 3.0M 73% /overlay
overlayfs:/overlay 11.0M 8.0M 3.0M 73% /
/dev/sda1 506.2M 38.4M 442.0M 8% /tmp/log/cmh
/dev/mtdblock8 4.1M 4.1M 0 100% /mios
root@MiOS_30013035:~#

watou · August 15, 2015, 8:31am

My VeraEdge on latest firmware is constantly dumping these messages into my LuaUPnP.log file along with a long directory listing. I don’t have a USB thumb drive attached.

01 08/15/15 9:24:23.096 UserData::WriteUserData saved--before move File Size: 8780 save size 8780 <0x76910520> 02 08/15/15 9:24:23.096 UserData::TempLogFileSystemFailure start 0 <0x76910520> 02 08/15/15 9:24:23.118 UserData::TempLogFileSystemFailure 4714 res:1 -rw-r--r-- 1 root root 33 Aug 1 10:46 /etc/cmh/HW_Key ....

No explanation from the developers yet, after months I think. Wish they would fix it!

hmspain · August 15, 2015, 3:14pm

[quote=“watou, post:28, topic:182683”]My VeraEdge on latest firmware is constantly dumping these messages into my LuaUPnP.log file along with a long directory listing. I don’t have a USB thumb drive attached.

01 08/15/15 9:24:23.096 UserData::WriteUserData saved--before move File Size: 8780 save size 8780 <0x76910520> 02 08/15/15 9:24:23.096 UserData::TempLogFileSystemFailure start 0 <0x76910520> 02 08/15/15 9:24:23.118 UserData::TempLogFileSystemFailure 4714 res:1 -rw-r--r-- 1 root root 33 Aug 1 10:46 /etc/cmh/HW_Key ....

No explanation from the developers yet, after months I think. Wish they would fix it![/quote]

I suspect this is one of those “Put a small piece of electrical tape over the light” type fixes we hear when the bogus engine light came on in earlier cars… hehe

pwlivewire · August 27, 2015, 9:50pm

this is crippling! how is this not solved, my controller is reloading every 10 minutes, scenes and triggers are a mess not to mention the mess Ui7 has made of my devices… furious with the tardy support and service, and this is public release as well! not even BETA!. I’m looking elsewhere and wont be buying vera again.

Ramias · November 21, 2015, 2:05am

Bump

Trying to resolve my frequent Vera Restarts (and missing triggers while restarting).

RubbrDug · January 11, 2016, 12:08pm

Wow, this error exists for a long time. Now I have it, too.

Maybe I should add that I did no programing or hacking whatsoever. Just installed a few Apps.

mostlychris · January 31, 2016, 1:10am

Just going to throw my 2 cents in here as well. I’ve had frequent lockups as of late and usually have to power cycle. For the first time today, I had a failure of the Luup engine but was able to SSH into the box and restart it. I am getting the dreaded failures as well.

01 01/30/16 14:17:11.707 UserData::WriteUserData failed result:1 size2:46740 vs 46740 <0x77519320> 02 01/30/16 14:17:11.708 UserData::TempLogFileSystemFailure start 1 <0x77519320> 02 01/30/16 14:17:11.975 UserData::TempLogFileSystemFailure 0 res:0 02 01/30/16 14:17:12.016 UserData::TempLogFileSystemFailure start 0 <0x77519320> 02 01/30/16 14:17:12.056 UserData::TempLogFileSystemFailure 0 res:0 02 01/30/16 18:56:05.523 UserData::TempLogFileSystemFailure start 1 <0x77f12320> 02 01/30/16 18:56:05.884 UserData::TempLogFileSystemFailure 7804 res:1 02 01/30/16 18:56:05.887 UserData::LoadUserData previous: 0 from *1.7.1707* <0x77f12320>

You can see that it failed at 14:17 and didn’t come back (I didn’t notice it broken) until I did a web page load at 18:56. Vera responded to my phone call but said they would reply to my ticket in email. It’s been a week. I ordered another unit for replacement because I can’t wait. I haven’t put it in yet, hoping I can troubleshoot this issue myself. I am using a USB stick for logging.

Filesystem Size Used Available Use% Mounted on rootfs 9.5M 3.8M 5.7M 40% / /dev/root 9.3M 9.3M 0 100% /rom tmpfs 61.9M 3.1M 58.8M 5% /tmp /dev/mtdblock6 9.5M 3.8M 5.7M 40% /overlay overlayfs:/overlay 9.5M 3.8M 5.7M 40% / tmpfs 512.0K 0 512.0K 0% /dev /dev/mtdblock10 64.8M 7.4M 57.3M 11% /storage /dev/mtdblock10 64.8M 7.4M 57.3M 11% /etc/cmh-firmware /dev/mtdblock10 64.8M 7.4M 57.3M 11% /etc/cmh-backup /dev/sda1 487.9M 25.0M 437.3M 5% /tmp/log/cmh /dev/mtdblock9 5.8M 5.8M 0 100% /mios

total used free shared buffers Mem: 126688 107144 19544 0 16276 -/+ buffers: 90868 35820 Swap: 0 0 0

mostlychris · January 31, 2016, 10:19am

I was watching the logs via ssh just a bit ago and refreshed the web page at the same time. I started getting the system failure errors again. I wanted to do a reboot via ssh quickly before everything died and this is what I got:

[code]root@MiOS_:/tmp/log/cmh# reboot
Segmentation fault
root@MiOS_:/tmp/log/cmh# df -h
Segmentation fault
root@MiOS_:/tmp/log/cmh# top
Segmentation fault
root@MiOS_:/tmp/log/cmh# tail -f LuaUPnP.log
Segmentation fault
root@MiOS_:/tmp/log/cmh# free -m
Segmentation fault

[/code]

I’m throwing this in there in case it helps to troubleshoot the issue. I’m wondering again if I have hardware failure.

Here are the logs right at failure:

01 01/31/16 4:11:18.454 02 01/31/16 4:11:18.454 02 01/31/16 4:11:18.491 01 01/31/16 4:11:18.667 02 01/31/16 4:11:18.668 02 01/31/16 4:11:19.449 01 01/31/16 4:11:19.668 02 01/31/16 4:11:19.668 02 01/31/16 4:11:19.999 02 01/31/16 4:11:20.039 02 01/31/16 4:11:20.125 06 01/31/16 4:11:20.127 06 01/31/16 4:11:20.128 01 01/31/16 4:11:20.177 01 01/31/16 4:11:20.691 02 01/31/16 4:11:20.692 02 01/31/16 4:11:20.728 01 01/31/16 4:11:20.919 02 01/31/16 4:11:20.920 02 01/31/16 4:11:21.246 01 01/31/16 4:11:21.469 02 01/31/16 4:11:21.470 02 01/31/16 4:11:21.713 02 01/31/16 4:11:21.751 02 01/31/16 4:11:21.791 01 01/31/16 4:11:21.795 06 01/31/16 4:11:23.181 50 01/31/16 4:11:23.183 06 01/31/16 4:11:23.223 50 01/31/16 4:11:23.225 01 01/31/16 4:11:23.811 01 01/31/16 4:11:23.811 01 01/31/16 4:11:23.812 01 01/31/16 4:11:24.439 02 01/31/16 4:11:24.440 02 01/31/16 4:11:24.474 UserData::WriteUserData saved--before move File Size: 46161 save size 46161 <0x74556520> UserData::TempLogFileSystemFailure start 0 <0x74556520> UserData::TempLogFileSystemFailure 0 res:0 UserData::WriteUserData failed File Size: 46161 save size 45973 <0x74556520> UserData::TempLogFileSystemFailure start 1 <0x74556520> UserData::TempLogFileSystemFailure 0 res:0 UserData::WriteUserData failed result:1 size2:46161 vs 46161 <0x74556520> UserData::TempLogFileSystemFailure start 1 <0x74556520> UserData::TempLogFileSystemFailure 0 res:0 UserData::TempLogFileSystemFailure start 0 <0x74556520> UserData::TempLogFileSystemFailure 0 res:0 Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: NetStatusID was: 1 now: 2 #hooks: 0 upnp: 0 skip: 0 v:0x975618/NONE duplicate:0 <0x74556520> Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: NetStatusText was: OK now: Resetting ZWave Network #hooks: 0 upnp: 0 skip: 0 v:0xba4208/NONE duplicate:0 <0x74556520> RAServerSync::SendAlert notification lost for time 17420660 type 7 code user_data <0x77997520> UserData::WriteUserData saved--before move File Size: 46220 save size 46220 <0x77ef9320> UserData::TempLogFileSystemFailure start 0 <0x77ef9320> UserData::TempLogFileSystemFailure 0 res:0 UserData::WriteUserData failed File Size: 46220 save size 46161 <0x77ef9320> UserData::TempLogFileSystemFailure start 1 <0x77ef9320> UserData::TempLogFileSystemFailure 0 res:0 UserData::WriteUserData failed result:1 size2:46220 vs 46220 <0x77ef9320> UserData::TempLogFileSystemFailure start 1 <0x77ef9320> UserData::TempLogFileSystemFailure 0 res:0 UserData::TempLogFileSystemFailure start 0 <0x77ef9320> UserData::TempLogFileSystemFailure 0 res:0 Mongoose XXX-mg_stop1 0x9e2cf8 1 2 <0x77ef9320> Device_Variable::m_szValue_set device: 107 service: urn:demo-ted-striker:serviceId:PingSensor1 variable: CurrentFailureCount was: 0 now: 1 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76397520> luup_log:107: PingSensor #107 ping failed, failure = 1/10 <0x76397520> Device_Variable::m_szValue_set device: 105 service: urn:demo-ted-striker:serviceId:PingSensor1 variable: CurrentFailureCount was: 0 now: 1 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x76597520> luup_log:105: PingSensor #105 ping failed, failure = 1/10 <0x76597520> Mongoose XXX-mg_stop2 0x9e2cf8 2 2 <0x77ef9320> Mongoose XXX-mg_stop3 0x9e2cf8 2 2 <0x77ef9320> Mongoose XXX-mg_stop4 0x9e2cf8 16742528 2 <0x77ef9320> UserData::WriteUserData saved--before move File Size: 46214 save size 46214 <0x77ef9320> UserData::TempLogFileSystemFailure start 0 <0x77ef9320> UserData::TempLogFileSystemFailure 0 res:0

pwlivewire · February 21, 2016, 11:25pm

Just got a New Vera Plus, added a few devices, noticed the interface and app is slow. Low and behold… Log is full of Templogfilesystemfailure events. Emailed support then I’m gona return the device if I don’t get a fix, huge waste of none responsive cash…

George · February 22, 2016, 8:42am

Hi Paul,

Can you send me your ticket id number so we could look into it ? As for the “TempLogFileSystemFailure” this is just a function in the UI which does exactly what it says, logs any errors saving the user configuration data and as long as the user configuration data is saved successfully (“WriteUserData saved”) there shouldn’t be any issues.

pwlivewire · February 22, 2016, 10:12am

I haven’t got a ticket number back yet, e-mailed yesterday and had no reply. Sent to ‘support at getvera.com’ . Is there somewhere or someone i can send it to direct?

mano · February 24, 2016, 3:55pm

Seeing the same here every 6 mins or so, luup restarting.
01 02/24/16 14:31:09.208 UserData::WriteUserData saved–before move File Size: 53490 save size 53490 <0x76e8a520>
01 02/24/16 14:37:09.217 UserData::WriteUserData saved–before move File Size: 53513 save size 53513 <0x76e8a520>
01 02/24/16 14:43:09.203 UserData::WriteUserData saved–before move File Size: 53506 save size 53506 <0x76e8a520>
01 02/24/16 14:49:09.257 UserData::WriteUserData saved–before move File Size: 53592 save size 53592 <0x76e8a520>
01 02/24/16 14:55:09.207 UserData::WriteUserData saved–before move File Size: 53527 save size 53527 <0x76e8a520>
01 02/24/16 15:01:09.211 UserData::WriteUserData saved–before move File Size: 53474 save size 53474 <0x76e8a520>
01 02/24/16 15:07:09.205 UserData::WriteUserData saved–before move File Size: 53587 save size 53587 <0x76e8a520>
01 02/24/16 15:13:09.205 UserData::WriteUserData saved–before move File Size: 53473 save size 53473 <0x76e8a520>
01 02/24/16 15:19:09.203 UserData::WriteUserData saved–before move File Size: 53530 save size 53530 <0x76e8a520>
01 02/24/16 15:25:09.216 UserData::WriteUserData saved–before move File Size: 53579 save size 53579 <0x76e8a520>

Raised a Support ticket few mins ago.

trouty00 · February 24, 2016, 5:11pm

watching with interest as i have it every 6 minutes and seems to take between 3 and 15 seconds to complete the task - if its doing what it should be then great but if its doing this every 6 minutes and then has an impact on me trying to launch a scene or dim a light at exactly that time then I’d rather not be impacted by it. why every 6 minutes? why not daily in the dark hours?

Stu

RichardTSchaefer · February 24, 2016, 5:31pm

This is Vera saving it’s state in case it restarts because of a failure …
In general Vera tries to save the current state before it restarts. Depending on the failure it might not be able to.

When vera reloads, it reverts to the last save point (within 6 min of the current time)