UNIX Time

[livius]

@dchappel
i can not test now - i am running stability test it must work 1 day
but what if you change line to:
print ('rtc.now:'+str(rtc.now())+" utime.time:"+str(utime.time()))

[dchappel]

That gives a truncated scientific notation output.

I need the full digit representation to pass to service as my timestamp.

[livius]

@dchappel
yes but it is different for every line?

[dchappel]

@livius

The number is same on every line. Digits to the right of the decimal point stop before point That they would show change.

Not in front of setup at the moment. Will post output a bit later.

[dchappel]

@livius

Here's the output without any formatting or use of int:

rtc.now:(2017, 1, 26, 20, 50, 14, 559838, None)  utime.time:1.485464e+09
rtc.now:(2017, 1, 26, 20, 50, 15, 562317, None)  utime.time:1.485464e+09
rtc.now:(2017, 1, 26, 20, 50, 16, 565325, None)  utime.time:1.485464e+09
rtc.now:(2017, 1, 26, 20, 50, 17, 567325, None)  utime.time:1.485464e+09
rtc.now:(2017, 1, 26, 20, 50, 18, 569324, None)  utime.time:1.485464e+09
rtc.now:(2017, 1, 26, 20, 50, 19, 571324, None)  utime.time:1.485464e+09
rtc.now:(2017, 1, 26, 20, 50, 20, 573324, None)  utime.time:1.485464e+09
rtc.now:(2017, 1, 26, 20, 50, 21, 575324, None)  utime.time:1.485464e+09
rtc.now:(2017, 1, 26, 20, 50, 22, 577342, None)  utime.time:1.485464e+09
rtc.now:(2017, 1, 26, 20, 50, 23, 580311, None)  utime.time:1.485464e+09
rtc.now:(2017, 1, 26, 20, 50, 24, 582313, None)  utime.time:1.485464e+09

And for what it's worth, sys.maxsize comes back with 2147483647. So we are working within that limitation.

[livius]

@dchappel
report this issue on github

[jmarcelino]

I traced the problem to esp32/mods/modutime.c and added a comment to the issue on github: https://github.com/pycom/pycom-micropython/issues/71#issuecomment-275624314

Simply changing time_time() to return an int fixed it for me, but not sure why it was returning a float in the first place so maybe I'm missing something :-)

With the patch in place it seems to be working

>>> rtc.init((2017,1,27,9,0))

Running utimeTest.py
rtc.now:(2017, 1, 27, 9, 0, 9, 37484, None)  utime.time:1485507609
rtc.now:(2017, 1, 27, 9, 0, 10, 39594, None)  utime.time:1485507610
rtc.now:(2017, 1, 27, 9, 0, 11, 41610, None)  utime.time:1485507611
rtc.now:(2017, 1, 27, 9, 0, 12, 43605, None)  utime.time:1485507612
rtc.now:(2017, 1, 27, 9, 0, 13, 45611, None)  utime.time:1485507613
rtc.now:(2017, 1, 27, 9, 0, 14, 48617, None)  utime.time:1485507614
rtc.now:(2017, 1, 27, 9, 0, 15, 50614, None)  utime.time:1485507615
rtc.now:(2017, 1, 27, 9, 0, 16, 52619, None)  utime.time:1485507616

[abilio]

@dchappel, @jmarcelino, thanks for the report. You're totally right about time not working properly after initialization.

To continue with @jmarcelino's finding, the reason why returns a float is to making it more compatible with CPython, taking advantage of the fact that floating point is supported. (reference here). It was a last minute change before the release, and must admit, not tested in the way you did, but only with the RTC in reset after boot state.

The original line reads:

return mp_obj_new_float(mach_rtc_get_us_since_epoch() / 1000000.0);

The fact is that if you do some printing:

printf("%lld %f\n", mach_rtc_get_us_since_epoch(), mach_rtc_get_us_since_epoch() / 1000000.0);

You'll see the value changing, yet the float object returned always have the same value. Furthermore, if you replace the C code by:

STATIC mp_obj_t time_time(void) {
    static float t = 1483229312.0;
    t = t + 1.0;
   // get date and time
   return mp_obj_new_float(t);
}

You would expect the value to change, but it doesn't. But if you do initialize t to 1.0, as in: static float t = 1.0; then it changes.

Now if t = 16777215.0, you'll see the value increment once, then get stuck at 16777216.0, which is 2 ˆ24.

I have to investigate further.

[abilio]

I've been doing some tests, and found this to be related to the Espressif tools. I created this simple test:

void check_this_float_passing(float f) {
    printf("this is a float: %f\n", f - 16777215.0); // the constant is there to prove that is not fault of the printf */
}

void test_float(void) {
    check_this_float_passing(16777215.0);
    check_this_float_passing(16777216.0);
    check_this_float_passing(16777216.1); // buggy from now on
    check_this_float_passing(16777217.0);
    printf("this is a big float showing it works: %f\n", 16777217.0); // this works
}

Expected result:

this is a float: 0.000000
this is a float: 1.000000
this is a float: 1.100000
this is a float: 2.000000
this is a big float showing it works: 16777217.000000

Obtained:

this is a float: 0.000000
this is a float: 1.000000
this is a float: 1.000000
this is a float: 1.000000
this is a big float showing it works: 16777217.000000

As you see, there is a problem with passing floats as a parameter of a function for numbers higher than 2^24. I'm going to investigate further.

Note: this is not related to the previous floating point bug (80000000.0 / 1000000.0 != 80).

[jmarcelino]

Thank you so much for posting your thoughts and debugging steps @abilio
This is really excellent for us entering the world of μpython internals debugging - and do I love a good mystery to apply some detective work ;-)

That the problem appears at 24 bits is interesting and I remember floats (when stored as 32 bit) only have 23 bits for the significant digits so maybe that explains it.

I think printf("%lld %f\n" ...) uses doubles so that's probably why you didn't see it there.

Just a theory at least. I'll look into it a bit more later if we're still stuck.

[abilio]

@jmarcelino, actually in the line:

printf("%lld %f\n", mach_rtc_get_us_since_epoch(), mach_rtc_get_us_since_epoch() / 1000000.0);

I wanted to print the us value after epoch, which is internally kept as a 64 bit integer (to go beyond the 2K38 problem), hence the %lld. Then at the same line I wanted to test that it was not an issue with converting it to a float seconds value (which proved not to be the case).

[jmarcelino]

@abilio

I meant that %f in the printf is usually a double not a float

[abilio]

@dchappel, @jmarcelino, and everyone else that reads this. I hope you guys all accept my humble apology. @jmarcelino made me realize of a mistake I made while coming into this conclusions (and in the original software too).

I had forgotten that single floating point values are 32 bit (so only 23 bits represent the fraction). The results are then correct. I'll check into the reported bug and look for a way to fix it ASAP. Probably it won't be included in today's release, as I want to test it properly this time.

[abilio]

After thinking it through and discussing it with my fellow workers, the only posible solution is to go back to integers. The reason is that at present time mp_float_t is now a C float, that only has 23 bit to represent the mantissa. This could be changed, but needs proper testing. Perhaps in the future this will change, but until then, time.time() will return an integer.

[soren]

This post is deleted!

[Devang Sharma]

@abilio, how can I sync/set RTC to UNIX time?

[jmarcelino]

@devang-sharma

Do you mean over NTP?

You can now use rtc.ntp_sync("pool.ntp.org")

Check the RTC docs: https://docs.pycom.io/chapter/firmwareapi/pycom/machine/RTC.html

[Devang Sharma]

@jmarcelino, I want to sync RTC to current time(UTC) and after that, I can use time.time() function to calculate time elapsed since Epoch and then use it as a timestamp.

[livius]

@devang-sharma
I do not know if i understand you corectly
but you can set timezone

utime.timezone([secs])

and then use

utime.localtime()

[Devang Sharma]

@jmarcelino It works for me now! I had to enable NTP client using the command line in Windows. Before that, "rtc.synced()" was returning False. Thanks.