Possible issue with time profiles #5

amprim · 2022-10-14T13:28:37Z

Hello! I'm not sure if this is an issue with uhppote-simulator, or if I'm doing something wrong - any guidance you can provide would be greatly appreciated.

Background

I'm working on a Python tool (using the uhppote-dll Python bindings) to allow my local makerspace's membership tooling to automatically sync door access to our Uhppote access control boards. I'm in the process of finishing the tool, and am working to expand testing. However, I appear to either be misunderstanding how time profiles work, or have disocvered a bug with uhppote-simulator, which I am using for initial testing in lieu of physical hardware.

Scenario

As part of testing, I stand up a simulator instance and expose a quick method to perform simulated card swipes. I then take the system through the process of syncing several test users/cards, and verifying that they have access only at the appropriate times. Between each test, I use the set-time function to change the simulator's time, then check to see if access is allowed or denied, based on the card's configured access.

Issue

Time profiles do not appear to be working correctly. When setting access to 1 (24/7) for a door, the card(s) work correctly. When setting to a defined time profile, access is variably granted/denied both outside and within the defined ranges of the profile. I've tried converting some/all times to UTC, which does not seem to help.

At time of last testing (9AM Eastern on October 14), test 1 for card 2 succeeds (access is denied prior to the time profile range), but test 2 fails (access is denied during the time profile range). Earlier, both test 1 and test 2 failed (i.e access granted before profile range, and denied during). My current best guess is that the simulator may not be respecting the time set by set-time when calculating time profile accesses. As a quick test, I changed the ranges below to encompass my current time, and the profile suddenly worked.

Issue encountered on Linux x86_64 (PopOS/Ubuntu 22.04 LTS).

Steps to Reproduce

I whipped up the following scripts to quickly reproduce the issue, using uhppote-simulator and uhppote-cli. This is essentially part of my Python tool testing, rewritten for Bash/uhppote-cli.

First, create test-cli.conf with the following contents:

UT0311-L0x.123456789.name = Test
UT0311-L0x.123456789.address = 127.0.0.1:60000
UT0311-L0x.123456789.door.1 = Front Door
UT0311-L0x.123456789.door.2 = Lobby
UT0311-L0x.123456789.door.3 = IT Room
UT0311-L0x.123456789.door.4 = Back Door
UT0311-L0x.123456789.timezone = UTC

Next, create test-cli.sh with the following contents.

curl -X POST http://127.0.0.1:8000/uhppote/simulator -H 'Content-Type: application/json' -d '{"device-id": 123456789, "device-type": "UT0311-L04", "compressed": false}'

# set profiles for "junior members" - 5-10 weekends, 12-5 weekends
./uhppote-cli --config test_cli.conf set-time-profile 123456789 3 1970-01-01:2099-12-31 Sat,Sun 11:45-17:15
./uhppote-cli --config test_cli.conf set-time-profile 123456789 2 1970-01-01:2099-12-31 Mon,Tue,Wed,Thu,Fri 16:45-22:15 3

# set cards, one full access, one "junior"
./uhppote-cli --config test_cli.conf put-card 123456789 00154321 1970-01-01 2099-12-31 1,2,4
./uhppote-cli --config test_cli.conf put-card 123456789 00112345 1970-01-01 2099-12-31 1:2,2:2,4:2

# set time and check access

# test 1 - door 1 prior to time on Monday
# card 1 should have access, card 2 should not
./uhppote-cli --config test_cli.conf set-time 123456789 '2022-10-03 16:35:00'  # monday
out=$(curl -s -X POST http://127.0.0.1:8000/uhppote/simulator/123456789/swipe -H 'Content-Type: application/json' -d '{"door": 1, "card-number": 154321}')
if [ "$out" != '{"access-granted":true,"message":"Access granted"}' ]; then
	  echo "card 154321 test 1 - access not allowed when it should be granted!"
	  echo "$out"
else
	  echo "card 154321 test 1 - access OK (granted)!"
fi

out=$(curl -s -X POST http://127.0.0.1:8000/uhppote/simulator/123456789/swipe -H 'Content-Type: application/json' -d '{"door": 1, "card-number": 112345}')
if [ "$out" != '{"access-granted":false,"message":"Access denied"}' ]; then
	  echo "card 112345 test 1 - access allowed when it should be denied!"
	  echo "$out"
else
	  echo "card 112345 test 1 - access OK (denied)!"
fi


# test 2 - door 1 during time on Monday
# both cards should have access
./uhppote-cli --config test_cli.conf set-time 123456789 '2021-10-03 16:55:00'
for card in 154321 112345; do
	  out=$(curl -s -X POST http://127.0.0.1:8000/uhppote/simulator/123456789/swipe -H 'Content-Type: application/json' -d "{\"door\": 1, \"card-number\": $card}")
	  if [ "$out" != '{"access-granted":true,"message":"Access granted"}' ]; then
	  	  echo "card $card test 2 - access not allowed when it should be granted!"
	  	  echo "$out"
	  else
	  	  echo "card $card test 2 - access OK (granted)!"
	  fi
done


echo ""
echo "current time is: $(./uhppote-cli --config test_cli.conf get-time 123456789)"
echo "card 1 data is: $(./uhppote-cli --config test_cli.conf get-card 123456789 112345)"
echo "card 2 data is: $(./uhppote-cli --config test_cli.conf get-card 123456789 154321)"
echo "profile 2 is: $(./uhppote-cli --config test_cli.conf get-time-profile 123456789 2)"
echo "profile 3 is: $(./uhppote-cli --config test_cli.conf get-time-profile 123456789 3)"

Next, create run-sim.sh with the following contents. This assumes that uhppote-simulator is available in the same directory. The fix in this file is related to another bug - I'll file a separate issue on that.

# fix for simulator refusing to startup when a config file is present
if [ -f "/tmp/123456789.json" ]; then
	  rm "/tmp/123456789.json"
fi
./uhppote-simulator --bind 127.0.0.1:60000 --rest 127.0.0.1:8000 --devices /tmp/

Finally, run run-sim.sh and test-cli.sh in seperate terminal windows. Be sure to run run-sim.sh first, and leave it running until done with test-cli.sh (CTRL+C to exit when done with it)!

Sample output:

123456789: time profile 3 created
123456789: time profile 2 created
123456789 154321 true
123456789 112345 true
123456789  2022-10-03 16:35:00
card 154321 test 1 - access OK (granted)!
card 112345 test 1 - access OK (denied)!
123456789  2021-10-03 16:55:00
card 154321 test 2 - access OK (granted)!
card 112345 test 2 - access not allowed when it should be granted!
{"access-granted":false,"message":"Access denied"}

current time is: 123456789  2021-10-03 16:55:00
card 1 data is: 123456789  112345   1970-01-01 2099-12-31 2 2 N 2
card 2 data is: 123456789  154321   1970-01-01 2099-12-31 Y Y N Y
profile 2 is: 123456789  2 1970-01-01:2099-12-31 Mon,Tue,Wed,Thurs,Fri 16:45-22:15 3
profile 3 is: 123456789  3 1970-01-01:2099-12-31 Sat,Sun 11:45-17:15 0

Again, not sure if this is an issue with the simulator, or if I'm missing something with the time profiles. I have a physical board and am planning to test with that as well, but I am currently waiting on some parts to get it hooked up.

Thank you in advance for your assistance!

The text was updated successfully, but these errors were encountered:

uhppoted · 2022-10-14T16:39:28Z

Thank you for the detailed bug report - makes things so much easier!

It looks like it's probably a bug in the simulator checkTimeProfile function:

func checkTimeProfile(profile types.TimeProfile) bool {
	now := types.HHmmFromTime(time.Now())
	today := types.Date(time.Now())
       ...

It's using the system time and not the simulated controller time. Nice catch!

)

uhppoted · 2022-10-14T22:30:05Z

Hi,

I've pushed a (provisional) fix to the master branch - it seems to work ok with your configuration and scripts (they were very helpful, thanks):

uhppoted@uhppoted:/opt/uhppoted/uhppote-cli$ ./test-cli.sh 
123456789: time profile 3 created
123456789: time profile 2 created
123456789 154321 true
123456789 112345 true
123456789  2022-10-03 16:35:00
card 154321 test 1 - access OK (granted)!
card 112345 test 1 - access OK (denied)!
123456789  2021-10-03 16:55:00
card 154321 test 2 - access OK (granted)!
card 112345 test 2 - access OK (granted)!

current time is: 123456789  2021-10-03 16:55:00
card 1 data is: 123456789  112345   1970-01-01 2099-12-31 2 2 N 2
card 2 data is: 123456789  154321   1970-01-01 2099-12-31 Y Y N Y
profile 2 is: 123456789  2 1970-01-01:2099-12-31 Mon,Tue,Wed,Thurs,Fri 16:45-22:15 3
profile 3 is: 123456789  3 1970-01-01:2099-12-31 Sat,Sun 11:45-17:15 0

I still need to wrap my head around some edge cases (e.g. what happens at day boundaries, etc) but hopefully you should be able to continue testing for the interim. Well, at least if you're not working around midnight anyway!

You'll need to grab the latest and greatest from the repo and build it but that's pretty straightforward - let me know if you run into anything.

amprim · 2022-10-14T23:23:39Z

The fix is partially working on my end - it appears that the local time zone setting may still be affecting things. I could not get the fix working until I either set my local timezone to UTC, or put the 16:XX timestamps forward by 4 hours (I'm in EDT, which is UTC-4). Without doing that, card 112345 test 2 still fails.

EDIT: Just remembered the timezone setting in the config file. Changing that appears to have no effect.

uhppoted · 2022-10-15T03:40:23Z

Time zones are the bane of my existence!

However, reworking the time profile stuff to consistently reference everything to UTC seems to have it sorted:

the unit tests now pass on my laptop and also on the github server (which I seems to recall from previous differences of opinion with time zones is most often EDT)
the unit tests and your script pass in a VPS on UTC
the unit tests and your script pass in a VPS on EDT

Let me know if it works for you..

The timezone setting in the config file is only for the client side (CLI in this case) - the simulator doesn't use it so it makes sense that changing it had no effect.

amprim · 2022-10-16T02:08:35Z

Well, this is fun. The previous failure (card 112345 test 2) is resolved, but card 112345 test 1 is now failing (access is being granted prior to the configured profile). Changing timezone no longer affects things, though putting the 16:XX times forward 4 hours resolves the new failure and causes the previous failure. Any ideas?

EDIT: spinning up a VM to test as well, in case it's just my system being stupid.

uhppoted · 2022-10-16T02:53:25Z

a.k.a. as time zone whack-a-mole!

I have a sneaking suspicion it might be something to do with day boundaries (EDT10pm is around UTC 02h00) but if it is that, it's really not clear why (and the also the github workflow should fail but doesn't).

I'm afraid I'm going to have to ask you run with a debugging build - I've added a whole bunch of debugging output to the checkTimeProfile routine, so if you could grab the latest from the master branch and run with that it should print out a whole slew of information. Maybe there's a clue in there somewhere..

Also:

Could you please include the output from a timedatectl on your system just before each run?
I'd be curious to know if the issue also occurs when you and UTC are in the same day
I'd really like to know if the unit tests pass on your system:
- make test runs all the tests
- make debug runs just the time profile tests and also prints out all the debug information

amprim · 2022-10-16T03:28:07Z

Was just typing an edit to the above when you posted! I was wondering about the new CHECK TIME PROFILE output on the VM...

One note: the above test script has one minor issue - the second set_time call should be for 2022-10-13, not 2021-10-13. Last year, the 3rd was a Sunday, so the tests partially still fell in the correct time range. I reran it with the initial 83688fa fix commit, and the new card 112345 test 1 error still occurs.

The VM still has the issue, even after correcting the script typo. Debug output is as follows:

With UTC set:

user@user:~/projects/testing$ timedatectl
               Local time: Sun 2022-10-16 02:58:32 UTC
           Universal time: Sun 2022-10-16 02:58:32 UTC
                 RTC time: Sun 2022-10-16 02:58:36
                Time zone: UTC (UTC, +0000)
System clock synchronized: yes
              NTP service: active
          RTC in local TZ: no
user@user:~/projects/testing$ make simulator
mkdir -p /tmp/devices
./uhppote-simulator --bind 127.0.0.1:60000 --rest 127.0.0.1:8000 --devices /tmp/devices/
   ... loading devices from '/tmp/devices/'
   ... bound to address '127.0.0.1:60000'

>> CHECK TIME PROFILE
>> Offset:             -298h24m0s
>> Current time:       2022-10-16 02:58:54.083821413 +0000 UTC m=+7.634600536
>> Current time (UTC): 2022-10-16 02:58:54.08344286 +0000 UTC
>> Adjusted tme (UTC): 2022-10-03 16:35:00.020552451 +0000 UTC
>> Controller time:    16:35
>>       segment 1:    start:16:45  end:22:15
>>       segment 2:    start:00:00  end:00:00
>>       segment 3:    start:00:00  end:00:00

>> CHECK TIME PROFILE
>> Offset:             -298h24m0s
>> Current time:       2022-10-16 02:58:54.084198111 +0000 UTC m=+7.634977246
>> Current time (UTC): 2022-10-16 02:58:54.084167648 +0000 UTC
>> Adjusted tme (UTC): 2022-10-03 16:35:00.021277239 +0000 UTC
>> Controller time:    16:35
>>       segment 1:    start:11:45  end:17:15
>>       segment 2:    start:00:00  end:00:00
>>       segment 3:    start:00:00  end:00:00

>> CHECK TIME PROFILE
>> Offset:             -298h4m0s
>> Current time:       2022-10-16 02:58:54.113387485 +0000 UTC m=+7.664166614
>> Current time (UTC): 2022-10-16 02:58:54.112880464 +0000 UTC
>> Adjusted tme (UTC): 2022-10-03 16:55:00.022979941 +0000 UTC
>> Controller time:    16:55
>>       segment 1:    start:16:45  end:22:15
>>       segment 2:    start:00:00  end:00:00
>>       segment 3:    start:00:00  end:00:00

>> CHECK TIME PROFILE
>> Offset:             -298h4m0s
>> Current time:       2022-10-16 02:58:54.113818457 +0000 UTC m=+7.664597586
>> Current time (UTC): 2022-10-16 02:58:54.113712265 +0000 UTC
>> Adjusted tme (UTC): 2022-10-03 16:55:00.023811742 +0000 UTC
>> Controller time:    16:55
>>       segment 1:    start:11:45  end:17:15
>>       segment 2:    start:00:00  end:00:00
>>       segment 3:    start:00:00  end:00:00

user@user:~/projects/testing$ make test_cli
bash test_cli.sh
123456789: time profile 3 created
123456789: time profile 2 created
123456789 154321 true
123456789 112345 true
123456789  2022-10-03 16:35:00
card 154321 test 1 - access OK (granted)!
card 112345 test 1 - access allowed when it should be denied!
{"access-granted":true,"message":"Access granted"}
123456789  2022-10-03 16:55:00
card 154321 test 2 - access OK (granted)!
card 112345 test 2 - access OK (granted)!

current time is: 123456789  2022-10-03 16:55:00
card 1 data is: 123456789  112345   1970-01-01 2099-12-31 2 2 N 2
card 2 data is: 123456789  154321   1970-01-01 2099-12-31 Y Y N Y
profile 2 is: 123456789  2 1970-01-01:2099-12-31 Mon,Tue,Wed,Thurs,Fri 16:45-22:15 3
profile 3 is: 123456789  3 1970-01-01:2099-12-31 Sat,Sun 11:45-17:15 0

With EDT set:

user@user:~/projects/testing$ timedatectl
               Local time: Sat 2022-10-15 22:55:37 EDT
           Universal time: Sun 2022-10-16 02:55:37 UTC
                 RTC time: Sun 2022-10-16 02:55:37
                Time zone: America/New_York (EDT, -0400)
System clock synchronized: yes
              NTP service: active
          RTC in local TZ: no
user@user:~/projects/testing$ make simulator
mkdir -p /tmp/devices
./uhppote-simulator --bind 127.0.0.1:60000 --rest 127.0.0.1:8000 --devices /tmp/devices/
   ... loading devices from '/tmp/devices/'
   ... bound to address '127.0.0.1:60000'

>> CHECK TIME PROFILE
>> Offset:             -298h21m0s
>> Current time:       2022-10-15 22:55:48.500081837 -0400 EDT m=+6.036198406
>> Current time (UTC): 2022-10-16 02:55:48.500034619 +0000 UTC
>> Adjusted tme (UTC): 2022-10-03 16:35:00.021084049 +0000 UTC
>> Controller time:    16:35
>>       segment 1:    start:16:45  end:22:15
>>       segment 2:    start:00:00  end:00:00
>>       segment 3:    start:00:00  end:00:00

>> CHECK TIME PROFILE
>> Offset:             -298h21m0s
>> Current time:       2022-10-15 22:55:48.500272758 -0400 EDT m=+6.036389328
>> Current time (UTC): 2022-10-16 02:55:48.500247162 +0000 UTC
>> Adjusted tme (UTC): 2022-10-03 16:35:00.021296592 +0000 UTC
>> Controller time:    16:35
>>       segment 1:    start:11:45  end:17:15
>>       segment 2:    start:00:00  end:00:00
>>       segment 3:    start:00:00  end:00:00

>> CHECK TIME PROFILE
>> Offset:             -298h1m0s
>> Current time:       2022-10-15 22:55:48.527536799 -0400 EDT m=+6.063653361
>> Current time (UTC): 2022-10-16 02:55:48.526954277 +0000 UTC
>> Adjusted tme (UTC): 2022-10-03 16:55:00.020331241 +0000 UTC
>> Controller time:    16:55
>>       segment 1:    start:16:45  end:22:15
>>       segment 2:    start:00:00  end:00:00
>>       segment 3:    start:00:00  end:00:00

>> CHECK TIME PROFILE
>> Offset:             -298h1m0s
>> Current time:       2022-10-15 22:55:48.527873023 -0400 EDT m=+6.063989578
>> Current time (UTC): 2022-10-16 02:55:48.527825113 +0000 UTC
>> Adjusted tme (UTC): 2022-10-03 16:55:00.021202077 +0000 UTC
>> Controller time:    16:55
>>       segment 1:    start:11:45  end:17:15
>>       segment 2:    start:00:00  end:00:00
>>       segment 3:    start:00:00  end:00:00

user@user:~/projects/testing$ make test_cli
bash test_cli.sh
123456789: time profile 3 created
123456789: time profile 2 created
123456789 154321 true
123456789 112345 true
123456789  2022-10-03 16:35:00
card 154321 test 1 - access OK (granted)!
card 112345 test 1 - access allowed when it should be denied!
{"access-granted":true,"message":"Access granted"}
123456789  2022-10-03 16:55:00
card 154321 test 2 - access OK (granted)!
card 112345 test 2 - access OK (granted)!

current time is: 123456789  2022-10-03 16:55:00
card 1 data is: 123456789  112345   1970-01-01 2099-12-31 2 2 N 2
card 2 data is: 123456789  154321   1970-01-01 2099-12-31 Y Y N Y
profile 2 is: 123456789  2 1970-01-01:2099-12-31 Mon,Tue,Wed,Thurs,Fri 16:45-22:15 3
profile 3 is: 123456789  3 1970-01-01:2099-12-31 Sat,Sun 11:45-17:15 0

Manually setting the time to my local time (11PM on the 15th), as though it was UTC, does not appear to be interesting.

user@user:~/projects/testing$ timedatectl
               Local time: Sun 2022-10-16 03:18:16 UTC
           Universal time: Sun 2022-10-16 03:18:16 UTC
                 RTC time: Sat 2022-10-15 11:17:16
                Time zone: UTC (UTC, +0000)
System clock synchronized: yes
              NTP service: active
          RTC in local TZ: no
user@user:~/projects/testing$ sudo timedatectl set-ntp false
user@user:~/projects/testing$ sudo timedatectl set-time "2022-10-15 11:18:00"
user@user:~/projects/testing$ timedatectl
               Local time: Sat 2022-10-15 11:18:04 UTC
           Universal time: Sat 2022-10-15 11:18:04 UTC
                 RTC time: Sat 2022-10-15 11:18:04
                Time zone: UTC (UTC, +0000)
System clock synchronized: no
              NTP service: inactive
          RTC in local TZ: no
user@user:~/projects/testing$ make simulator
mkdir -p /tmp/devices
./uhppote-simulator --bind 127.0.0.1:60000 --rest 127.0.0.1:8000 --devices /tmp/devices/
   ... loading devices from '/tmp/devices/'
   ... bound to address '127.0.0.1:60000'

>> CHECK TIME PROFILE
>> Offset:             -282h43m0s
>> Current time:       2022-10-15 11:18:10.287365799 +0000 UTC m=+3.609710886
>> Current time (UTC): 2022-10-15 11:18:10.287266273 +0000 UTC
>> Adjusted tme (UTC): 2022-10-03 16:35:00.025558836 +0000 UTC
>> Controller time:    16:35
>>       segment 1:    start:16:45  end:22:15
>>       segment 2:    start:00:00  end:00:00
>>       segment 3:    start:00:00  end:00:00

>> CHECK TIME PROFILE
>> Offset:             -282h43m0s
>> Current time:       2022-10-15 11:18:10.287593798 +0000 UTC m=+3.609938890
>> Current time (UTC): 2022-10-15 11:18:10.287552866 +0000 UTC
>> Adjusted tme (UTC): 2022-10-03 16:35:00.025845429 +0000 UTC
>> Controller time:    16:35
>>       segment 1:    start:11:45  end:17:15
>>       segment 2:    start:00:00  end:00:00
>>       segment 3:    start:00:00  end:00:00

>> CHECK TIME PROFILE
>> Offset:             -282h23m0s
>> Current time:       2022-10-15 11:18:10.318088447 +0000 UTC m=+3.640433525
>> Current time (UTC): 2022-10-15 11:18:10.318035402 +0000 UTC
>> Adjusted tme (UTC): 2022-10-03 16:55:00.023365469 +0000 UTC
>> Controller time:    16:55
>>       segment 1:    start:16:45  end:22:15
>>       segment 2:    start:00:00  end:00:00
>>       segment 3:    start:00:00  end:00:00

>> CHECK TIME PROFILE
>> Offset:             -282h23m0s
>> Current time:       2022-10-15 11:18:10.3188998 +0000 UTC m=+3.641244896
>> Current time (UTC): 2022-10-15 11:18:10.318695078 +0000 UTC
>> Adjusted tme (UTC): 2022-10-03 16:55:00.024025145 +0000 UTC
>> Controller time:    16:55
>>       segment 1:    start:11:45  end:17:15
>>       segment 2:    start:00:00  end:00:00
>>       segment 3:    start:00:00  end:00:00

^CFailed to read from UDP socket [read udp 127.0.0.1:60000: use of closed network connection]
make: *** [Makefile:4: simulator] Error 1

user@user:~/projects/testing$ timedatectl
               Local time: Sat 2022-10-15 11:18:17 UTC
           Universal time: Sat 2022-10-15 11:18:17 UTC
                 RTC time: Sat 2022-10-15 11:18:18
                Time zone: UTC (UTC, +0000)
System clock synchronized: no
              NTP service: inactive
          RTC in local TZ: no

user@user:~/projects/testing$ make test_cli 
bash test_cli.sh
123456789: time profile 3 created
123456789: time profile 2 created
123456789 154321 true
123456789 112345 true
123456789  2022-10-03 16:35:00
card 154321 test 1 - access OK (granted)!
card 112345 test 1 - access allowed when it should be denied!
{"access-granted":true,"message":"Access granted"}
123456789  2022-10-03 16:55:00
card 154321 test 2 - access OK (granted)!
card 112345 test 2 - access OK (granted)!

current time is: 123456789  2022-10-03 16:55:00
card 1 data is: 123456789  112345   1970-01-01 2099-12-31 2 2 N 2
card 2 data is: 123456789  154321   1970-01-01 2099-12-31 Y Y N Y
profile 2 is: 123456789  2 1970-01-01:2099-12-31 Mon,Tue,Wed,Thurs,Fri 16:45-22:15 3
profile 3 is: 123456789  3 1970-01-01:2099-12-31 Sat,Sun 11:45-17:15 0

All tests appear to pass (EDIT: on the VM and on my main machine):

user@user:~/projects/uhppote-simulator$ make test
go fmt ./...
mkdir -p bin
go build -trimpath -o bin ./...
go test ./...
?   	github.com/uhppoted/uhppote-simulator/cmd/uhppote-simulator	[no test files]
?   	github.com/uhppoted/uhppote-simulator/commands	[no test files]
ok  	github.com/uhppoted/uhppote-simulator/entities	0.023s
?   	github.com/uhppoted/uhppote-simulator/rest	[no test files]
?   	github.com/uhppoted/uhppote-simulator/simulator	[no test files]
ok  	github.com/uhppoted/uhppote-simulator/simulator/UT0311L04	0.005s
user@user:~/projects/uhppote-simulator$ make debug
go fmt ./...
mkdir -p bin
go build -trimpath -o bin ./...
go test -v ./simulator/UT0311L04/... -run TestCheckTime
=== RUN   TestCheckTimeProfileWithValidProfile
>> CHECK TIME PROFILE
>> Offset:             0s
>> Current time:       2022-10-16 03:01:07.547180708 +0000 UTC m=+0.000757496
>> Current time (UTC): 2022-10-16 03:01:07.547117896 +0000 UTC
>> Adjusted tme (UTC): 2022-10-16 03:01:07.547117896 +0000 UTC
>> Controller time:    03:01
>>       segment 1:    start:00:00  end:23:59

--- PASS: TestCheckTimeProfileWithValidProfile (0.00s)
=== RUN   TestCheckTimeProfileInTimeSegment
>> CHECK TIME PROFILE
>> Offset:             0s
>> Current time:       2022-10-16 03:01:07.547751382 +0000 UTC m=+0.001328171
>> Current time (UTC): 2022-10-16 03:01:07.547631201 +0000 UTC
>> Adjusted tme (UTC): 2022-10-16 03:01:07.547631201 +0000 UTC
>> Controller time:    03:01
>>       segment 1:    start:02:51  end:03:11

--- PASS: TestCheckTimeProfileInTimeSegment (0.00s)
=== RUN   TestCheckTimeProfileBeforeTimeSegment
>> CHECK TIME PROFILE
>> Offset:             0s
>> Current time:       2022-10-16 03:01:07.548271239 +0000 UTC m=+0.001848029
>> Current time (UTC): 2022-10-16 03:01:07.548197067 +0000 UTC
>> Adjusted tme (UTC): 2022-10-16 03:01:07.548197067 +0000 UTC
>> Controller time:    03:01
>>       segment 1:    start:03:11  end:04:01

--- PASS: TestCheckTimeProfileBeforeTimeSegment (0.00s)
=== RUN   TestCheckTimeProfileAfterTimeSegment
>> CHECK TIME PROFILE
>> Offset:             0s
>> Current time:       2022-10-16 03:01:07.54878166 +0000 UTC m=+0.002358449
>> Current time (UTC): 2022-10-16 03:01:07.548690887 +0000 UTC
>> Adjusted tme (UTC): 2022-10-16 03:01:07.548690887 +0000 UTC
>> Controller time:    03:01
>>       segment 1:    start:02:01  end:02:51

--- PASS: TestCheckTimeProfileAfterTimeSegment (0.00s)
=== RUN   TestCheckTimeProfileWithValidProfileAndTimeOffset
>> CHECK TIME PROFILE
>> Offset:             -8h0m0s
>> Current time:       2022-10-16 03:01:07.549277806 +0000 UTC m=+0.002854595
>> Current time (UTC): 2022-10-16 03:01:07.549185808 +0000 UTC
>> Adjusted tme (UTC): 2022-10-15 19:01:07.549185808 +0000 UTC
>> Controller time:    19:01
>>       segment 1:    start:00:00  end:23:59

--- PASS: TestCheckTimeProfileWithValidProfileAndTimeOffset (0.00s)
=== RUN   TestCheckTimeProfileInTimeSegmentWithOffset
>> CHECK TIME PROFILE
>> Offset:             8h56m0s
>> Current time:       2022-10-16 03:01:07.549773241 +0000 UTC m=+0.003350028
>> Current time (UTC): 2022-10-16 03:01:07.549684054 +0000 UTC
>> Adjusted tme (UTC): 2022-10-16 11:57:32.000000352 +0000 UTC
>> Controller time:    11:57
>>       segment 1:    start:11:30  end:12:30

--- PASS: TestCheckTimeProfileInTimeSegmentWithOffset (0.00s)
=== RUN   TestCheckTimeProfileBeforeTimeSegmentWithOffset
>> CHECK TIME PROFILE
>> Offset:             8h4m0s
>> Current time:       2022-10-16 03:01:07.550276267 +0000 UTC m=+0.003853055
>> Current time (UTC): 2022-10-16 03:01:07.5501622 +0000 UTC
>> Adjusted tme (UTC): 2022-10-16 11:05:32.000000253 +0000 UTC
>> Controller time:    11:05
>>       segment 1:    start:11:30  end:12:30

--- PASS: TestCheckTimeProfileBeforeTimeSegmentWithOffset (0.00s)
=== RUN   TestCheckTimeProfileAfterTimeSegmentWithOffset
>> CHECK TIME PROFILE
>> Offset:             10h12m0s
>> Current time:       2022-10-16 03:01:07.550750242 +0000 UTC m=+0.004327031
>> Current time (UTC): 2022-10-16 03:01:07.550651187 +0000 UTC
>> Adjusted tme (UTC): 2022-10-16 13:13:13.000000239 +0000 UTC
>> Controller time:    13:13
>>       segment 1:    start:11:30  end:12:30

--- PASS: TestCheckTimeProfileAfterTimeSegmentWithOffset (0.00s)
PASS
ok  	github.com/uhppoted/uhppote-simulator/simulator/UT0311L04	0.008s

uhppoted · 2022-10-16T03:54:10Z

Oooooooooooooooooh .. duh!!! checkTimeProfile only adjusts the time for the controller offset - it also needs to adjust the date (which I only noticed because you mentioned the date was wrong :-)).

Ok, I'm fairly sure I know what is wrong now - I'll fix it sometime tomorrow when my brain is not mush if that's ok? And thanks for all the testing. Really helped!!

amprim · 2022-10-16T03:56:51Z

No worries (I know the feeling), no problem, and thank you!

EDIT: that was not quite the right positioning. Brain = mush. -_-

…t when calculating the weekday (cf. #5)

uhppoted · 2022-10-16T17:52:03Z

Hi,

I've pushed a fix to github - looks ok when I run your script on a VPS:

123456789: time profile 3 created
123456789: time profile 2 created
123456789 154321 true
123456789 112345 true
123456789  2022-10-03 16:35:00
card 154321 test 1 - access OK (granted)!
card 112345 test 1 - access OK (denied)!
123456789  2021-10-03 16:55:00
card 154321 test 2 - access OK (granted)!
card 112345 test 2 - access OK (granted)!

but that was just a very quick test. I'll run a more extended test if you give it the ok..

amprim · 2022-10-16T18:16:22Z

It looks like that may have done it! Both the test script and our tool testing are now working! Thank you so much!

uhppoted · 2022-10-16T18:40:38Z

Oh great! Thanks for letting me know! I still need to clean up the tests and do an extended run before I can put this to bed, but (hopefully) that shouldn't affect you in any way.

Good luck with your project - sounds like fun :-).

uhppoted · 2022-10-18T23:50:00Z

Closing this as fixed - feel free to reopen it if necessary :-)

amprim mentioned this issue Oct 14, 2022

Simulator hangs on startup when existing device file is present #6

Closed

uhppoted assigned twystd Oct 14, 2022

twystd pushed a commit that referenced this issue Oct 14, 2022

(provisional) reworked 'checkTimeProfile' to use controller time (cf. #5

83688fa

)

twystd pushed a commit that referenced this issue Oct 15, 2022

Reworked checkTimeProfile to reference everything from UTC (cf. #5)

6009fa1

twystd pushed a commit that referenced this issue Oct 16, 2022

Reworking 'checkTimeProfile' to account for the controller time offse…

6a18124

…t when calculating the weekday (cf. #5)

twystd pushed a commit that referenced this issue Oct 17, 2022

Cleaned up unit tests for 'checkTimeProfile' (cf. #5)

1f763aa

uhppoted closed this as completed Oct 18, 2022

uhppoted moved this to Todo in dev-cycle 0.8.3 Oct 25, 2022

uhppoted added this to dev-cycle 0.8.3 Oct 25, 2022

uhppoted moved this from Todo to Done in dev-cycle 0.8.3 Oct 25, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Possible issue with time profiles #5

Possible issue with time profiles #5

amprim commented Oct 14, 2022

uhppoted commented Oct 14, 2022

uhppoted commented Oct 14, 2022 •

edited

Loading

amprim commented Oct 14, 2022 •

edited

Loading

uhppoted commented Oct 15, 2022

amprim commented Oct 16, 2022 •

edited

Loading

uhppoted commented Oct 16, 2022

amprim commented Oct 16, 2022 •

edited

Loading

uhppoted commented Oct 16, 2022

amprim commented Oct 16, 2022 •

edited

Loading

uhppoted commented Oct 16, 2022

amprim commented Oct 16, 2022

uhppoted commented Oct 16, 2022

uhppoted commented Oct 18, 2022

Possible issue with time profiles #5

Possible issue with time profiles #5

Comments

amprim commented Oct 14, 2022

Background

Scenario

Issue

Steps to Reproduce

uhppoted commented Oct 14, 2022

uhppoted commented Oct 14, 2022 • edited Loading

amprim commented Oct 14, 2022 • edited Loading

uhppoted commented Oct 15, 2022

amprim commented Oct 16, 2022 • edited Loading

uhppoted commented Oct 16, 2022

amprim commented Oct 16, 2022 • edited Loading

With UTC set:

With EDT set:

uhppoted commented Oct 16, 2022

amprim commented Oct 16, 2022 • edited Loading

uhppoted commented Oct 16, 2022

amprim commented Oct 16, 2022

uhppoted commented Oct 16, 2022

uhppoted commented Oct 18, 2022

uhppoted commented Oct 14, 2022 •

edited

Loading

amprim commented Oct 14, 2022 •

edited

Loading

amprim commented Oct 16, 2022 •

edited

Loading

amprim commented Oct 16, 2022 •

edited

Loading

amprim commented Oct 16, 2022 •

edited

Loading