Log Date/Time incorrect on events?

Developer Programs Writing SmartApps
1

Anyone using Java Dates in their SmartApps?

Based on my 6yo daughter sleep walking last night I’m writing an app that logs everything in the system (at least 1000 events back) so that I can replay them in the IDE logger so I can see what triggers were fired in the last hour or so.

I’m doing a simple:

def stamp = new Date().format('yyyy-M-d hh:mm:ss')

This should, however, print the current date (in my hub’s timezone). I’ve tested this and that appears to be the default. However, I’m seeing really weird mixed data:

3:38:10 PM: debug [2015-4-27 03:38:10] Living Room Motion 2 detected active 3:38:00 PM: debug [2015-4-27 03:38:00] Garage Lights Two was turned off 3:37:58 PM: debug [2015-4-27 08:37:58] Garage Lights One was turned off 3:37:51 PM: debug [2015-4-27 08:37:51] Living Room Motion 2 detected inactive 3:37:40 PM: debug [2015-4-27 08:37:40] Living Room Motion 3 detected inactive 3:37:40 PM: debug [2015-4-27 03:37:40] Laundry Room Motion detected inactive 3:37:25 PM: debug [2015-4-27 08:37:25] Living Room Motion 3 detected active 3:37:25 PM: debug [2015-4-27 03:37:25] Laundry Room Motion detected active 3:37:14 PM: debug [2015-4-27 03:37:14] Living Room Motion 3 detected inactive 3:37:13 PM: debug [2015-4-27 08:37:13] Laundry Room Motion detected inactive 3:37:09 PM: debug [2015-4-27 08:37:09] Media Room Motion detected inactive

Note that some of the stamps are coming in about 5 hours off, I’m in GMT-0500 CDT so that makes sense. Just not sure why the ST platform isn’t handling that properly.

Anyone else seen this before I ping support@?

2

Note that the first time in the log is from the ST IDE log, the second stamp is from my debug statement.

1 Like
3

This behavior was reported in another Topic and ST said they are looking into it.

Speculation was some sort of time sync issue across cloud servers, but it’s hard to make sense of it. Probably just a TZ offset bug in some methods but not others.

1 Like
4

Yeah, I thought that too… It’s likely the servers being out of sync since there is no rhyme or reason to them. I would expect that if it was coming from different places but it’s a simple log with a custom Date call and not relying on the evt.isoDate that is on the event. That I could see being a code issue.

2 Likes
5

I have posted a somewhat related scenario in another thread. In the IDE, wife’s mobile presence device events are in UTC while mine are always in EST.

1 Like
6

I just put 2 & 2 together on that :smile:

7

Why not try giving it a timezone like:

def stamp = new Date().format('yyyy-MM-Dd hh:mm:ss',TimeZone.getTimeZone('GMT'))

That should give more consistent results.

1 Like
8

I should have mentioned that I did try that too. I’m pretty sure the clocks are out of sync as the evt.isoDate is also returning the wrong times. The stamp itself is different on the various events.

1 Like
9

I came across this bug as well. I will appreciate any updates on this.

1 Like
10

No idea either, but adding a “me too”. We have one SmartRules user that is reporting issues with time triggers/conditions, and when we check the logs, it definitely seems to be a time zone issue, although the SmartThings location and the phone’s time zone are both set correctly and the same.

1 Like
11

This morning all of my events are now in the same timezone and I can reference them with:

def stamp = new Date().format('yyyy-M-d hh:mm:ss',location.timeZone)

This is producing the exact results that I expected:

8:48:30 AM: debug [2015-4-28 08:48:30] Laundry Room Motion detected inactive 8:48:28 AM: debug [2015-4-28 08:48:28] Living Room Motion 2 detected inactive 8:48:24 AM: debug [2015-4-28 08:48:24] Living Room Motion 3 detected inactive 8:48:23 AM: debug [2015-4-28 08:48:23] Living Room Motion detected inactive 8:48:20 AM: debug [2015-4-28 08:48:20] Hallway Motion detected inactive 8:48:20 AM: debug [2015-4-28 08:48:20] Pantry Light was turned on 8:48:19 AM: debug [2015-4-28 08:48:19] Pantry Motion detected active 8:48:15 AM: debug [2015-4-28 08:48:15] Daughter Motion detected inactive 8:48:13 AM: debug [2015-4-28 08:48:13] Living Room Motion detected active 8:48:10 AM: debug [2015-4-28 08:48:10] Laundry Room Motion detected active

1 Like
12

@ndasu, @April or @Jim , please get someone to look at these methods, they don’t process the time zone:

device.eventsSince
device.eventsBetween
timeToday(String timeString)

1 Like
13

timeToday() actually does accept an optional (but recommended) timezone argument:

timeToday(timeString, TimeZone)

14

I sort of hate to dredge up an old topic, but timeToday still appears to be ignoring the TimeZone parameter.

This code (startTime_1 is set via an input of type “time”):

log.debug "time: ${startTime_1}"
log.debug "timeToday(now): " + timeToday(startTime_1)
log.debug "timeToday(now, location.timeZone): " + timeToday(startTime_1, location.timeZone)
log.debug "The time zone for this location is: ${location.timeZone}"
log.debug "The zip code for this location: ${location.zipCode}"

…produces the following output (The timeZone it came up with is correct for my location):

12:43:03 AM: debug The zip code for this location: 18060
12:43:03 AM: debug The time zone for this location is: sun.util.calendar.ZoneInfo[id="America/New_York",offset=-18000000,dstSavings=3600000,useDaylight=true,transitions=235,lastRule=java.util.SimpleTimeZone[id=America/New_York,offset=-18000000,dstSavings=3600000,useDaylight=true,startYear=0,startMode=3,startMonth=2,startDay=8,startDayOfWeek=1,startTime=7200000,startTimeMode=0,endMode=3,endMonth=10,endDay=1,endDayOfWeek=1,endTime=7200000,endTimeMode=0]]
12:43:03 AM: debug timeToday(now, location.timeZone): Mon Oct 05 02:00:00 UTC 2015
12:43:03 AM: debug timeToday(now): Mon Oct 05 02:00:00 UTC 2015
12:43:03 AM: debug time: 2015-10-03T22:00:42.000-0400

Nothing against our friends across the pond, but when debugging my time-based apps I’d really like to see my stamps in the One True Timezone. :wink:

1 Like