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.

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

Connection keeps getting disconnected and reconnecting over and over #3749

Closed
caojxi opened this issue Jul 31, 2023 · 4 comments · Fixed by #3750
Closed

Connection keeps getting disconnected and reconnecting over and over #3749

caojxi opened this issue Jul 31, 2023 · 4 comments · Fixed by #3750
Assignees
Labels
TransByAI Translated by AI/GPT.

Comments

@caojxi
Copy link

caojxi commented Jul 31, 2023

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

Description

When testing on DJI M30, we have identified an issue where the device successfully streams RTMP to the server but keeps getting disconnected and reconnecting repeatedly. The disconnections are usually brief, and the device is able to reconnect quickly. However, this affects the live viewing experience as it becomes choppy. Additionally, the SRS server runs the DVR on every disconnect, resulting in small segments of the full stream being saved on the disk.

Unfortunately, the devices are limited to RTMP, so using SRT is not an option to resolve this issue. We have replicated the problem on a seemingly good wifi connection, so it is unlikely to be solely an internet quality problem, although we cannot completely rule it out. We also cannot rule out the possibility that the device itself is limiting the bandwidth.

  1. SRS Version: 4.0.268

  2. SRS Log:

[2023-07-30 23:50:10.075][Trace][49][2u29kj95] https: connected to https://API:443, cost=8ms
[2023-07-30 23:50:10.352][Trace][49][2u29kj95] http: on_hls ok, client_id=2u29kj95, url=https://VERIFICATION, request={...}, response={"code":0}
[2023-07-30 23:50:10.359][Trace][49][2u29kj95] https: connected to https://API:443, cost=5ms
[2023-07-30 23:50:10.557][Trace][49][2u29kj95] http hook on_hls_notify success. client_id=2u29kj95, url=https://VERIFICATION, code=405, spent=204ms, read=64B, err=Success
[2023-07-30 23:50:10.596][Trace][49][2u29kj95] cleanup when unpublish
[2023-07-30 23:50:10.596][Trace][49][2u29kj95] cleanup when unpublish, created=1, deliver=1
[2023-07-30 23:50:10.602][Trace][49][2u29kj95] https: connected to https://API:443, cost=5ms
[2023-07-30 23:50:10.604][Trace][49][0uv14058] https: connected to https://API:443, cost=7ms
[2023-07-30 23:50:10.949][Trace][49][0uv14058] http hook on_dvr success. client_id=2u29kj95, url=https://VERIFICATION, request={...}, response={"code":0}
[2023-07-30 23:50:10.965][Trace][49][2u29kj95] http: on_unpublish ok, client_id=2u29kj95, url=https://VERIFICATION, request={...}, response={"code":0}
[2023-07-30 23:50:10.976][Trace][49][2u29kj95] https: connected to https://API:443, cost=7ms
[2023-07-30 23:50:11.311][Trace][49][2u29kj95] http: on_close ok, client_id=2u29kj95, url=https://VERIFICATION, request={...}, response={"code":0}
[2023-07-30 23:50:11.311][Trace][49][2u29kj95] TCP: before dispose resource(RtmpConn)(0x55f9b6d8cfc0), conns=2, zombies=0, ign=0, inz=0, ind=0
[2023-07-30 23:50:11.311][Error][49][2u29kj95][0] serve error code=3006 : service cycle : rtmp: stream service : rtmp: receive thread : handle publish message : rtmp: consume message : rtmp: consume video : hub consume video : hls: video : hls: write video : hls: cache video : ts: cache avc : ts: invalid avc sample length=0

↑↑ Here is the moment of disconnection ↑↑

↓↓ Reconnecting again ↓↓

thread [49][2u29kj95]: do_cycle() [src/app/srs_app_rtmp_conn.cpp:217][errno=0]
thread [49][2u29kj95]: service_cycle() [src/app/srs_app_rtmp_conn.cpp:414][errno=0]
thread [49][2u29kj95]: do_publishing() [src/app/srs_app_rtmp_conn.cpp:910][errno=11]
thread [49][2u29kj95]: consume() [src/app/srs_app_recv_thread.cpp:380][errno=11]
thread [49][2u29kj95]: handle_publish_message() [src/app/srs_app_rtmp_conn.cpp:1037][errno=11]
thread [49][2u29kj95]: process_publish_message() [src/app/srs_app_rtmp_conn.cpp:1065][errno=11]
thread [49][2u29kj95]: on_video_imp() [src/app/srs_app_source.cpp:2348][errno=11]
thread [49][2u29kj95]: on_video() [src/app/srs_app_source.cpp:1078][errno=11]
thread [49][2u29kj95]: on_video() [src/app/srs_app_hls.cpp:1338][errno=11]
thread [49][2u29kj95]: write_video() [src/app/srs_app_hls.cpp:1011][errno=11]
thread [49][2u29kj95]: cache_video() [src/kernel/srs_kernel_ts.cpp:2795][errno=11]
thread [49][2u29kj95]: do_cache_avc() [src/kernel/srs_kernel_ts.cpp:2995][errno=11]
[2023-07-30 23:50:11.311][Trace][49][96m892j2] TCP: clear zombies=1 resources, conns=2, removing=0, unsubs=0
[2023-07-30 23:50:11.311][Trace][49][2u29kj95] TCP: disposing #0 resource(RtmpConn)(0x55f9b6d8cfc0), conns=2, disposing=1, zombies=0
[2023-07-30 23:50:11.430][Trace][49][0637j570] HTTP #0 172.31.1.220:8764 GET http://IP:58080/, content-length=-1
[2023-07-30 23:50:11.430][Trace][49][0637j570] http match file=./objs/nginx/html/index.html, pattern=/, upath=/
[2023-07-30 23:50:11.431][Trace][49][0637j570] TCP: before dispose resource(HttpStream)(0x55f9b85879c0), conns=2, zombies=0, ign=0, inz=0, ind=0
[2023-07-30 23:50:11.431][Trace][49][0637j570] client finished.
[2023-07-30 23:50:11.431][Trace][49][96m892j2] TCP: clear zombies=1 resources, conns=2, removing=0, unsubs=0
[2023-07-30 23:50:11.431][Trace][49][0637j570] TCP: disposing #0 resource(HttpStream)(0x55f9b85879c0), conns=2, disposing=1, zombies=0
[2023-07-30 23:50:11.431][Trace][49][42736451] RTMP client ip=61.69.129.33:39808, fd=16
[2023-07-30 23:50:11.470][Trace][49][42736451] simple handshake success.
[2023-07-30 23:50:11.470][Trace][49][42736451] connect app, tcUrl=rtmp://LIVESTREAM_SERVER, pageUrl=, swfUrl=, schema=rtmp, vhost=LIVESTREAM_SERVER, port=51935, app=COMPANY, args=null
[2023-07-30 23:50:11.470][Trace][49][42736451] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2023-07-30 23:50:11.573][Trace][49][42736451] client identified, type=fmle-publish, vhost=LIVESTREAM_SERVER, app=COMPANY, stream=UUID, param=?secret=SECRET, duration=0ms
[2023-07-30 23:50:11.580][Trace][49][42736451] https: connected to https://API:443, cost=5ms
[2023-07-30 23:50:11.817][Trace][49][42736451] http: on_connect ok, client_id=42736451, url=https://VERIFICATION, request={...}, response={"code":0}
[2023-07-30 23:50:11.817][Trace][49][42736451] connected stream, tcUrl=rtmp://LIVESTREAM_SERVER, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=51935, app=COMPANY, stream=UUID, param=?secret=SECRET, args=null
[2023-07-30 23:50:11.817][Trace][49][42736451] source url=/COMPANY/UUID, ip=61.69.129.33, cache=1, is_edge=0, source_id=/2u29kj95
[2023-07-30 23:50:11.888][Trace][49][42736451] https: connected to https://API:443, cost=6ms
[2023-07-30 23:50:12.125][Trace][49][42736451] http: on_publish ok, client_id=42736451, url=https://VERIFICATION, request={...}, response={"code":0}
[2023-07-30 23:50:12.126][Trace][49][42736451] RTC bridge from RTMP, rtmp2rtc=1, keep_bframe=0, merge_nalus=0
[2023-07-30 23:50:12.126][Trace][49][42736451] hls: win=120000ms, frag=10000ms, prefix=, path=./objs/nginx/html, m3u8=[app]/[stream].m3u8, ts=[app]/[stream]-[seq].ts, aof=2.00, floor=0, clean=1, waitk=1, dispose=60000ms, dts_directly=1
[2023-07-30 23:50:12.133][Trace][49][42736451] dvr stream UUID to file /LOCATION/UUID/TIMESTAMP.mp4
[2023-07-30 23:50:12.133][Trace][49][42736451] ignore disabled exec for vhost=__defaultVhost__


↑↑ Generate an MP4 ↑↑
  1. SRS Config:
# !!! Important: SRS will restore this file during each upgrade, please never modify it.

# The config for LigthHouse SRS.
# See https://github.com/ossrs/srs/blob/develop/trunk/conf/full.conf

listen              1935;
max_connections     1000;
# For docker, please use docker logs to manage the logs of SRS.
# See https://docs.docker.com/config/containers/logging/
srs_log_tank        file;
srs_log_file        /data/logs/srs.log;
daemon              on;
disable_daemon_for_docker off;
http_api {
    enabled         on;
    listen          1985;
}
http_server {
    enabled         on;
    listen          8080;
    dir             ./objs/nginx/html;
}
rtc_server {
    enabled on;

    #tcp {
    #   enabled on;
    #   listen 8000;
    #}

    listen 8000; # UDP port
    # @see https://github.com/ossrs/srs/wiki/v4_CN_WebRTC#config-candidate
    candidate $CANDIDATE;
}

# See https://github.com/ossrs/srs/issues/1147
srt_server {
    enabled on;
    listen 10080; # UDP port
    maxbw 1000000000;
    connect_timeout 4000;
    latency 20;
    peerlatency 20;
    recvlatency 20;
}

vhost __defaultVhost__ {
    hls {
        enabled         on;
        hls_fragment    10;
        hls_window      120;
        hls_path        ./objs/nginx/html;
        hls_m3u8_file   [app]/[stream].m3u8;
        hls_ts_file     [app]/[stream]-[seq].ts;
        hls_wait_keyframe       on;
        hls_dispose     60;
    }
    http_remux {
        enabled     on;
        mount       [vhost]/[app]/[stream].flv;
    }
    rtc {
        enabled     on;
        nack on;
        twcc on;
        stun_timeout 30;
        dtls_role passive;
        # @see https://github.com/ossrs/srs/wiki/v4_CN_WebRTC#rtmp-to-rtc
        rtmp_to_rtc on;
        keep_bframe off;
        # @see https://github.com/ossrs/srs/wiki/v4_CN_WebRTC#rtc-to-rtmp
        rtc_to_rtmp on;
        pli_for_rtmp 6.0;
    }

    dvr {
        enabled on;
        dvr_path /data/vlive/[app]/[stream]/[timestamp].mp4;
        dvr_plan session;
    }

    # For the backend server to verify the client.
    http_hooks {
        enabled         on;
        on_connect      https://VERIFICATION_API;
        on_close        https://VERIFICATION_API;
        on_publish      https://VERIFICATION_API;
        on_unpublish    https://VERIFICATION_API;
        on_play         https://VERIFICATION_API;
        on_stop         https://VERIFICATION_API;
        on_dvr          https://VERIFICATION_API;
        on_hls          https://VERIFICATION_API;
        on_hls_notify   https://VERIFICATION_API;
    }
}

Replay

Please describe how to replay the bug.

Step 1: Turn on the manual live stream mode from M30T

Expect

The connection is stable when testing with DJI Mini 2.

TRANS_BY_GPT3

@winlinvip winlinvip added the TransByAI Translated by AI/GPT. label Jul 31, 2023
@chundonglinlin
Copy link
Member

We have analyzed the above problems and there are several solutions that need to be tried.

  1. We have fixed some issues in version 5.0 release. Can you switch to version 5.0 release for testing? The Dockefile path is https://github.com/ossrs/srs/blob/5.0release/Dockerfile
  2. If this problem persists, it may be necessary to perform a packet capture to facilitate the analysis of the problem.It should be noted that chunk_size needs to be set to 128.
    Please provide feedback at any time.

@winlinvip
Copy link
Member

winlinvip commented Aug 1, 2023

SRS 5.0 log:

Directly run srs5, the connection of the drone was stable at the beginning, but then this error occurred.

docker run --rm -it -p 1935:1935 -p 1985:1985 -p 8080:8080 \
    registry.cn-hangzhou.aliyuncs.com/ossrs/srs:5 ./objs/srs -c conf/docker.conf




[2023-08-01 06:41:41.238][INFO][1][9x68ypo3] RTMP client ip=172.17.0.1:34000, fd=13
[2023-08-01 06:41:41.246][INFO][1][9x68ypo3] simple handshake success.
[2023-08-01 06:41:41.246][INFO][1][9x68ypo3] connect app, tcUrl=rtmp://192.168.1.114/live, pageUrl=, swfUrl=, schema=rtmp, vhost=192.168.1.114, port=1935, app=live, args=null
[2023-08-01 06:41:41.246][INFO][1][9x68ypo3] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2023-08-01 06:41:41.256][INFO][1][9x68ypo3] client identified, type=fmle-publish, vhost=192.168.1.114, app=live, stream=livestream, param=, duration=0ms
[2023-08-01 06:41:41.256][INFO][1][9x68ypo3] connected stream, tcUrl=rtmp://192.168.1.114/live, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=live, stream=livestream, param=, args=null
[2023-08-01 06:41:41.256][INFO][1][9x68ypo3] new live source, stream_url=/live/livestream
[2023-08-01 06:41:41.256][INFO][1][9x68ypo3] source url=/live/livestream, ip=172.17.0.1, cache=1/2500, is_edge=0, source_id=/
[2023-08-01 06:41:41.263][INFO][1][9x68ypo3] new rtc source, stream_url=/live/livestream
[2023-08-01 06:41:41.263][INFO][1][9x68ypo3] RTC bridge from RTMP, rtmp2rtc=1, keep_bframe=0, merge_nalus=0
[2023-08-01 06:41:41.264][INFO][1][9x68ypo3] hls: win=60000ms, frag=10000ms, prefix=, path=./objs/nginx/html, m3u8=[app]/[stream].m3u8, ts=[app]/[stream]-[seq].ts, aof=2.00, floor=0, clean=1, waitk=1, dispose=0ms, dts_directly=1
[2023-08-01 06:41:41.264][INFO][1][9x68ypo3] ignore disabled exec for vhost=__defaultVhost__
[2023-08-01 06:41:41.264][INFO][1][9x68ypo3] http: mount flv stream for sid=/live/livestream, mount=/live/livestream.flv
[2023-08-01 06:41:41.264][INFO][1][9x68ypo3] start publish mr=0/350, p1stpt=20000, pnt=5000, tcp_nodelay=0
[2023-08-01 06:41:41.498][INFO][1][0762c298] Hybrid cpu=2.00%,37MB
[2023-08-01 06:41:41.502][INFO][1][wk8v8507] Process: cpu=2.00%,39MB, threads=2
[2023-08-01 06:41:41.782][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:42.721][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:43.774][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:44.749][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:45.736][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:46.498][INFO][1][0762c298] Hybrid cpu=6.00%,47MB
[2023-08-01 06:41:46.507][INFO][1][wk8v8507] Process: cpu=4.00%,49MB, threads=2
[2023-08-01 06:41:46.725][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:47.711][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:48.738][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:49.701][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:50.690][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:51.292][INFO][1][9x68ypo3] -> HLS time=10035889ms, sno=1, ts=livestream-0.ts, dur=9518ms, dva=0p
[2023-08-01 06:41:51.498][INFO][1][0762c298] Hybrid cpu=4.00%,57MB, cid=3,1, timer=61,0,0, clock=1,36,11,0,0,0,0,0,0, objs=(pkt:229,raw:6,fua:221,msg:313,oth:1,buf:1)
[2023-08-01 06:41:51.513][INFO][1][wk8v8507] Process: cpu=4.00%,59MB, threads=2
[2023-08-01 06:41:51.686][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:52.673][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:53.687][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:54.664][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:55.664][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:56.499][INFO][1][0762c298] Hybrid cpu=5.00%,68MB, cid=3,1, timer=61,0,0, clock=1,36,11,0,0,0,0,0,0, objs=(pkt:229,raw:6,fua:221,msg:313,oth:1,buf:1)
[2023-08-01 06:41:56.518][INFO][1][wk8v8507] Process: cpu=4.00%,70MB, threads=2
[2023-08-01 06:41:56.670][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:57.697][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:58.652][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:41:59.626][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:42:00.621][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:42:01.313][INFO][1][9x68ypo3] -> HLS time=20045013ms, sno=2, ts=livestream-1.ts, dur=8632ms, dva=0p
[2023-08-01 06:42:01.499][INFO][1][0762c298] Hybrid cpu=4.00%,79MB, cid=3,1, timer=61,0,0, clock=1,36,11,0,0,0,0,0,0, objs=(pkt:229,raw:6,fua:221,msg:313,oth:1,buf:1)
[2023-08-01 06:42:01.524][INFO][1][wk8v8507] Process: cpu=5.00%,80MB, threads=2
[2023-08-01 06:42:01.617][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:42:02.659][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
[2023-08-01 06:42:03.606][INFO][1][9x68ypo3] 39B video sh,  codec(7, profile=High, level=4, 1920x1088, 0kbps, 0.0fps, 0.0s)
=================================================================
==1==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x60200002c759 at pc 0x5579fa424e7d bp 0x7fcf5a9d4c10 sp 0x7fcf5a9d4c00

image

TRANS_BY_GPT3

@caojxi
Copy link
Author

caojxi commented Aug 1, 2023

tcpdump by running

tcpdump -i any tcp port 1935 -w t.pcap

t.pcap.zip
srs.log

@winlinvip
Copy link
Member

winlinvip commented Aug 2, 2023

Fixed in 4.0.271 5.0.170 6.0.65 See 577cd29 and 6477f31 and 939f6b4 and #3750

@winlinvip winlinvip linked a pull request Aug 2, 2023 that will close this issue
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
TransByAI Translated by AI/GPT.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants