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

When obs stops streaming, there is a certain probability that it will trigger srs to receive the sig=15 signal and exit. #1634

Closed
bevistomato opened this issue Mar 11, 2020 · 6 comments
Assignees
Labels
Bug It might be a bug. TransByAI Translated by AI/GPT.
Milestone

Comments

@bevistomato
Copy link

bevistomato commented Mar 11, 2020

Description'

Please ensure that the markdown structure is maintained.

Please describe the issue you encountered here.
'
Make sure to maintain the markdown structure.

On Alibaba Cloud ECS machine, deploying SRS in a Docker environment, using OBS for streaming, there is a certain probability that SRS will receive a sig=15 signal and exit when OBS stops streaming (manually or due to network reconnection).

On the morning of March 11, 2020, the experimental data was repeatedly tested and the results are as follows:

Assuming that OBS streaming + stopping streaming is one cycle, the logs are cleared every time SRS exits, and a new Docker container is started to run SRS.

After the first cycle, SRS is triggered to exit twice.
After the second cycle, SRS is triggered to exit four times.
After the third cycle, SRS is triggered to exit once.
After the fourth cycle, SRS is triggered to exit twice.
After the seventh cycle, SRS is triggered to exit once.

  1. SRS version: ossrs/srs:v3.0-b2 ossrs/srs:3
  2. OS: CentOS 7.5 public image
  3. Docker: CE 19.03.7
  4. SRS log is as follows:

There are a total of 10 logs, each of which is very similar. The following are six of them. The first four are the log contents after the second cycle when SRS exits, and the last two are the log contents after the first cycle when SRS exits.

[2020-03-11 02:16:07.092][Trace][1][327] dispatch cached gop success. count=0, duration=0
[2020-03-11 02:16:07.092][Trace][1][327] create consumer, active=1, queue_size=0.00, jitter=30000000
[2020-03-11 02:16:07.092][Trace][1][327] set fd=13, SO_SNDBUF=2626560=>175000, buffer=350ms
[2020-03-11 02:16:07.092][Trace][1][327] start play smi=0ms, mw_sleep=350, mw_enabled=1, realtime=0, tcp_nodelay=0
[2020-03-11 02:16:08.214][Trace][1][326] 7B audio sh, codec(10, profile=LC, 2channels, 0kbps, 44100HZ), flv(16bits, 2channels, 44100HZ)
[2020-03-11 02:16:08.214][Trace][1][326] 44B video sh,  codec(7, profile=Baseline, level=3.1, 960x544, 0kbps, 0.0fps, 0.0s)
[2020-03-11 02:16:08.256][Trace][1][326] -> HLS time=22002395ms, sno=2, ts=yuwen9-1.ts, dur=0.00, dva=0p
[2020-03-11 02:16:09.928][Trace][1][326] -> ENC time=24002389, encoders=1, input=__defaultVhost__/xes/yuwen9
[2020-03-11 02:16:14.140][Warn][1][327][32] client disconnect peer. ret=1009
[2020-03-11 02:16:15.928][Trace][1][326] process pid=14 terminate, please restart it.
[2020-03-11 02:16:16.479][Trace][1][326] fored process, pid=18, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__/yuwen9 -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/xes/yuwen9-%03d.png
[2020-03-11 02:16:16.479][Trace][1][326] send SIGTERM to pid=18
[2020-03-11 02:16:16.480][Trace][1][321] sig=15, user terminate program, fast quit
[2020-03-11 02:16:16.482][Trace][1][328] RTMP client ip=127.0.0.1, fd=13
[2020-03-11 02:16:16.483][Trace][1][328] complex handshake success
[2020-03-11 02:16:16.523][Trace][1][328] connect app, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, args=null
[2020-03-11 02:16:16.523][Trace][1][328] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2020-03-11 02:16:16.603][Trace][1][328] ignore AMF0/AMF3 command message.
[2020-03-11 02:16:16.643][Trace][1][328] ignore AMF0/AMF3 command message.
[2020-03-11 02:16:16.643][Trace][1][328] client identified, type=Play, vhost=__defaultVhost__, app=xes, stream=yuwen9, param=, duration=-1ms
[2020-03-11 02:16:16.643][Trace][1][328] connected stream, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, stream=yuwen9, param=, args=null
[2020-03-11 02:16:16.643][Trace][1][328] source url=/xes/yuwen9, ip=127.0.0.1, cache=1, is_edge=0, source_id=326[326]
[2020-03-11 02:16:16.643][Trace][1][328] create consumer, active=0, queue_size=0.00, jitter=30000000
[2020-03-11 02:16:16.643][Trace][1][328] set fd=13, SO_SNDBUF=2626560=>175000, buffer=350ms
[2020-03-11 02:16:16.643][Trace][1][328] start play smi=0ms, mw_sleep=350, mw_enabled=1, realtime=0, tcp_nodelay=0
[2020-03-11 02:16:16.758][Trace][1][316] cleanup for quit signal fast=1, grace=0
[2020-03-11 02:16:16.758][Warn][1][316][11] main cycle terminated, system quit normally.
[2020-03-11 02:16:16.858][Trace][1][316] srs disposed
[2020-03-11 02:16:16.858][Trace][1][316] srs terminated

[2020-03-11 02:17:22.563][Trace][1][678] fored process, pid=11, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__/yuwen9 -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/xes/yuwen9-%03d.png
[2020-03-11 02:17:22.563][Trace][1][678] ignore disabled exec for vhost=__defaultVhost__
[2020-03-11 02:17:22.564][Trace][1][678] start publish mr=0/350, p1stpt=20000, pnt=5000, tcp_nodelay=0
[2020-03-11 02:17:22.566][Trace][1][679] RTMP client ip=127.0.0.1, fd=13
[2020-03-11 02:17:22.567][Trace][1][679] complex handshake success
[2020-03-11 02:17:22.607][Trace][1][679] connect app, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, args=null
[2020-03-11 02:17:22.607][Trace][1][679] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2020-03-11 02:17:22.687][Trace][1][679] ignore AMF0/AMF3 command message.
[2020-03-11 02:17:22.722][Trace][1][678] got metadata, width=960, height=540
[2020-03-11 02:17:22.727][Trace][1][679] ignore AMF0/AMF3 command message.
[2020-03-11 02:17:22.727][Trace][1][679] client identified, type=Play, vhost=__defaultVhost__, app=xes, stream=yuwen9, param=, duration=-1ms
[2020-03-11 02:17:22.727][Trace][1][679] connected stream, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, stream=yuwen9, param=, args=null
[2020-03-11 02:17:22.727][Trace][1][679] source url=/xes/yuwen9, ip=127.0.0.1, cache=1, is_edge=0, source_id=678[678]
[2020-03-11 02:17:22.727][Trace][1][679] dispatch cached gop success. count=0, duration=0
[2020-03-11 02:17:22.727][Trace][1][679] create consumer, active=1, queue_size=0.00, jitter=30000000
[2020-03-11 02:17:22.727][Trace][1][679] set fd=13, SO_SNDBUF=2626560=>175000, buffer=350ms
[2020-03-11 02:17:22.727][Trace][1][679] start play smi=0ms, mw_sleep=350, mw_enabled=1, realtime=0, tcp_nodelay=0
[2020-03-11 02:17:23.883][Trace][1][678] 7B audio sh, codec(10, profile=LC, 2channels, 0kbps, 44100HZ), flv(16bits, 2channels, 44100HZ)
[2020-03-11 02:17:23.883][Trace][1][678] 44B video sh,  codec(7, profile=Baseline, level=3.1, 960x544, 0kbps, 0.0fps, 0.0s)
[2020-03-11 02:17:24.599][Trace][1][679] -> PLA time=1999998, msgs=26, okbps=188,0,0, ikbps=14,0,0, mw=350
[2020-03-11 02:17:27.779][Trace][1][678] -> HLS time=20000891ms, sno=2, ts=yuwen9-1.ts, dur=0.00, dva=3900p
[2020-03-11 02:17:28.563][Trace][1][678] -> ENC time=20000891, encoders=1, input=__defaultVhost__/xes/yuwen9
[2020-03-11 02:17:29.752][Warn][1][679][32] client disconnect peer. ret=1009
[2020-03-11 02:17:31.563][Trace][1][678] process pid=11 terminate, please restart it.
[2020-03-11 02:17:31.754][Trace][1][678] fored process, pid=15, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__/yuwen9 -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/xes/yuwen9-%03d.png
[2020-03-11 02:17:31.754][Trace][1][678] send SIGTERM to pid=15
[2020-03-11 02:17:31.754][Trace][1][673] sig=15, user terminate program, fast quit
[2020-03-11 02:17:31.757][Trace][1][680] RTMP client ip=127.0.0.1, fd=13
[2020-03-11 02:17:31.757][Trace][1][680] complex handshake success
[2020-03-11 02:17:31.758][Trace][1][668] cleanup for quit signal fast=1, grace=0
[2020-03-11 02:17:31.758][Warn][1][668][11] main cycle terminated, system quit normally.
[2020-03-11 02:17:31.797][Trace][1][680] connect app, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, args=null
[2020-03-11 02:17:31.797][Trace][1][680] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2020-03-11 02:17:31.859][Trace][1][668] srs disposed
[2020-03-11 02:17:31.859][Trace][1][668] srs terminated

[2020-03-11 02:30:59.601][Trace][1][914] fored process, pid=30, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__/yuwen9 -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/xes/yuwen9-%03d.png
[2020-03-11 02:30:59.601][Trace][1][914] ignore disabled exec for vhost=__defaultVhost__
[2020-03-11 02:30:59.601][Trace][1][914] start publish mr=0/350, p1stpt=20000, pnt=5000, tcp_nodelay=0
[2020-03-11 02:30:59.604][Trace][1][915] RTMP client ip=127.0.0.1, fd=13
[2020-03-11 02:30:59.605][Trace][1][915] complex handshake success
[2020-03-11 02:30:59.644][Trace][1][915] connect app, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, args=null
[2020-03-11 02:30:59.644][Trace][1][915] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2020-03-11 02:30:59.724][Trace][1][915] ignore AMF0/AMF3 command message.
[2020-03-11 02:30:59.744][Trace][1][914] got metadata, width=960, height=540
[2020-03-11 02:30:59.764][Trace][1][915] ignore AMF0/AMF3 command message.
[2020-03-11 02:30:59.764][Trace][1][915] client identified, type=Play, vhost=__defaultVhost__, app=xes, stream=yuwen9, param=, duration=-1ms
[2020-03-11 02:30:59.764][Trace][1][915] connected stream, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, stream=yuwen9, param=, args=null
[2020-03-11 02:30:59.764][Trace][1][915] source url=/xes/yuwen9, ip=127.0.0.1, cache=1, is_edge=0, source_id=914[914]
[2020-03-11 02:30:59.764][Trace][1][915] dispatch cached gop success. count=0, duration=0
[2020-03-11 02:30:59.764][Trace][1][915] create consumer, active=1, queue_size=0.00, jitter=30000000
[2020-03-11 02:30:59.764][Trace][1][915] set fd=13, SO_SNDBUF=2626560=>175000, buffer=350ms
[2020-03-11 02:30:59.764][Trace][1][915] start play smi=0ms, mw_sleep=350, mw_enabled=1, realtime=0, tcp_nodelay=0
[2020-03-11 02:31:00.906][Trace][1][914] 7B audio sh, codec(10, profile=LC, 2channels, 0kbps, 44100HZ), flv(16bits, 2channels, 44100HZ)
[2020-03-11 02:31:00.906][Trace][1][914] 44B video sh,  codec(7, profile=Baseline, level=3.1, 960x544, 0kbps, 0.0fps, 0.0s)
[2020-03-11 02:31:03.136][Trace][1][915] -> PLA time=3000312, msgs=27, okbps=384,0,0, ikbps=7,0,0, mw=350
[2020-03-11 02:31:04.759][Trace][1][914] -> HLS time=60003545ms, sno=4, ts=yuwen9-3.ts, dur=0.00, dva=3833p
[2020-03-11 02:31:05.600][Trace][1][914] -> ENC time=60003545, encoders=1, input=__defaultVhost__/xes/yuwen9
[2020-03-11 02:31:06.859][Warn][1][915][32] client disconnect peer. ret=1009
[2020-03-11 02:31:08.600][Trace][1][914] process pid=30 terminate, please restart it.
[2020-03-11 02:31:08.701][Trace][1][914] fored process, pid=34, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__/yuwen9 -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/xes/yuwen9-%03d.png
[2020-03-11 02:31:08.701][Trace][1][914] send SIGTERM to pid=34
[2020-03-11 02:31:08.701][Trace][1][905] sig=15, user terminate program, fast quit
[2020-03-11 02:31:08.704][Trace][1][916] RTMP client ip=127.0.0.1, fd=13
[2020-03-11 02:31:08.705][Trace][1][916] complex handshake success
[2020-03-11 02:31:08.740][Trace][1][900] cleanup for quit signal fast=1, grace=0
[2020-03-11 02:31:08.740][Warn][1][900][11] main cycle terminated, system quit normally.
[2020-03-11 02:31:08.744][Trace][1][916] connect app, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, args=null
[2020-03-11 02:31:08.744][Trace][1][916] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2020-03-11 02:31:08.824][Trace][1][916] ignore AMF0/AMF3 command message.
[2020-03-11 02:31:08.841][Trace][1][900] srs disposed
[2020-03-11 02:31:08.841][Trace][1][900] srs terminated

[2020-03-11 02:22:22.331][Trace][1][422] fored process, pid=14, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__/yuwen9 -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/xes/yuwen9-%03d.png
[2020-03-11 02:22:22.331][Trace][1][422] ignore disabled exec for vhost=__defaultVhost__
[2020-03-11 02:22:22.331][Trace][1][422] start publish mr=0/350, p1stpt=20000, pnt=5000, tcp_nodelay=0
[2020-03-11 02:22:22.334][Trace][1][423] RTMP client ip=127.0.0.1, fd=13
[2020-03-11 02:22:22.335][Trace][1][423] complex handshake success
[2020-03-11 02:22:22.374][Trace][1][423] connect app, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, args=null
[2020-03-11 02:22:22.374][Trace][1][423] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2020-03-11 02:22:22.448][Trace][1][422] got metadata, width=960, height=540
[2020-03-11 02:22:22.454][Trace][1][423] ignore AMF0/AMF3 command message.
[2020-03-11 02:22:22.494][Trace][1][423] ignore AMF0/AMF3 command message.
[2020-03-11 02:22:22.494][Trace][1][423] client identified, type=Play, vhost=__defaultVhost__, app=xes, stream=yuwen9, param=, duration=-1ms
[2020-03-11 02:22:22.494][Trace][1][423] connected stream, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, stream=yuwen9, param=, args=null
[2020-03-11 02:22:22.494][Trace][1][423] source url=/xes/yuwen9, ip=127.0.0.1, cache=1, is_edge=0, source_id=422[422]
[2020-03-11 02:22:22.494][Trace][1][423] dispatch cached gop success. count=0, duration=0
[2020-03-11 02:22:22.494][Trace][1][423] create consumer, active=1, queue_size=0.00, jitter=30000000
[2020-03-11 02:22:22.494][Trace][1][423] set fd=13, SO_SNDBUF=2626560=>175000, buffer=350ms
[2020-03-11 02:22:22.494][Trace][1][423] start play smi=0ms, mw_sleep=350, mw_enabled=1, realtime=0, tcp_nodelay=0
[2020-03-11 02:22:23.608][Trace][1][422] 7B audio sh, codec(10, profile=LC, 2channels, 0kbps, 44100HZ), flv(16bits, 2channels, 44100HZ)
[2020-03-11 02:22:23.609][Trace][1][422] 44B video sh,  codec(7, profile=Baseline, level=3.1, 960x544, 0kbps, 0.0fps, 0.0s)
[2020-03-11 02:22:24.341][Trace][1][423] -> PLA time=2000241, msgs=26, okbps=193,0,0, ikbps=14,0,0, mw=350
[2020-03-11 02:22:24.636][Trace][1][422] -> HLS time=20001744ms, sno=2, ts=yuwen9-1.ts, dur=0.00, dva=966p
[2020-03-11 02:22:25.331][Trace][1][422] -> ENC time=20001744, encoders=1, input=__defaultVhost__/xes/yuwen9
[2020-03-11 02:22:29.497][Warn][1][423][104] client disconnect peer. ret=1007
[2020-03-11 02:22:31.331][Trace][1][422] process pid=14 terminate, please restart it.
[2020-03-11 02:22:31.394][Trace][1][422] fored process, pid=18, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__/yuwen9 -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/xes/yuwen9-%03d.png
[2020-03-11 02:22:31.394][Trace][1][422] send SIGTERM to pid=18
[2020-03-11 02:22:31.394][Trace][1][417] sig=15, user terminate program, fast quit
[2020-03-11 02:22:31.397][Trace][1][424] RTMP client ip=127.0.0.1, fd=13
[2020-03-11 02:22:31.398][Trace][1][424] complex handshake success
[2020-03-11 02:22:31.438][Trace][1][424] connect app, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, args=null
[2020-03-11 02:22:31.438][Trace][1][424] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2020-03-11 02:22:31.518][Trace][1][424] ignore AMF0/AMF3 command message.
[2020-03-11 02:22:31.558][Trace][1][424] ignore AMF0/AMF3 command message.
[2020-03-11 02:22:31.558][Trace][1][424] client identified, type=Play, vhost=__defaultVhost__, app=xes, stream=yuwen9, param=, duration=-1ms
[2020-03-11 02:22:31.558][Trace][1][424] connected stream, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, stream=yuwen9, param=, args=null
[2020-03-11 02:22:31.558][Trace][1][424] source url=/xes/yuwen9, ip=127.0.0.1, cache=1, is_edge=0, source_id=422[422]
[2020-03-11 02:22:31.558][Trace][1][424] create consumer, active=0, queue_size=0.00, jitter=30000000
[2020-03-11 02:22:31.558][Trace][1][424] set fd=13, SO_SNDBUF=2626560=>175000, buffer=350ms
[2020-03-11 02:22:31.558][Trace][1][424] start play smi=0ms, mw_sleep=350, mw_enabled=1, realtime=0, tcp_nodelay=0
[2020-03-11 02:22:31.570][Trace][1][412] cleanup for quit signal fast=1, grace=0
[2020-03-11 02:22:31.570][Warn][1][412][11] main cycle terminated, system quit normally.
[2020-03-11 02:22:31.670][Trace][1][412] srs disposed
[2020-03-11 02:22:31.670][Trace][1][412] srs terminated

[2020-03-11 02:13:32.898][Trace][1][386] fored process, pid=14, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__/yuwen9 -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/xes/yuwen9-%03d.png
[2020-03-11 02:13:32.901][Trace][1][390] RTMP client ip=127.0.0.1, fd=13
[2020-03-11 02:13:32.902][Trace][1][390] complex handshake success
[2020-03-11 02:13:32.941][Trace][1][390] connect app, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, args=null
[2020-03-11 02:13:32.941][Trace][1][390] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2020-03-11 02:13:33.021][Trace][1][390] ignore AMF0/AMF3 command message.
[2020-03-11 02:13:33.061][Trace][1][390] ignore AMF0/AMF3 command message.
[2020-03-11 02:13:33.061][Trace][1][390] client identified, type=Play, vhost=__defaultVhost__, app=xes, stream=yuwen9, param=, duration=-1ms
[2020-03-11 02:13:33.061][Trace][1][390] connected stream, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, stream=yuwen9, param=, args=null
[2020-03-11 02:13:33.061][Trace][1][390] source url=/xes/yuwen9, ip=127.0.0.1, cache=1, is_edge=0, source_id=386[386]
[2020-03-11 02:13:33.061][Trace][1][390] dispatch cached gop success. count=233, duration=3177
[2020-03-11 02:13:33.061][Trace][1][390] create consumer, active=1, queue_size=0.00, jitter=30000000
[2020-03-11 02:13:33.061][Trace][1][390] set fd=13, SO_SNDBUF=2626560=>175000, buffer=350ms
[2020-03-11 02:13:33.061][Trace][1][390] start play smi=0ms, mw_sleep=350, mw_enabled=1, realtime=0, tcp_nodelay=0
[2020-03-11 02:13:35.600][Warn][1][390][32] client disconnect peer. ret=1009
[2020-03-11 02:13:35.898][Trace][1][386] process pid=14 terminate, please restart it.
[2020-03-11 02:13:35.898][Trace][1][386] -> ENC time=24000192, encoders=1, input=__defaultVhost__/xes/yuwen9
[2020-03-11 02:13:36.897][Trace][1][386] <- CPB time=20000184, okbps=1,0,0, ikbps=658,0,0, mr=0/350, p1stpt=20000, pnt=5000
[2020-03-11 02:13:37.559][Trace][1][386] fored process, pid=18, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__/yuwen9 -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/xes/yuwen9-%03d.png
[2020-03-11 02:13:37.559][Trace][1][386] send SIGTERM to pid=18
[2020-03-11 02:13:37.559][Trace][1][385] sig=15, user terminate program, fast quit
[2020-03-11 02:13:37.562][Trace][1][391] RTMP client ip=127.0.0.1, fd=13
[2020-03-11 02:13:37.563][Trace][1][391] complex handshake success
[2020-03-11 02:13:37.602][Trace][1][391] connect app, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, args=null
[2020-03-11 02:13:37.602][Trace][1][391] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2020-03-11 02:13:37.682][Trace][1][391] ignore AMF0/AMF3 command message.
[2020-03-11 02:13:37.722][Trace][1][391] ignore AMF0/AMF3 command message.
[2020-03-11 02:13:37.722][Trace][1][391] client identified, type=Play, vhost=__defaultVhost__, app=xes, stream=yuwen9, param=, duration=-1ms
[2020-03-11 02:13:37.722][Trace][1][391] connected stream, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, stream=yuwen9, param=, args=null
[2020-03-11 02:13:37.722][Trace][1][391] source url=/xes/yuwen9, ip=127.0.0.1, cache=1, is_edge=0, source_id=386[386]
[2020-03-11 02:13:37.722][Trace][1][391] create consumer, active=0, queue_size=0.00, jitter=30000000
[2020-03-11 02:13:37.722][Trace][1][391] set fd=13, SO_SNDBUF=2626560=>175000, buffer=350ms
[2020-03-11 02:13:37.722][Trace][1][391] start play smi=0ms, mw_sleep=350, mw_enabled=1, realtime=0, tcp_nodelay=0
[2020-03-11 02:13:38.458][Trace][1][380] cleanup for quit signal fast=1, grace=0
[2020-03-11 02:13:38.458][Warn][1][380][11] main cycle terminated, system quit normally.
[2020-03-11 02:13:38.559][Trace][1][380] srs disposed
[2020-03-11 02:13:38.559][Trace][1][380] srs terminated
[2020-03-11 02:18:53.456][Trace][1][354] fored process, pid=22, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__/yuwen9 -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/xes/yuwen9-%03d.png
[2020-03-11 02:18:53.456][Trace][1][354] -> ENC time=36000196, encoders=1, input=__defaultVhost__/xes/yuwen9
[2020-03-11 02:18:53.459][Trace][1][360] RTMP client ip=127.0.0.1, fd=13
[2020-03-11 02:18:53.460][Trace][1][360] complex handshake success
[2020-03-11 02:18:53.500][Trace][1][360] connect app, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, args=null
[2020-03-11 02:18:53.500][Trace][1][360] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2020-03-11 02:18:53.580][Trace][1][360] ignore AMF0/AMF3 command message.
[2020-03-11 02:18:53.620][Trace][1][360] ignore AMF0/AMF3 command message.
[2020-03-11 02:18:53.620][Trace][1][360] client identified, type=Play, vhost=__defaultVhost__, app=xes, stream=yuwen9, param=, duration=-1ms
[2020-03-11 02:18:53.620][Trace][1][360] connected stream, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, stream=yuwen9, param=, args=null
[2020-03-11 02:18:53.620][Trace][1][360] source url=/xes/yuwen9, ip=127.0.0.1, cache=1, is_edge=0, source_id=354[354]
[2020-03-11 02:18:53.620][Trace][1][360] dispatch cached gop success. count=111, duration=1510
[2020-03-11 02:18:53.620][Trace][1][360] create consumer, active=1, queue_size=0.00, jitter=30000000
[2020-03-11 02:18:53.620][Trace][1][360] set fd=13, SO_SNDBUF=2626560=>175000, buffer=350ms
[2020-03-11 02:18:53.620][Trace][1][360] start play smi=0ms, mw_sleep=350, mw_enabled=1, realtime=0, tcp_nodelay=0
[2020-03-11 02:18:54.369][Trace][1][360] -> PLA time=1000000, msgs=29, okbps=1450,0,0, ikbps=28,0,0, mw=350
[2020-03-11 02:18:56.860][Trace][1][354] -> HLS time=40000198ms, sno=3, ts=yuwen9-2.ts, dur=0.00, dva=4767p
[2020-03-11 02:18:57.721][Warn][1][360][4] client disconnect peer. ret=1009
[2020-03-11 02:18:59.456][Trace][1][354] process pid=22 terminate, please restart it.
[2020-03-11 02:18:59.969][Trace][1][354] fored process, pid=26, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-xes-yuwen9-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__/yuwen9 -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/xes/yuwen9-%03d.png
[2020-03-11 02:18:59.969][Trace][1][354] send SIGTERM to pid=26
[2020-03-11 02:18:59.969][Trace][1][353] sig=15, user terminate program, fast quit
[2020-03-11 02:18:59.972][Trace][1][361] RTMP client ip=127.0.0.1, fd=13
[2020-03-11 02:18:59.973][Trace][1][361] complex handshake success
[2020-03-11 02:19:00.013][Trace][1][361] connect app, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, args=null
[2020-03-11 02:19:00.013][Trace][1][361] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=128, out.chunk=128
[2020-03-11 02:19:00.093][Trace][1][361] ignore AMF0/AMF3 command message.
[2020-03-11 02:19:00.133][Trace][1][361] ignore AMF0/AMF3 command message.
[2020-03-11 02:19:00.133][Trace][1][361] client identified, type=Play, vhost=__defaultVhost__, app=xes, stream=yuwen9, param=, duration=-1ms
[2020-03-11 02:19:00.133][Trace][1][361] connected stream, tcUrl=rtmp://127.0.0.1:1935/xes?vhost=__defaultVhost__, pageUrl=, swfUrl=, schema=rtmp, vhost=__defaultVhost__, port=1935, app=xes, stream=yuwen9, param=, args=null
[2020-03-11 02:19:00.133][Trace][1][361] source url=/xes/yuwen9, ip=127.0.0.1, cache=1, is_edge=0, source_id=354[354]
[2020-03-11 02:19:00.133][Trace][1][361] create consumer, active=0, queue_size=0.00, jitter=30000000
[2020-03-11 02:19:00.133][Trace][1][361] set fd=13, SO_SNDBUF=2626560=>175000, buffer=350ms
[2020-03-11 02:19:00.133][Trace][1][361] start play smi=0ms, mw_sleep=350, mw_enabled=1, realtime=0, tcp_nodelay=0
[2020-03-11 02:19:00.840][Trace][1][348] cleanup for quit signal fast=1, grace=0
[2020-03-11 02:19:00.840][Warn][1][348][11] main cycle terminated, system quit normally.
[2020-03-11 02:19:00.941][Trace][1][348] srs disposed
[2020-03-11 02:19:00.941][Trace][1][348] srs terminated
  1. The configuration of SRS is as follows (Config):

listen              1935;
max_connections     1000;
srs_log_tank        file;
srs_log_file        ./objs/srs.log;
daemon              off;
http_api {
    enabled         on;
    listen          1985;
}
http_server {
    enabled         on;
    listen          8080;
    dir             ./objs/nginx/html;
}
stats {
    network         0;
    disk            sda sdb xvda xvdb;
}
vhost __defaultVhost__ {
    hls {
        enabled         on;
		hls_cleanup     on;
		hls_dispose     0;
    }
    http_remux {
        enabled     on;
    }
	http_hooks {
        enabled         on;
		on_publish      http://47.112.246.249/api/UserChecker.php;
	}
	transcode {
        enabled on;
        ffmpeg ./objs/ffmpeg/bin/ffmpeg;
        engine snapshot {
            enabled on;
            iformat flv;
            vfilter {
                vf fps=1;
            }
            vcodec png;
            vparams {
                vframes 6;
            }
            acodec an;
            oformat image2;
            output ./objs/nginx/html/[app]/[stream]-%03d.png;
        }
    }
}

  1. The startup script is as follows:
docker run -d -p 1935:1935 -p 1985:1985 -p 8080:8080 \
    -v /root/srs/srs.conf:/usr/local/srs/conf/srs.conf \
    -v /root/srs/srs.log:/usr/local/srs/objs/srs.log \
    ossrs/srs:v3.0-b2
  1. The general configuration of OBS is as follows:
- Bitrate: 550kbps
- Encoding: x264
- Preset: ultrafast
- Resolution: 960x540
- Frame rate: 30
- Streaming content: A video file received on WeChat PC version

Replay

How to replay bug?

Steps to reproduce the bug

Steps to replay the bug:

  1. Start SRS using the startup script.
  2. Track the log in real-time by running tail -f srs.log.
  3. Stream using OBS.
  4. When you see the following content in the log, immediately click on stop streaming in OBS (as soon as you see "client disconnect" flash), which has a high chance of triggering SRS to exit.
[2020-03-11 02:17:28.563][Trace][1][678] -> ENC time=20000891, encoders=1, input=__defaultVhost__/xes/yuwen9
[2020-03-11 02:17:29.752][Warn][1][679][32] client disconnect peer. ret=1009

Expected behavior:

Expected behavior:

Describe your expectation
The SRS does not exit and continues to work normally.

TRANS_BY_GPT3

@winlinvip
Copy link
Member

winlinvip commented Mar 11, 2020

According to the above logs and operations, find a reproducible path where SRS will receive a SIGTERM exit immediately after the screenshot of FFMPEG exits and OBS is stopped.

[2020-03-11 10:32:15.758][Trace][1][1098] RTMP client ip=42.120.75.143, fd=10
[2020-03-11 10:32:15.792][Trace][1][1098] simple handshake success.
[2020-03-11 10:32:15.823][Trace][1][1098] connect app, tcUrl=rtmp://ossrs.net:2935live, pageUrl=, swfUrl=rtmp://ossrs.net:2935live, schema=rtmp, vhost=, port=1935, app=ossrs.net:2935live, args=null
[2020-03-11 10:32:15.823][Trace][1][1098] protocol in.buffer=0, in.ack=0, out.ack=0, in.chunk=4096, out.chunk=128
[2020-03-11 10:32:15.888][Trace][1][1098] client identified, type=fmle-publish, vhost=, app=ossrs.net:2935live, stream=livestream, param=, duration=0ms
[2020-03-11 10:32:15.888][Trace][1][1098] connected stream, tcUrl=rtmp://ossrs.net:2935live, pageUrl=, swfUrl=rtmp://ossrs.net:2935live, schema=rtmp, vhost=__defaultVhost__, port=1935, app=ossrs.net:2935live, stream=livestream, param=, args=null
[2020-03-11 10:32:15.889][Trace][1][1098] source url=/ossrs.net:2935live/livestream, ip=42.120.75.143, cache=1, is_edge=0, source_id=-1[-1]
[2020-03-11 10:32:15.981][Trace][1][1098] ignore disabled exec for vhost=__defaultVhost__
[2020-03-11 10:32:15.981][Trace][1][1098] start publish mr=0/350, p1stpt=20000, pnt=5000, tcp_nodelay=0
[2020-03-11 10:32:15.981][Trace][1][1098] fork process, ppid=1, cid=1098: ./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/ossrs.net:2935live?vhost=__defaultVhost__/livestream -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/ossrs.net:2935live/livestream-%03d.png 1 > ./objs/ffmpeg-encoder-__defaultVhost__-ossrs.net:2935live-livestream-snapshot.log 2 > ./objs/ffmpeg-encoder-__defaultVhost__-ossrs.net:2935live-livestream-snapshot.log
[2020-03-11 10:32:15.981][Trace][1][1098] fored process, pid=10, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-ossrs.net:2935live-livestream-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-ossrs.net:2935live-livestream-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/ossrs.net:2935live?vhost=__defaultVhost__/livestream -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/ossrs.net:2935live/livestream-%03d.png
[2020-03-11 10:32:16.043][Trace][1][1098] got metadata, width=1152, height=720
[2020-03-11 10:32:16.953][Trace][1][1098] 4B audio sh, codec(10, profile=LC, 2channels, 0kbps, 44100HZ), flv(16bits, 2channels, 44100HZ)
[2020-03-11 10:32:16.953][Trace][1][1098] 45B video sh,  codec(7, profile=High, level=3.1, 1152x720, 0kbps, 0.0fps, 0.0s)

[2020-03-11 10:32:18.981][Trace][1][1098] process pid=10 terminate, please restart it.
[2020-03-11 10:32:21.352][Trace][1][1098] fork process, ppid=1, cid=1098: ./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/ossrs.net:2935live?vhost=__defaultVhost__/livestream -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/ossrs.net:2935live/livestream-%03d.png 1 > ./objs/ffmpeg-encoder-__defaultVhost__-ossrs.net:2935live-livestream-snapshot.log 2 > ./objs/ffmpeg-encoder-__defaultVhost__-ossrs.net:2935live-livestream-snapshot.log
[2020-03-11 10:32:21.353][Trace][1][1098] fored process, pid=11, bin=./objs/ffmpeg/bin/ffmpeg, stdout=./objs/ffmpeg-encoder-__defaultVhost__-ossrs.net:2935live-livestream-snapshot.log, stderr=./objs/ffmpeg-encoder-__defaultVhost__-ossrs.net:2935live-livestream-snapshot.log, argv=./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/ossrs.net:2935live?vhost=__defaultVhost__/livestream -vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 -y ./objs/nginx/html/ossrs.net:2935live/livestream-%03d.png
[2020-03-11 10:32:21.353][Trace][1][1098] send SIGTERM to pid=11
[2020-03-11 10:32:21.353][Trace][1][1097] sig=15, user terminate program, fast quit
[2020-03-11 10:32:21.362][Trace][1][1098] SIGTERM stop process pid=11 ok.
[2020-03-11 10:32:21.362][Trace][1][1098] cleanup when unpublish

[2020-03-11 10:32:21.362][Warn][1][1098][104] client disconnect peer. ret=1007
[2020-03-11 10:32:21.412][Trace][1][1092] cleanup for quit signal fast=1, grace=0
[2020-03-11 10:32:21.412][Warn][1][1092][104] main cycle terminated, system quit normally.
[2020-03-11 10:32:21.512][Trace][1][1092] srs disposed
[2020-03-11 10:32:21.512][Trace][1][1092] srs terminated

In fact, the process PID of the exiting FFMPEG for the screenshot is 10, while the new FFMPEG process for restarting is 11. When the streaming is stopped at this point, the signal is sent to 11.

It seems that after forking, SIGTERM is immediately sent, which may cause the parent process to receive the signal before the child process is fully started. To avoid this issue, it can be modified to wait for about 10ms after starting before sending the signal.

TRANS_BY_GPT3

@winlinvip
Copy link
Member

winlinvip commented Mar 11, 2020

There is another improvement to be made. Before restarting the FFMPEG process, it can first check if it has already stopped. Currently, it waits for 3 seconds, starts the FFMPEG subprocess, and then checks if it has stopped, resulting in the need to immediately stop the process after starting it.

[2020-03-11 11:09:41.116][Trace][624][666] process pid=625 terminate, please restart it.
[2020-03-11 11:09:43.335][Trace][624][666] cleanup when unpublish
[2020-03-11 11:09:43.335][Warn][624][666][104] client disconnect peer. ret=1007

As shown in the log above, if you stop the stream, there will be no need to fork FFMPEG and send SIGTERM to stop it, avoiding such unnecessary hassle.

TRANS_BY_GPT3

@winlinvip
Copy link
Member

winlinvip commented Mar 11, 2020

There is another improvement point, FFMPEG's output does not support time and date format, while HLS and DVR support this format.

        # the hls ts file name.
        # we supports some variables to generate the filename.
        #       [vhost], the vhost of stream.
        #       [app], the app of stream.
        #       [stream], the stream name of stream.
        #       [2006], replace this const to current year.
        #       [01], replace this const to current month.
        #       [02], replace this const to current date.
        #       [15], replace this const to current hour.
        #       [04], replace this const to current minute.
        #       [05], replace this const to current second.
        #       [999], replace this const to current millisecond.
        #       [timestamp],replace this const to current UNIX timestamp in ms.
        #       [seq], the sequence number of ts.
        #       [duration], replace this const to current ts duration.
        # @see https://github.com/ossrs/srs/wiki/v2_CN_DVR#custom-path
        # @see https://github.com/ossrs/srs/wiki/v2_CN_DeliveryHLS#hls-config
        # default: [app]/[stream]-[seq].ts
        hls_ts_file     [app]/[stream]-[seq].ts;

From what I see in the configuration of this issue, when using FFMPEG to capture screenshots, it requires passing a timestamp.

output ./objs/nginx/html/[app]/[stream]-[04]-[05].png;

Currently, due to the lack of variable replacement, there is still only one screenshot.

./objs/ffmpeg/bin/ffmpeg -f flv -i rtmp://127.0.0.1:1935/ossrs.net:2935live?vhost=__defaultVhost__/livestream \
-vf fps=1 -vcodec png -threads 1 -vframes 6 -an -f image2 \
-y ./objs/nginx/html/live/livestream-[04]-[05].png

TRANS_BY_GPT3

@songliwei2014
Copy link

songliwei2014 commented Aug 6, 2020

Hi, I want to ask, has this issue been resolved?
We are currently using the old SRS2.0 and we have also encountered the problem mentioned by the user, where the SRS forked subprocess is immediately sent a SIGTERM signal, but surprisingly, this signal is handled by the parent process, causing the parent process SRS to exit itself.
[2020-08-02 07:52:51] DEBUG src/app/srs_app_ffmpeg.cpp|854| vfored ffmpeg encoder engine, pid=118711
[2020-08-02 07:52:51] DEBUG src/app/srs_app_utility.cpp|352| send SIGTERM to pid=118711
[2020-08-02 07:52:51] WARNING src/app/srs_app_rtmp_conn.cpp|763| stream|/live/5159818|publishing already ended, stop playing
[2020-08-02 07:52:51] ERROR src/app/srs_app_rtmp_conn.cpp|468| stream service cycle failed. ret=9002
[2020-08-02 07:52:51] DEBUG src/app/srs_app_server.cpp|1136| user terminate program, gracefully quit.
[2020-08-02 07:52:52] DEBUG src/app/srs_app_utility.cpp|367| SIGTERM stop process pid=118711 ok.

Then I saw the reason you mentioned: "It seems that the SIGTERM signal is sent immediately after forking, and at this time the subprocess may not have fully started, so the parent process receives the signal. Changing it to wait for about 10ms after starting can avoid this problem.

But I tried to reproduce it by forking and immediately sending SIGTERM to the child process, but I couldn't reproduce the phenomenon of the parent process receiving the signal. May I ask if you have any methods to reproduce it?

Although the parent process and the child process will share the same signal handler function SrsServer::on_signal(int signo) after forking and before executing, when the child process calls this signal handler function and sets the variable signal_gracefully_quit = true, a copy-on-write operation will be performed. Then I printed the variable signal_gracefully_quit in both the parent and child processes, and in the parent process it is false, while in the child process it is true.

TRANS_BY_GPT3

@winlinvip
Copy link
Member

winlinvip commented Aug 6, 2020

SRS3 has been resolved, you can see the detailed changes in the commit above.

The main issue is that after starting the FFMPEG process in SRS, it is immediately stopped. Since the FFMPEG subprocess has not yet started, a SIGTERM signal is sent to it, causing the parent process (SRS process) to receive this signal.

TRANS_BY_GPT3

@songliwei2014
Copy link

songliwei2014 commented Aug 7, 2020

Disturbing you again.
SRS log:
[2020-08-06 21:58:55.270329] DEBUG src/app/srs_app_ffmpeg.cpp|854| vfored ffmpeg encoder engine, pid=303001
[2020-08-06 21:58:55.270608] DEBUG src/app/srs_app_utility.cpp|352| send SIGTERM to pid=303001
[2020-08-06 21:58:55.272311] DEBUG src/app/srs_app_server.cpp|1136| user terminate program, gracefully quit.
[2020-08-06 21:58:55.505645] DEBUG src/app/srs_app_utility.cpp|367| SIGTERM stop process pid=303001 ok.

From the logs, it can be seen that at the same moment on 2020-08-06 21:58:55.27, forking was successful, followed immediately by executing kill(303001, SIGTERM). This is the phenomenon you mentioned, the "must-have" path: "Based on the above logs and operations, find a must-have path, when the screenshot FFMPEG exits, immediately stop OBS, then SRS will receive SIGTERM to exit." This path causes SRS to fork first and then immediately kill the child process FFmpeg. But when forking first and then immediately killing the child process, the signal goes to the parent process. What is the underlying principle behind this?

Why does it cause SRS to, after forking at 2020-08-06 21:58:55.270329, obtain the child process's pid=303001, and then send kill SIGTERM at 2020-08-06 21:58:55.270608, resulting in both the child process and the parent process receiving and handling this signal?
The fact that the parent process receives and handles the signal can be seen through the logs:
[2020-08-06 21:58:55.272311] DEBUG src/app/srs_app_server.cpp|1136| user terminate program, gracefully quit.
This is printed in srs_app_server.cpp, immediately after SRS sends kill SIGTERM.

The question I want to figure out is:
Why does the parent process SRS, after forking at 2020-08-06 21:58:55.270329, immediately execute kill(303001, SIGTERM) at 2020-08-06 21:58:55.270608? The result is that the parent process handles this SIGTERM. After forking, before the child process executes exec, the parent and child processes share the same signal handler function. Even if the child process receives the signal, it will use the same signal handler function void SrsServer::on_signal(int signo) as the parent process. It updates the signal_gracefully_quit field through copy-on-write, updating the process itself, which is the child process, not the parent process. I have verified this through experiments. I am very curious about the underlying principles and want to understand them.

Thank you once again for your valuable time. I hope to receive your reply.

TRANS_BY_GPT3

@winlinvip winlinvip self-assigned this Sep 4, 2021
@winlinvip winlinvip changed the title obs停止推流时一定几率会触发srs收到sig=15信号退出 When obs stops streaming, there is a certain probability that it will trigger srs to receive the sig=15 signal and exit. Jul 28, 2023
@winlinvip winlinvip added the TransByAI Translated by AI/GPT. label Jul 28, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug It might be a bug. TransByAI Translated by AI/GPT.
Projects
None yet
Development

No branches or pull requests

3 participants