同时推两路log:
[2019-09-04 05:46:54.102][Trace][8386][105] RTMP client ip=::ffff:107.150.28.246, fd=9
[2019-09-04 05:46:54.333][Trace][8386][105] simple handshake success.
[2019-09-04 05:46:54.333][Trace][8386][105] connect app, tcUrl=rtmp://107.150.28.246:1936/test, pageUrl=, swfUrl=rtmp://107.150.28.246:1936/test, schema=rtmp, vhost=107.150.28.246, port=1936, app=test, args=null
[2019-09-04 05:47:11.592][Trace][8386][105] client identified, type=fmle-publish, vhost=107.150.28.246, app=test, stream=11-11, param=, duration=0ms
[2019-09-04 05:47:11.592][Trace][8386][105] connected stream, tcUrl=rtmp://107.150.28.246:1936/test, pageUrl=, swfUrl=rtmp://107.150.28.246:1936/test, schema=rtmp, vhost=__defaultVhost__, port=1936, app=test, stream=11-11, param=, args=null
[2019-09-04 05:47:11.592][Trace][8386][105] source url=/test/11-11, ip=::ffff:107.150.28.246, cache=1, is_edge=0, source_id=-1[-1]
[2019-09-04 05:47:12.321][Trace][8386][105] ignore disabled exec for vhost=__defaultVhost__
[2019-09-04 05:47:12.321][Trace][8386][105] start publish mr=0/350, p1stpt=20000, pnt=5000, tcp_nodelay=0
[2019-09-04 05:47:12.820][Trace][8386][105] cleanup when unpublish
[2019-09-04 05:47:12.820][Trace][8386][105] rtmp: retry for republish
[2019-09-04 05:47:12.820][Trace][8386][105] client identified, type=fmle-publish, vhost=107.150.28.246, app=test, stream=11-12, param=, duration=0ms
[2019-09-04 05:47:12.820][Trace][8386][105] connected stream, tcUrl=rtmp://107.150.28.246:1936/test, pageUrl=, swfUrl=rtmp://107.150.28.246:1936/test, schema=rtmp, vhost=__defaultVhost__, port=1936, app=test, stream=11-12, param=, args=null
[2019-09-04 05:47:12.820][Trace][8386][105] source url=/test/11-12, ip=::ffff:107.150.28.246, cache=1, is_edge=0, source_id=-1[-1]
[2019-09-04 05:47:38.006][Trace][8386][105] protocol in.buffer=0, in.ack=2500000, out.ack=2500000, in.chunk=128, out.chunk=60000
[2019-09-04 05:47:38.006][Trace][8386][105] drop unknown message, type=9
推一路或分开推1路log:
[2019-09-04 06:03:23.752][Trace][8386][132] RTMP client ip=::ffff:107.150.28.246, fd=9
[2019-09-04 06:03:23.984][Trace][8386][132] simple handshake success.
[2019-09-04 06:03:23.984][Trace][8386][132] connect app, tcUrl=rtmp://107.150.28.246:1936/test, pageUrl=, swfUrl=rtmp://107.150.28.246:1936/test, schema=rtmp, vhost=107.150.28.246, port=1936, app=test, args=null
[2019-09-04 06:03:28.638][Trace][8386][132] client identified, type=fmle-publish, vhost=107.150.28.246, app=test, stream=11-11, param=, duration=0ms
[2019-09-04 06:03:28.638][Trace][8386][132] connected stream, tcUrl=rtmp://107.150.28.246:1936/test, pageUrl=, swfUrl=rtmp://107.150.28.246:1936/test, schema=rtmp, vhost=__defaultVhost__, port=1936, app=test, stream=11-11, param=, args=null
[2019-09-04 06:03:28.638][Trace][8386][132] source url=/test/11-11, ip=::ffff:107.150.28.246, cache=1, is_edge=0, source_id=-1[-1]
[2019-09-04 06:03:29.138][Trace][8386][132] ignore disabled exec for vhost=__defaultVhost__
[2019-09-04 06:03:29.139][Trace][8386][132] start publish mr=0/350, p1stpt=20000, pnt=5000, tcp_nodelay=0
[2019-09-04 06:03:29.803][Trace][8386][132] got metadata, width=800, height=600
[2019-09-04 06:03:29.803][Trace][8386][132] protocol in.buffer=0, in.ack=2500000, out.ack=2500000, in.chunk=128, out.chunk=60000
[2019-09-04 06:03:29.803][Trace][8386][132] 69B video sh, codec(7, profile=Baseline, level=5.1, 800x608, 0kbps, 0.0fps, 0.0s)
根据日志对源代码进行跟踪分析。
cleanup when unpublish只在void SrsSource::on_unpublish()中打印。
这个类方法在release_publish(source)中被调用的。
进一步追踪发现:
srs_error_t SrsRtmpConn::publishing(SrsSource* source)
{
srs_error_t err = srs_success;
SrsRequest* req = info->req;
if (_srs_config->get_refer_enabled(req->vhost)) {
if ((err = refer->check(req->pageUrl, _srs_config->get_refer_publish(req->vhost))) != srs_success) {
return srs_error_wrap(err, "rtmp: referer check");
}
}
if ((err = http_hooks_on_publish()) != srs_success) {
return srs_error_wrap(err, "rtmp: callback on publish");
}
// TODO: FIXME: Should refine the state of publishing.
//上一个publish还未结束,又来一个publish造成前一个publish被释放了??
// 作者的注释表明,这个地方是有缺陷的,要修改。
if ((err = acquire_publish(source)) == srs_success) {
// use isolate thread to recv,
// @see: https://github.com/ossrs/srs/issues/237
SrsPublishRecvThread rtrd(rtmp, req, srs_netfd_fileno(stfd), 0, this, source, _srs_context->get_id());
err = do_publishing(source, &rtrd);
rtrd.stop();
}
// whatever the acquire publish, always release publish.
// when the acquire error in the midlle-way, the publish state changed,
// but failed, so we must cleanup it.
// @see https://github.com/ossrs/srs/issues/474
// @remark when stream is busy, should never release it.
if (srs_error_code(err) != ERROR_SYSTEM_STREAM_BUSY) {
//这里这个地方调用的,但原因在前一个func失败造成的。
release_publish(source);
}
http_hooks_on_unpublish();
return err;
}
进一步查,下面这段分支代码是关键。感觉是接连收到两条发布命令,SRS把后一条当作前一条的重发布了。
// for republish, continue service
if (srs_error_code(err) == ERROR_CONTROL_REPUBLISH) {
// set timeout to a larger value, wait for encoder to republish.
rtmp->set_send_timeout(SRS_REPUBLISH_RECV_TIMEOUT);
rtmp->set_recv_timeout(SRS_REPUBLISH_SEND_TIMEOUT);
srs_trace("rtmp: retry for republish");
srs_freep(err);
continue;
}
显然,问题在于:SRS对于FMLE的一次connect,publish两个以上stream_url的情况不能处理。
接下来是如何修改SRS代码处理这种情况呢?
消息处理主体:
srs_error_t SrsRtmpConn::handle_publish_message(SrsSource* source, SrsCommonMessage* msg)
srs_error_t SrsProtocol::decode_message(SrsCommonMessage* msg, SrsPacket** ppacket)
[2019-09-04 23:16:51.575][Trace][31180][106] fmle publishing:error_code=2999, desc=code=2999 : rtmp: receive thread : handle publish message : rtmp: republish
thread #106: do_publishing() [src/app/srs_app_rtmp_conn.cpp:890][errno=11]
thread #106: consume() [src/app/srs_app_recv_thread.cpp:396][errno=11]
thread #106: handle_publish_message() [src/app/srs_app_rtmp_conn.cpp:985][errno=11]
定位于由下面这行code:
return srs_error_new(ERROR_CONTROL_REPUBLISH, "rtmp: republish");
如果屏蔽这段code,就可以连接成功一路而已。达不到目标!
如果我们可以识别并处理第二个stream_url发布请求,再启动一个线程来处理就可以了。
SrsPublishRecvThread rtrd(rtmp, req, srs_netfd_fileno(stfd), 0, this, source, _srs_context->get_id());
推流1消息处理:
[2019-09-05 02:02:39.112][Trace][7933][104] simple handshake success.
[2019-09-05 02:02:39.112][Trace][7933][104] AMF command=connect
[2019-09-05 02:02:39.112][Trace][7933][104] connect app, tcUrl=rtmp://107.150.28.246:1936/test, pageUrl=, swfUrl=rtmp://107.150.28.246:1936/test, schema=rtmp, vhost=107.150.28.246, port=1936, app=test, args=null
[2019-09-05 02:02:39.856][Trace][7933][104] AMF command=releaseStream
[2019-09-05 02:02:39.856][Trace][7933][104] client identified, type=fmle-publish, vhost=107.150.28.246, app=test, stream=11-11, param=, duration=0ms
[2019-09-05 02:02:39.856][Trace][7933][104] connected stream, tcUrl=rtmp://107.150.28.246:1936/test, pageUrl=, swfUrl=rtmp://107.150.28.246:1936/test, schema=rtmp, vhost=__defaultVhost__, port=1936, app=test, stream=11-11, param=, args=null
[2019-09-05 02:02:39.856][Trace][7933][104] source url=/test/11-11, ip=::ffff:107.150.28.246, cache=1, is_edge=0, source_id=-1[-1]
[2019-09-05 02:02:39.856][Trace][7933][104] AMF command=FCPublish
[2019-09-05 02:02:39.856][Trace][7933][104] AMF command=createStream
[2019-09-05 02:02:40.364][Trace][7933][104] AMF command=publish
同时推流2消息就被忽略掉了:
[2019-09-05 02:02:40.884][Trace][7933][104] AMF command=releaseStream
[2019-09-05 02:02:40.884][Trace][7933][104] fmle ignore AMF0/AMF3 command message. info->type=2
[2019-09-05 02:02:40.884][Trace][7933][104] AMF command=FCPublish
[2019-09-05 02:02:40.884][Trace][7933][104] fmle ignore AMF0/AMF3 command message. info->type=2
[2019-09-05 02:02:40.884][Trace][7933][104] AMF command=createStream
[2019-09-05 02:02:40.884][Trace][7933][104] fmle ignore AMF0/AMF3 command message. info->type=2
最后发现,其实问题很简单,处理完交互命令后再发布,而不是处理1路发布一路。
[2019-09-05 22:00:01.738][Trace][2864][105] RTMP client ip=::ffff:107.150.28.246, fd=9
[2019-09-05 22:00:01.977][Trace][2864][105] simple handshake success.
[2019-09-05 22:00:01.977][Trace][2864][105] AMF command=connect
[2019-09-05 22:00:01.977][Trace][2864][105] connect app, tcUrl=rtmp://107.150.28.246:1936/test, pageUrl=, swfUrl=rtmp://107.150.28.246:1936/test, schema=rtmp, vhost=107.150.28.246, port=1936, app=test, args=null
[2019-09-05 22:00:06.619][Trace][2864][105] AMF command=releaseStream
[2019-09-05 22:00:06.620][Trace][2864][105] client identified, type=fmle-publish, vhost=107.150.28.246, app=test, stream=12-11, param=, duration=0ms
[2019-09-05 22:00:06.620][Trace][2864][105] connected stream, tcUrl=rtmp://107.150.28.246:1936/test, pageUrl=, swfUrl=rtmp://107.150.28.246:1936/test, schema=rtmp, vhost=__defaultVhost__, port=1936, app=test, stream=12-11, param=, args=null
[2019-09-05 22:00:06.620][Trace][2864][105] source url=/test/12-11, ip=::ffff:107.150.28.246, cache=1, is_edge=0, source_id=-1[-1]
[2019-09-05 22:00:06.620][Trace][2864][105] AMF command=FCPublish
[2019-09-05 22:00:06.620][Trace][2864][105] AMF command=createStream
[2019-09-05 22:00:07.135][Trace][2864][105] AMF command=publish
[2019-09-05 22:00:07.135][Trace][2864][105] fmle publish start:error_code=0, desc=Success
[2019-09-05 22:00:07.651][Trace][2864][105] AMF command=releaseStream
[2019-09-05 22:00:07.651][Trace][2864][105] client identified, type=fmle-publish, vhost=107.150.28.246, app=test, stream=12-12, param=, duration=0ms
[2019-09-05 22:00:07.651][Trace][2864][105] connected stream, tcUrl=rtmp://107.150.28.246:1936/test, pageUrl=, swfUrl=rtmp://107.150.28.246:1936/test, schema=rtmp, vhost=__defaultVhost__, port=1936, app=test, stream=12-12, param=, args=null
[2019-09-05 22:00:07.651][Trace][2864][105] source url=/test/12-12, ip=::ffff:107.150.28.246, cache=1, is_edge=0, source_id=-1[-1]
[2019-09-05 22:00:07.651][Trace][2864][105] AMF command=FCPublish
[2019-09-05 22:00:07.651][Trace][2864][105] AMF command=createStream
[2019-09-05 22:00:08.166][Trace][2864][105] AMF command=publish
[2019-09-05 22:00:08.166][Trace][2864][105] fmle publish start:error_code=0, desc=Success
[2019-09-05 22:00:08.167][Trace][2864][105] ignore disabled exec for vhost=__defaultVhost__
[2019-09-05 22:00:08.167][Trace][2864][105] start publish mr=0/350, p1stpt=20000, pnt=5000, tcp_nodelay=0
[2019-09-05 22:00:08.942][Trace][2864][105] AMF command=@setDataFrame
[2019-09-05 22:00:08.942][Trace][2864][105] got metadata, width=800, height=600
[2019-09-05 22:00:08.942][Trace][2864][105] protocol in.buffer=0, in.ack=2500000, out.ack=2500000, in.chunk=128, out.chunk=60000
[2019-09-05 22:00:08.942][Trace][2864][105] 69B video sh, codec(7, profile=Baseline, level=5.1, 800x608, 0kbps, 0.0fps, 0.0s)
[2019-09-05 22:00:08.942][Trace][2864][105] AMF command=onFI
[2019-09-05 22:00:08.942][Trace][2864][105] AMF command=@setDataFrame
[2019-09-05 22:00:08.942][Trace][2864][105] got metadata, width=800, height=600
[2019-09-05 22:00:08.942][Trace][2864][105] 69B video sh, codec(7, profile=Baseline, level=5.1, 800x608, 0kbps, 0.0fps, 0.0s)
[2019-09-05 22:00:08.943][Trace][2864][105] AMF command=onFI
[2019-09-05 22:00:10.059][Trace][2864][105] AMF command=onFI
[2019-09-05 22:00:10.099][Trace][2864][105] AMF command=onFI
[2019-09-05 22:00:11.260][Trace][2864][105] AMF command=onFI
[2019-09-05 22:00:11.260][Trace][2864][105] AMF command=onFI
publish的回复超时只有500ms,不然就认为发布该路视频失败。
[2019-09-06 05:11:26.336][Trace][26022][104] start publish mr=0/350, p1stpt=20000, pnt=5000, tcp_nodelay=0
[2019-09-06 05:11:26.943][Trace][26022][104] AMF command=releaseStream
发第二路流时有很多ignore message.
[2019-09-06 05:25:55.134][Trace][26902][104] source url=/test/12-12, ip=::ffff:107.150.28.246, cache=1, is_edge=0, source_id=-1[-1]
[2019-09-06 05:25:55.134][Trace][26902][104] AMF command=FCPublish
[2019-09-06 05:25:55.134][Trace][26902][104] AMF command=createStream
[2019-09-06 05:25:55.634][Trace][26902][104] AMF command=publish
[2019-09-06 05:25:55.634][Trace][26902][104] fmle publish start:error_code=0, stream_id=1, desc=Success
[2019-09-06 05:25:56.398][Trace][26902][104] ignore message type=0x12
[2019-09-06 05:25:56.398][Trace][26902][104] protocol in.buffer=0, in.ack=2500000, out.ack=2500000, in.chunk=128, out.chunk=60000
[2019-09-06 05:25:56.398][Trace][26902][104] ignore message type=0x9
[2019-09-06 05:25:56.398][Trace][26902][104] ignore message type=0x9
[2019-09-06 05:25:56.398][Trace][26902][104] ignore message type=0x12
[2019-09-06 05:25:56.399][Trace][26902][104] ignore message type=0x12
这是因为应答了第一路流后,就开始发数据包消息了。
带内信令,处理起来是麻烦啊!这个问题只有慢慢来解决了。