search

scottlamb / retina

High-level RTSP multimedia streaming library, in Rust
https://crates.io/crates/retina
Apache License 2.0
237 stars 47 forks source link

retry TEARDOWN and avoid having to wait for session expiration #34

Closed scottlamb closed 3 years ago

scottlamb commented 3 years ago

After trying out the new Retina 0.3.1 TEARDOWN logic with UDP sessions overnight, I see these log messages:

Sep 09 22:53:27 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Ok(())
Sep 09 22:57:59 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Err("[192.168.5.3:42002(me)->192.168.5.101:554@2021-09-09T22:22:10] Error writing to RTSP peer: Broken pipe (os error 32)")
Sep 09 22:58:59 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Err("[192.168.5.3:41990(me)->192.168.5.101:554@2021-09-09T22:22:10] Error writing to RTSP peer: Broken pipe (os error 32)")
Sep 09 23:19:27 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Ok(())
Sep 10 00:42:16 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Err("[192.168.5.3:33594(me)->192.168.5.104:554@2021-09-09T23:19:28] Error writing to RTSP peer: Broken pipe (os error 32)")
Sep 10 01:03:30 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Err("[192.168.5.3:34470(me)->192.168.5.102:554@2021-09-09T22:22:11] Error writing to RTSP peer: Broken pipe (os error 32)")
Sep 10 02:40:29 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Err("[192.168.5.3:57580(me)->192.168.5.104:554@2021-09-09T22:22:10] Error writing to RTSP peer: Broken pipe (os error 32)")
Sep 10 03:28:36 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Ok(())
Sep 10 03:46:18 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Err("[192.168.5.3:44742(me)->192.168.5.101:554@2021-09-09T22:58:59] Error writing to RTSP peer: Broken pipe (os error 32)")
Sep 10 03:46:18 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Err("[192.168.5.3:44818(me)->192.168.5.101:554@2021-09-09T22:59:59] Error writing to RTSP peer: Broken pipe (os error 32)")
Sep 10 05:03:49 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Err("[192.168.5.3:46364(me)->192.168.5.102:554@2021-09-10T01:04:30] Error writing to RTSP peer: Broken pipe (os error 32)")
Sep 10 05:38:48 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Err("[192.168.5.3:48316(me)->192.168.5.104:554@2021-09-10T02:41:29] Error writing to RTSP peer: Broken pipe (os error 32)")
Sep 10 06:57:56 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Err("[192.168.5.3:51720(me)->192.168.5.104:554@2021-09-10T03:28:37] Error writing to RTSP peer: Broken pipe (os error 32)")
Sep 10 07:18:00 nuc moonfire-nvr[2940163]: tokio-runtime-worker retina::client] Background TEARDOWN: Err("[192.168.5.3:34462(me)->192.168.5.102:554@2021-09-09T22:22:10] Error writing to RTSP peer: Broken pipe (os error 32)")

In other words, most attempts failed because the connection was lost. Matching original errors:

Sep 09 22:53:27 nuc moonfire-nvr[2940163]: s-west_side-main moonfire_nvr::streamer] west_side-main: sleeping for PT1S after error: [192.168.5.3:57566(me)->192.168.5.104:554@2021-09-09T22:22:10, 192.168.5.104:8346->192.168.5.3:19542@2021-09-09T22:53:27, stream=0, ssrc=601c8a2c, seq=0000992e] NAL header ef has F bit set
Sep 09 22:57:59 nuc moonfire-nvr[2940163]: s-back_west-sub moonfire_nvr::streamer] back_west-sub: sleeping for PT1S after error: [192.168.5.3:42002(me)->192.168.5.101:554@2021-09-09T22:22:10, 6399@2021-09-09T22:57:59] Error reading from RTSP peer: Connection reset by peer (os error 104)
Sep 09 22:58:59 nuc moonfire-nvr[2940163]: s-back_west-main moonfire_nvr::streamer] back_west-main: sleeping for PT1S after error: [192.168.5.3:41990(me)->192.168.5.101:554@2021-09-09T22:22:10, 6562@2021-09-09T22:58:59] Error reading from RTSP peer: Connection reset by peer (os error 104)
Sep 09 23:19:27 nuc moonfire-nvr[2940163]: s-west_side-main moonfire_nvr::streamer] west_side-main: sleeping for PT1S after error: [192.168.5.3:59856(me)->192.168.5.104:554@2021-09-09T22:53:28, 192.168.5.104:8350->192.168.5.3:38554@2021-09-09T23:19:27, stream=0, ssrc=15df6214, seq=0000392f] bad header ad in STAP-A
Sep 10 00:42:16 nuc moonfire-nvr[2940163]: s-west_side-main moonfire_nvr::streamer] west_side-main: sleeping for PT1S after error: [192.168.5.3:33594(me)->192.168.5.104:554@2021-09-09T23:19:28, 12796@2021-09-10T00:42:16] Error reading from RTSP peer: Connection reset by peer (os error 104)
Sep 10 01:03:30 nuc moonfire-nvr[2940163]: s-back_east-main moonfire_nvr::streamer] back_east-main: sleeping for PT1S after error: [192.168.5.3:34470(me)->192.168.5.102:554@2021-09-09T22:22:11, 23473@2021-09-10T01:03:30] Error reading from RTSP peer: Connection reset by peer (os error 104)
Sep 10 02:40:29 nuc moonfire-nvr[2940163]: s-west_side-sub moonfire_nvr::streamer] west_side-sub: sleeping for PT1S after error: [192.168.5.3:57580(me)->192.168.5.104:554@2021-09-09T22:22:10, 36635@2021-09-10T02:40:29] Error reading from RTSP peer: Connection reset by peer (os error 104)
Sep 10 03:28:36 nuc moonfire-nvr[2940163]: s-west_side-main moonfire_nvr::streamer] west_side-main: sleeping for PT1S after error: [192.168.5.3:39700(me)->192.168.5.104:554@2021-09-10T00:43:16, 192.168.5.104:8354->192.168.5.3:10646@2021-09-10T03:28:36, stream=0, ssrc=142611f4, seq=00004cf0] Non-fragmented NAL 0d while fragment in progress
Sep 10 03:46:18 nuc moonfire-nvr[2940163]: s-back_west-sub moonfire_nvr::streamer] back_west-sub: sleeping for PT1S after error: [192.168.5.3:44742(me)->192.168.5.101:554@2021-09-09T22:58:59, 40579@2021-09-10T03:46:18] Error reading from RTSP peer: Connection reset by peer (os error 104)
Sep 10 03:46:18 nuc moonfire-nvr[2940163]: s-back_west-main moonfire_nvr::streamer] back_west-main: sleeping for PT1S after error: [192.168.5.3:44818(me)->192.168.5.101:554@2021-09-09T22:59:59, 40473@2021-09-10T03:46:18] Error reading from RTSP peer: Connection reset by peer (os error 104)
Sep 10 03:47:18 nuc moonfire-nvr[2940163]: s-back_west-main moonfire_nvr::streamer] back_west-main: sleeping for PT1S after error: [192.168.5.3:37462(me)->192.168.5.101:554@2021-09-10T03:47:18, 0@2021-09-10T03:47:18] Unauthorized response to DESCRIBE CSeq=1: Non-digest authentication requested: Basic realm="4419b6696b42", Basic realm="4419b6696b42"
Sep 10 05:03:49 nuc moonfire-nvr[2940163]: s-back_east-main moonfire_nvr::streamer] back_east-main: sleeping for PT1S after error: [192.168.5.3:46364(me)->192.168.5.102:554@2021-09-10T01:04:30, 34081@2021-09-10T05:03:49] Error reading from RTSP peer: Connection reset by peer (os error 104)
Sep 10 05:38:48 nuc moonfire-nvr[2940163]: s-west_side-sub moonfire_nvr::streamer] west_side-sub: sleeping for PT1S after error: [192.168.5.3:48316(me)->192.168.5.104:554@2021-09-10T02:41:29, 25618@2021-09-10T05:38:48] Error reading from RTSP peer: Connection reset by peer (os error 104)
Sep 10 06:57:56 nuc moonfire-nvr[2940163]: s-west_side-main moonfire_nvr::streamer] west_side-main: sleeping for PT1S after error: [192.168.5.3:51720(me)->192.168.5.104:554@2021-09-10T03:28:37, 29999@2021-09-10T06:57:56] Error reading from RTSP peer: Connection reset by peer (os error 104)
Sep 10 07:18:00 nuc moonfire-nvr[2940163]: s-back_east-sub moonfire_nvr::streamer] back_east-sub: sleeping for PT1S after error: [192.168.5.3:34462(me)->192.168.5.102:554@2021-09-09T22:22:10, 74450@2021-09-10T07:18:00] Error reading from RTSP peer: Connection reset by peer (os error 104)

After each TEARDOWN failure, we waited for the session to expire before retrying.

Sep 09 22:58:00 nuc moonfire-nvr[2940163]: s-back_west-sub moonfire_nvr::streamer] back_west-sub: Waiting 58.998622284s for 1 stale sessions to expire
Sep 09 22:58:59 nuc moonfire-nvr[2940163]: s-back_west-sub moonfire_nvr::streamer] back_west-sub: Done waiting
Sep 09 22:59:00 nuc moonfire-nvr[2940163]: s-back_west-main moonfire_nvr::streamer] back_west-main: Waiting 58.999854808s for 1 stale sessions to expire
Sep 09 22:59:59 nuc moonfire-nvr[2940163]: s-back_west-main moonfire_nvr::streamer] back_west-main: Done waiting
Sep 10 00:42:17 nuc moonfire-nvr[2940163]: s-west_side-main moonfire_nvr::streamer] west_side-main: Waiting 58.997838487s for 1 stale sessions to expire
Sep 10 00:43:16 nuc moonfire-nvr[2940163]: s-west_side-main moonfire_nvr::streamer] west_side-main: Done waiting
Sep 10 01:03:31 nuc moonfire-nvr[2940163]: s-back_east-main moonfire_nvr::streamer] back_east-main: Waiting 58.99851865s for 1 stale sessions to expire
Sep 10 01:04:30 nuc moonfire-nvr[2940163]: s-back_east-main moonfire_nvr::streamer] back_east-main: Done waiting
Sep 10 02:40:30 nuc moonfire-nvr[2940163]: s-west_side-sub moonfire_nvr::streamer] west_side-sub: Waiting 58.99778954s for 1 stale sessions to expire
Sep 10 02:41:29 nuc moonfire-nvr[2940163]: s-west_side-sub moonfire_nvr::streamer] west_side-sub: Done waiting
Sep 10 03:46:19 nuc moonfire-nvr[2940163]: s-back_west-sub moonfire_nvr::streamer] back_west-sub: Waiting 59.005662614s for 2 stale sessions to expire
Sep 10 03:46:19 nuc moonfire-nvr[2940163]: s-back_west-main moonfire_nvr::streamer] back_west-main: Waiting 58.998409337s for 2 stale sessions to expire
Sep 10 03:47:18 nuc moonfire-nvr[2940163]: s-back_west-sub moonfire_nvr::streamer] back_west-sub: Done waiting
Sep 10 03:47:18 nuc moonfire-nvr[2940163]: s-back_west-main moonfire_nvr::streamer] back_west-main: Done waiting
Sep 10 05:03:50 nuc moonfire-nvr[2940163]: s-back_east-main moonfire_nvr::streamer] back_east-main: Waiting 58.998603346s for 1 stale sessions to expire
Sep 10 05:04:49 nuc moonfire-nvr[2940163]: s-back_east-main moonfire_nvr::streamer] back_east-main: Done waiting
Sep 10 05:38:49 nuc moonfire-nvr[2940163]: s-west_side-sub moonfire_nvr::streamer] west_side-sub: Waiting 58.998713597s for 1 stale sessions to expire
Sep 10 05:39:48 nuc moonfire-nvr[2940163]: s-west_side-sub moonfire_nvr::streamer] west_side-sub: Done waiting
Sep 10 06:57:57 nuc moonfire-nvr[2940163]: s-west_side-main moonfire_nvr::streamer] west_side-main: Waiting 58.998505047s for 1 stale sessions to expire
Sep 10 06:58:56 nuc moonfire-nvr[2940163]: s-west_side-main moonfire_nvr::streamer] west_side-main: Done waiting
Sep 10 07:18:01 nuc moonfire-nvr[2940163]: s-back_east-sub moonfire_nvr::streamer] back_east-sub: Waiting 58.995361566s for 1 stale sessions to expire
Sep 10 07:19:00 nuc moonfire-nvr[2940163]: s-back_east-sub moonfire_nvr::streamer] back_east-sub: Done waiting
Sep 10 08:44:38 nuc moonfire-nvr[2940163]: s-back_west-sub moonfire_nvr::streamer] back_west-sub: Waiting 58.998242234s for 1 stale sessions to expire
Sep 10 08:45:37 nuc moonfire-nvr[2940163]: s-back_west-sub moonfire_nvr::streamer] back_west-sub: Done waiting

Most likely starting a fresh connection and issuing a TEARDOWN would have been successful, and then we could have resumed the stream a minute sooner.

So:

  1. at least in the "connection reset by peer" (on read) / "broken pipe" (on write) case, and probably the "RTSP framing error" case, retry with a fresh connection at least once.
  2. improve the SessionGroup API so there's a way to wait for all the maybe_playing stale session to be gone. There's a wait to wait for all teardowns to be attempted once, and a way to wait for the session expiration time, but not a way to wait for "all have either been torn down successfully (possibly on retry) or have expired".