Test cases using "repeatsAllowed" : "True" (i.e. using HBT repeats) cause test failure with multiple heartbeats. The failure occurs due to time between heartbeats > heartbeatInterval.
In this case, two HBT are sent in authorized state, and the second fails due to heartbeatInterval check.
example from logs:
2017-11-24T20:41:32.357Z - INFO - The time interval between two heartbeat request messages is 18091.087
Of course, the time interval was not 18091 seconds (you will note it is 5 hrs off).
The root cause is that, during HBT repeats, the code wrongly uses local time to record heartbeat time, not UTC time. Therefore in Eastern time zone, it is 5 hours late when doing the heartbeatInterval check.
The fix to be implemented is as follows: in CBRSRequestHandler.py, search for:
self.lastHeartBeatTime = DT.datetime.now()
and replace with:
self.lastHeartBeatTime = DT.datetime.utcnow()
There is one instance of this in the code.
This will be incorporated into an upcoming pull-request (TBD).
Test cases using "repeatsAllowed" : "True" (i.e. using HBT repeats) cause test failure with multiple heartbeats. The failure occurs due to time between heartbeats > heartbeatInterval.
In this case, two HBT are sent in authorized state, and the second fails due to heartbeatInterval check.
example from logs: 2017-11-24T20:41:32.357Z - INFO - The time interval between two heartbeat request messages is 18091.087
Of course, the time interval was not 18091 seconds (you will note it is 5 hrs off).
The root cause is that, during HBT repeats, the code wrongly uses local time to record heartbeat time, not UTC time. Therefore in Eastern time zone, it is 5 hours late when doing the heartbeatInterval check.
The fix to be implemented is as follows: in CBRSRequestHandler.py, search for:
self.lastHeartBeatTime = DT.datetime.now()
and replace with:
self.lastHeartBeatTime = DT.datetime.utcnow()
There is one instance of this in the code.
This will be incorporated into an upcoming pull-request (TBD).