Поток начинается и сразу же закрывается

Ivan

Member
Вот такие Логи пишутся в это время
Code:
2017-06-15 04:03:06;WebRTC;111ed2ba50799a8e00a66a389b3a07fc;10577100-51a1-11e7-87f0-c980c56c08ef;00:00:00;UNPUBLISHED;Stopped by publisher stop;PUBLISH;0;

04:03:06,585 INFO          MediaHandler - WSS-pool-9-thread-8 publishStream arguments - Stream{mediaSessionId='10577100-51a1-11e7-87f0-c980c56c08ef'name='111ed2ba50799a8e00a66a389b3a07fc', status='PENDING', sdp='v=0
04:03:06,587 INFO                 Agent - WSS-pool-9-thread-8 Gathering candidates for component audio.RTP. Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,587 INFO                 Agent - WSS-pool-9-thread-8 Gathering candidates for component video.RTP. Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,589 INFO                 Agent - WSS-pool-9-thread-8 Start ICE connectivity establishment. Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,589 INFO                 Agent - WSS-pool-9-thread-8 ICE state changed from Waiting to Running. Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,589 INFO       RtcMediaSession - WSS-pool-9-thread-8 propertyChange Agent for id = 10577100-51a1-11e7-87f0-c980c56c08ef entered the Running state.
04:03:06,589 INFO  nectivityCheckClient - WSS-pool-9-thread-8 Start connectivity checks. Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
a=ice-ufrag:10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
a=ice-ufrag:10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,659 INFO                 Agent - Stun4J Message Processor Received check from 93.95.103.104:38864/udp/host -> 213.79.124.178:51563/udp/prflx (audio.RTP) triggered a check. Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,660 INFO                 Agent - Stun4J Message Processor Received check from 93.95.103.104:34772/udp/host -> 213.79.124.178:50455/udp/prflx (video.RTP) triggered a check. Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,674 INFO  nectivityCheckClient - Stun4J Message Processor Pair succeeded: 93.95.103.104:38864/udp/host -> 213.79.124.178:51563/udp/prflx (audio.RTP). Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,674 INFO  nectivityCheckClient - Stun4J Message Processor Pair validated: 93.95.103.104:38864/udp/host -> 213.79.124.178:51563/udp/prflx (audio.RTP). Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,675 INFO  nectivityCheckClient - Stun4J Message Processor IsControlling: false USE-CANDIDATE:false. Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,704 INFO  nectivityCheckClient - Stun4J Message Processor Pair succeeded: 93.95.103.104:34772/udp/host -> 213.79.124.178:50455/udp/prflx (video.RTP). Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,704 INFO  nectivityCheckClient - Stun4J Message Processor Pair validated: 93.95.103.104:34772/udp/host -> 213.79.124.178:50455/udp/prflx (video.RTP). Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,704 INFO  nectivityCheckClient - Stun4J Message Processor IsControlling: false USE-CANDIDATE:false. Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,704 INFO                 Agent - Stun4J Message Processor ICE state changed from Running to Completed. Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,704 INFO       RtcMediaSession - Stun4J Message Processor propertyChange Agent for id = 10577100-51a1-11e7-87f0-c980c56c08ef entered the Completed state.
04:03:06,704 INFO       RtcMediaSession - Stun4J Message Processor Init RtcMediaSession 10577100-51a1-11e7-87f0-c980c56c08ef
04:03:06,704 INFO       RtcMediaSession - Stun4J Message Processor init audioSession 10577100-51a1-11e7-87f0-c980c56c08ef
04:03:06,718 INFO       RtcMediaSession - Stun4J Message Processor init videoSession 10577100-51a1-11e7-87f0-c980c56c08ef
04:03:06,732 INFO          MediaSession - Stun4J Message Processor Start rtp activity detecting for audio session 10577100-51a1-11e7-87f0-c980c56c08ef
04:03:06,732 INFO        AudioProcessor - AudioProcessor-10577100-51a1-11e7-87f0-c980c56c08ef Starting with queue size 0
04:03:06,733 INFO        VideoProcessor - VideoProcessor-10577100-51a1-11e7-87f0-c980c56c08ef Starting with queue size 0
04:03:06,755 INFO                 Agent - Stun4J Message Processor Harvester used for selected pair for audio.RTP (local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q): host
04:03:06,755 INFO                 Agent - Stun4J Message Processor Harvester used for selected pair for video.RTP (local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q): host
04:03:06,894 INFO          MediaHandler - WSS-pool-9-thread-8 unPublishStream - Stream{mediaSessionId='10577100-51a1-11e7-87f0-c980c56c08ef'name='111ed2ba50799a8e00a66a389b3a07fc', status='PUBLISHING', sdp='null', remoteMediaElementId='null', hasVideo='true', hasAudio='true'}Context{custom={}, nodeId='null', appKey='defaultApp', sessionId='/213.79.124.178:62327/93.95.103.104:8443'}
04:03:06,894 INFO        RtcMediaClient - WSS-pool-9-thread-8 Stop media session 10577100-51a1-11e7-87f0-c980c56c08ef
04:03:06,896 INFO          MediaSession - WSS-pool-9-thread-8 Stop MediaSession id: 10577100-51a1-11e7-87f0-c980c56c08ef
04:03:06,896 INFO    AbstractRtpSession - WSS-pool-9-thread-8 RtpSession with id 10577100-51a1-11e7-87f0-c980c56c08ef terminated.
04:03:06,897 INFO  stractRtpRtcpSession - WSS-pool-9-thread-8 RtpSession with id 10577100-51a1-11e7-87f0-c980c56c08ef terminated.
04:03:06,897 INFO                 Agent - WSS-pool-9-thread-8 ICE state changed from Completed to Terminated. Local ufrag 10577100-51a1-11e7-87f0-c980c56c08efdn1ka1bilcdv6q
04:03:06,897 INFO       RtcMediaSession - WSS-pool-9-thread-8 propertyChange Agent for id = 10577100-51a1-11e7-87f0-c980c56c08ef entered the Terminated state.
04:03:11,735 INFO  e7-87f0-c980c56c08ef - VideoProcessor-10577100-51a1-11e7-87f0-c980c56c08ef STOP DISTRIBUTOR
04:03:11,735 INFO  e7-87f0-c980c56c08ef - VideoProcessor-10577100-51a1-11e7-87f0-c980c56c08ef STOP DISTRIBUTOR
04:03:11,735 INFO        VideoProcessor - VideoProcessor-10577100-51a1-11e7-87f0-c980c56c08ef Ended with queue size 0
04:03:11,862 INFO  e7-87f0-c980c56c08ef - AudioProcessor-10577100-51a1-11e7-87f0-c980c56c08ef STOP DISTRIBUTOR
04:03:11,863 INFO        AudioProcessor - AudioProcessor-10577100-51a1-11e7-87f0-c980c56c08ef Ended with queue size 0

04:03:06,459 INFO  agerRemoteRmiService - RMI TCP Connection(3102)-93.95.103.104 SEND REST OBJECT ==>
URL:https://api.vichatter.com/external.flashphoner.serverIncoming/publishStream
OBJECT:
{
"nodeId" : "dORxhMBSBhZlf1vylM6e8U7xZIj4eE3n@93.95.103.104",
"appKey" : "defaultApp",
"sessionId" : "/213.79.124.178:62327/93.95.103.104:8443",
"mediaSessionId" : "10577100-51a1-11e7-87f0-c980c56c08ef",
"name" : "111ed2ba50799a8e00a66a389b3a07fc",
"published" : true,
"hasVideo" : true,
"hasAudio" : true,
"status" : "PENDING",
"record" : false,
"width" : 0,
"height" : 0,
"bitrate" : 0,
"quality" : 0,
"mediaProvider" : "WebRTC",
"custom" : {
"auth" : "53eec79ab93ca5b0724daff24ecc7ca9",
"name" : "111ed2ba50799a8e00a66a389b3a07fc"
}
}


04:03:06,583 INFO  agerRemoteRmiService - RMI TCP Connection(3102)-93.95.103.104 RECEIVED REST OBJECT <==
URL:https://api.vichatter.com/external.flashphoner.serverIncoming/publishStream
OBJECT:
{
"nodeId" : "dORxhMBSBhZlf1vylM6e8U7xZIj4eE3n@93.95.103.104",
"appKey" : "defaultApp",
"sessionId" : "/213.79.124.178:62327/93.95.103.104:8443",
"mediaSessionId" : "10577100-51a1-11e7-87f0-c980c56c08ef",
"name" : "111ed2ba50799a8e00a66a389b3a07fc",
"published" : true,
"hasVideo" : true,
"hasAudio" : true,
"status" : "PENDING",
"record" : false,
"width" : 0,
"height" : 0,
"bitrate" : 0,
"quality" : 0,
"mediaProvider" : "WebRTC",
"auth" : "53eec79ab93ca5b0724daff24ecc7ca9",
"name" : "111ed2ba50799a8e00a66a389b3a07fc"
}


04:03:06,741 INFO  agerRemoteRmiService - RMI TCP Connection(3100)-93.95.103.104 SEND REST OBJECT ==>
URL:https://api.vichatter.com/external.flashphoner.serverIncoming/StreamStatusEvent
OBJECT:
{
"nodeId" : "dORxhMBSBhZlf1vylM6e8U7xZIj4eE3n@93.95.103.104",
"appKey" : "defaultApp",
"sessionId" : "/213.79.124.178:62327/93.95.103.104:8443",
"mediaSessionId" : "10577100-51a1-11e7-87f0-c980c56c08ef",
"name" : "111ed2ba50799a8e00a66a389b3a07fc",
"published" : true,
"hasVideo" : true,
"hasAudio" : true,
"status" : "PUBLISHING",
"record" : false,
"width" : 0,
"height" : 0,
"bitrate" : 0,
"quality" : 0,
"mediaProvider" : "WebRTC",
"custom" : {
"auth" : "53eec79ab93ca5b0724daff24ecc7ca9",
"name" : "111ed2ba50799a8e00a66a389b3a07fc"
}
}



04:03:06,753 INFO  agerRemoteRmiService - RMI TCP Connection(3100)-93.95.103.104 RECEIVED REST OBJECT <==
URL:https://api.vichatter.com/external.flashphoner.serverIncoming/StreamStatusEvent
OBJECT:
{
"nodeId" : "dORxhMBSBhZlf1vylM6e8U7xZIj4eE3n@93.95.103.104",
"appKey" : "defaultApp",
"sessionId" : "/213.79.124.178:62327/93.95.103.104:8443",
"mediaSessionId" : "10577100-51a1-11e7-87f0-c980c56c08ef",
"name" : "111ed2ba50799a8e00a66a389b3a07fc",
"published" : true,
"hasVideo" : true,
"hasAudio" : true,
"status" : "PUBLISHING",
"record" : false,
"width" : 0,
"height" : 0,
"bitrate" : 0,
"quality" : 0,
"mediaProvider" : "WebRTC",
"auth" : "53eec79ab93ca5b0724daff24ecc7ca9",
"name" : "111ed2ba50799a8e00a66a389b3a07fc"
}
 

Ivan

Member
Code:
04:03:06,878 INFO  agerRemoteRmiService - RMI TCP Connection(3101)-93.95.103.104 SEND REST OBJECT ==>
URL:https://api.vichatter.com/external.flashphoner.serverIncoming/unPublishStream
OBJECT:
{
"nodeId" : "dORxhMBSBhZlf1vylM6e8U7xZIj4eE3n@93.95.103.104",
"appKey" : "defaultApp",
"sessionId" : "/213.79.124.178:62327/93.95.103.104:8443",
"mediaSessionId" : "10577100-51a1-11e7-87f0-c980c56c08ef",
"name" : "111ed2ba50799a8e00a66a389b3a07fc",
"published" : true,
"hasVideo" : true,
"hasAudio" : true,
"status" : "PUBLISHING",
"record" : false,
"width" : 0,
"height" : 0,
"bitrate" : 0,
"quality" : 0
}



04:03:06,893 INFO  agerRemoteRmiService - RMI TCP Connection(3101)-93.95.103.104 RECEIVED REST OBJECT <==
URL:https://api.vichatter.com/external.flashphoner.serverIncoming/unPublishStream
OBJECT:
{
"nodeId" : "dORxhMBSBhZlf1vylM6e8U7xZIj4eE3n@93.95.103.104",
"appKey" : "defaultApp",
"sessionId" : "/213.79.124.178:62327/93.95.103.104:8443",
"mediaSessionId" : "10577100-51a1-11e7-87f0-c980c56c08ef",
"name" : "111ed2ba50799a8e00a66a389b3a07fc",
"published" : true,
"hasVideo" : true,
"hasAudio" : true,
"status" : "PUBLISHING",
"record" : false,
"width" : 0,
"height" : 0,
"bitrate" : 0,
"quality" : 0
}



04:03:06,911 INFO  agerRemoteRmiService - RMI TCP Connection(3100)-93.95.103.104 SEND REST OBJECT ==>
URL:https://api.vichatter.com/external.flashphoner.serverIncoming/StreamStatusEvent
OBJECT:
{
"nodeId" : "dORxhMBSBhZlf1vylM6e8U7xZIj4eE3n@93.95.103.104",
"appKey" : "defaultApp",
"sessionId" : "/213.79.124.178:62327/93.95.103.104:8443",
"mediaSessionId" : "10577100-51a1-11e7-87f0-c980c56c08ef",
"name" : "111ed2ba50799a8e00a66a389b3a07fc",
"published" : true,
"hasVideo" : true,
"hasAudio" : true,
"status" : "UNPUBLISHED",
"info" : "Stopped by publisher stop",
"record" : false,
"width" : 0,
"height" : 0,
"bitrate" : 0,
"quality" : 0
}




04:03:06,924 INFO  agerRemoteRmiService - RMI TCP Connection(3100)-93.95.103.104 RECEIVED REST OBJECT <==
URL:https://api.vichatter.com/external.flashphoner.serverIncoming/StreamStatusEvent
OBJECT:
{
"nodeId" : "dORxhMBSBhZlf1vylM6e8U7xZIj4eE3n@93.95.103.104",
"appKey" : "defaultApp",
"sessionId" : "/213.79.124.178:62327/93.95.103.104:8443",
"mediaSessionId" : "10577100-51a1-11e7-87f0-c980c56c08ef",
"name" : "111ed2ba50799a8e00a66a389b3a07fc",
"published" : true,
"hasVideo" : true,
"hasAudio" : true,
"status" : "UNPUBLISHED",
"info" : "Stopped by publisher stop",
"record" : false,
"width" : 0,
"height" : 0,
"bitrate" : 0,
"quality" : 0
}
 

Max

Administrator
Staff member
Пришлите пожалуйста весь logs/server_log/flashphoner.log
на logs@flashphoner.com
Проверим.

По текущим логам видно, что команда unpublish приходит от клиента (браузера).
Т.е. нужен еще лог со стороны браузера.
Для того, чтобы собирать логи браузера на стороне сервера, можно включить на клиенте (Web SDK)
Flashphoner.init({logger:{push:true,severity: "DEBUG"}});
Можно не собирать. Просто скопировать из консоли Chrome, если воспроизводится.
 

Ivan

Member
Отправил письмо с логом от клиента, в тот момент когда поток закрылся сам собой и server_log.
Происходит это по непонятным причинам периодически, т.е. может быть 5 раз создался 1 раз автоматически закрылся, а может быть 5 раз создался и 4 раза закрылся.
 

Max

Administrator
Staff member
Из логов, которые вы прислали, видно, что:
1. Клиент публикует WebRTC поток из браузера b7d5e310cb6e414c7e1fd52b82d608c7.
2. В эту же секунду к потоку пытается подключиться Flash Player на Linux LNX 9,0,124,2 и пытается проиграть поток по RTMP.
3. Между клиентом и сервером закрывается Websocket соединение.
Выглядит так, как если бы клиент закрыл браузер.

1. Скорее всего, у вас воспроизведение потока по RTMP в Flash Player привязано к началу стриминга по WebRTC.
Попробуйте этого не делать и отключить попытки воспроизведения. Будет ли проблема воспроизводиться просто при попытке publish?

2. Снимите дамп трафика с адресом клиента, у которого воспроизводится эта проблема:
Code:
tcpdump host 192.168.88.253 -s 4096 -w log.pcap
Здесь 192.168.88.253 - адрес клиента, трафик которого снимаем.
Возможно в этом дампе будет видно причину дисконнекта.

3. Если у вас один из последних билдов, пришлите
logs/cdr/conndr.log - в нем должна быть причина Websocket - дисконнекта

Таким образом, главное, что нужно выяснить, почему было разорвано соединение между клиентом и сервером:
Code:
10:15:28,731 INFO              WSClient - WSS-pool-9-thread-29 Close connection for channel [id: 0x2792438e, /213.79.xxx.xxx:61560 => /93.95.xxx.xxx:8443] with status code: 1000
10:15:28,732 INFO           WCS4Handler - WSS-pool-9-thread-29 Disconnect client: com.flashphoner.server.client.MediaWCSClient@3698990d
У нас на тестах такое не воспроизводится, когда мы
1. Публикуем WebRTC поток с Two Way Streaming
https://wcs5-eu.flashphoner.com/demo2/two-way-streaming
2. Одновременно пытаемся играть его же по RTMP
https://wcs5-eu.flashphoner.com/demo2/flash-streaming
 

Ivan

Member
Воспроизведение RTMP потока сразу после стара WebRTC - это ffmpeg сохранял скриншот и записывал маленькое видео.
Сделал запуск этого процесса через 10 секунд, после старта вещания - Проблема ушла.
Спасибо за помощь!
 
Top