Trouble getting values from RTC variables

[Chronocento]

Hi yozik, it's me again: sorry to bother you!

I'm using a Nextion Enhanced screen, with embedded RTC: in the Nextion Instruction Set, it is reported that it is possible to set and read time and date from certain variables (rtc0, rtc1, etc.).

Once set from a custom screen UI, I'm trying to read these variables values over serial with your library. With this code:

print(await client.get('rtc3')) print(await client.get('rtc4')) print(await client.get('rtc2')) print(await client.get('rtc1')) print(await client.get('rtc0'))

in the async def run() function of your example code, I get this error:

2020-03-30 16:03:44,531 - INFO - Successfully connected to the device 2020-03-30 16:03:44,532 - DEBUG - sent: b'get rtc3' 2020-03-30 16:03:44,537 - DEBUG - received: b'01' 2020-03-30 16:03:44,537 - DEBUG - received: b'' True 2020-03-30 16:03:44,540 - DEBUG - sent: b'get rtc4' 2020-03-30 16:03:44,553 - DEBUG - received: b'7107000000' 2020-03-30 16:03:44,553 - DEBUG - received: b'' 7 2020-03-30 16:03:44,555 - DEBUG - sent: b'get rtc2' 2020-03-30 16:03:44,562 - DEBUG - received: b'01' 2020-03-30 16:03:44,564 - DEBUG - received: b'71260000' 2020-03-30 16:03:44,568 - ERROR - Task exception was never retrieved future: <Task finished coro=<run() done, defined at nextion_time.py:15> exception=error('unpack requires a bytes object of length 4',)> Traceback (most recent call last): File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step result = coro.send(None) File "nextion_time.py", line 64, in run print(await client.get('rtc2')) File "/usr/local/lib/python3.5/dist-packages/nextion/client.py", line 136, in get return await self.command('get %s' % key) File "/usr/local/lib/python3.5/dist-packages/nextion/client.py", line 192, in command data = struct.unpack('i', raw)[0] struct.error: unpack requires a bytes object of length 4 2020-03-30 16:03:44,576 - DEBUG - received: b'7126000000' 2020-03-30 16:03:44,577 - DEBUG - received: b'01' 2020-03-30 16:03:44,578 - DEBUG - received: b'' 2020-03-30 16:03:44,580 - DEBUG - received: b'7103000000' 2020-03-30 16:03:44,581 - DEBUG - received: b'' 2020-03-30 16:03:44,588 - DEBUG - received: b'01' 2020-03-30 16:03:44,590 - DEBUG - received: b''

If I add a delay between requests:

print(await client.get('rtc3')) time.sleep(1) print(await client.get('rtc4')) time.sleep(1) print(await client.get('rtc2')) time.sleep(1) print(await client.get('rtc1')) time.sleep(1) print(await client.get('rtc0'))

The error is gone, but the data received is not what I'm expecting (as in the previous log, the value for the first value is reported as "True", and the following values seems to be suffering some kind of offset, as 7 is what I'm expecting for rtc3, and so on):

2020-03-30 16:14:26,144 - INFO - Successfully connected to the device 2020-03-30 16:14:27,146 - DEBUG - sent: b'get rtc3' 2020-03-30 16:14:27,148 - DEBUG - received: b'01' 2020-03-30 16:14:27,149 - DEBUG - received: b'' True 2020-03-30 16:14:28,153 - DEBUG - sent: b'get rtc4' 2020-03-30 16:14:28,155 - DEBUG - received: b'7107000000' 2020-03-30 16:14:28,156 - DEBUG - received: b'01' 2020-03-30 16:14:28,157 - DEBUG - received: b'' 7 2020-03-30 16:14:29,163 - DEBUG - sent: b'get rtc2' 2020-03-30 16:14:29,165 - DEBUG - received: b'7130000000' 2020-03-30 16:14:29,166 - DEBUG - received: b'01' 2020-03-30 16:14:29,167 - DEBUG - received: b'' 48 2020-03-30 16:14:30,172 - DEBUG - sent: b'get rtc1' 2020-03-30 16:14:30,175 - DEBUG - received: b'7103000000' 2020-03-30 16:14:30,176 - DEBUG - received: b'01' 2020-03-30 16:14:30,176 - DEBUG - received: b'' 3 2020-03-30 16:14:31,182 - DEBUG - sent: b'get rtc0' 2020-03-30 16:14:31,184 - DEBUG - received: b'7102000000' 2020-03-30 16:14:31,185 - DEBUG - received: b'01' 2020-03-30 16:14:31,186 - DEBUG - received: b'' 2

Any idea on how I can solve this "offset" problem that starts with the "True" (I tried requesting other values before the rtc variables, like txts form labels, and the first returned value is always "True"), and the first error, avoiding to add delays?

Thanks in advance!

[yozik04]

Never do time.sleep in an async function. Do asyncio.sleep. It is very important! Replace and rerun.

[Chronocento]

Sorry, I'm not well versed in asynchronous programming, and I didn't stop to think about the dumbness of putting a synchronous delay in asynchronous code.

About your suggestion:

print(await client.get('rtc3')) asyncio.sleep(1) print(await client.get('rtc4')) asyncio.sleep(1) print(await client.get('rtc2')) asyncio.sleep(1) print(await client.get('rtc1')) asyncio.sleep(1) print(await client.get('rtc0'))

Returns:

2020-03-31 09:05:04,896 - INFO - Successfully connected to the device 2020-03-31 09:05:04,897 - DEBUG - sent: b'get rtc3' 2020-03-31 09:05:04,902 - DEBUG - received: b'01' 2020-03-31 09:05:04,903 - DEBUG - received: b'' True 2020-03-31 09:05:04,904 - DEBUG - sent: b'get rtc4' 2020-03-31 09:05:04,918 - DEBUG - received: b'7107000000' 2020-03-31 09:05:04,919 - DEBUG - received: b'' 7 2020-03-31 09:05:04,921 - DEBUG - sent: b'get rtc2' 2020-03-31 09:05:04,927 - DEBUG - received: b'01' 2020-03-31 09:05:04,928 - DEBUG - received: b'71140000' 2020-03-31 09:05:04,930 - ERROR - Task exception was never retrieved future: <Task finished coro=<run() done, defined at nextion_time.py:15> exception=error('unpack requires a bytes object of length 4',)> Traceback (most recent call last): File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step result = coro.send(None) File "nextion_time.py", line 64, in run print(await client.get('rtc2')) File "/usr/local/lib/python3.5/dist-packages/nextion/client.py", line 136, in get return await self.command('get %s' % key) File "/usr/local/lib/python3.5/dist-packages/nextion/client.py", line 192, in command data = struct.unpack('i', raw)[0] struct.error: unpack requires a bytes object of length 4 2020-03-31 09:05:04,936 - DEBUG - received: b'7114000000' 2020-03-31 09:05:04,937 - DEBUG - received: b'01' 2020-03-31 09:05:04,938 - DEBUG - received: b'' 2020-03-31 09:05:04,946 - DEBUG - received: b'710f000000' 2020-03-31 09:05:04,946 - DEBUG - received: b'' 2020-03-31 09:05:04,953 - DEBUG - received: b'01' 2020-03-31 09:05:04,954 - DEBUG - received: b''

The same error as my first try in the OP, where I didn't put any delay; also, the first result is still "True", instead of the value of rtc3, that is then displayed in the next return (when I call for rtc4). Any idea? Thanks for your time!

[yozik04]

I am trying to understand why you receive 3 bytes of data 71140000 instead of 4 710f000000.

[yozik04]

I have released 1.3.0 where you can specify timeout for get command. Maybe RTC is slow and requires more time. Try to put a bigger number than 0.15 (default)

[Chronocento]

Thank you for your efforts! I updated to 1.3.0, but there's still this "3 bytes problem".

This is the full code (I tried increasing IO_TIMEOUT gradually: 0.30, 0.5, and finally, 1.0):

import asyncio
import logging
import random

from nextion import Nextion, EventType

def event_handler(type_, data):
    if type_ == EventType.STARTUP:
        print('We have booted up!')

    #logging.info('Event %s data: %s' % type, str(data))
    logging.info('Data: ' + str(type(data)))

async def run():
    IO_TIMEOUT = 1.0
    client = Nextion('/dev/ttyAMA0', 9600, event_handler)
    await client.connect()

    print(await client.get('rtc3'))
    print(await client.get('rtc4'))
    print(await client.get('rtc2'))
    print(await client.get('rtc1'))
    print(await client.get('rtc0'))

    print('finished')

if __name__ == '__main__':
    logging.basicConfig(
        format='%(asctime)s - %(levelname)s - %(message)s',
        level=logging.DEBUG,
        handlers=[
            logging.StreamHandler()
        ])
    loop = asyncio.get_event_loop()
    asyncio.ensure_future(run())
    loop.run_forever()

But the error, and the "offset", is still there:

2020-03-31 16:07:45,492 - INFO - Connecting: /dev/ttyAMA0, baud: 9600 2020-03-31 16:07:45,494 - INFO - Connected to serial 2020-03-31 16:07:45,495 - DEBUG - sent: b'' 2020-03-31 16:07:45,497 - DEBUG - sent: b'connect' 2020-03-31 16:07:45,593 - DEBUG - received: b'636f6d6f6b20312c33303631342d302c4e58343833324b3033355f303131522c3133382c36313639392c444236393043313544333232333932442c3333353534343332' 2020-03-31 16:07:45,593 - DEBUG - received: b'' 2020-03-31 16:07:45,595 - INFO - Detected model: NX4832K035_011R 2020-03-31 16:07:45,596 - INFO - Firmware version: 138 2020-03-31 16:07:45,597 - INFO - Serial number: DB690C15D322392D 2020-03-31 16:07:45,597 - DEBUG - Flash size: 33554432 2020-03-31 16:07:45,598 - DEBUG - Dropping dangling: b'' 2020-03-31 16:07:45,598 - DEBUG - sent: b'bkcmd=3' 2020-03-31 16:07:45,617 - DEBUG - received: b'01' 2020-03-31 16:07:45,618 - DEBUG - received: b'' 2020-03-31 16:07:45,620 - DEBUG - sent: b'get sleep' 2020-03-31 16:07:45,641 - DEBUG - received: b'7100000000' 2020-03-31 16:07:45,642 - DEBUG - received: b'' 2020-03-31 16:07:45,644 - INFO - Successfully connected to the device 2020-03-31 16:07:45,645 - DEBUG - sent: b'get rtc3' 2020-03-31 16:07:45,649 - DEBUG - received: b'01' 2020-03-31 16:07:45,650 - DEBUG - received: b'' True 2020-03-31 16:07:45,652 - DEBUG - sent: b'get rtc4' 2020-03-31 16:07:45,665 - DEBUG - received: b'710f000000' 2020-03-31 16:07:45,666 - DEBUG - received: b'' 15 2020-03-31 16:07:45,668 - DEBUG - sent: b'get rtc2' 2020-03-31 16:07:45,675 - DEBUG - received: b'01' 2020-03-31 16:07:45,675 - DEBUG - received: b'71160000' 2020-03-31 16:07:45,678 - ERROR - Task exception was never retrieved future: <Task finished coro=<run() done, defined at nextion_time.py:15> exception=error('unpack requires a bytes object of length 4',)> Traceback (most recent call last): File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step result = coro.send(None) File "nextion_time.py", line 66, in run print(await client.get('rtc2')) File "/usr/local/lib/python3.5/dist-packages/nextion/client.py", line 157, in get return await self.command("get %s" % key, timeout=timeout) File "/usr/local/lib/python3.5/dist-packages/nextion/client.py", line 221, in command data = struct.unpack("i", raw)[0] struct.error: unpack requires a bytes object of length 4 2020-03-31 16:07:45,684 - DEBUG - received: b'7116000000' 2020-03-31 16:07:45,684 - DEBUG - received: b'01' 2020-03-31 16:07:45,685 - DEBUG - received: b'' 2020-03-31 16:07:45,693 - DEBUG - received: b'7111000000' 2020-03-31 16:07:45,694 - DEBUG - received: b'' 2020-03-31 16:07:45,701 - DEBUG - received: b'01' 2020-03-31 16:07:45,702 - DEBUG - received: b''

Is there any way I can help you tracing the reason of this problem?

[yozik04]

According to spec:

26 | 0x71 | 8 | Numeric Data Enclosed | 0x71 0x01 0x02 0x03 0x04 0xFF 0xFF 0xFF Returned when get command to return a number 4 byte 32-bit value in little endian order. (0x01+0x02256+0x0365536+0x04*16777216) data: 67305985

So my code does exactly what is in spec.

Can you check what responses you get in emulator for get rtc calls?

[yozik04]

Alternatively you can always collect all rtc values to a string and read that string from python.

[yozik04]

Also maybe RTC values need to be set to valid datetime before first use?

[Chronocento]

Sorry for my late reply, in the meantime I tried to do some tests to understand the issue.

About RTC, I manage to set the proper values before trying to read directly from rtc* (I know because rtc6, that acts as a sort of "checksum", returning the number of the day of the week, calculates it correctly).

I tried to read directly data from serial with some simple Python code:

import serial 

def main():
    port=serial.Serial(port='/dev/ttyAMA0',baudrate=9600, timeout=1.0)
    eof = b'\xff\xff\xff'

    port.write(b'get rtc0' + eof)
    print(readData(port))
    port.write(b'get rtc1' + eof)
    print(readData(port))

def readData(port):
    i = 0
    buffer = ""
    while True:
        oneByte = port.read(1)
        if oneByte == b"\xff": 
            i+=1
            if i==3:
                return buffer[1:]
        else:
            buffer += oneByte.decode("ascii")

if __name__ == "__main__":
    main()

This led quickly to this error:

Traceback (most recent call last): File "test.py", line 37, in main() File "test.py", line 10, in main print(readData(port)) File "test.py", line 34, in readData buffer += oneByte.decode("ascii") UnicodeDecodeError: 'ascii' codec can't decode byte 0xe4 in position 0: ordinal not in range(128)

That may be related to this one:

b'\x00\x00\x00\x00' 2020-04-09 10:35:00,072 - DEBUG - sent: b'get rtc0' 2020-04-09 10:35:00,078 - DEBUG - received: b'01' 2020-04-09 10:35:00,079 - DEBUG - received: b'' True 2020-04-09 10:35:00,081 - DEBUG - sent: b'get rtc1' 2020-04-09 10:35:00,093 - DEBUG - received: b'71e4070000' 2020-04-09 10:35:00,094 - DEBUG - received: b'' b'\xe4\x07\x00\x00' 2020 2020-04-09 10:35:00,096 - DEBUG - sent: b'get rtc2' 2020-04-09 10:35:00,102 - DEBUG - received: b'01' 2020-04-09 10:35:00,103 - DEBUG - received: b'71040000' b'\x04\x00\x00' Traceback (most recent call last): File "nex.py", line 75, in main() File "nex.py", line 72, in main result = loop.run_until_complete(run()) File "/usr/lib/python3.5/asyncio/base_events.py", line 466, in run_until_complete return future.result() File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result raise self._exception File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step result = coro.send(None) File "nex.py", line 55, in run print(await client.command('get rtc2')) File "/usr/local/lib/python3.5/dist-packages/nextion/client.py", line 222, in command data = struct.unpack("i", raw)[0] struct.error: unpack requires a bytes object of length 4

That happens when I execute this code that uses your library:

import asyncio
import logging

from nextion import Nextion, EventType

r = redis.Redis()

def event_handler(type_, data):
    if type_ == EventType.STARTUP:
        print('We have booted up!')

    logging.info('Event %s data: %s', type, str(data))

client = Nextion('/dev/ttyAMA0', 9600, event_handler)
loop = asyncio.get_event_loop()
result = loop.run_until_complete(client.connect())

async def run():
    print(await client.command('get rtc0'))
    print(await client.command('get rtc1'))
    print(await client.command('get rtc2'))
    print(await client.command('get rtc3'))

def main():
    logging.basicConfig(
        format='%(asctime)s - %(levelname)s - %(message)s',
        level=logging.DEBUG,
        handlers=[
            logging.StreamHandler()
        ])
    #while True:
    loop = asyncio.get_event_loop()
    result = loop.run_until_complete(run())

if __name__ == "__main__":
    main()

So, I decided to follow your advice and read data from a txt/string element, swapping the code in the run(), with this:

print(await client.get('t14.txt'))
print(await client.get('t15.txt'))
print(await client.get('t16.txt'))
print(await client.get('t17.txt'))
print(await client.get('t18.txt'))

But it still presents a True as the first result, while the actual value is returned with the get to the second value (there's still that "offset": t18.txt should return 2020):

b'\x00\x00\x00\x00' 2020-04-09 10:39:24,581 - DEBUG - sent: b'get t14.txt' 2020-04-09 10:39:24,585 - DEBUG - received: b'01' 2020-04-09 10:39:24,586 - DEBUG - received: b'' True 2020-04-09 10:39:24,588 - DEBUG - sent: b'get t15.txt' 2020-04-09 10:39:24,604 - DEBUG - received: b'703132' 2020-04-09 10:39:24,605 - DEBUG - received: b'01ff' 2020-04-09 10:39:24,607 - ERROR - Unknown data received: b'01ff' 2020-04-09 10:39:24,610 - DEBUG - received: b'01' 2020-04-09 10:39:24,611 - DEBUG - received: b'' 12 2020-04-09 10:39:24,613 - DEBUG - sent: b'get t16.txt' 2020-04-09 10:39:24,619 - DEBUG - received: b'703430' 2020-04-09 10:39:24,620 - DEBUG - received: b'01ff' 2020-04-09 10:39:24,621 - ERROR - Unknown data received: b'01ff' 2020-04-09 10:39:24,625 - DEBUG - received: b'01' 2020-04-09 10:39:24,625 - DEBUG - received: b'' 40 2020-04-09 10:39:24,628 - DEBUG - sent: b'get t17.txt' 2020-04-09 10:39:24,637 - DEBUG - received: b'7039' 2020-04-09 10:39:24,637 - DEBUG - received: b'01ffff' 2020-04-09 10:39:24,639 - ERROR - Unknown data received: b'01ffff' 2020-04-09 10:39:24,641 - DEBUG - received: b'01' 2020-04-09 10:39:24,642 - DEBUG - received: b'' 9 2020-04-09 10:39:24,644 - DEBUG - sent: b'get t18.txt' 2020-04-09 10:39:24,652 - DEBUG - received: b'7034' 2020-04-09 10:39:24,653 - DEBUG - received: b'01ffff' 2020-04-09 10:39:24,655 - ERROR - Unknown data received: b'01ffff' 2020-04-09 10:39:24,656 - DEBUG - received: b'01' 2020-04-09 10:39:24,657 - DEBUG - received: b'' 4

So, I decided to reuse that simple code that I wrote, asking for the same txts:

port.write(b'get t14.txt' + eof)
print(readData(port))
port.write(b'get t15.txt' + eof)
print(readData(port))
port.write(b'get t16.txt' + eof)
print(readData(port))
port.write(b'get t17.txt' + eof)
print(readData(port))
port.write(b'get t18.txt' + eof)
print(readData(port))

And I discovered something interesting: if I run it after running the code that uses your library, this is the result (hour, minutes and day of the month)

12

49

9

While if I run it after having powered off and on the screen, the data is received correctly (hour, minuter, day of the month, month, year):

12 49 9 4 2020

So I started to wonder... could it be that, somehow, with your code, the serial is not cleared correctly after reading? I tried to get some insights modifying your code (that's why in the logs that uses your library you read b'\x00\x00\x00\x00' and alike here and there), but I didn't manage to grasp its working, so I preferred to share what I "discovered", hoping of not offending you with my statement. What do you think?

[yozik04]

Not offending for sure.

There is such a command bkcmd=3. It is called with my lib when connected first time. If you keep the script running and replug the panel this command won't be issued. I guess. Then my lib fails to read expected reply. Can it be the case?

[yozik04]

Found a bug. Fixing. Thank you for the debug.

[Chronocento]

Great! Glad that I helped somehow. Are you releasing a new version, or do I have to manually edit the library to add the fix?

[yozik04]

Fixing consequences of this change. I will notify when ready.

[Chronocento]

Ok, thank you!

[yozik04]

Try 1.4.0

[yozik04]

maybe all initial rtc stuff will just work now.

[Chronocento]

Just tried: it's perfect! Thanks!!! Tried both reading from txt and rtc*:

2020-04-09 15:44:54,448 - DEBUG - sent: b'get t14.txt' 2020-04-09 15:44:54,472 - DEBUG - received: b'703137' 2020-04-09 15:44:54,478 - DEBUG - received: b'01' 17 2020-04-09 15:44:54,479 - DEBUG - sent: b'get t15.txt' 2020-04-09 15:44:54,503 - DEBUG - received: b'703435' 2020-04-09 15:44:54,509 - DEBUG - received: b'01' 45 2020-04-09 15:44:54,510 - DEBUG - sent: b'get t16.txt' 2020-04-09 15:44:54,534 - DEBUG - received: b'7039' 2020-04-09 15:44:54,538 - DEBUG - received: b'01' 9 2020-04-09 15:44:54,540 - DEBUG - sent: b'get t17.txt' 2020-04-09 15:44:54,564 - DEBUG - received: b'7034' 2020-04-09 15:44:54,568 - DEBUG - received: b'01' 4 2020-04-09 15:44:54,569 - DEBUG - sent: b'get t18.txt' 2020-04-09 15:44:54,593 - DEBUG - received: b'7032303230' 2020-04-09 15:44:54,601 - DEBUG - received: b'01' 2020

2020-04-09 15:45:34,994 - DEBUG - sent: b'get rtc0' 2020-04-09 15:45:35,015 - DEBUG - received: b'71e4070000' 2020-04-09 15:45:35,023 - DEBUG - received: b'01' 2020 2020-04-09 15:45:35,025 - DEBUG - sent: b'get rtc1' 2020-04-09 15:45:35,046 - DEBUG - received: b'7104000000' 2020-04-09 15:45:35,054 - DEBUG - received: b'01' 4 2020-04-09 15:45:35,056 - DEBUG - sent: b'get rtc2' 2020-04-09 15:45:35,077 - DEBUG - received: b'7109000000' 2020-04-09 15:45:35,085 - DEBUG - received: b'01' 9 2020-04-09 15:45:35,086 - DEBUG - sent: b'get rtc3' 2020-04-09 15:45:35,107 - DEBUG - received: b'7111000000' 2020-04-09 15:45:35,115 - DEBUG - received: b'01' 17

I know that I can read the fixes, but if you had to summarize, what was/were the problem(s)?

[yozik04]

If a payload was read in multiple chunks then my lib failed to properly collect the chunks and split it into messages. Actually a stupid bug. test_protocol.py now covers it.