JoelBender / bacpypes

BACpypes provides a BACnet application layer and network layer written in Python for daemons, scripting, and graphical interfaces.
MIT License
302 stars 129 forks source link

Erroneous Day-of-week code in packet when building readRange log-buffer request with time-range #523

Closed TomasPaier closed 6 months ago

TomasPaier commented 7 months ago

Hello, When I try to readRange log-buffer of a trend-log with time-range option (using BAC0, but I think it is probably a bacpypes issue), the packet contains erroneous day-of-week indication, and thus it is completely REFUSED by the controller (Delta Controls ORCA, in this case).

With a call: TL=bacnet.readRange("192.168.192.99 trendLog 1 logBuffer", ("t", None, "2024-04-05", "19:23:00", 10000)) the packet contains the correct date (today - April, 5) BUT it says it is THURSDAY (value 4) (while today is definitely Friday). Wireshark says:

Frame 300: 74 bytes on wire (592 bits), 74 bytes captured (592 bits) on interface \Device\NPF_{5177C9A4-E780-4068-A516-F357E3201967}, id 0
Ethernet II, Src: 0a:00:27:00:00:0d (0a:00:27:00:00:0d), Dst: PCSSystemtec_85:8f:9c (08:00:27:85:8f:9c)
Internet Protocol Version 4, Src: 192.168.192.168, Dst: 192.168.192.99
User Datagram Protocol, Src Port: 47808, Dst Port: 47808
BACnet Virtual Link Control
Building Automation and Control Network NPDU
Building Automation and Control Network APDU
    0000 .... = APDU Type: Confirmed-REQ (0)
    .... 0010 = PDU Flags: 0x2
    .111 .... = Max Response Segments accepted: Greater than 64 segments (7)
    .... 0100 = Size of Maximum ADPU accepted: Up to 1024 octets (4)
    Invoke ID: 39
    Service Choice: readRange (26)
    ObjectIdentifier: trend-log, 1
    Property Identifier: log-buffer (131)
    range byTime
        {[7]
        reference Date/Time: 
            Date: April 5, 2024, (Day of Week = Thursday)
                Application Tag: Date, Length/Value/Type: 4
                    .... 0... = Tag Class: Application Tag
                    1010 .... = Application Tag Number: Date (10)
                    Length Value Type: 4
            Time: 7:23:00.0 P.M. = 19:23:00.0
                Application Tag: Time, Length/Value/Type: 4
                    .... 0... = Tag Class: Application Tag
                    1011 .... = Application Tag Number: Time (11)
                    Length Value Type: 4
        reference Count: (Signed) 10000
        }[7]

immagine

I've done many tries: the only day it works is 1970-01-01 when the weekday is for some reason "Any" = 0xff; any other day is shifted by one. While this issue is probably generally ignored by many devices, the Delta is aware of the correct weekday and thus it (correctly) refuses the request with value-out-of-range error.

Is there a way / simple patch? (I'm on bacpypes 0.18.7) I think the simplest way could be to build all these packets just with "Any" weekday code (255); the weekday is not important here. But maybe this issue is related also with some other consequences I'm not aware of. Maybe the issue is somewhere in primitivedata.py, but I'm not experienced enough to not create a bigger problem then the current. However, I'd need to solve it in some quick way...

Let me know if you need any further details...

Thank you a lot!

JoelBender commented 7 months ago

Humm... a puzzler. First build the structure...

>>> from bacpypes.primitivedata import Date, Time
>>> from bacpypes.basetypes import DateTime
>>> from bacpypes.apdu import RangeByTime
>>> y = RangeByTime(referenceTime=DateTime(date=Date("2024-04-05"), time=Time("19:23:00.0")), count=10000)

Now try the encoding...

>>> from bacpypes.primitivedata import TagList
>>> t = TagList()
>>> y.encode(t)
>>> t.debug_contents()
        <bacpypes.primitivedata.Tag(date) instance at 0x7acc86f56f80>
            tagClass = 0 application
            tagNumber = 10 date
            tagLVT = 4
            tagData = '7c.04.05.05'
        <bacpypes.primitivedata.Tag(time) instance at 0x7acc86f56e60>
            tagClass = 0 application
            tagNumber = 11 time
            tagLVT = 4
            tagData = '13.17.00.00'
        <bacpypes.primitivedata.Tag(integer) instance at 0x7acc86f57310>
            tagClass = 0 application
            tagNumber = 3 integer
            tagLVT = 2
            tagData = '27.10'

So something else is happening.

According to Clause 20.2.12:

The processing of a day of week received in a service that is in the range 1 to 7 and is inconsistent with the values in the other octets shall be a local matter.

So refused by Delta and accepted by others is accepted.

TomasPaier commented 7 months ago

Hello Joel, Thank you for the analysis! Hmmm.... I've tried the SAME operations on my system:

from bacpypes.primitivedata import Date, Time
from bacpypes.basetypes import DateTime
from bacpypes.apdu import RangeByTime
y = RangeByTime(referenceTime=DateTime(date=Date("2024-04-05"), time=Time("19:23:00.0")), count=10000)

from bacpypes.primitivedata import TagList
t = TagList()
y.encode(t)
t.debug_contents()

But my output is DIFFERENT:

        <bacpypes.primitivedata.Tag(date) instance at 0x18064d40dd0>
            tagClass = 0 application
            tagNumber = 10 date
            tagLVT = 4
            tagData = '7c.04.05.04'
        <bacpypes.primitivedata.Tag(time) instance at 0x1806511aa10>
            tagClass = 0 application
            tagClass = 0 application
            tagNumber = 3 integer
            tagLVT = 2
            tagData = '27.10'

(Please note: tagData = '7c.04.05.04 -- so, Thursday here! ;-) )

Just after y = RangeByTime... I'm seeing: immagine

So, it seems to me the issue depends on system locals, or something like that. The bad weekday is there before encoding the tag. I'm on Windows 11 with default ITALIAN locales, python 3.11, bacpypes 0.18.7.

I agree the way Delta controller is decoding the packet is too much "sensible" which doesn't help, however, I can do nothing with it. Maybe there are another controllers in the wild with similar behavior, maybe not. However, the packet built by the library should be correct anyway...

I will try to dive into the RangeByTime function in the meantime... Thank you, have a nice day!

JoelBender commented 7 months ago

The calculation is done by mktime() here, this could be a time zone and/or daylight savings time problem.

TomasPaier commented 7 months ago

Hello Joel, Another update: I think I got it.

The critical code is in primitivedata.py on rows 1449-1450:

                today = time.mktime( (year + 1900, month, day, 0, 0, 0, 0, 0, -1) )
                day_of_week = time.gmtime(today)[6] + 1

See these tries:

time.gmtime(time.mktime( (2024, 4, 7, 0, 0, 0, 0, 0, 0) ))
time.struct_time(tm_year=2024, tm_mon=4, tm_mday=6, tm_hour=23, tm_min=0, tm_sec=0, tm_wday=5, tm_yday=97, tm_isdst=0)

time.gmtime(time.mktime( (2024, 4, 7, 0, 0, 0, 0, 0, 1) ))
time.struct_time(tm_year=2024, tm_mon=4, tm_mday=6, tm_hour=22, tm_min=0, tm_sec=0, tm_wday=5, tm_yday=97, tm_isdst=0)

time.gmtime(time.mktime( (2024, 4, 7, 0, 0, 0, 0, 0, -1) ))
time.struct_time(tm_year=2024, tm_mon=4, tm_mday=6, tm_hour=22, tm_min=0, tm_sec=0, tm_wday=5, tm_yday=97, tm_isdst=0)

time.gmtime(time.mktime( (2024, 4, 7, 0, 0, 0, 0, 0, -2) ))
time.struct_time(tm_year=2024, tm_mon=4, tm_mday=6, tm_hour=22, tm_min=0, tm_sec=0, tm_wday=5, tm_yday=97, tm_isdst=0)

time.gmtime(time.mktime( (2024, 4, 7, 0, 0, 0, 0, 0, -3) ))
time.struct_time(tm_year=2024, tm_mon=4, tm_mday=6, tm_hour=22, tm_min=0, tm_sec=0, tm_wday=5, tm_yday=97, tm_isdst=0)

time.gmtime(time.mktime( (2024, 4, 7, 0, 0, 0, 0, 0, -4) ))
time.struct_time(tm_year=2024, tm_mon=4, tm_mday=6, tm_hour=22, tm_min=0, tm_sec=0, tm_wday=5, tm_yday=97, tm_isdst=0)

time.gmtime(time.mktime( (2024, 4, 7, 0, 0, 0, 0, 0, 4) ))
time.struct_time(tm_year=2024, tm_mon=4, tm_mday=6, tm_hour=22, tm_min=0, tm_sec=0, tm_wday=5, tm_yday=97, tm_isdst=0)

What we're seeing here is in fact very clear: I'm asking for the date 2024-04-07 00:00 LOCAL TIME (I'm in CEST = UTC+2). The gmtime function however returns to me the correct date (and weekday) for exactly that moment in LONDON (UTC) timezone -- thus (as you can see from EVERY response) 2024-04-06 22:00. And this is ANOTHER day and thus another weekday. You're not experiencing this issue just because you're in UTC-xx and thus your "midnight" 00:00 weekday corresponds with that of London.

The solution seems to be very simple: on row 1450 of primitivedata.py, use localtime instead of gmtime: day_of_week = time.localtime(today)[6] + 1

From https://docs.python.org/3/library/time.html _time.mktime(t) This is the inverse function of localtime(). Its argument is the structtime or full 9-tuple (since the dst flag is needed; use -1 as the dst flag if it is unknown) which expresses the time in local time, not UTC. What we need here is the INVERSE function for mktime -- thus: localtime.

I've tested the patch here, and it works fine; please test it in your timezone, just to be sure...

Another solution (using datetime library, more straightforward) could be (rows 1449-1450):

                from datetime import datetime
                day_of_week = datetime (year + 1900, month, day).weekday() + 1

(Also this version tested here with success.)

Thank you for providing the whole bacpypes library which is really useful! Have a nice day!

TomasPaier commented 7 months ago

Wow, we both updated this thread in exactly the SAME time... :-)

JoelBender commented 7 months ago

Thank you for hunting this down! I'll be able to try this out later "today" :-).