[2021-05-21 11:07:41,179]      root -     INFO - Setting nodes : 
[2021-05-21 11:07:41,181]   asyncio -    DEBUG - Using selector: SelectSelector
[2021-05-21 11:07:41,184]      root -     INFO - Message receiver started
[2021-05-21 11:07:41,185]      root -     INFO - RTLS Manager started
[2021-05-21 11:07:41,197]   asyncio -    DEBUG - Get address info localhost:5049, type=<SocketKind.SOCK_STREAM: 1>, flags=<AddressInfo.AI_PASSIVE: 1>
[2021-05-21 11:07:41,206]   asyncio -    DEBUG - Getting address info localhost:5049, type=<SocketKind.SOCK_STREAM: 1>, flags=<AddressInfo.AI_PASSIVE: 1> took 15.000ms: [(<AddressFamily.AF_INET6: 23>, <SocketKind.SOCK_STREAM: 1>, 0, '', ('::1', 5049, 0, 0)), (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 0, '', ('127.0.0.1', 5049))]
[2021-05-21 11:07:41,209]   asyncio -    DEBUG - poll took 15.000 ms: 1 events
[2021-05-21 11:07:41,211]   asyncio -     INFO - <Server sockets=[<socket.socket fd=1500, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=0, laddr=('127.0.0.1', 5049)>, <socket.socket fd=1548, family=AddressFamily.AF_INET6, type=SocketKind.SOCK_STREAM, proto=0, laddr=('::1', 5049, 0, 0)>]> is serving
[2021-05-21 11:07:41,246] serialnode -    DEBUG - >>> UNPIMessage(originator=Ap type=SyncReq, subsystem=25, command=RTLS_CMD_IDENTIFY, data=)
[2021-05-21 11:07:41,247] serialnode -    DEBUG - >>> UNPIMessage(originator=Ap type=SyncReq, subsystem=25, command=RTLS_CMD_IDENTIFY, data=)
[2021-05-21 11:07:41,247] serialnode -    DEBUG - >>> FE:00:00:39:00:39
[2021-05-21 11:07:41,248] serialnode -    DEBUG - >>> FE:00:00:39:00:39
[2021-05-21 11:07:41,309] serialnode -    DEBUG - <<< FE:0C:00:79:00:04:01:02:00:05:2C:77:2D:5E:8A:F8:08:25
[2021-05-21 11:07:41,309] serialnode -    DEBUG - <<< FE:0C:00:79:00:94:00:02:00:05:FC:98:2D:5E:8A:F8:08:8B
[2021-05-21 11:07:41,311] serialnode -    DEBUG - <<< 
[2021-05-21 11:07:41,311] serialnode -    DEBUG - <<< 
[2021-05-21 11:07:41,312] serialnode -    DEBUG - <<< UNPIMessage(originator=Nwp type=SyncRsp, subsystem=RTLS, command=RTLS_CMD_IDENTIFY, data=04:01:02:00:05:2C:77:2D:5E:8A:F8:08)
[2021-05-21 11:07:41,312] serialnode -    DEBUG - <<< UNPIMessage(originator=Nwp type=SyncRsp, subsystem=RTLS, command=RTLS_CMD_IDENTIFY, data=94:00:02:00:05:FC:98:2D:5E:8A:F8:08)
[2021-05-21 11:07:41,312] serialnode -    DEBUG - <<< 
[2021-05-21 11:07:41,314] serialnode -    DEBUG - <<< 
[2021-05-21 11:07:41,531]   asyncio -    DEBUG - poll took 313.000 ms: 1 events
[2021-05-21 11:07:41,532]   asyncio -    DEBUG - <Server sockets=[<socket.socket fd=1500, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=0, laddr=('127.0.0.1', 5049)>, <socket.socket fd=1548, family=AddressFamily.AF_INET6, type=SocketKind.SOCK_STREAM, proto=0, laddr=('::1', 5049, 0, 0)>]> got a new connection from ('127.0.0.1', 64050): <socket.socket fd=1568, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=0, laddr=('127.0.0.1', 5049), raddr=('127.0.0.1', 64050)>
[2021-05-21 11:07:41,535] websockets.protocol -    DEBUG - server - state = CONNECTING
[2021-05-21 11:07:41,540] websockets.protocol -    DEBUG - server - event = connection_made(<_SelectorSocketTransport fd=1568 read=idle write=<idle, bufsize=0>>)
[2021-05-21 11:07:41,547] websockets.protocol -    DEBUG - server - state = OPEN
[2021-05-21 11:07:43,193]      root -     INFO - Done setting node
[2021-05-21 11:07:43,194]  rtlsnode -     INFO - PASSIVE : F8:8A:5E:2D:77:2C <-- {'type': 'Command', 'command': 'RTLS_CMD_RESET_DEVICE', 'payload': None}
[2021-05-21 11:07:43,194]  rtlsnode -     INFO - MASTER  : F8:8A:5E:2D:98:FC <-- {'type': 'Command', 'command': 'RTLS_CMD_RESET_DEVICE', 'payload': None}
[2021-05-21 11:07:43,209] serialnode -    DEBUG - >>> UNPIMessage(originator=Ap type=SyncReq, subsystem=25, command=RTLS_CMD_RESET_DEVICE, data=)
[2021-05-21 11:07:43,210] serialnode -    DEBUG - >>> UNPIMessage(originator=Ap type=SyncReq, subsystem=25, command=RTLS_CMD_RESET_DEVICE, data=)
[2021-05-21 11:07:43,210] serialnode -    DEBUG - >>> FE:00:00:39:20:19
[2021-05-21 11:07:43,211] serialnode -    DEBUG - >>> FE:00:00:39:20:19
[2021-05-21 11:07:43,272] serialnode -    DEBUG - <<< 00:FE:00:00:59:20:79
[2021-05-21 11:07:43,272] serialnode -    DEBUG - <<< 00:FE:00:00:59:20:79
[2021-05-21 11:07:43,273]      root -  WARNING - ConstError('parsing expected 254 but parsed 0')
[2021-05-21 11:07:43,273]      root -  WARNING - ConstError('parsing expected 254 but parsed 0')
[2021-05-21 11:07:43,274] serialnode -    DEBUG - <<< 
[2021-05-21 11:07:43,275] serialnode -    DEBUG - <<< 
[2021-05-21 11:07:43,275] serialnode -    DEBUG - <<< UNPIMessage(originator=Nwp type=AsyncReq, subsystem=RTLS, command=RTLS_CMD_RESET_DEVICE, data=)
[2021-05-21 11:07:43,275] serialnode -    DEBUG - <<< UNPIMessage(originator=Nwp type=AsyncReq, subsystem=RTLS, command=RTLS_CMD_RESET_DEVICE, data=)
[2021-05-21 11:07:43,275] serialnode -    DEBUG - <<< 
[2021-05-21 11:07:43,277]  rtlsnode -    DEBUG - Have 0 subscribers for UNPIMessage(originator=Nwp type=AsyncReq, subsystem=RTLS, command=RTLS_CMD_RESET_DEVICE, data=)
[2021-05-21 11:07:43,277] serialnode -    DEBUG - <<< 
[2021-05-21 11:07:43,279]  rtlsnode -    DEBUG - Have 0 subscribers for UNPIMessage(originator=Nwp type=AsyncReq, subsystem=RTLS, command=RTLS_CMD_RESET_DEVICE, data=)
[2021-05-21 11:07:43,280]      root -     INFO - MASTER  : F8:8A:5E:2D:98:FC --> {'type': 'Event', 'command': 'RTLS_CMD_RESET_DEVICE', 'payload': {'raw_payload': ''}}
[2021-05-21 11:07:43,280]   asyncio -     INFO - poll 20000.000 ms took 1703.000 ms: 1 events
[2021-05-21 11:07:43,282]      root -     INFO - PASSIVE : F8:8A:5E:2D:77:2C --> {'type': 'Event', 'command': 'RTLS_CMD_RESET_DEVICE', 'payload': {'raw_payload': ''}}
[2021-05-21 11:07:43,285] websockets.protocol -    DEBUG - server > Frame(fin=True, opcode=1, data=b'{"identifier": "F8:8A:5E:2D:98:FC", "message": {"originator": "Nwp", "type": "AsyncReq", "subsystem": "RTLS", "command": "RTLS_CMD_RESET_DEVICE", "payload": {"raw_payload": ""}}}', rsv1=False, rsv2=False, rsv3=False)
[2021-05-21 11:07:43,286] websockets.protocol -    DEBUG - server > Frame(fin=True, opcode=1, data=b'{"identifier": "F8:8A:5E:2D:77:2C", "message": {"originator": "Nwp", "type": "AsyncReq", "subsystem": "RTLS", "command": "RTLS_CMD_RESET_DEVICE", "payload": {"raw_payload": ""}}}', rsv1=False, rsv2=False, rsv3=False)
[2021-05-21 11:07:43,306]  werkzeug -     INFO - 127.0.0.1 - - [21/May/2021 11:07:43] "POST /rtls-ui/api/initialize HTTP/1.1" 200 -
[2021-05-21 11:07:43,418]  rtlsnode -     INFO - PASSIVE : F8:8A:5E:2D:77:2C <-- {'type': 'Command', 'command': 'RTLS_CMD_IDENTIFY', 'payload': None}
[2021-05-21 11:07:43,419]  rtlsnode -     INFO - MASTER  : F8:8A:5E:2D:98:FC <-- {'type': 'Command', 'command': 'RTLS_CMD_IDENTIFY', 'payload': None}
[2021-05-21 11:07:43,463] serialnode -    DEBUG - >>> UNPIMessage(originator=Ap type=SyncReq, subsystem=25, command=RTLS_CMD_IDENTIFY, data=)
[2021-05-21 11:07:43,464] serialnode -    DEBUG - >>> UNPIMessage(originator=Ap type=SyncReq, subsystem=25, command=RTLS_CMD_IDENTIFY, data=)
[2021-05-21 11:07:43,465] serialnode -    DEBUG - >>> FE:00:00:39:00:39
[2021-05-21 11:07:43,465] serialnode -    DEBUG - >>> FE:00:00:39:00:39
[2021-05-21 11:07:43,526] serialnode -    DEBUG - <<< FE:0C:00:79:00:04:01:02:00:05:2C:77:2D:5E:8A:F8:08:25
[2021-05-21 11:07:43,526] serialnode -    DEBUG - <<< FE:0C:00:79:00:94:00:02:00:05:FC:98:2D:5E:8A:F8:08:8B
[2021-05-21 11:07:43,527] serialnode -    DEBUG - <<< 
[2021-05-21 11:07:43,528] serialnode -    DEBUG - <<< 
[2021-05-21 11:07:43,528] serialnode -    DEBUG - <<< UNPIMessage(originator=Nwp type=SyncRsp, subsystem=RTLS, command=RTLS_CMD_IDENTIFY, data=04:01:02:00:05:2C:77:2D:5E:8A:F8:08)
[2021-05-21 11:07:43,529] serialnode -    DEBUG - <<< UNPIMessage(originator=Nwp type=SyncRsp, subsystem=RTLS, command=RTLS_CMD_IDENTIFY, data=94:00:02:00:05:FC:98:2D:5E:8A:F8:08)
[2021-05-21 11:07:43,529] serialnode -    DEBUG - <<< 
[2021-05-21 11:07:43,530]  rtlsnode -    DEBUG - Have 0 subscribers for UNPIMessage(originator=Nwp type=SyncRsp, subsystem=RTLS, command=RTLS_CMD_IDENTIFY, data=04:01:02:00:05:2C:77:2D:5E:8A:F8:08)
[2021-05-21 11:07:43,530] serialnode -    DEBUG - <<< 
[2021-05-21 11:07:43,531]  rtlsnode -    DEBUG - Have 0 subscribers for UNPIMessage(originator=Nwp type=SyncRsp, subsystem=RTLS, command=RTLS_CMD_IDENTIFY, data=94:00:02:00:05:FC:98:2D:5E:8A:F8:08)
[2021-05-21 11:07:43,533]      root -     INFO - PASSIVE : F8:8A:5E:2D:77:2C --> {'type': 'Response', 'command': 'RTLS_CMD_IDENTIFY', 'payload': {'capabilities': {'CM': False, 'AOA_TX': False, 'AOA_RX': True, 'RESERVED1': False, 'RTLS_CAP_CL_AOA': False, 'RESERVED2': False, 'RTLS_SLAVE': False, 'RTLS_MASTER': False, 'RTLS_PASSIVE': True}, 'revNum': 2, 'devId': 'DeviceFamily_ID_CC26X2', 'identifier': 'F8:8A:5E:2D:77:2C'}}
[2021-05-21 11:07:43,533]   asyncio -    DEBUG - poll 18282.000 ms took 250.000 ms: 1 events
[2021-05-21 11:07:43,534]      root -     INFO - MASTER  : F8:8A:5E:2D:98:FC --> {'type': 'Response', 'command': 'RTLS_CMD_IDENTIFY', 'payload': {'capabilities': {'CM': False, 'AOA_TX': False, 'AOA_RX': True, 'RESERVED1': False, 'RTLS_CAP_CL_AOA': True, 'RESERVED2': False, 'RTLS_SLAVE': False, 'RTLS_MASTER': True, 'RTLS_PASSIVE': False}, 'revNum': 2, 'devId': 'DeviceFamily_ID_CC26X2', 'identifier': 'F8:8A:5E:2D:98:FC'}}
[2021-05-21 11:07:43,539] websockets.protocol -    DEBUG - server > Frame(fin=True, opcode=1, data=b'{"identifier": "F8:8A:5E:2D:77:2C", "message": {"originator": "Nwp", "type": "SyncRsp", "subsystem": "RTLS", "command": "RTLS_CMD_IDENTIFY", "payload": {"capabilities": {"CM": false, "AOA_TX": false, "AOA_RX": true, "RESERVED1": false, "RTLS_CAP_CL_AOA": false, "RESERVED2": false, "RTLS_SLAVE": false, "RTLS_MASTER": false, "RTLS_PASSIVE": true}, "revNum": 2, "devId": "DeviceFamily_ID_CC26X2", "identifier": "F8:8A:5E:2D:77:2C"}}}', rsv1=False, rsv2=False, rsv3=False)
[2021-05-21 11:07:43,540] websockets.protocol -    DEBUG - server > Frame(fin=True, opcode=1, data=b'{"identifier": "F8:8A:5E:2D:98:FC", "message": {"originator": "Nwp", "type": "SyncRsp", "subsystem": "RTLS", "command": "RTLS_CMD_IDENTIFY", "payload": {"capabilities": {"CM": false, "AOA_TX": false, "AOA_RX": true, "RESERVED1": false, "RTLS_CAP_CL_AOA": true, "RESERVED2": false, "RTLS_SLAVE": false, "RTLS_MASTER": true, "RTLS_PASSIVE": false}, "revNum": 2, "devId": "DeviceFamily_ID_CC26X2", "identifier": "F8:8A:5E:2D:98:FC"}}}', rsv1=False, rsv2=False, rsv3=False)
[2021-05-21 11:07:43,639]  werkzeug -     INFO - 127.0.0.1 - - [21/May/2021 11:07:43] "GET /rtls-ui/api/initialize HTTP/1.1" 200 -
[2021-05-21 11:08:01,575]   asyncio -     INFO - poll 18032.000 ms took 18032.000 ms: timeout
[2021-05-21 11:08:01,579] websockets.protocol -    DEBUG - server > Frame(fin=True, opcode=9, data=b'\xc8\x13\x11.', rsv1=False, rsv2=False, rsv3=False)
[2021-05-21 11:08:01,584]   asyncio -    DEBUG - poll 20000.000 ms took 0.000 ms: 1 events
[2021-05-21 11:08:01,585] websockets.protocol -    DEBUG - server < Frame(fin=True, opcode=10, data=b'\xc8\x13\x11.', rsv1=False, rsv2=False, rsv3=False)
[2021-05-21 11:08:01,586] websockets.protocol -    DEBUG - server - received solicited pong: c813112e
[2021-05-21 11:08:18,018]   asyncio -     INFO - poll 20000.000 ms took 16438.000 ms: 1 events
[2021-05-21 11:08:18,019]   asyncio -    DEBUG - <_SelectorSocketTransport fd=1568 read=polling write=<idle, bufsize=0>>: Fatal read error on socket transport
Traceback (most recent call last):
  File "asyncio\selector_events.py", line 814, in _read_ready__data_received
ConnectionResetError: [WinError 10054] 远程主机强迫关闭了一个现有的连接。
[2021-05-21 11:08:18,021] websockets.protocol -    DEBUG - server - event = connection_lost([WinError 10054] 远程主机强迫关闭了一个现有的连接。)
[2021-05-21 11:08:18,021] websockets.protocol -    DEBUG - server - state = CLOSED
[2021-05-21 11:08:18,022] websockets.protocol -    DEBUG - server x code = 1006, reason = [no reason]
[2021-05-21 11:08:18,023]      root -     INFO - AOA Stopped
[2021-05-21 11:08:18,024] websockets.protocol -    DEBUG - server ! failing WebSocket connection in the CLOSED state: 1006 [no reason]
[2021-05-21 11:08:18,028] websockets.protocol -    DEBUG - server x half-closing TCP connection
[2021-05-21 11:08:18,804]   asyncio -    DEBUG - poll took 766.000 ms: 1 events
[2021-05-21 11:08:18,816]   asyncio -    DEBUG - Close <_WindowsSelectorEventLoop running=False closed=False debug=True>