search

ossrs / srs

SRS is a simple, high-efficiency, real-time media server supporting RTMP, WebRTC, HLS, HTTP-FLV, HTTP-TS, SRT, MPEG-DASH, and GB28181.
https://ossrs.io
MIT License
25.32k stars 5.33k forks source link

WebRTC: Session terminated after 48 hours, triggering "on_unpublish" despite an unchanged client. #3546

Closed linkewei0580 closed 1 year ago

linkewei0580 commented 1 year ago

Note: Please read FAQ before file an issue, see #2716

Description

Please description your issue here

  1. SRS Version: x5.0

  2. SRS Log:

[2023-05-17 16:33:38.120][INFO][410372][79266kn6] http: on_publish ok, client_id=79266kn6, url=http://192.168.1.121:8082/vod/live-room-webrtc/push-stream-start, request={"server_id":"vid-tf37615","service_id":"57s519t4","action":"on_publish","client_id":"79266kn6","ip":"192.168.1.122","vhost":"defaultVhost","app":"live","tcUrl":"webrtc://192.168.1.122/live","stream":"6645","param":"upstream=rtc","stream_url":"/live/6645","stream_id":"vid-718zui9"}, response={"code":0} [2023-05-17 16:33:38.120][INFO][410372][79266kn6] RTC username=557kw04v:2B56, offer=5083B, answer=1602B ............................................................... [2023-05-19 14:50:08.791][INFO][410372][79266kn6] -> HLS time=157225703ms, sno=369205, ts=6645-369204.ts, dur=1526ms, dva=0p [2023-05-19 14:50:38.814][INFO][410372][0dll0r90] -> HLS time=187239588ms, sno=369220, ts=6645-369219.ts, dur=1518ms, dva=0p [2023-05-19 14:51:43.232][INFO][410372][0dll0r90] -> HLS time=251668653ms, sno=369228, ts=6645-369227.ts, dur=1709ms, dva=0p [2023-05-19 14:52:07.939][INFO][410372][0dll0r90] http: on_stop ok, client_id=0dll0r90, url=http://192.168.1.121:7999/stop.json, request={"server_id":"vid-tf37615","service_id":"57s519t4","action":"on_stop","client_id":"0dll0r90","ip":"192.168.1.107","vhost":"defaultVhost","app":"live","tcUrl":"webrtc://192.168.1.122/live","stream":"6645","param":"","stream_url":"/live/6645","stream_id":"vid-718zui9"}, response={"code":0} [2023-05-19 14:52:33.405][INFO][410372][79266kn6] http: on_unpublish ok, client_id=79266kn6, url=http://192.168.1.121:8082/vod/live-room-webrtc/push-stream-end, request={"server_id":"vid-tf37615","service_id":"57s519t4","action":"on_unpublish","client_id":"79266kn6","ip":"192.168.1.122","vhost":"defaultVhost","app":"live","tcUrl":"webrtc://192.168.1.122/live","stream":"6645","param":"upstream=rtc","stream_url":"/live/6645"}, response={"code":0} [2023-05-21 01:14:12.498][WARN][410372][p039dl50][104] handle udp pkt, count=1137/886, err: code=5008(RtcStun)(RTC do STUN or ICE failed) : size=88, data=[12 2e 67 00 1d 7f 32 0d] : no session, peer_id=89.163.144.122:42624, fast=-9176647188664507559 root@ubuntu-1:/home/install/srs/trunk/objs# more srs.log|grep 14:52 [2023-05-17 18:14:52.083][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-17 18:14:52.083][INFO][410372][o7841b47] RTC: Need PLI ssrc=3084392995, play=[79266kn6], publish=[79266kn6], count=1005/1007 [2023-05-17 18:14:52.083][INFO][410372][79266kn6] RTC: Request PLI ssrc=3084392995, play=[79266kn6], count=1004/1005, bytes=12B [2023-05-17 18:14:52.113][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-17 18:14:52.114][INFO][410372][0dll0r90] set ts=2332258095, header=16760, lost=16761 [2023-05-17 18:14:52.352][INFO][410372][p039dl50] <- RTC RECV #15, udp 1215, pps 88/121, schedule 1215 [2023-05-17 18:14:52.400][INFO][410372][4687g23m] Hybrid cpu=15.97%,682MB, cid=2,4, timer=60,10,94, clock=0,25,21,1,0,0,0,0,0, objs=(pkt:300,raw:266,fua:32,msg:510,oth:1,buf:116) [2023-05-17 18:14:52.400][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(121,rtp:116,stun:1,rtcp:4), spkts=(131,rtp:116,stun:1,rtcp:28), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:121,ffid:0,addr:1,faddr:121) [2023-05-17 19:14:52.552][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-17 19:14:52.552][INFO][410372][o7841b47] RTC: Need PLI ssrc=3084392995, play=[79266kn6], publish=[79266kn6], count=1599/1601 [2023-05-17 19:14:52.552][INFO][410372][79266kn6] RTC: Request PLI ssrc=3084392995, play=[79266kn6], count=1598/1599, bytes=12B [2023-05-17 19:14:52.580][INFO][410372][79266kn6] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-17 19:14:52.580][INFO][410372][79266kn6] set ts=2656296885, header=62212, lost=62213 [2023-05-17 22:14:52.695][INFO][410372][0dll0r90] -> HLS time=70019281ms, sno=309200, ts=6645-309199.ts, dur=1886ms, dva=0p [2023-05-17 23:14:52.658][INFO][410372][p039dl50] <- RTC RECV #15, udp 1273, pps 89/127, schedule 1273 [2023-05-18 00:14:52.846][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 00:14:52.865][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 00:14:52.865][INFO][410372][0dll0r90] set ts=4276306425, header=43075, lost=43076 [2023-05-18 01:14:52.759][INFO][410372][4687g23m] Hybrid cpu=14.99%,682MB, cid=2,7, timer=60,10,93, clock=0,21,24,0,0,0,0,0,0, objs=(pkt:309,raw:269,fua:38,msg:521,oth:1,buf:119) [2023-05-18 01:14:52.759][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(126,rtp:119,stun:1,rtcp:6), spkts=(134,rtp:119,stun:1,rtcp:28), rtcp=(pli:1,twcc:9,rr:1), snk=(93,a:46,v:46,h:0), fid=(id:0,fid:126,ffid:0,addr:1,faddr:126) [2023-05-18 06:14:52.043][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 06:14:52.070][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 06:14:52.071][INFO][410372][0dll0r90] set ts=1925248229, header=10312, lost=10313 [2023-05-18 07:14:52.623][INFO][410372][4687g23m] Hybrid cpu=8.99%,681MB, cid=2,4, timer=60,10,94, clock=0,24,22,1,0,0,0,0,0, objs=(pkt:309,raw:270,fua:39,msg:522,oth:1,buf:119) [2023-05-18 07:14:52.623][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(123,rtp:119,stun:1,rtcp:3), spkts=(134,rtp:119,stun:1,rtcp:28), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:123,ffid:0,addr:1,faddr:123) [2023-05-18 07:14:52.809][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 07:14:52.834][INFO][410372][79266kn6] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 07:14:52.834][INFO][410372][79266kn6] set ts=2249313839, header=57686, lost=57687 [2023-05-18 09:14:52.825][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 09:14:52.846][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 09:14:52.847][INFO][410372][0dll0r90] set ts=2897308349, header=15971, lost=15972 [2023-05-18 10:14:52.618][INFO][410372][79266kn6] time diff to large=1002, next out=2124520740, new pkt=2124521742, set to new pkt [2023-05-18 13:14:52.162][INFO][410372][0dll0r90] -> HLS time=-1765095520ms, sno=336211, ts=6645-336210.ts, dur=65ms, dva=0p [2023-05-18 14:14:52.283][INFO][410372][p039dl50] <- RTC RECV #15, udp 1249, pps 91/124, schedule 1249 [2023-05-18 14:14:52.364][INFO][410372][56irc03r] Process: cpu=12.00%,686MB, threads=2 [2023-05-18 14:14:52.779][INFO][410372][4687g23m] Hybrid cpu=12.99%,686MB, cid=2,4, timer=60,10,94, clock=0,27,19,1,0,0,0,0,0, objs=(pkt:306,raw:267,fua:38,msg:516,oth:1,buf:118) [2023-05-18 14:14:52.779][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(123,rtp:118,stun:1,rtcp:4), spkts=(133,rtp:118,stun:1,rtcp:27), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:123,ffid:0,addr:1,faddr:123) [2023-05-18 14:52:00.606][INFO][410372][56irc03r] Process: cpu=6.99%,685MB, threads=2 [2023-05-18 14:52:01.733][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 14:52:01.764][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:01.764][INFO][410372][0dll0r90] set ts=422925673, header=3522, lost=3523 [2023-05-18 14:52:02.835][INFO][410372][0dll0r90] time diff to large=1001, next out=2141150792, new pkt=2141151793, set to new pkt [2023-05-18 14:52:03.188][INFO][410372][4687g23m] Hybrid cpu=4.00%,685MB, cid=2,6, timer=60,10,94, clock=0,27,19,1,1,1,0,0,0, objs=(pkt:290,raw:250,fua:39,msg:492,oth:1,buf:113) [2023-05-18 14:52:03.188][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(119,rtp:113,stun:1,rtcp:5), spkts=(128,rtp:113,stun:1,rtcp:28), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:119,ffid:0,addr:1,faddr:119) [2023-05-18 14:52:05.611][INFO][410372][56irc03r] Process: cpu=10.99%,685MB, threads=2 [2023-05-18 14:52:05.863][INFO][410372][p039dl50] <- RTC RECV #15, udp 1206, pps 91/120, schedule 1206 [2023-05-18 14:52:07.795][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 14:52:07.795][INFO][410372][o7841b47] RTC: Need PLI ssrc=3084392995, play=[79266kn6], publish=[79266kn6], count=13257/13259 [2023-05-18 14:52:07.796][INFO][410372][79266kn6] RTC: Request PLI ssrc=3084392995, play=[79266kn6], count=13256/13257, bytes=12B [2023-05-18 14:52:07.870][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:07.870][INFO][410372][0dll0r90] set ts=423471703, header=3894, lost=3895 [2023-05-18 14:52:08.190][INFO][410372][4687g23m] Hybrid cpu=10.99%,685MB, cid=2,6, timer=60,10,94, clock=0,27,19,1,1,1,0,0,0, objs=(pkt:290,raw:250,fua:39,msg:492,oth:1,buf:113) [2023-05-18 14:52:08.190][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(119,rtp:113,stun:1,rtcp:5), spkts=(128,rtp:113,stun:1,rtcp:28), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:119,ffid:0,addr:1,faddr:119) [2023-05-18 14:52:08.368][INFO][410372][79266kn6] -> HLS time=-223863808ms, sno=339113, ts=6645-339112.ts, dur=1194ms, dva=0p [2023-05-18 14:52:10.619][INFO][410372][56irc03r] Process: cpu=12.99%,685MB, threads=2 [2023-05-18 14:52:12.013][WARN][410372][79266kn6][11] empty nalu [2023-05-18 14:52:13.191][INFO][410372][4687g23m] Hybrid cpu=5.00%,685MB, cid=2,5, timer=60,10,94, clock=0,29,16,1,0,1,0,0,0, objs=(pkt:264,raw:245,fua:18,msg:447,oth:1,buf:104) [2023-05-18 14:52:13.191][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(110,rtp:104,stun:1,rtcp:4), spkts=(119,rtp:104,stun:1,rtcp:27), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:110,ffid:0,addr:1,faddr:110) [2023-05-18 14:52:13.851][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 14:52:14.040][INFO][410372][79266kn6] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:14.041][INFO][410372][79266kn6] set ts=424014943, header=4226, lost=4227 [2023-05-18 14:52:15.625][INFO][410372][56irc03r] Process: cpu=12.96%,685MB, threads=2 [2023-05-18 14:52:15.879][INFO][410372][p039dl50] <- RTC RECV #15, udp 1009, pps 91/100, schedule 1009 [2023-05-18 14:52:16.761][INFO][410372][0dll0r90] 36B video sh, codec(7, profile=Baseline, level=3.1, 544x306, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:16.761][INFO][410372][0dll0r90] set ts=424274143, header=4245, lost=4246 [2023-05-18 14:52:17.214][WARN][410372][79266kn6][11] empty nalu [2023-05-18 14:52:18.191][INFO][410372][4687g23m] Hybrid cpu=12.01%,685MB, cid=2,5, timer=60,10,94, clock=0,29,16,1,0,1,0,0,0, objs=(pkt:264,raw:245,fua:18,msg:447,oth:1,buf:104) [2023-05-18 14:52:18.191][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(110,rtp:104,stun:1,rtcp:4), spkts=(119,rtp:104,stun:1,rtcp:27), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:110,ffid:0,addr:1,faddr:110) [2023-05-18 14:52:19.914][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 14:52:19.914][INFO][410372][o7841b47] RTC: Need PLI ssrc=3084392995, play=[79266kn6], publish=[79266kn6], count=13259/13261 [2023-05-18 14:52:19.914][INFO][410372][79266kn6] RTC: Request PLI ssrc=3084392995, play=[79266kn6], count=13258/13259, bytes=12B [2023-05-18 14:52:19.933][INFO][410372][0dll0r90] 36B video sh, codec(7, profile=Baseline, level=3.1, 544x306, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:19.934][INFO][410372][0dll0r90] set ts=424560793, header=4409, lost=4410 [2023-05-18 14:52:20.633][INFO][410372][56irc03r] Process: cpu=11.99%,685MB, threads=2 [2023-05-18 14:52:23.192][INFO][410372][4687g23m] Hybrid cpu=11.99%,685MB, cid=2,5, timer=60,10,94, clock=0,29,16,1,0,1,0,0,0, objs=(pkt:264,raw:245,fua:18,msg:447,oth:1,buf:104) [2023-05-18 14:52:23.192][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(110,rtp:104,stun:1,rtcp:4), spkts=(119,rtp:104,stun:1,rtcp:27), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:110,ffid:0,addr:1,faddr:110) [2023-05-18 14:52:25.636][INFO][410372][56irc03r] Process: cpu=9.99%,685MB, threads=2 [2023-05-18 14:52:25.897][INFO][410372][p039dl50] <- RTC RECV #15, udp 1088, pps 91/108, schedule 1088 [2023-05-18 14:52:25.968][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 14:52:26.014][INFO][410372][p039dl50] 36B video sh, codec(7, profile=Baseline, level=3.1, 544x306, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:26.014][INFO][410372][p039dl50] set ts=425108173, header=4796, lost=4797 [2023-05-18 14:52:26.790][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:26.790][INFO][410372][0dll0r90] set ts=425177113, header=4863, lost=4864 [2023-05-18 14:52:28.192][INFO][410372][4687g23m] Hybrid cpu=4.00%,686MB, cid=2,4, timer=60,10,94, clock=0,27,19,1,0,1,0,0,0, objs=(pkt:263,raw:229,fua:33,msg:423,oth:1,buf:104) [2023-05-18 14:52:28.192][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(108,rtp:104,stun:1,rtcp:3), spkts=(119,rtp:104,stun:1,rtcp:27), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:108,ffid:0,addr:1,faddr:108) [2023-05-18 14:52:30.645][INFO][410372][56irc03r] Process: cpu=15.00%,685MB, threads=2 [2023-05-18 14:52:32.031][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 14:52:32.031][INFO][410372][o7841b47] RTC: Need PLI ssrc=3084392995, play=[79266kn6], publish=[79266kn6], count=13261/13263 [2023-05-18 14:52:32.031][INFO][410372][79266kn6] RTC: Request PLI ssrc=3084392995, play=[79266kn6], count=13260/13261, bytes=12B [2023-05-18 14:52:32.057][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:32.058][INFO][410372][0dll0r90] set ts=425651233, header=5219, lost=5220 [2023-05-18 14:52:33.193][INFO][410372][4687g23m] Hybrid cpu=11.99%,685MB, cid=2,4, timer=60,10,94, clock=0,27,19,1,0,1,0,0,0, objs=(pkt:263,raw:229,fua:33,msg:423,oth:1,buf:104) [2023-05-18 14:52:33.193][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(108,rtp:104,stun:1,rtcp:3), spkts=(119,rtp:104,stun:1,rtcp:27), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:108,ffid:0,addr:1,faddr:108) [2023-05-18 14:52:35.652][INFO][410372][56irc03r] Process: cpu=12.99%,685MB, threads=2 [2023-05-18 14:52:35.903][INFO][410372][p039dl50] <- RTC RECV #15, udp 1247, pps 91/124, schedule 1247 [2023-05-18 14:52:38.085][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 14:52:38.134][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:38.134][INFO][410372][0dll0r90] set ts=426198523, header=5628, lost=5629 [2023-05-18 14:52:38.193][INFO][410372][4687g23m] Hybrid cpu=12.97%,685MB, cid=2,4, timer=60,10,94, clock=0,27,18,1,0,0,1,0,0, objs=(pkt:293,raw:271,fua:21,msg:504,oth:1,buf:114) [2023-05-18 14:52:38.193][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(118,rtp:114,stun:1,rtcp:3), spkts=(129,rtp:114,stun:1,rtcp:28), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:118,ffid:0,addr:1,faddr:118) [2023-05-18 14:52:38.369][INFO][410372][79266kn6] -> HLS time=-193848952ms, sno=339127, ts=6645-339126.ts, dur=500ms, dva=0p [2023-05-18 14:52:40.661][INFO][410372][56irc03r] Process: cpu=3.99%,686MB, threads=2 [2023-05-18 14:52:43.198][INFO][410372][4687g23m] Hybrid cpu=9.94%,686MB, cid=2,4, timer=60,10,94, clock=0,27,18,1,0,0,1,0,0, objs=(pkt:293,raw:271,fua:21,msg:504,oth:1,buf:114) [2023-05-18 14:52:43.198][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(118,rtp:114,stun:1,rtcp:3), spkts=(129,rtp:114,stun:1,rtcp:28), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:118,ffid:0,addr:1,faddr:118) [2023-05-18 14:52:44.150][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 14:52:44.150][INFO][410372][o7841b47] RTC: Need PLI ssrc=3084392995, play=[79266kn6], publish=[79266kn6], count=13263/13265 [2023-05-18 14:52:44.150][INFO][410372][79266kn6] RTC: Request PLI ssrc=3084392995, play=[79266kn6], count=13262/13263, bytes=12B [2023-05-18 14:52:44.209][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:44.209][INFO][410372][0dll0r90] set ts=426743563, header=6040, lost=6041 [2023-05-18 14:52:45.668][INFO][410372][56irc03r] Process: cpu=3.00%,686MB, threads=2 [2023-05-18 14:52:45.898][INFO][410372][p039dl50] <- RTC RECV #15, udp 1162, pps 91/116, schedule 1162 [2023-05-18 14:52:46.864][INFO][410372][0dll0r90] 36B video sh, codec(7, profile=Baseline, level=3.1, 544x306, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:46.864][INFO][410372][0dll0r90] set ts=426981613, header=6148, lost=6149 [2023-05-18 14:52:48.199][INFO][410372][4687g23m] Hybrid cpu=4.00%,686MB, cid=2,4, timer=60,10,94, clock=0,27,18,1,0,0,1,0,0, objs=(pkt:293,raw:271,fua:21,msg:504,oth:1,buf:114) [2023-05-18 14:52:48.199][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(118,rtp:114,stun:1,rtcp:3), spkts=(129,rtp:114,stun:1,rtcp:28), rtcp=(pli:1,twcc:9,rr:1), snk=(94,a:47,v:47,h:0), fid=(id:0,fid:118,ffid:0,addr:1,faddr:118) [2023-05-18 14:52:50.207][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 14:52:50.240][INFO][410372][79266kn6] 36B video sh, codec(7, profile=Baseline, level=3.1, 544x306, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:50.240][INFO][410372][79266kn6] set ts=427287883, header=6370, lost=6371 [2023-05-18 14:52:50.674][INFO][410372][56irc03r] Process: cpu=11.98%,686MB, threads=2 [2023-05-18 14:52:51.916][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:51.916][INFO][410372][0dll0r90] set ts=427433143, header=6492, lost=6493 [2023-05-18 14:52:53.199][INFO][410372][4687g23m] Hybrid cpu=4.00%,686MB, cid=2,4, timer=60,10,95, clock=0,30,16,1,0,0,0,0,0, objs=(pkt:295,raw:245,fua:49,msg:494,oth:1,buf:115) [2023-05-18 14:52:53.199][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(119,rtp:115,stun:1,rtcp:3), spkts=(130,rtp:115,stun:1,rtcp:27), rtcp=(pli:1,twcc:9,rr:1), snk=(95,a:47,v:47,h:0), fid=(id:0,fid:119,ffid:0,addr:1,faddr:119) [2023-05-18 14:52:55.679][INFO][410372][56irc03r] Process: cpu=11.95%,686MB, threads=2 [2023-05-18 14:52:55.905][INFO][410372][p039dl50] <- RTC RECV #15, udp 1205, pps 91/120, schedule 1205 [2023-05-18 14:52:56.248][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 14:52:56.248][INFO][410372][o7841b47] RTC: Need PLI ssrc=3084392995, play=[79266kn6], publish=[79266kn6], count=13265/13267 [2023-05-18 14:52:56.248][INFO][410372][79266kn6] RTC: Request PLI ssrc=3084392995, play=[79266kn6], count=13264/13265, bytes=12B [2023-05-18 14:52:56.267][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 14:52:56.267][INFO][410372][0dll0r90] set ts=427830853, header=6795, lost=6796 [2023-05-18 14:52:58.199][INFO][410372][4687g23m] Hybrid cpu=13.99%,686MB, cid=2,4, timer=60,10,95, clock=0,30,16,1,0,0,0,0,0, objs=(pkt:295,raw:245,fua:49,msg:494,oth:1,buf:115) [2023-05-18 14:52:58.201][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(119,rtp:115,stun:1,rtcp:3), spkts=(130,rtp:115,stun:1,rtcp:27), rtcp=(pli:1,twcc:9,rr:1), snk=(95,a:47,v:47,h:0), fid=(id:0,fid:119,ffid:0,addr:1,faddr:119) [2023-05-18 15:14:52.023][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-18 15:14:52.023][INFO][410372][0dll0r90] set ts=546243223, header=9511, lost=9512 [2023-05-18 15:14:52.459][INFO][410372][56irc03r] Process: cpu=4.00%,689MB, threads=2 [2023-05-18 16:14:52.486][INFO][410372][79266kn6] -> HLS time=445299989ms, sno=341570, ts=6645-341569.ts, dur=1552ms, dva=0p [2023-05-18 16:14:52.671][INFO][410372][56irc03r] Process: cpu=4.00%,687MB, threads=2 [2023-05-18 16:14:52.937][INFO][410372][p039dl50] <- RTC RECV #15, udp 1197, pps 91/119, schedule 1197 [2023-05-18 17:14:52.633][INFO][410372][56irc03r] Process: cpu=9.99%,685MB, threads=2 [2023-05-18 18:14:52.926][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-18 18:14:52.926][INFO][410372][o7841b47] RTC: Need PLI ssrc=3084392995, play=[79266kn6], publish=[79266kn6], count=15266/15268 [2023-05-18 18:14:52.926][INFO][410372][79266kn6] RTC: Request PLI ssrc=3084392995, play=[79266kn6], count=15265/15266, bytes=12B [2023-05-18 18:14:52.940][INFO][410372][p039dl50] <- RTC RECV #15, udp 532, pps 91/53, schedule 532 [2023-05-18 19:14:52.341][INFO][410372][4687g23m] Hybrid cpu=13.96%,705MB, cid=2,3, timer=59,10,92, clock=0,16,29,1,0,0,0,0,0, objs=(pkt:100,raw:100,fua:0,msg:193,oth:0,buf:50) [2023-05-18 19:14:52.341][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(53,rtp:50,stun:1,rtcp:2), spkts=(64,rtp:50,stun:1,rtcp:27), rtcp=(pli:1,twcc:9,rr:1), snk=(92,a:46,v:46,h:0), fid=(id:0,fid:53,ffid:0,addr:1,faddr:53) [2023-05-19 00:14:52.008][INFO][410372][4687g23m] Hybrid cpu=10.96%,705MB, cid=2,3, timer=59,10,91, clock=0,15,29,1,0,0,0,0,0, objs=(pkt:99,raw:99,fua:0,msg:193,oth:0,buf:49) [2023-05-19 00:14:52.008][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(53,rtp:49,stun:1,rtcp:2), spkts=(64,rtp:49,stun:1,rtcp:27), rtcp=(pli:1,twcc:9,rr:1), snk=(91,a:45,v:45,h:0), fid=(id:0,fid:53,ffid:0,addr:1,faddr:53) [2023-05-19 01:14:52.673][INFO][410372][p039dl50] <- RTC RECV #15, udp 531, pps 90/53, schedule 531 [2023-05-19 02:14:52.066][INFO][410372][56irc03r] Process: cpu=9.99%,705MB, threads=2 [2023-05-19 04:14:52.716][INFO][410372][4687g23m] Hybrid cpu=12.99%,705MB, cid=2,3, timer=60,10,93, clock=0,20,25,1,0,1,1,0,0, objs=(pkt:99,raw:99,fua:0,msg:193,oth:0,buf:49) [2023-05-19 04:14:52.716][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(53,rtp:49,stun:1,rtcp:2), spkts=(64,rtp:49,stun:1,rtcp:28), rtcp=(pli:1,twcc:9,rr:1), snk=(93,a:46,v:46,h:0), fid=(id:0,fid:53,ffid:0,addr:1,faddr:53) [2023-05-19 08:14:52.154][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-19 08:14:52.154][INFO][410372][o7841b47] RTC: Need PLI ssrc=3084392995, play=[79266kn6], publish=[79266kn6], count=23550/23552 [2023-05-19 08:14:52.154][INFO][410372][79266kn6] RTC: Request PLI ssrc=3084392995, play=[79266kn6], count=23549/23550, bytes=12B [2023-05-19 08:14:52.185][INFO][410372][79266kn6] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-19 08:14:52.185][INFO][410372][79266kn6] set ts=1759248477, header=154, lost=155 [2023-05-19 09:14:52.066][INFO][410372][4687g23m] Hybrid cpu=7.99%,689MB, cid=2,7, timer=60,10,93, clock=0,24,22,1,1,0,0,0,0, objs=(pkt:309,raw:269,fua:39,msg:521,oth:1,buf:119) [2023-05-19 09:14:52.066][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(126,rtp:119,stun:1,rtcp:6), spkts=(134,rtp:119,stun:1,rtcp:27), rtcp=(pli:1,twcc:9,rr:1), snk=(93,a:46,v:46,h:0), fid=(id:0,fid:126,ffid:0,addr:1,faddr:126) [2023-05-19 09:14:52.806][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-19 09:14:52.806][INFO][410372][o7841b47] RTC: Need PLI ssrc=3084392995, play=[79266kn6], publish=[79266kn6], count=24144/24146 [2023-05-19 09:14:52.806][INFO][410372][79266kn6] RTC: Request PLI ssrc=3084392995, play=[79266kn6], count=24143/24144, bytes=12B [2023-05-19 09:14:52.833][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-19 09:14:52.833][INFO][410372][0dll0r90] set ts=2083303377, header=46556, lost=46557 [2023-05-19 09:14:52.867][INFO][410372][0dll0r90] time diff to large=1002, next out=2207320235, new pkt=2207321237, set to new pkt [2023-05-19 10:14:52.834][INFO][410372][4687g23m] Hybrid cpu=13.00%,689MB, cid=2,6, timer=60,10,95, clock=0,25,21,1,0,0,0,0,0, objs=(pkt:309,raw:269,fua:39,msg:522,oth:1,buf:119) [2023-05-19 10:14:52.835][INFO][410372][4687g23m] RTC: Server conns=2, rpkts=(126,rtp:119,stun:1,rtcp:5), spkts=(134,rtp:119,stun:1,rtcp:28), rtcp=(pli:1,twcc:9,rr:1), snk=(95,a:47,v:47,h:0), fid=(id:0,fid:126,ffid:0,addr:1,faddr:126) [2023-05-19 14:14:52.782][INFO][410372][o7841b47] RTC: to rtmp bridge request key frame, ssrc=3084392995, publisher cid=79266kn6 [2023-05-19 14:14:52.805][INFO][410372][0dll0r90] 35B video sh, codec(7, profile=Baseline, level=3.1, 816x458, 0kbps, 0.0fps, 0.0s) [2023-05-19 14:14:52.805][INFO][410372][0dll0r90] set ts=3703284657, header=22503, lost=22504 [2023-05-19 14:52:00.944][WARN][410372][79266kn6][4] 2 frames left in the queue on closing [2023-05-19 14:52:03.139][INFO][410372][56irc03r] Process: cpu=99.71%,694MB, threads=2 [2023-05-19 14:52:04.553][INFO][410372][4687g23m] Hybrid cpu=99.71%,694MB, cid=13,1, timer=2,1,1, clock=0,0,0,0,0,0,0,0,1, free=1, objs=(pkt:1,raw:1,fua:0,msg:2,oth:0,buf:1) [2023-05-19 14:52:04.553][INFO][410372][lx0fj1z3] CircuitBreaker: cpu=84.18%,692MB, break=1,0,0, cond=84.18% [2023-05-19 14:52:04.553][WARN][410372][p039dl50][4] handle udp pkt, count=817/566, err: code=5008(RtcStun)(RTC do STUN or ICE failed) : size=41, data=[90 ea 65 8e e8 57 39 0b] : no session, peer_id=192.168.1.115:50081, fast=-6790583811215087424 [2023-05-19 14:52:04.553][INFO][410372][p039dl50] <- RTC RECV #15, udp 44, pps 90/4, schedule 44 [2023-05-19 14:52:05.743][WARN][410372][79266kn6][4][DTLS_HANG] DTLS: Hang, done=0, version=-1, arq=0 [2023-05-19 14:52:07.939][INFO][410372][0dll0r90] http: on_stop ok, client_id=0dll0r90, url=http://192.168.1.121:7999/stop.json, request={"server_id":"vid-tf37615","service_id":"57s519t4","action":"on_stop","client_id":"0dll0r90","ip":"192.168.1.107","vhost":"defaultVhost","app":"live","tcUrl":"webrtc://192.168.1.122/live","stream":"6645","param":"","stream_url":"/live/6645","stream_id":"vid-718zui9"}, response={"code":0} [2023-05-19 14:52:08.889][INFO][410372][56irc03r] Process: cpu=86.12%,692MB, threads=2 [2023-05-19 14:52:09.635][INFO][410372][4687g23m] Hybrid cpu=50.38%,692MB, cid=22,1, timer=1,0,0, clock=0,0,0,0,0,0,0,0,1 [2023-05-19 14:52:14.637][INFO][410372][56irc03r] Process: cpu=0.00%,692MB, threads=2 [2023-05-19 14:52:14.638][INFO][410372][4687g23m] Hybrid cpu=0.00%,692MB, cid=22,1, timer=1,0,0, clock=0,0,0,0,0,0,0,0,1 [2023-05-19 14:52:19.638][INFO][410372][4687g23m] Hybrid cpu=0.00%,692MB, cid=1,0, timer=39,0,0, clock=0,23,4,0,0,0,1,1,1 [2023-05-19 14:52:20.262][INFO][410372][56irc03r] Process: cpu=1.00%,692MB, threads=2 [2023-05-19 14:52:24.876][INFO][410372][4687g23m] Hybrid cpu=0.00%,692MB, cid=1,0, timer=39,0,0, clock=0,23,4,0,0,0,1,1,1 [2023-05-19 14:52:25.303][INFO][410372][56irc03r] Process: cpu=0.00%,692MB, threads=2 [2023-05-19 14:52:29.876][INFO][410372][4687g23m] Hybrid cpu=0.00%,692MB, cid=1,0, timer=40,0,0, clock=0,23,5,0,0,0,1,1,1 [2023-05-19 14:52:31.392][INFO][410372][56irc03r] Process: cpu=0.00%,692MB, threads=2 [2023-05-19 14:52:33.405][INFO][410372][79266kn6] http: on_unpublish ok, client_id=79266kn6, url=http://192.168.1.121:8082/vod/live-room-webrtc/push-stream-end, request={"server_id":"vid-tf37615","service_id":"57s519t4","action":"on_unpublish","client_id":"79266kn6","ip":"192.168.1.122","vhost":"defaultVhost","app":"live","tcUrl":"webrtc://192.168.1.122/live","stream":"6645","param":"upstream=rtc","stream_url":"/live/6645"}, response={"code":0}

  1. SRS Config:

main config for srs.

@see full.conf for detail config.

listen 1935; max_connections 1000; srs_log_tank file; srs_log_file ./objs/srs.log; daemon on;

stream_caster { enabled on; caster gb28181; output rtmp://127.0.0.1/live/[stream]; listen 9000;

Deprecated config, moved to sip.candidate, see gb28181.conf

# @see https://ossrs.net/lts/zh-cn/docs/v5/doc/gb28181#config-candidate
host $CANDIDATE;
sip {
    enabled on;
    listen 5060;
}

}

http_api { enabled on; listen 1985; } http_server { enabled on; listen 8080; dir ./objs/nginx/html;

whether enable crossdomain request.

# for both http static and stream server and apply on all vhosts.
# default: on
crossdomain     on;
# For https_server or HTTPS Streaming.
https {
    # Whether enable HTTPS Streaming.
    # default: off
    enabled on;
    # The listen endpoint for HTTPS Streaming.
    # default: 8088
    listen 8088;
    # The SSL private key file, generated by:
    #       openssl genrsa -out server.key 2048
    # default: ./conf/server.key
    key ./conf/server.key;
    # The SSL public cert file, generated by:
    #       openssl req -new -x509 -key server.key -out server.crt -days 3650 -subj "/C=CN/ST=Beijing/L=Beijing/O=Me/OU=Me/CN=ossrs.net"
    # default: ./conf/server.crt
    cert ./conf/server.crt;
}

} rtc_server { enabled on; listen 8000; # UDP port

@see https://ossrs.net/lts/zh-cn/docs/v4/doc/webrtc#config-candidate

candidate 183.193.74.238; #$CANDIDATE;

} vhost defaultVhost {

 dvr {
     enabled      off;
     dvr_path     /home/install/vidoes/[app]/[stream].[timestamp].flv;
     dvr_plan     session;
 }

 http_hooks {
    # default off.
    enabled   on;
    #on_publish      http://192.168.1.121:7999/publish.json;
    #on_unpublish    http://192.168.1.121:7999/unpublish.json;
    on_publish      http://192.168.1.121:8082/vod/live-room-webrtc/push-stream-start;
    on_unpublish    http://192.168.1.121:8082/vod/live-room-webrtc/push-stream-end;
    on_play         http://192.168.1.121:7999/play.json;
    on_stop         http://192.168.1.121:7999/stop.json;
    on_dvr          http://192.168.1.121:7999/recorddone;

 }

hls {
    enabled         on;
    hls_path        ./objs/nginx/html;
    hls_fragment    2; #10;2;
    hls_window      4; #60;8;
    hls_wait_keyframe   off;
    hls_continuous  on
}

http_remux {
    enabled     on;
    mount       [vhost]/[app]/[stream].flv;
}
rtc {
    enabled     on;
    # @see https://ossrs.net/lts/zh-cn/docs/v4/doc/webrtc#rtmp-to-rtc
    rtmp_to_rtc on;
    # @see https://ossrs.net/lts/zh-cn/docs/v4/doc/webrtc#rtc-to-rtmp
    rtc_to_rtmp on;
    nack on;
    twcc on;
}

tcp_nodelay     on;
min_latency     on;

play{
    gop_cache_max_frames 2500;
    gop_cache       off;
    queue_length    10;
    mw_latency      100;
}
publish {
    mr off;
}

}

Replay

Please describe how to replay the bug?

Step 1: xxxxxx

xxxxxxxxxxxx
xxxxxxxxxxxx
xxxxxxxxxxxx

Step 2: xxxxxx

xxxxxxxxxxxx
xxxxxxxxxxxx
xxxxxxxxxxxx

Step 3: xxxxxx

xxxxxxxxxxxx
xxxxxxxxxxxx
xxxxxxxxxxxx

Expect

Please describe your expectation.

linkewei0580 commented 1 year ago

Today I discovered this again, "on_unpublish", preceded by RTC: session destroy by timeout. What situation can cause this? [2023-05-23 14:55:55.291][INFO][410372][56irc03r] Process: cpu=0.00%,723MB, threads=2 [2023-05-23 14:55:58.398][INFO][410372][4687g23m] Hybrid cpu=2.00%,723MB, cid=2,1, timer=61,10,96, clock=0,42,5,0,1,0,0,0,0 [2023-05-23 14:55:58.399][INFO][410372][c2c9l114] RTC: session destroy by timeout, username=m3usr9l8:sPKY [2023-05-23 14:55:58.399][INFO][410372][c2c9l114] RTC: before dispose resource(RtcConn)(0x61d0008c3c80), conns=2, zombies=0, ign=0, inz=0, ind=0 [2023-05-23 14:55:58.399][INFO][410372][c2c9l114] RTC: session detach from c2c9l114, disposing=1 [2023-05-23 14:55:58.399][INFO][410372][4687g23m] RTC: Server conns=1, rpkts=(1,rtp:0,stun:1,rtcp:1), spkts=(4,rtp:0,stun:1,rtcp:8), rtcp=(pli:1,twcc:9,rr:1), snk=(96,a:48,v:48,h:0), fid=(id:0,fid:1,ffid:0,addr:1,faddr:1) [2023-05-23 14:55:58.399][INFO][410372][0309nu35] RTC: clear zombies=1 resources, conns=2, removing=0, unsubs=1 [2023-05-23 14:55:58.399][INFO][410372][c2c9l114] RTC: disposing #0 resource(RtcConn)(0x61d0008c3c80), conns=2, disposing=1, zombies=0 [2023-05-23 14:55:58.400][INFO][410372][c2c9l114] cleanup when unpublish, created=1, deliver=1 [2023-05-23 14:55:58.404][INFO][410372][c2c9l114] cleanup when unpublish [2023-05-23 14:55:58.404][INFO][410372][c2c9l114] Qavg: 197.672 [2023-05-23 14:55:58.404][WARN][410372][c2c9l114][4] 2 frames left in the queue on closing [2023-05-23 14:55:58.405][WARN][410372][c2c9l114][4][DTLS_HANG] DTLS: Hang, done=0, version=-1, arq=0 [2023-05-23 14:55:58.544][INFO][410372][c2c9l114] http: on_unpublish ok, client_id=c2c9l114, url=http://192.168.1.121:8082/vod/live-room-webrtc/push-stream-end, request={"server_id":"vid-tf37615","service_id":"57s519t4","action":"on_unpublish","client_id":"c2c9l114","ip":"192.168.1.122","vhost":"defaultVhost","app":"live","tcUrl":"webrtc://192.168.1.122/live","stream":"6645","param":"upstream=rtc","stream_url":"/live/6645","stream_id":"vid-d971ut0"}, response={"code":0}

TRANS_BY_GPT3

winlinvip commented 1 year ago

The root cause of the issue is a timeout, and it is a clear and simple explanation.

RTC: session destroy by timeout