Author Topic: Basic Event Logging Problems - TempLogFileSystemFailure  (Read 10906 times)

Offline businesstime

  • Newbie
  • *
  • Posts: 4
  • Karma: +0/-0
Basic Event Logging Problems - TempLogFileSystemFailure
« on: August 27, 2014, 10:30:40 pm »
Hi All,

I am trying to write a very simple script (heavily borrowing from code discussed in this post:http://forum.micasaverde.com/index.php/topic,6489.msg40139.html#msg40139) that watches when a variable changes and logs the event via a GET request to a database on another server. Much like the Alternate Event Server (which doesn't seems to behave as documented on the wiki in the current production firmware my Vera Lite came with [1.7.318])

When I tail the LuaUPnP.log file on the Vera Lite I notice that after a number of firings of my logging function the unit has the following error:

02   08/27/14 19:15:04.116   UserData::TempLogFileSystemFailure start <0x2c0fa680>

After this point my logging stops working.

The actual code being called is as follows:

Code: [Select]
function w_switch (lul_device, lul_service, lul_variable, lul_value_old, lul_value_new)
url = ("http://192.168.0.113/alert?DeviceID=%s&Description=%s&OldValue=%s&NewValue=%s&UtcTs=%s"):format(tostring(lul_device), lul_variable, lul_value_old, lul_value_new, os.time())
luup.log(("TEST:: Logging update for sensor(%s). Current Memory Usage:%s"):format(tostring(lul_device),collectgarbage("count")*1024))
luup.inet.wget(url, 5)
collectgarbage("collect")
luup.log(("TEST:: Garbage Collected. Current Memory Usage:%s"):format(collectgarbage("count")*1024))
end

Below is a snippet of the log file where you can see the log events and bound function firing. I initially thought that I may be suffering some kind of memory problem which is why there are garbage collect calls in my logging function. Adding/removing these calls does not change the result.

Code: [Select]
50 08/27/14 19:14:37.894 luup_log:0: TEST:: Logging update for sensor(3). Current Memory Usage:42891 <0x2befa680>
50 08/27/14 19:14:37.934 luup_log:0: TEST:: Garbage Collected. Current Memory Usage:42641 <0x2befa680>
50 08/27/14 19:14:37.935 luup_log:0: TEST:: Logging update for sensor(3). Current Memory Usage:42778 <0x2befa680>
50 08/27/14 19:14:37.963 luup_log:0: TEST:: Garbage Collected. Current Memory Usage:42641 <0x2befa680>
06 08/27/14 19:14:37.964 Device_Variable::m_szValue_set device: 3 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: ArmedTripped was: 0 now: 0 #hooks: 0 upnp: 0 v:0xbe5718/DL_ARMEDTRIPPED duplicate:1 <0x2befa680>
06 08/27/14 19:14:37.964 Device_Variable::m_szValue_set device: 3 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: LastTrip was: 1409192040 now: 1409192077 #hooks: 0 upnp: 0 v:0xbd49b0/NONE duplicate:0 <0x2befa680>
01 08/27/14 19:15:04.115 UserData::WriteUserData saved--before move File Size: 4559 save size 4559 <0x2c0fa680>
02 08/27/14 19:15:04.116 UserData::TempLogFileSystemFailure start <0x2c0fa680>
02 08/27/14 19:15:04.139 UserData::TempLogFileSystemFailure 4329
-rw-r--r--    1 root     root            33 Aug 26 20:28 /etc/cmh/HW_Key
-rw-r--r--    1 root     root            33 Aug 26 20:23 /etc/cmh/HW_Key2
-rw-r--r--    1 root     root             9 Aug 26 20:28 /etc/cmh/PK_AccessPoint

I don't know if or how my code is creating this problem. Any advice would be appreciated.

Thanks,
BusinessTime

Offline wangzang

  • Sr. Newbie
  • *
  • Posts: 33
  • Karma: +0/-0
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #1 on: September 29, 2014, 08:17:38 pm »
Did you have any luck figuring this out?

I'm seeing similar failures in my logs.


Code: [Select]
06      09/29/14 17:14:14.356   Device_Variable::m_szValue_set device: 41 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: KWH was: 80.4380 now: 80.4380 #hooks: 0 upnp: 0 skip: 0 v:0xcee3c8/NONE duplicate:1 <0x2b91c680>
06      09/29/14 17:14:14.357   Device_Variable::m_szValue_set device: 41 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: KWHReading was: 1412036053 now: 1412036054 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x2b91c680>
01      09/29/14 17:14:22.283   UserData::WriteUserData saved--before move File Size: 47177 save size 47177 __LEAK__ this:262144 start:491520 to 0x1112000 <0x2bb1c680>
02      09/29/14 17:14:22.284   UserData::TempLogFileSystemFailure start <0x2bb1c680>
02      09/29/14 17:14:22.311   UserData::TempLogFileSystemFailure 5922
-rw-r--r--    1 root     root            33 Sep 28 21:27 /etc/cmh/HW_Key
-rw-r--r--    1 root     root            33 Jun 27  2013 /etc/cmh/HW_Key2
...

Offline lolodomo

  • Master Member
  • *******
  • Posts: 3484
  • Karma: +74/-10
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #2 on: October 02, 2014, 01:08:35 am »
I saw th? dame error un m'y logs yesterday acter upgrading tout UI7.

Offline hmspain

  • Hero Member
  • *****
  • Posts: 513
  • Karma: +16/-8
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #3 on: October 19, 2014, 05:09:53 pm »
I too am seeing "UserData::TempLogFileSystemFailure" with disturbing frequency (every 6 minutes in some cases).  Vera recovers, but these errors are still a concern.  I'm running UI7.

02      10/19/14 13:03:12.499   UserData::TempLogFileSystemFailure start <0x2b826680>
02      10/19/14 13:03:12.532   UserData::TempLogFileSystemFailure 5490
02      10/19/14 13:03:12.553   UserData::TempLogFileSystemFailure start <0x2b826680>
02      10/19/14 13:03:12.582   UserData::TempLogFileSystemFailure 5401
02      10/19/14 13:18:18.488   UserData::TempLogFileSystemFailure start <0x2c024680>
02      10/19/14 13:18:18.516   UserData::TempLogFileSystemFailure 5490
02      10/19/14 13:18:18.542   UserData::TempLogFileSystemFailure start <0x2c024680>
02      10/19/14 13:18:18.571   UserData::TempLogFileSystemFailure 5401
02      10/19/14 13:24:18.446   UserData::TempLogFileSystemFailure start <0x2c024680>
02      10/19/14 13:24:18.475   UserData::TempLogFileSystemFailure 5490
02      10/19/14 13:24:18.509   UserData::TempLogFileSystemFailure start <0x2c024680>
02      10/19/14 13:24:18.540   UserData::TempLogFileSystemFailure 5401
02      10/19/14 13:43:24.456   UserData::TempLogFileSystemFailure start <0x2b482680>
02      10/19/14 13:43:24.484   UserData::TempLogFileSystemFailure 5490
02      10/19/14 13:43:24.508   UserData::TempLogFileSystemFailure start <0x2b482680>
02      10/19/14 13:43:24.536   UserData::TempLogFileSystemFailure 5401
02      10/19/14 13:49:24.419   UserData::TempLogFileSystemFailure start <0x2b482680>
02      10/19/14 13:49:24.447   UserData::TempLogFileSystemFailure 5490
02      10/19/14 13:49:24.472   UserData::TempLogFileSystemFailure start <0x2b482680>
02      10/19/14 13:49:24.500   UserData::TempLogFileSystemFailure 5401
02      10/19/14 13:55:24.462   UserData::TempLogFileSystemFailure start <0x2b482680>
02      10/19/14 13:55:24.490   UserData::TempLogFileSystemFailure 5490
02      10/19/14 13:55:24.510   UserData::TempLogFileSystemFailure start <0x2b482680>
02      10/19/14 13:55:24.538   UserData::TempLogFileSystemFailure 5401
02      10/19/14 14:01:24.515   UserData::TempLogFileSystemFailure start <0x2b482680>
02      10/19/14 14:01:24.543   UserData::TempLogFileSystemFailure 5490
02      10/19/14 14:01:24.565   UserData::TempLogFileSystemFailure start <0x2b482680>
02      10/19/14 14:01:24.593   UserData::TempLogFileSystemFailure 5401

I removed my USB drive thinking it may have caused the errors.  Since UI7 is very confusing with regard to using a USB drive, it might be that part of my OS still thinks I'm using a USB drive...
VeraPlus (1); Cameras (6), Sirens (2), Hue Bulbs/Strips/Blooms (42), Fan Dimmer (6), Aeon 4-in-1s (10), Water Sensors (3), Z-Wave Switches (20), Nest Smoke/CO Protects (5), Nest Thermostat Gen3 (1), HEM Gen2s (2)

Offline watou

  • Hero Member
  • *****
  • Posts: 866
  • Karma: +43/-12
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #4 on: November 09, 2014, 05:00:07 pm »
I am also getting these "UserData::TempLogFileSystemFailure" errors in my log frequently and the Luup engine is crashing as well.  This is on a Vera3 running 1.7.388.  Does anyone have any more information about this?

Thanks,
watou

Offline shoover02

  • Newbie
  • *
  • Posts: 1
  • Karma: +0/-0
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #5 on: November 19, 2014, 07:23:52 pm »
Same log message here on 1.7.439.

Offline dbmccallum

  • Jr. Member
  • **
  • Posts: 71
  • Karma: +0/-0
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #6 on: November 29, 2014, 11:10:45 pm »
I have the same issue as well

Vera Edge (1.7.2406), (56) GE/Jasco ON/OFF switches, (18) GE dimmers, (8 GE Outdoor modules, (4) 4-1 Aeotech Multisensor, (7) 6-1 Aeotech Multisensor, (1) Siren WA105DBZ, (2) Liftmaster Garage Doors,Vera 3 (1.7.830), 2 GE Outdoor Modules,Vera Lite (1.7.902) RTS Bridge, 14 Somphy Blinds, Homewave

Offline HansW

  • Full Member
  • ***
  • Posts: 105
  • Karma: +1/-0
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #7 on: December 24, 2014, 10:42:29 am »
Same issue here on latest UI7 and crashing every few hours....

Offline YzRacer

  • Full Member
  • ***
  • Posts: 137
  • Karma: +0/-0
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #8 on: December 25, 2014, 12:14:50 pm »
I also see this in my logs, just as hmspain said, sometimes every 6 minutes. It may always be every 6 minutes. I originally thought it was a major issue but everything works as far as I can tell. I searched around here a bit and found some notes about Vera saving userdata every 6 or 7 minutes and I thought that may be associated. I have about 50 tabs open right now researching some other Vera stuff but if I come across those other threads I will post back.

Offline hmspain

  • Hero Member
  • *****
  • Posts: 513
  • Karma: +16/-8
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #9 on: December 25, 2014, 09:46:26 pm »
I also see this in my logs, just as hmspain said, sometimes every 6 minutes. It may always be every 6 minutes. I originally thought it was a major issue but everything works as far as I can tell. I searched around here a bit and found some notes about Vera saving userdata every 6 or 7 minutes and I thought that may be associated. I have about 50 tabs open right now researching some other Vera stuff but if I come across those other threads I will post back.

I went back to using Vera Alerts (UI7 compatible now) so I'm now notified when my Vera restarts... which is often.  I run out of log file, so I can't debug the restarts... back to using a USB drive.  The good news is the USB drive "enabled" without a lot of pain.  The bad news is the Vera restarts and the cryptic "TempLogFileSystemFailure"s are all over my log file.

When this happens, the system become totally unresponsive which might account for some of the perceived "delays".

Sure would like to hear from MCV on this one!  I'll try opening a trouble ticket; it is what I would ask myself to do (I'm in support too).
VeraPlus (1); Cameras (6), Sirens (2), Hue Bulbs/Strips/Blooms (42), Fan Dimmer (6), Aeon 4-in-1s (10), Water Sensors (3), Z-Wave Switches (20), Nest Smoke/CO Protects (5), Nest Thermostat Gen3 (1), HEM Gen2s (2)

Offline YzRacer

  • Full Member
  • ***
  • Posts: 137
  • Karma: +0/-0
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #10 on: December 26, 2014, 04:35:44 am »
I also see this in my logs, just as hmspain said, sometimes every 6 minutes. It may always be every 6 minutes. I originally thought it was a major issue but everything works as far as I can tell. I searched around here a bit and found some notes about Vera saving userdata every 6 or 7 minutes and I thought that may be associated. I have about 50 tabs open right now researching some other Vera stuff but if I come across those other threads I will post back.

I went back to using Vera Alerts (UI7 compatible now) so I'm now notified when my Vera restarts... which is often.  I run out of log file, so I can't debug the restarts... back to using a USB drive.  The good news is the USB drive "enabled" without a lot of pain.  The bad news is the Vera restarts and the cryptic "TempLogFileSystemFailure"s are all over my log file.

When this happens, the system become totally unresponsive which might account for some of the perceived "delays".

Sure would like to hear from MCV on this one!  I'll try opening a trouble ticket; it is what I would ask myself to do (I'm in support too).

Good call on the Vera Alerts! I had turned that off some time ago when I first set it up because it was often and annoying. I made sure I had plenty of space on my Vera and turned it back on. So far I only have 1 restart today.

Offline hmspain

  • Hero Member
  • *****
  • Posts: 513
  • Karma: +16/-8
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #11 on: December 31, 2014, 06:20:20 pm »
I filed another trouble ticket on the "TempLogFileSystemFailure" error which seems to cause the Vera to crash (at least it's restarting!).  Nothing from MCV yet...

I filed a trouble ticket a couple weeks back, but support is hit and miss.  I think they have a helpdesk agent that just trashes requests, counts them as work, and goes about collecting a paycheck.  A long time ago, I had a job where we found a closet stuffed with old (unanswered) trouble tickets...
VeraPlus (1); Cameras (6), Sirens (2), Hue Bulbs/Strips/Blooms (42), Fan Dimmer (6), Aeon 4-in-1s (10), Water Sensors (3), Z-Wave Switches (20), Nest Smoke/CO Protects (5), Nest Thermostat Gen3 (1), HEM Gen2s (2)

Offline hmspain

  • Hero Member
  • *****
  • Posts: 513
  • Karma: +16/-8
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #12 on: December 31, 2014, 06:25:25 pm »
I filed another trouble ticket on the "TempLogFileSystemFailure" error which seems to cause the Vera to crash (at least it's restarting!).  Nothing from MCV yet...

I filed a trouble ticket a couple weeks back, but support is hit and miss.  I think they have a helpdesk agent that just trashes requests, counts them as work, and goes about collecting a paycheck.  A long time ago, I had a job where we found a closet stuffed with old (unanswered) trouble tickets...

The "TempLogFileSystemFailure" is part of the LuaUPnP image.  If MCV posts the code, we could perhaps debug it further :-).
VeraPlus (1); Cameras (6), Sirens (2), Hue Bulbs/Strips/Blooms (42), Fan Dimmer (6), Aeon 4-in-1s (10), Water Sensors (3), Z-Wave Switches (20), Nest Smoke/CO Protects (5), Nest Thermostat Gen3 (1), HEM Gen2s (2)

Offline YzRacer

  • Full Member
  • ***
  • Posts: 137
  • Karma: +0/-0
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #13 on: January 01, 2015, 02:08:43 pm »
Is this in any way related to log rotation? Seems like I see this sometimes if my space is getting low and logs are rotating quickly. If I could get my LuaUPnP.log tailed over to my syslog this would be a lot easier to watch.

Offline hmspain

  • Hero Member
  • *****
  • Posts: 513
  • Karma: +16/-8
Re: Basic Event Logging Problems - TempLogFileSystemFailure
« Reply #14 on: January 01, 2015, 03:00:31 pm »
Is this in any way related to log rotation? Seems like I see this sometimes if my space is getting low and logs are rotating quickly. If I could get my LuaUPnP.log tailed over to my syslog this would be a lot easier to watch.

I think I disabled log file rotation, at least the cron job that says it rotates the logs :).

crontab -e

No impact on the number of crashes...
VeraPlus (1); Cameras (6), Sirens (2), Hue Bulbs/Strips/Blooms (42), Fan Dimmer (6), Aeon 4-in-1s (10), Water Sensors (3), Z-Wave Switches (20), Nest Smoke/CO Protects (5), Nest Thermostat Gen3 (1), HEM Gen2s (2)