search

UCSD-E4E / ASM-data-server

Aye-Aye Sleep Monitoring Project: Data Server Code
MIT License
1 stars 0 forks source link

[Bug]: Error when reconnecting node (can't reproduce) #31

Open ocboogie opened 1 year ago

ocboogie commented 1 year ago

Commit Hash

77da5c392f259ca18f88b5959c1a8a16798d88de

Steps to Reproduce?

Although I can't reproduce it again, this is what I did:

  1. Start server
  2. Start node
  3. Stop node
  4. Start node

Observed Behavior

Server shut down

Desired Behavior

Server stays up and connects to the node

Component

Server

Relevant Sensor Node log output

2023-06-08 07:32:55.031 - root - INFO - Using config file /boot/asm_config.yaml
2023-06-08 07:32:55.048 - NodeCreator - INFO - Discovered uuid: a105a7ea-3eae-11ec-8446-a0afbd87594c
2023-06-08 07:32:55.049 - NodeCreator - INFO - Discovered type: ASM_NestingBox
2023-06-08 07:32:55.049 - NodeCreator - INFO - Discovered data_server: e4e-brix.dynamic.ucsd.edu
2023-06-08 07:32:55.058 - NodeCreator - ERROR - Failed to import SensorNode.sensor_nodes.animalFlipper
2023-06-08 07:32:55.126 - OnBoxSensorNode - INFO - Starting ASM Sensor Node v0.0.0.2_Sending_fix,  dirty
2023-06-08 07:32:55.127 - OnBoxSensorNode - INFO - Loading configuration
2023-06-08 07:32:55.147 - OnBoxSensorNode - INFO - Discovered uuid: a105a7ea-3eae-11ec-8446-a0afbd87594c
2023-06-08 07:32:55.147 - OnBoxSensorNode - INFO - Discovered type: ASM_NestingBox
2023-06-08 07:32:55.147 - OnBoxSensorNode - INFO - Discovered data_server: e4e-brix.dynamic.ucsd.edu
2023-06-08 07:32:55.147 - OnBoxSensorNode - INFO - Discovered port: 9000
2023-06-08 07:32:55.147 - OnBoxSensorNode - INFO - Discovered heartbeat_period_s: 5
2023-06-08 07:32:55.147 - OnBoxSensorNode - INFO - Discovered data_server_uuid: fda6297c-1107-11ec-bbd2-fcaa14694a7a
2023-06-08 07:32:55.148 - OnBoxSensorNode - INFO - I am a105a7ea-3eae-11ec-8446-a0afbd87594c
2023-06-08 07:32:55.157 - OnBoxSensorNode - INFO - Resolving endpoint as 132.239.10.180, UUID: fda6297c-1107-11ec-bbd2-fcaa14694a7
a, port: 9000
2023-06-08 07:32:55.158 - asyncio - DEBUG - Using selector: EpollSelector
2023-06-08 07:32:55.159 - OnBoxSensorNode - INFO - Codecs initialized
2023-06-08 07:32:55.159 - OnBoxSensorNode - INFO - Discovered video_endpoint: /dev/video0
2023-06-08 07:32:55.159 - OnBoxSensorNode - INFO - Discovered illumination_on: 10:00
2023-06-08 07:32:55.160 - OnBoxSensorNode - INFO - Discovered illumination_off: 19:30
2023-06-08 07:32:55.160 - OnBoxSensorNode - INFO - Discovered illumination_level: 100
2023-06-08 07:32:55.160 - OnBoxSensorNode - INFO - Discovered illumination_pin: 19
2023-06-08 07:32:55.161 - OnBoxSensorNode - INFO - Registered <bound method OnBoxSensorNode.onRTPCommandResponse of <SensorNode.se
nsor_nodes.onBoxSensorNode.OnBoxSensorNode object at 0xb4ee8450>> for <class 'asm_protocol.codec.E4E_START_RTP_RSP'>
2023-06-08 07:32:55.193 - asyncio - DEBUG - Using selector: EpollSelector
2023-06-08 07:32:55.195 - OnBoxSensorNode - INFO - Networking tasks created
2023-06-08 07:32:55.196 - OnBoxSensorNode - INFO - Queued Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a105
a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:32:55.196375)
2023-06-08 07:32:55.196 - OnBoxSensorNode - INFO - Sending Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a10
5a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:32:55.196375)
2023-06-08 07:32:55.197 - OnBoxSensorNode - INFO - Queued Packet E4E_START_RTP_CMD(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=
fda6297c-1107-11ec-bbd2-fcaa14694a7a, streamID=1)
2023-06-08 07:32:55.197 - OnBoxSensorNode - INFO - Sending Packet E4E_START_RTP_CMD(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest
=fda6297c-1107-11ec-bbd2-fcaa14694a7a, streamID=1)
2023-06-08 07:32:55.204 - OnBoxSensorNode - INFO - Received packet E4E_START_RTP_RSP(src=fda6297c-1107-11ec-bbd2-fcaa14694a7a, des
t=a105a7ea-3eae-11ec-8446-a0afbd87594c, port=9100, streamid=1)
2023-06-08 07:32:55.204 - OnBoxSensorNode - INFO - Starting ffmpeg with command: ffmpeg -f video4linux2 -input_format h264 -i /dev
/video0 -vcodec copy -f mpegts tcp://132.239.10.180:9100  -vcodec copy -f mpegts udp://100.83.58.65:10010?pkt_size=1316 -vcodec co
py -f mpegts udp://100.83.58.65:10011?pkt_size=1316 2>&1 | /usr/bin/python3 -m ASM_utils.ffmpeg.split_log /var/log/ffmpeg_logs/ffs
tats.log /var/log/ffmpeg_logs/ffinfo.log
2023-06-08 07:32:55.204 - OnBoxSensorNode - INFO - FFmpeg logging to: /var/log/ffmpeg_logs
2023-06-08 07:33:00.197 - OnBoxSensorNode - INFO - Queued Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a105
a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:33:00.196991)
2023-06-08 07:33:00.198 - OnBoxSensorNode - INFO - Sending Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a10
5a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:33:00.196991)
2023-06-08 07:33:05.198 - OnBoxSensorNode - INFO - Queued Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a105
a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:33:05.198094)
2023-06-08 07:33:05.198 - OnBoxSensorNode - INFO - Sending Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a10
5a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:33:05.198094)
2023-06-08 07:33:10.198 - OnBoxSensorNode - INFO - Queued Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a105
a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:33:10.198693)
2023-06-08 07:33:10.199 - OnBoxSensorNode - INFO - Sending Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a10
5a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:33:10.198693)
2023-06-08 07:37:28.272 - root - INFO - Using config file /boot/asm_config.yaml
2023-06-08 07:37:28.289 - NodeCreator - INFO - Discovered uuid: a105a7ea-3eae-11ec-8446-a0afbd87594c
2023-06-08 07:37:28.289 - NodeCreator - INFO - Discovered type: ASM_NestingBox
2023-06-08 07:37:28.289 - NodeCreator - INFO - Discovered data_server: e4e-brix.dynamic.ucsd.edu
2023-06-08 07:37:28.299 - NodeCreator - ERROR - Failed to import SensorNode.sensor_nodes.animalFlipper
2023-06-08 07:37:28.368 - OnBoxSensorNode - INFO - Starting ASM Sensor Node v0.0.0.2_Sending_fix,  dirty
2023-06-08 07:37:28.369 - OnBoxSensorNode - INFO - Loading configuration
2023-06-08 07:37:28.386 - OnBoxSensorNode - INFO - Discovered uuid: a105a7ea-3eae-11ec-8446-a0afbd87594c
2023-06-08 07:37:28.386 - OnBoxSensorNode - INFO - Discovered type: ASM_NestingBox
2023-06-08 07:37:28.386 - OnBoxSensorNode - INFO - Discovered data_server: e4e-brix.dynamic.ucsd.edu
2023-06-08 07:37:28.387 - OnBoxSensorNode - INFO - Discovered port: 9000
2023-06-08 07:37:28.387 - OnBoxSensorNode - INFO - Discovered heartbeat_period_s: 5
2023-06-08 07:37:28.387 - OnBoxSensorNode - INFO - Discovered data_server_uuid: fda6297c-1107-11ec-bbd2-fcaa14694a7a
2023-06-08 07:37:28.387 - OnBoxSensorNode - INFO - I am a105a7ea-3eae-11ec-8446-a0afbd87594c
2023-06-08 07:37:28.395 - OnBoxSensorNode - INFO - Resolving endpoint as 132.239.10.180, UUID: fda6297c-1107-11ec-bbd2-fcaa14694a7
a, port: 9000
2023-06-08 07:37:28.396 - asyncio - DEBUG - Using selector: EpollSelector
2023-06-08 07:37:28.397 - OnBoxSensorNode - INFO - Codecs initialized
2023-06-08 07:37:28.397 - OnBoxSensorNode - INFO - Discovered video_endpoint: /dev/video0
2023-06-08 07:37:28.398 - OnBoxSensorNode - INFO - Discovered illumination_on: 10:00
2023-06-08 07:37:28.398 - OnBoxSensorNode - INFO - Discovered illumination_off: 19:30
2023-06-08 07:37:28.398 - OnBoxSensorNode - INFO - Discovered illumination_level: 100
2023-06-08 07:37:28.398 - OnBoxSensorNode - INFO - Discovered illumination_pin: 19
2023-06-08 07:37:28.399 - OnBoxSensorNode - INFO - Registered <bound method OnBoxSensorNode.onRTPCommandResponse of <SensorNode.se
nsor_nodes.onBoxSensorNode.OnBoxSensorNode object at 0xb4fbc9d0>> for <class 'asm_protocol.codec.E4E_START_RTP_RSP'>
2023-06-08 07:37:28.432 - asyncio - DEBUG - Using selector: EpollSelector
2023-06-08 07:37:28.435 - OnBoxSensorNode - INFO - Networking tasks created
2023-06-08 07:37:28.435 - OnBoxSensorNode - INFO - Queued Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a105
a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:37:28.435579)
2023-06-08 07:37:28.436 - OnBoxSensorNode - INFO - Sending Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a10
5a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:37:28.435579)
2023-06-08 07:37:28.436 - OnBoxSensorNode - INFO - Queued Packet E4E_START_RTP_CMD(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=
fda6297c-1107-11ec-bbd2-fcaa14694a7a, streamID=1)
2023-06-08 07:37:28.436 - OnBoxSensorNode - INFO - Sending Packet E4E_START_RTP_CMD(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest
=fda6297c-1107-11ec-bbd2-fcaa14694a7a, streamID=1)
2023-06-08 07:37:28.443 - OnBoxSensorNode - INFO - Received packet E4E_START_RTP_RSP(src=fda6297c-1107-11ec-bbd2-fcaa14694a7a, des
t=a105a7ea-3eae-11ec-8446-a0afbd87594c, port=9100, streamid=1)
2023-06-08 07:37:28.443 - OnBoxSensorNode - INFO - Starting ffmpeg with command: ffmpeg -f video4linux2 -input_format h264 -i /dev
/video0 -vcodec copy -f mpegts tcp://132.239.10.180:9100  -vcodec copy -f mpegts udp://100.83.58.65:10010?pkt_size=1316 -vcodec co
py -f mpegts udp://100.83.58.65:10011?pkt_size=1316 2>&1 | /usr/bin/python3 -m ASM_utils.ffmpeg.split_log /var/log/ffmpeg_logs/ffs
tats.log /var/log/ffmpeg_logs/ffinfo.log
2023-06-08 07:37:28.443 - OnBoxSensorNode - INFO - FFmpeg logging to: /var/log/ffmpeg_logs
2023-06-08 07:37:33.436 - OnBoxSensorNode - INFO - Queued Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a105
a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:37:33.436243)
2023-06-08 07:37:33.437 - OnBoxSensorNode - INFO - Sending Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a10
5a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:37:33.436243)
2023-06-08 07:37:38.437 - OnBoxSensorNode - INFO - Queued Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a105
a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:37:38.437587)
2023-06-08 07:37:38.438 - OnBoxSensorNode - INFO - Sending Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a10
5a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:37:38.437587)
2023-06-08 07:37:43.438 - OnBoxSensorNode - INFO - Queued Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a105
a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:37:43.438251)
2023-06-08 07:37:43.439 - OnBoxSensorNode - INFO - Sending Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a10
5a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:37:43.438251)
2023-06-08 07:37:48.439 - OnBoxSensorNode - INFO - Queued Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a105
a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:37:48.438869)
2023-06-08 07:37:48.439 - OnBoxSensorNode - INFO - Sending Packet E4E_Heartbeat(src=a105a7ea-3eae-11ec-8446-a0afbd87594c, dest=a10
5a7ea-3eae-11ec-8446-a0afbd87594c, timestamp=2023-06-08 00:37:48.438869)

Relevant Sensor Node configuration

No response

Relevant Server log output

2023-06-08 07:31:18.197 - Server - INFO - Starting ASM Data Server v0.0.0.1,  dirty
2023-06-08 07:31:18.201 - root - INFO - Discovered data_dir: /home/asm-data/data
2023-06-08 07:31:18.201 - root - INFO - Discovered port: 9000
2023-06-08 07:31:18.201 - root - INFO - Discovered server_uuid: fda6297c-1107-11ec-bbd2-fcaa14694a7a
2023-06-08 07:31:18.201 - root - INFO - Discovered video_increment: 300
2023-06-08 07:31:18.201 - root - INFO - Discovered rtsp_port_block: [9100, 9200]
2023-06-08 07:31:18.201 - root - INFO - Discovered heartbeat_timeout_secs: 10.0
2023-06-08 07:31:18.201 - root - INFO - Discovered outage_report_interval_secs: 5.0
2023-06-08 07:31:18.201 - root - INFO - Data Directory: /home/asm-data/data
2023-06-08 07:31:18.203 - asyncio - DEBUG - Using selector: EpollSelector
2023-06-08 07:31:18.204 - Server - INFO - Connecting to :9000
2023-06-08 07:31:30.064 - ClientHandler - INFO - Getting client for uuid a105a7ea-3eae-11ec-8446-a0afbd87594c
2023-06-08 07:31:30.064 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:31:30.066000
2023-06-08 07:31:30.065 - ClientHandler - INFO - Got RTP Start Command
2023-06-08 07:31:30.065 - ClientHandler - INFO - Got port 9100
2023-06-08 07:31:30.065 - ClientHandler - INFO - Started ffmpeg with command: ffmpeg -i tcp://@:9100?listen -c copy -flags +global
_header -f segment -segment_time 300 -strftime 1 -reset_timestamps 1 /home/asm-data/data/a105a7ea-3eae-11ec-8446-a0afbd87594c/%Y.%
m.%d.%H.%M.%S.mp4  2>&1 | /home/asm-data/ASM-data-server/.venv/bin/python -m ASM_utils.ffmpeg.split_log /var/log/ffmpeg_logs/a105a
7ea-3eae-11ec-8446-a0afbd87594c/stats.log /var/log/ffmpeg_logs/a105a7ea-3eae-11ec-8446-a0afbd87594c/info.log
2023-06-08 07:31:30.066 - ClientHandler - INFO - RTP Server on port 9100 started outputting to /home/asm-data/data/a105a7ea-3eae-1
1ec-8446-a0afbd87594c
2023-06-08 07:31:30.066 - ClientHandler - INFO - FFmpeg logging to: /var/log/ffmpeg_logs/a105a7ea-3eae-11ec-8446-a0afbd87594c
2023-06-08 07:31:35.065 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:31:35.066000
2023-06-08 07:31:40.066 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:31:40.067000
2023-06-08 07:31:45.066 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:31:45.068000
2023-06-08 07:31:46.379 - ClientHandler - INFO - Rx closed
2023-06-08 07:31:46.379 - ClientHandler - INFO - Tx closed
2023-06-08 07:31:46.386 - ClientHandler - INFO - ffmpeg returned with code 0
2023-06-08 07:31:58.245 - root - WARNING - There was an outage: device a105a7ea-3eae-11ec-8446-a0afbd87594c went offline
2023-06-08 07:32:03.251 - root - WARNING - There was an outage: device a105a7ea-3eae-11ec-8446-a0afbd87594c went offline
2023-06-08 07:32:08.256 - root - WARNING - There was an outage: device a105a7ea-3eae-11ec-8446-a0afbd87594c went offline
2023-06-08 07:32:12.237 - ClientHandler - INFO - Getting client for uuid a105a7ea-3eae-11ec-8446-a0afbd87594c
2023-06-08 07:32:12.237 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:32:12.237000
2023-06-08 07:32:12.237 - ClientHandler - INFO - Got RTP Start Command
2023-06-08 07:32:12.238 - ClientHandler - INFO - Got port 9100
2023-06-08 07:32:12.238 - ClientHandler - INFO - Started ffmpeg with command: ffmpeg -i tcp://@:9100?listen -c copy -flags +global
_header -f segment -segment_time 300 -strftime 1 -reset_timestamps 1 /home/asm-data/data/a105a7ea-3eae-11ec-8446-a0afbd87594c/%Y.%
m.%d.%H.%M.%S.mp4  2>&1 | /home/asm-data/ASM-data-server/.venv/bin/python -m ASM_utils.ffmpeg.split_log /var/log/ffmpeg_logs/a105a
7ea-3eae-11ec-8446-a0afbd87594c/stats.log /var/log/ffmpeg_logs/a105a7ea-3eae-11ec-8446-a0afbd87594c/info.log
2023-06-08 07:32:12.238 - ClientHandler - INFO - RTP Server on port 9100 started outputting to /home/asm-data/data/a105a7ea-3eae-1
1ec-8446-a0afbd87594c
2023-06-08 07:32:12.239 - ClientHandler - INFO - FFmpeg logging to: /var/log/ffmpeg_logs/a105a7ea-3eae-11ec-8446-a0afbd87594c
2023-06-08 07:32:17.238 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:32:17.238000
2023-06-08 07:32:22.238 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:32:22.239000
2023-06-08 07:32:27.238 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:32:27.240000
2023-06-08 07:32:32.242 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:32:32.241000
2023-06-08 07:32:35.339 - ClientHandler - INFO - Rx closed
2023-06-08 07:32:35.339 - ClientHandler - INFO - Tx closed
2023-06-08 07:32:35.356 - ClientHandler - INFO - ffmpeg returned with code 0
2023-06-08 07:32:55.194 - ClientHandler - INFO - Getting client for uuid a105a7ea-3eae-11ec-8446-a0afbd87594c
2023-06-08 07:32:55.194 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:32:55.196000
2023-06-08 07:32:55.196 - ClientHandler - INFO - Got RTP Start Command
2023-06-08 07:32:55.197 - ClientHandler - INFO - Got port 9100
2023-06-08 07:32:55.197 - ClientHandler - INFO - Started ffmpeg with command: ffmpeg -i tcp://@:9100?listen -c copy -flags +global
_header -f segment -segment_time 300 -strftime 1 -reset_timestamps 1 /home/asm-data/data/a105a7ea-3eae-11ec-8446-a0afbd87594c/%Y.%
m.%d.%H.%M.%S.mp4  2>&1 | /home/asm-data/ASM-data-server/.venv/bin/python -m ASM_utils.ffmpeg.split_log /var/log/ffmpeg_logs/a105a
7ea-3eae-11ec-8446-a0afbd87594c/stats.log /var/log/ffmpeg_logs/a105a7ea-3eae-11ec-8446-a0afbd87594c/info.log
2023-06-08 07:32:55.197 - ClientHandler - INFO - RTP Server on port 9100 started outputting to /home/asm-data/data/a105a7ea-3eae-1
1ec-8446-a0afbd87594c
2023-06-08 07:32:55.198 - ClientHandler - INFO - FFmpeg logging to: /var/log/ffmpeg_logs/a105a7ea-3eae-11ec-8446-a0afbd87594c
2023-06-08 07:33:00.196 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:33:00.196000
2023-06-08 07:33:05.200 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:33:05.198000
2023-06-08 07:33:10.201 - ClientHandler - INFO - Got heartbeat from a105a7ea-3eae-11ec-8446-a0afbd87594c (Auto-registered device) 
at 2023-06-08 00:33:10.198000
2023-06-08 07:33:12.541 - ClientHandler - INFO - Rx closed
2023-06-08 07:33:12.542 - ClientHandler - INFO - Tx closed
2023-06-08 07:33:12.566 - asyncio - ERROR - Task exception was never retrieved
future: <Task finished name='Task-31' coro=<ClientHandler.onRTPStart() done, defined at /home/asm-data/ASM-data-server/DataServer/
server.py:214> exception=OSError(98, 'Address already in use')>
Traceback (most recent call last):
  File "/home/asm-data/ASM-data-server/DataServer/server.py", line 225, in onRTPStart
    self._config.rtsp_ports.releasePort(free_port)
  File "/home/asm-data/ASM-data-server/DataServer/portAllocator.py", line 96, in releasePort
    self.__reservedPorts[port].bind((self.__ip, port))
OSError: [Errno 98] Address already in use

Relevant Server configuration

# This is a sample configuration for the Aye-Aye Sleep Monitoring Data Server.
# Use this as a basis for configuring the data server for the specific server.

# Local path in which to store the data hierarchy
data_dir: /home/asm-data/data

# This is the primary port for the data server.
port: 9000

# Data Server UID
# 
# This is the UUID that uniquely identifies this device.
server_uuid: 'fda6297c-1107-11ec-bbd2-fcaa14694a7a'

# This is the maximum length of video data
video_increment: 300

# RTSP Server Port Block
#
# This is the block of ports that RTSP servers should use.
rtsp_port_block: [9100, 9200]

# The amount of time in senconds for a device to be considered dropped
# without hearing a heartbeat
heartbeat_timeout_secs: 10.0

# When there is an outage, a report will be sent out every this many seconds
outage_report_interval_secs: 5.0
ntlhui commented 1 year ago

Unclear what the precise problem is - this seems to be a portAllocator issue. Let's start by adding logging to the port allocator