Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

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

Closed
scottlamb opened this issue Sep 10, 2021 · 0 comments
Closed

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

scottlamb opened this issue Sep 10, 2021 · 0 comments

Comments

@scottlamb
Copy link
Owner

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".
@scottlamb scottlamb mentioned this issue Sep 10, 2021
Closed
scottlamb added a commit that referenced this issue Sep 27, 2021
@scottlamb
keep retrying TEARDOWN, using fresh connections
f682d75 
This is half of #34. I still need to adjust the API for waiting until
there are no more stale sessions.
scottlamb added a commit that referenced this issue Sep 28, 2021
@scottlamb
treat TEARDOWN 500 response as OK (sigh)
4961261 
for #34

Details in the new code comment, but this avoids an unnecessary wait
for session expiration with (at least some) Hikvision cameras.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@scottlamb