[BUG] PLEG Log records wrong date and time...

For a while not I see this bug ALL OVER the PLEG Logs.

Examples…

Mon Apr 17 23:03:49.117 - EvalConditions:Condition:Occupied_no Trigger:NOW Result:false
Mon Apr 18 05:03:49.118 - FireAction:Nothing found for:!Occupied_no
Mon Apr 17 23:03:49.120 - GetSequence:08:00:00:1492437600:2017:4:17

and

Tue Apr 18 05:00:54.155 - GetSequence:06:30:00:1492518600:2017:4:18
Tue Apr 18 11:00:54.157 - GetSequence:07:59:59:1492523999:2017:4:18
Tue Apr 18 05:00:54.163 - EvalConditions:Condition:Stay Trigger:NOW Result:false

and

Tue Apr 18 06:36:26.137 - GetSequence:06:29:59:1492518599:2017:4:18
Tue Apr 18 12:36:26.138 - GetSequence:23:30:00:1492579800:2017:4:18
Tue Apr 18 06:36:26.141 - EvalConditions:Condition:Sleep Trigger:NOW Result:false

and MANY MORE.

Richard, have you never seen this before?

No and that’s disturbing … those numbers are coming from the LUA code library.

My Code for logging (the variable “s” is the message to be printed)
The following adds the time of the message to the beginning of the message.

 local ts = socket.gettime()
 s = os.date("%a %b %d %H:%M:", ts)  .. string.format("%4.3f - %s\n", ts % 60, s)

I use the socket.gettime() to get the stamp with ms precision.
It use the os.date function to format the “DayName Month Date HH:MM:SS:”
It uses the string.format to add the seconds.ms (from ts % 60)
I am assuming the problem is in the os.date function, this might be an LUA reentrancy problem. (i.e. some other LUA code interrupted this function and corrupted it when it returned)
If the problem is from socket.gettime() than there is a serious problem.

I’ll submit a ticket to vera. Thx

Sent from my SAMSUNG-SM-G935A using Tapatalk