Wireless-Innovation-Forum / Citizens-Broadband-Radio-Service-Device

Apache License 2.0
31 stars 19 forks source link

<Branch: bug fixes> Mock SAS giving error at the end of test case WINNF.FT.C.HBT.10 #92

Open pawan25062 opened 6 years ago

pawan25062 commented 6 years ago

Hi,

Mock SAS giving error at the end of test case WINNF.FT.C.HBT.10:

LAST HBT RESPONSE THAT SET TRANSMIT_EXPIRE_TIME WAS AT: 2017-12-22 08:50:22.265000 2017-12-22T08:52:25.328000Z: CBSD sent heartbeat Request from the address : 172.19.61.243 2017-12-22T08:53:25.336000Z: CBSD sent heartbeat Request from the address : 172.19.61.243 2017-12-22T08:54:25.396000Z: CBSD sent heartbeat Request from the address : 172.19.61.243 2017-12-22T08:54:42Z: validation passed successfully, the engine sent heartbeat Response

Exception happened during processing of request from ('172.19.61.243', 47913) Traceback (most recent call last): File "C:\Python27\lib\SocketServer.py", line 596, in process_request_thread self.finish_request(request, client_address) File "C:\Python27\lib\SocketServer.py", line 331, in finish_request self.RequestHandlerClass(request, client_address, self) File "C:\Python27\lib\SocketServer.py", line 654, in init self.finish() File "C:\Python27\lib\SocketServer.py", line 713, in finish self.wfile.close() File "C:\Python27\lib\socket.py", line 283, in close self.flush() File "C:\Python27\lib\socket.py", line 307, in flush self._sock.sendall(view[write_offset:write_offset+buffer_size]) File "C:\Python27\lib\ssl.py", line 753, in sendall v = self.send(data[count:]) File "C:\Python27\lib\ssl.py", line 719, in send v = self._sslobj.write(data) error: [Errno 10053] An established connection was aborted by the software in your host machine

arrived to nstep starting question answer session with the technician the question is : Does Cbsd stop transmiting within (transmitExpireTime + 60seconds) of last valid heartbeat response? please choose one of the answers : y n 2017-12-22T08:54:46Z: validation passed successfully, the engine sent heartbeat Response 2017-12-22T08:54:46Z: validation passed successfully, the engine sent heartbeat Response

Exception happened during processing of request from ('172.19.61.243', 55058) Traceback (most recent call last): File "C:\Python27\lib\SocketServer.py", line 596, in process_request_thread self.finish_request(request, client_address) File "C:\Python27\lib\SocketServer.py", line 331, in finish_request self.RequestHandlerClass(request, client_address, self) File "C:\Python27\lib\SocketServer.py", line 654, in init self.finish() File "C:\Python27\lib\SocketServer.py", line 713, in finish self.wfile.close() File "C:\Python27\lib\socket.py", line 283, in close self.flush() File "C:\Python27\lib\socket.py", line 307, in flush self._sock.sendall(view[write_offset:write_offset+buffer_size]) File "C:\Python27\lib\ssl.py", line 753, in sendall v = self.send(data[count:]) File "C:\Python27\lib\ssl.py", line 719, in send v = self._sslobj.write(data) error: [Errno 10053] An established connection was aborted by the software in your host machine

2017-12-22T08:54:46Z: validation passed successfully, the engine sent heartbeat Response

Mock SAS window image is attached.

WINNF.FT.C.HBT.10.zip

2017-12-22T08:54:25.395Z - INFO - request message received while HBT is absent, sleep 21 sec before responding 2017-12-22T08:54:42.275Z - INFO - engine sent successfully, the response to CBRS : { "heartbeatResponse": [ { "cbsdId": "S9GQ710US01Mock-SAS401629000040", "grantId": "235928613", "response": { "responseCode": 0 }, "transmitExpireTime": "2017-12-22T08:58:02Z" } ] } 2017-12-22T08:54:43.523Z - INFO - arrived to nstep starting question answer session with the technician 2017-12-22T08:54:43.523Z - INFO - the question is : Does Cbsd stop transmiting within (transmitExpireTime + 60seconds) of last valid heartbeat response? please choose one of the answers : 2017-12-22T08:54:46.331Z - INFO - engine sent successfully, the response to CBRS : "list index out of range" 2017-12-22T08:54:46.346Z - INFO - engine sent successfully, the response to CBRS : "list index out of range" 2017-12-22T08:54:46.408Z - INFO - engine sent successfully, the response to CBRS : "list index out of range"

log file is also attached here for more reference.

WINNF.FT.C.HBT.10_2017-12-22T08.49.13Z.zip

cwilliams-ericsson commented 6 years ago

Will look into this. I don't see the same thing on my setup. It is worrying since the crash log states "error: [Errno 10053] An established connection was aborted by the software in your host machine", so I suspect our "delay" method to avoid sending responses during HBT absent test case may not work reliably.

cwilliams-ericsson commented 6 years ago

Hi pawan25062. A few more questions to understand what is going on:

  1. What os is this running on?
  2. It is not clear to me: did this actually crash the server? Or, if you ignore the exception messages, does the test harness continue to operate properly? That is: is this fatal, or is it a nuisance problem on the display? If you go ahead and answer the question, does the test pass or fail?

errno 10053 seems to be a timeout issue: the test harness has delayed several response messages until the end of the test, then tries to send them. It seems that the CBSD or OS has timed out the connection since it is a long delay...

pawan25062 commented 6 years ago

hi,

  1. What os is this running on?

    It is running on Windows

  2. It is not clear to me: did this actually crash the server? Or, if you ignore the exception messages, does the test harness continue to operate properly? That is: is this fatal, or is it a nuisance problem on the display? If you go ahead and answer the question, does the test pass or fail?

    We are able to choose answer even after all these errors and test case is also getting passed with these error.

Snap is also attached here for reference. WINNF.FT.C.HBT.10_26Dec.zip

cwilliams-ericsson commented 6 years ago

This appears to be an artifact of using delayed response to simulate loss of communications with the test harness. Device may send one or more requests while the test harness is not answering. Those requests are processed at the end of the test, causing response messages to be sent at that time. If the socket for the response is closed, these error messages are displayed.

Based on some research, this appears to be a nuisance message. Based on python forums, this is seen in Python 2.7, but not Python 3.

We could consider a different method to silence server, but may need significantly more time to generate a proper solution.