[jitsi-dev] [jitsi-meet][jicofo][jitsi-videobridge] Focus is often lost


#1

Hey,

Often videobridge fails here:

2015-04-23 01:30:43.955 INFO: [68]
org.jitsi.videobridge.Channel.info() Expired channel 61c2d000ef23f016
of content audio of conference f3fde3e778f022ac. The total number of
conferences is now 6, channel$
2015-04-23 01:30:43.955 INFO: [68]
org.jitsi.impl.neomedia.MediaStreamImpl.info()
Receive stream stats: discarded RTP packets: 0
Receive stream stats: decoded with FEC: 0
2015-04-23 01:30:43.959 INFO: [68]
org.jitsi.videobridge.transform.CachingTransformer.info() Closing.
Maximum size reached: 0 bytes, 0 packets; 0 hits, 0 misses (0 total
requests); 0 total packets added.
2015-04-23 01:30:43.960 WARNING: [68]
org.jitsi.videobridge.Channel.warn() Failed to close the
MediaStream/stream of channel fcc6e9648a70117d of content video of
conference f3fde3e778f022ac!
java.lang.IllegalMonitorStateException
        at java.lang.Object.notify(Native Method)
        at org.jitsi.videobridge.transform.CachingTransformer.close(CachingTransformer.java:203)
        at org.jitsi.impl.neomedia.transform.TransformEngineChain$PacketTransformerChain.close(TransformEngineChain.java:241)
        at org.jitsi.impl.neomedia.transform.TransformEngineChain$PacketTransformerChain.close(TransformEngineChain.java:241)
        at org.jitsi.impl.neomedia.MediaStreamImpl.close(MediaStreamImpl.java:605)
        at org.jitsi.impl.neomedia.VideoMediaStreamImpl.close(VideoMediaStreamImpl.java:519)
        at org.jitsi.videobridge.RtpChannel.closeStream(RtpChannel.java:582)
        at org.jitsi.videobridge.Channel.expire(Channel.java:330)
        at org.jitsi.videobridge.Channel.setExpire(Channel.java:652)
        at org.jitsi.videobridge.Videobridge.handleColibriConferenceIQ(Videobridge.java:757)
        at org.jitsi.videobridge.Videobridge.handleColibriConferenceIQ(Videobridge.java:545)
        at org.jitsi.videobridge.xmpp.ComponentImpl.handleColibriConferenceIQ(ComponentImpl.java:209)
        at org.jitsi.videobridge.xmpp.ComponentImpl.handleIQRequest(ComponentImpl.java:380)
        at org.jitsi.videobridge.xmpp.ComponentImpl.handleIQ(ComponentImpl.java:311)
        at org.jitsi.videobridge.xmpp.ComponentImpl.handleIQ(ComponentImpl.java:263)
        at org.jitsi.videobridge.xmpp.ComponentImpl.handleIQSet(ComponentImpl.java:437)
        at org.xmpp.component.AbstractComponent.processIQRequest(AbstractComponent.java:515)
        at org.xmpp.component.AbstractComponent.processIQ(AbstractComponent.java:289)
        at org.xmpp.component.AbstractComponent.processQueuedPacket(AbstractComponent.java:239)
        at org.xmpp.component.AbstractComponent.access$100(AbstractComponent.java:81)
        at org.xmpp.component.AbstractComponent$PacketProcessor.run(AbstractComponent.java:1051)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
2015-04-23 01:30:43.960 INFO: [68]
org.jitsi.videobridge.Channel.info() Expired channel fcc6e9648a70117d
of content video of conference f3fde3e778f022ac. The total number of
conferences is now 6, channel$
2015-04-23 01:30:43.961 INFO: [68] org.ice4j.ice.Agent.setState() ICE
state changed from Completed to Terminated
2015-04-23 01:30:43.961 INFO: [60578]
org.ice4j.ice.Agent.runInStunKeepAliveThread() StunKeepAliveThread
ends.
2015-04-23 01:30:43.962 INFO: [68]
org.jitsi.videobridge.Channel.info() Expired channel 4b8499e44ec437be
of content data of conference f3fde3e778f022ac. The total number of
conferences is now 6, channels$
2015-04-23 01:30:43.964 INFO: [68]
org.jitsi.videobridge.xmpp.ComponentImpl.info() SENT: <iq
type="result" id="bX6aU-69620" from="jitsi-videobridge.domain"
to="focus@auth.domain/focus1140190629254207$
2015-04-23 01:30:48.684 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Total packets added: 1
2015-04-23 01:30:48.684 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Times reset() called: 2
2015-04-23 01:30:48.684 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Times grow() called: 0
2015-04-23 01:30:48.684 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because full: 0
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped while shrinking:
0
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were
late: 0
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were
late by more than MAX_SIZE: 0
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped in reset(): 1
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Max size reached: 4
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Adaptive jitter buffer mode was
enabled
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
Stopping RTPSourceStream.
2015-04-23 01:30:57.100 INFO: [60500]
org.ice4j.ice.ConnectivityCheckClient.processTimeout() timeout for
pair: 95.163.117.17:12916/udp/host -> 41.92.113.46:61517/udp/prflx
(stream.RTP), failing.

2015-04-23 01:31:02.257 INFO: [170]
org.jitsi.videobridge.xmpp.ComponentImpl.info() RECV: <iq type=“get”
to=“jitsi-videobridge.domain”
from=“focus@auth.domain/focus11401906292542079”
id=“bX6aU-69629”><conference
xmlns=“http://jitsi.org/protocol/colibri
id=“f3fde3e778f022ac”><content name=“audio”><channel
channel-bundle-id=“9595” initiator=“true” last-n=“1”
endpoint=“9595”><payload-type name=“opus”
clockrate=“48000” id=“111” channels=“2”><parameter value=“10”
name=“minptime”/></payload-type><payload-type id=“103” name=“ISAC”
clockrate=“16000”/><payload-type id=“104” name=“ISAC”
clockrate=“32000”/><payload-type id=“0” name=“PCMU”
clockrate=“8000”/><payload-type id=“8” name=“PCMA”
clockrate=“8000”/><payload-type id=“106” name=“CN”
clockrate=“32000”/><payload-type id=“105”
name=“CN” clockrate=“16000”/><payload-type id=“13” name=“CN”
clockrate=“8000”/><payload-type id=“126” name=“telephone-event”
clockrate=“8000”/><rtp-hdrext id=“1”
uri=“urn:ietf:params:rtp-hdrext:ssrc-audio-level”/></channel></content><content
name=“video”><channel channel-bundle-id=“9595” initiator=“true”
last-n=“1” endpoint=“9595”><payload-type id=“100”
name=“VP8” clockrate=“90000”><rtcp-fb
xmlns=“urn:xmpp:jingle:apps:rtp:rtcp-fb:0” type=“ccm”
subtype=“fir”/><rtcp-fb xmlns=“urn:xmpp:jingle:apps:rtp:rtcp-fb:0”
type=“nack”/><rtcp-fb
xmlns=“urn:xmpp:jingle:apps:rtp:rtcp-fb:0” type=“nack”
subtype=“pli”/><rtcp-fb xmlns=“urn:xmpp:jingle:apps:rtp:rtcp-fb:0”
type=“goog-remb”/></payload-type><payload-type id=“116” name=“red”
clockrate=“90000”/><payload-type id=“117” name=“ulpfec”
clockrate=“90000”/><rtp-hdrext id=“2”
uri=“urn:ietf:params:rtp-hdrext:toffset”/><rtp-hdrext id=“3”
uri=“http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time”/></channel></content><content
name=“data”><sctpconnection channel-bundle-id=“9595” port=“5000”
initiator=“true”
endpoint=“9595”/></content><channel-bundle id=“9595”><transport
xmlns=“urn:xmpp:jingle:transports:ice-udp:1”/></channel-bundle></conference></iq>

2015-04-23 01:31:02.257 INFO: [170]
org.jitsi.videobridge.Channel.info() Transport connected for channel
b83ad5c208aee149 of content audio of conference f3fde3e778f022ac
java.lang.NullPointerException
        at org.jitsi.videobridge.RtpChannel.maybeStartStream(RtpChannel.java:943)
        at org.jitsi.videobridge.Channel.transportConnected(Channel.java:754)
        at org.jitsi.videobridge.IceUdpTransportManager.addChannel(IceUdpTransportManager.java:429)
        at org.jitsi.videobridge.Channel.initialize(Channel.java:537)
        at org.jitsi.videobridge.RtpChannel.initialize(RtpChannel.java:882)
        at org.jitsi.videobridge.Content.createRtpChannel(Content.java:275)
        at org.jitsi.videobridge.Videobridge.handleColibriConferenceIQ(Videobridge.java:733)
        at org.jitsi.videobridge.Videobridge.handleColibriConferenceIQ(Videobridge.java:545)
        at org.jitsi.videobridge.xmpp.ComponentImpl.handleColibriConferenceIQ(ComponentImpl.java:209)
        at org.jitsi.videobridge.xmpp.ComponentImpl.handleIQRequest(ComponentImpl.java:380)
        at org.jitsi.videobridge.xmpp.ComponentImpl.handleIQ(ComponentImpl.java:311)
        at org.jitsi.videobridge.xmpp.ComponentImpl.handleIQ(ComponentImpl.java:263)
        at org.jitsi.videobridge.xmpp.ComponentImpl.handleIQGet(ComponentImpl.java:362)
        at org.xmpp.component.AbstractComponent.processIQRequest(AbstractComponent.java:511)
        at org.xmpp.component.AbstractComponent.processIQ(AbstractComponent.java:289)
        at org.xmpp.component.AbstractComponent.processQueuedPacket(AbstractComponent.java:239)
        at org.xmpp.component.AbstractComponent.access$100(AbstractComponent.java:81)
        at org.xmpp.component.AbstractComponent$PacketProcessor.run(AbstractComponent.java:1051)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
2015-04-23 01:31:02.259 INFO: [269]
org.jitsi.videobridge.xmpp.ComponentImpl.info() RECV: <iq type="set"
to="jitsi-videobridge.domain"
from="focus@auth.domain/focus11401906292542079" id="bX6aU-69630"$
2015-04-23 01:31:02.491 SEVERE: [39260]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.error() Failed
to analyze an outgoing RTCP packet for the purposes of statistics.
java.lang.ArrayIndexOutOfBoundsException
2015-04-23 01:31:02.491 SEVERE: [39260]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.error() Failed
to analyze an outgoing RTCP packet for the purposes of statistics.
java.lang.ArrayIndexOutOfBoundsException

As a result, jicofo gets the following exception:

2015-04-23 01:31:02.264 INFO: [43]
org.jitsi.jicofo.FocusManager.conferenceEnded().309 Disposed
conference for room: room@conference.domain conference count: 5
2015-04-23 01:31:02.264 SEVERE: [43]
org.jitsi.jicofo.JitsiMeetConference.discoverFeaturesAndInvite().548
Failed to invite room@conference.domain/rid
net.java.sip.communicator.service.protocol.OperationFailedException:
Failed to allocate channels - all bridges are faulty
        at org.jitsi.jicofo.JitsiMeetConference.allocateChannels(JitsiMeetConference.java:667)
        at org.jitsi.jicofo.JitsiMeetConference.createOffer(JitsiMeetConference.java:720)
        at org.jitsi.jicofo.JitsiMeetConference.discoverFeaturesAndInvite(JitsiMeetConference.java:538)
        at org.jitsi.jicofo.JitsiMeetConference.access$000(JitsiMeetConference.java:45)
        at org.jitsi.jicofo.JitsiMeetConference$1.run(JitsiMeetConference.java:450)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
2015-04-23 01:31:08.394 INFO: [70]
org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().370 Focus
request for room: room@conference.domain
2015-04-23 01:31:08.394 INFO: [49]
org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().370 Focus
request for room: room@conference.domain
2015-04-23 01:31:08.394 INFO: [70]
org.jitsi.jicofo.FocusManager.createConference().263 Created new focus
for room@conference.domain@auth.domain conferences count: 6 options:
    channelLastN: 1
    adaptiveLastN: false
    adaptiveSimulcast: false
    startAudioMuted: 1
    bridge: jitsi-videobridge.domain
    startVideoMuted: 1
    openSctp: true

2015-04-23 01:31:08.787 SEVERE: [25]
org.jitsi.jicofo.MeetExtensionsHandler.handlePresence().449 Unable to
send DisplayNameChanged event - no conference id

2015-04-23 01:32:10.118 SEVERE: [29]
org.jitsi.jicofo.JitsiMeetConference.createOffer().832
java.lang.NullPointerException
java.lang.NullPointerException

In this case, jitsi-meet reloads the page for all the participants
("Focus has left the room - leaving conference"), and it works, but it
happens often.

Regards,
Zalmoxisus


#2

Thanks Michael, I'll look into it.

Boris

···

On May 23, 2015 1:08:27 PM CEST, Michael Diordiev <zalmoxisus@gmail.com> wrote:

Hey,

Often videobridge fails here:

2015-04-23 01:30:43.955 INFO: [68]
org.jitsi.videobridge.Channel.info() Expired channel 61c2d000ef23f016
of content audio of conference f3fde3e778f022ac. The total number of
conferences is now 6, channel$
2015-04-23 01:30:43.955 INFO: [68]
org.jitsi.impl.neomedia.MediaStreamImpl.info()
Receive stream stats: discarded RTP packets: 0
Receive stream stats: decoded with FEC: 0
2015-04-23 01:30:43.959 INFO: [68]
org.jitsi.videobridge.transform.CachingTransformer.info() Closing.
Maximum size reached: 0 bytes, 0 packets; 0 hits, 0 misses (0 total
requests); 0 total packets added.
2015-04-23 01:30:43.960 WARNING: [68]
org.jitsi.videobridge.Channel.warn() Failed to close the
MediaStream/stream of channel fcc6e9648a70117d of content video of
conference f3fde3e778f022ac!
java.lang.IllegalMonitorStateException
       at java.lang.Object.notify(Native Method)
at
org.jitsi.videobridge.transform.CachingTransformer.close(CachingTransformer.java:203)
at
org.jitsi.impl.neomedia.transform.TransformEngineChain$PacketTransformerChain.close(TransformEngineChain.java:241)
at
org.jitsi.impl.neomedia.transform.TransformEngineChain$PacketTransformerChain.close(TransformEngineChain.java:241)
at
org.jitsi.impl.neomedia.MediaStreamImpl.close(MediaStreamImpl.java:605)
at
org.jitsi.impl.neomedia.VideoMediaStreamImpl.close(VideoMediaStreamImpl.java:519)
  at org.jitsi.videobridge.RtpChannel.closeStream(RtpChannel.java:582)
       at org.jitsi.videobridge.Channel.expire(Channel.java:330)
       at org.jitsi.videobridge.Channel.setExpire(Channel.java:652)
at
org.jitsi.videobridge.Videobridge.handleColibriConferenceIQ(Videobridge.java:757)
at
org.jitsi.videobridge.Videobridge.handleColibriConferenceIQ(Videobridge.java:545)
at
org.jitsi.videobridge.xmpp.ComponentImpl.handleColibriConferenceIQ(ComponentImpl.java:209)
at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQRequest(ComponentImpl.java:380)
at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQ(ComponentImpl.java:311)
at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQ(ComponentImpl.java:263)
at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQSet(ComponentImpl.java:437)
at
org.xmpp.component.AbstractComponent.processIQRequest(AbstractComponent.java:515)
at
org.xmpp.component.AbstractComponent.processIQ(AbstractComponent.java:289)
at
org.xmpp.component.AbstractComponent.processQueuedPacket(AbstractComponent.java:239)
at
org.xmpp.component.AbstractComponent.access$100(AbstractComponent.java:81)
at
org.xmpp.component.AbstractComponent$PacketProcessor.run(AbstractComponent.java:1051)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
       at java.lang.Thread.run(Thread.java:745)
2015-04-23 01:30:43.960 INFO: [68]
org.jitsi.videobridge.Channel.info() Expired channel fcc6e9648a70117d
of content video of conference f3fde3e778f022ac. The total number of
conferences is now 6, channel$
2015-04-23 01:30:43.961 INFO: [68] org.ice4j.ice.Agent.setState() ICE
state changed from Completed to Terminated
2015-04-23 01:30:43.961 INFO: [60578]
org.ice4j.ice.Agent.runInStunKeepAliveThread() StunKeepAliveThread
ends.
2015-04-23 01:30:43.962 INFO: [68]
org.jitsi.videobridge.Channel.info() Expired channel 4b8499e44ec437be
of content data of conference f3fde3e778f022ac. The total number of
conferences is now 6, channels$
2015-04-23 01:30:43.964 INFO: [68]
org.jitsi.videobridge.xmpp.ComponentImpl.info() SENT: <iq
type="result" id="bX6aU-69620" from="jitsi-videobridge.domain"
to="focus@auth.domain/focus1140190629254207$
2015-04-23 01:30:48.684 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Total packets added: 1
2015-04-23 01:30:48.684 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Times reset() called: 2
2015-04-23 01:30:48.684 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Times grow() called: 0
2015-04-23 01:30:48.684 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because full: 0
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped while shrinking:
0
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were
late: 0
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were
late by more than MAX_SIZE: 0
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped in reset(): 1
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Max size reached: 4
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Adaptive jitter buffer mode was
enabled
2015-04-23 01:30:48.685 INFO: [39247] net.sf.fmj.media.Log.info()
Stopping RTPSourceStream.
2015-04-23 01:30:57.100 INFO: [60500]
org.ice4j.ice.ConnectivityCheckClient.processTimeout() timeout for
pair: 95.163.117.17:12916/udp/host -> 41.92.113.46:61517/udp/prflx
(stream.RTP), failing.

2015-04-23 01:31:02.257 INFO: [170]
org.jitsi.videobridge.xmpp.ComponentImpl.info() RECV: <iq type=“get”
to=“jitsi-videobridge.domain”
from=“focus@auth.domain/focus11401906292542079”
id=“bX6aU-69629”><conference
xmlns=“http://jitsi.org/protocol/colibri
id=“f3fde3e778f022ac”><content name=“audio”><channel
channel-bundle-id=“9595” initiator=“true” last-n=“1”
endpoint=“9595”><payload-type name=“opus”
clockrate=“48000” id=“111” channels=“2”><parameter value=“10”
name=“minptime”/></payload-type><payload-type id=“103” name=“ISAC”
clockrate=“16000”/><payload-type id=“104” name=“ISAC”
clockrate=“32000”/><payload-type id=“0” name=“PCMU”
clockrate=“8000”/><payload-type id=“8” name=“PCMA”
clockrate=“8000”/><payload-type id=“106” name=“CN”
clockrate=“32000”/><payload-type id=“105”
name=“CN” clockrate=“16000”/><payload-type id=“13” name=“CN”
clockrate=“8000”/><payload-type id=“126” name=“telephone-event”
clockrate=“8000”/><rtp-hdrext id=“1”
uri=“urn:ietf:params:rtp-hdrext:ssrc-audio-level”/></channel></content><content
name=“video”><channel channel-bundle-id=“9595” initiator=“true”
last-n=“1” endpoint=“9595”><payload-type id=“100”
name=“VP8” clockrate=“90000”><rtcp-fb
xmlns=“urn:xmpp:jingle:apps:rtp:rtcp-fb:0” type=“ccm”
subtype=“fir”/><rtcp-fb xmlns=“urn:xmpp:jingle:apps:rtp:rtcp-fb:0”
type=“nack”/><rtcp-fb
xmlns=“urn:xmpp:jingle:apps:rtp:rtcp-fb:0” type=“nack”
subtype=“pli”/><rtcp-fb xmlns=“urn:xmpp:jingle:apps:rtp:rtcp-fb:0”
type=“goog-remb”/></payload-type><payload-type id=“116” name=“red”
clockrate=“90000”/><payload-type id=“117” name=“ulpfec”
clockrate=“90000”/><rtp-hdrext id=“2”
uri=“urn:ietf:params:rtp-hdrext:toffset”/><rtp-hdrext id=“3”
uri=“http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time”/></channel></content><content
name=“data”><sctpconnection channel-bundle-id=“9595” port=“5000”
initiator=“true”
endpoint=“9595”/></content><channel-bundle id=“9595”><transport
xmlns=“urn:xmpp:jingle:transports:ice-udp:1”/></channel-bundle></conference></iq>

2015-04-23 01:31:02.257 INFO: [170]
org.jitsi.videobridge.Channel.info() Transport connected for channel
b83ad5c208aee149 of content audio of conference f3fde3e778f022ac
java.lang.NullPointerException
at
org.jitsi.videobridge.RtpChannel.maybeStartStream(RtpChannel.java:943)
at org.jitsi.videobridge.Channel.transportConnected(Channel.java:754)
at
org.jitsi.videobridge.IceUdpTransportManager.addChannel(IceUdpTransportManager.java:429)
       at org.jitsi.videobridge.Channel.initialize(Channel.java:537)
   at org.jitsi.videobridge.RtpChannel.initialize(RtpChannel.java:882)
   at org.jitsi.videobridge.Content.createRtpChannel(Content.java:275)
at
org.jitsi.videobridge.Videobridge.handleColibriConferenceIQ(Videobridge.java:733)
at
org.jitsi.videobridge.Videobridge.handleColibriConferenceIQ(Videobridge.java:545)
at
org.jitsi.videobridge.xmpp.ComponentImpl.handleColibriConferenceIQ(ComponentImpl.java:209)
at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQRequest(ComponentImpl.java:380)
at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQ(ComponentImpl.java:311)
at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQ(ComponentImpl.java:263)
at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQGet(ComponentImpl.java:362)
at
org.xmpp.component.AbstractComponent.processIQRequest(AbstractComponent.java:511)
at
org.xmpp.component.AbstractComponent.processIQ(AbstractComponent.java:289)
at
org.xmpp.component.AbstractComponent.processQueuedPacket(AbstractComponent.java:239)
at
org.xmpp.component.AbstractComponent.access$100(AbstractComponent.java:81)
at
org.xmpp.component.AbstractComponent$PacketProcessor.run(AbstractComponent.java:1051)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
       at java.lang.Thread.run(Thread.java:745)
2015-04-23 01:31:02.259 INFO: [269]
org.jitsi.videobridge.xmpp.ComponentImpl.info() RECV: <iq type="set"
to="jitsi-videobridge.domain"
from="focus@auth.domain/focus11401906292542079" id="bX6aU-69630"$
2015-04-23 01:31:02.491 SEVERE: [39260]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.error() Failed
to analyze an outgoing RTCP packet for the purposes of statistics.
java.lang.ArrayIndexOutOfBoundsException
2015-04-23 01:31:02.491 SEVERE: [39260]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.error() Failed
to analyze an outgoing RTCP packet for the purposes of statistics.
java.lang.ArrayIndexOutOfBoundsException

As a result, jicofo gets the following exception:

2015-04-23 01:31:02.264 INFO: [43]
org.jitsi.jicofo.FocusManager.conferenceEnded().309 Disposed
conference for room: room@conference.domain conference count: 5
2015-04-23 01:31:02.264 SEVERE: [43]
org.jitsi.jicofo.JitsiMeetConference.discoverFeaturesAndInvite().548
Failed to invite room@conference.domain/rid
net.java.sip.communicator.service.protocol.OperationFailedException:
Failed to allocate channels - all bridges are faulty
at
org.jitsi.jicofo.JitsiMeetConference.allocateChannels(JitsiMeetConference.java:667)
at
org.jitsi.jicofo.JitsiMeetConference.createOffer(JitsiMeetConference.java:720)
at
org.jitsi.jicofo.JitsiMeetConference.discoverFeaturesAndInvite(JitsiMeetConference.java:538)
at
org.jitsi.jicofo.JitsiMeetConference.access$000(JitsiMeetConference.java:45)
at
org.jitsi.jicofo.JitsiMeetConference$1.run(JitsiMeetConference.java:450)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
       at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
       at java.lang.Thread.run(Thread.java:745)
2015-04-23 01:31:08.394 INFO: [70]
org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().370 Focus
request for room: room@conference.domain
2015-04-23 01:31:08.394 INFO: [49]
org.jitsi.jicofo.xmpp.FocusComponent.handleConferenceIq().370 Focus
request for room: room@conference.domain
2015-04-23 01:31:08.394 INFO: [70]
org.jitsi.jicofo.FocusManager.createConference().263 Created new focus
for room@conference.domain@auth.domain conferences count: 6 options:
   channelLastN: 1
   adaptiveLastN: false
   adaptiveSimulcast: false
   startAudioMuted: 1
   bridge: jitsi-videobridge.domain
   startVideoMuted: 1
   openSctp: true

2015-04-23 01:31:08.787 SEVERE: [25]
org.jitsi.jicofo.MeetExtensionsHandler.handlePresence().449 Unable to
send DisplayNameChanged event - no conference id

2015-04-23 01:32:10.118 SEVERE: [29]
org.jitsi.jicofo.JitsiMeetConference.createOffer().832
java.lang.NullPointerException
java.lang.NullPointerException

In this case, jitsi-meet reloads the page for all the participants
("Focus has left the room - leaving conference"), and it works, but it
happens often.

Regards,
Zalmoxisus

_______________________________________________
dev mailing list
dev@jitsi.org
Unsubscribe instructions and other list options:
http://lists.jitsi.org/mailman/listinfo/dev

--
Sent from a mobile. Please excuse my brevity.


#3

Fixed in https://github.com/jitsi/jitsi-videobridge/commit/d18167488131acf7dd505c333750cc7e6146318f

Thanks,
Boris


#4

Hi Michael (also including dev@ again),

···

On 25/05/15 14:32, Michael Diordiev wrote:

Unfortunately, it didn't solve this. There are no
java.lang.NullPointerException anymore, but the SEVERE errors (which
were after that) still occur:

2015-04-25 15:22:41.510 SEVERE: [166]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.error() Failed
to analyze an outgoing RTCP packet for the purposes of statistics.

java.lang.ArrayIndexOutOfBoundsException

These should also be fixed now (they were unrelated). Thanks for reporting and please let me know if there are still unresolved problems.

Regards,
Boris


#5

Hi,

Adding dev@ again.

Hi, Boris, Paweł and dev!

I solved this issue by using constant resource identifier for jid, and
as a result Prosody assures to have only one active instance for a
persistent jid.

I still lose the focus as a result of a JVB exception:
http://pastebin.com/yZuCZK0u

It seems to me that it's another one, but related to that.

Boris, could you please give a hint why payload type number could be
used by more than one channel and if it is the issue.

The root of the problem is the same, as far as I see: a new channel is created, with the "endpoint" attribute set to one that already exists for the COLIBRI conference (140388). This results in reusing the same transport bundle, hence the PT warnings (there are now two audio channels with the same payload types in the same bundle).

The exception you see results from setting the channel parameters (specifically RTP header extensions) after the stream has been connected. It shouldn't happen and I will fix it shortly, but it won't fix your problem.

Regards,
Boris

···

On 10/06/15 01:14, Michael Diordiev wrote:


#6

Hi, Boris.

Thanks for your detailed explanation and for the commit.
After updating the error <http://pastebin.com/NuZ0dYZW> is different, but,
yes,the root of the problem is the same.

Regards,
Zalmoxisus

···

On Wed, Jun 10, 2015 at 10:34 AM, Boris Grozev <boris@jitsi.org> wrote:

Hi,

Adding dev@ again.

On 10/06/15 01:14, Michael Diordiev wrote:

Hi, Boris, Paweł and dev!

I solved this issue by using constant resource identifier for jid, and
as a result Prosody assures to have only one active instance for a
persistent jid.

I still lose the focus as a result of a JVB exception:
http://pastebin.com/yZuCZK0u

It seems to me that it's another one, but related to that.

Boris, could you please give a hint why payload type number could be
used by more than one channel and if it is the issue.

The root of the problem is the same, as far as I see: a new channel is
created, with the "endpoint" attribute set to one that already exists for
the COLIBRI conference (140388). This results in reusing the same transport
bundle, hence the PT warnings (there are now two audio channels with the
same payload types in the same bundle).

The exception you see results from setting the channel parameters
(specifically RTP header extensions) after the stream has been connected.
It shouldn't happen and I will fix it shortly, but it won't fix your
problem.

Regards,
Boris


#7

Hi, Boris.

Any chances to get it fixed?
I was thinking to make a workaround. I may attach a timestamp to the id of
jids, and in the prosody authentication (I use mod_auth_external) will
remove it. So, the jid will be always unique. Just want to be sure if it
could help to avoid double audio channels.

Regards,
Zalmoxisus

···

On Thu, Jun 11, 2015 at 1:52 AM, Michael Diordiev <zalmoxisus@gmail.com> wrote:

Hi, Boris.

Thanks for your detailed explanation and for the commit.
After updating the error <http://pastebin.com/NuZ0dYZW> is different,
but, yes,the root of the problem is the same.

Regards,
Zalmoxisus

On Wed, Jun 10, 2015 at 10:34 AM, Boris Grozev <boris@jitsi.org> wrote:

Hi,

Adding dev@ again.

On 10/06/15 01:14, Michael Diordiev wrote:

Hi, Boris, Paweł and dev!

I solved this issue by using constant resource identifier for jid, and
as a result Prosody assures to have only one active instance for a
persistent jid.

I still lose the focus as a result of a JVB exception:
http://pastebin.com/yZuCZK0u

It seems to me that it's another one, but related to that.

Boris, could you please give a hint why payload type number could be
used by more than one channel and if it is the issue.

The root of the problem is the same, as far as I see: a new channel is
created, with the "endpoint" attribute set to one that already exists for
the COLIBRI conference (140388). This results in reusing the same transport
bundle, hence the PT warnings (there are now two audio channels with the
same payload types in the same bundle).

The exception you see results from setting the channel parameters
(specifically RTP header extensions) after the stream has been connected.
It shouldn't happen and I will fix it shortly, but it won't fix your
problem.

Regards,
Boris


#8

Sorry for bothering with this issue, but maybe we may add and exception here
<https://github.com/jitsi/jitsi-videobridge/blob/ec9e05b05ae3203d1244c7b30db71432a0a05b6b/src/org/jitsi/videobridge/TransportManager.java#L342>,
and as the result only the participant that got this problem will have to
reconnect, instead of reconnecting all the participants.
It doesn't happen so often, but sometimes because of one participant all
the conference is spoiled by reconnecting continuously other participants,
and there are no other solution than finishing this conference.

Best regards,
Zalmoxisus

···

On Tue, Jun 23, 2015 at 2:13 AM, Michael Diordiev <zalmoxisus@gmail.com> wrote:

Hi, Boris.

Any chances to get it fixed?
I was thinking to make a workaround. I may attach a timestamp to the id of
jids, and in the prosody authentication (I use mod_auth_external) will
remove it. So, the jid will be always unique. Just want to be sure if it
could help to avoid double audio channels.

Regards,
Zalmoxisus

On Thu, Jun 11, 2015 at 1:52 AM, Michael Diordiev <zalmoxisus@gmail.com> > wrote:

Hi, Boris.

Thanks for your detailed explanation and for the commit.
After updating the error <http://pastebin.com/NuZ0dYZW> is different,
but, yes,the root of the problem is the same.

Regards,
Zalmoxisus

On Wed, Jun 10, 2015 at 10:34 AM, Boris Grozev <boris@jitsi.org> wrote:

Hi,

Adding dev@ again.

On 10/06/15 01:14, Michael Diordiev wrote:

Hi, Boris, Paweł and dev!

I solved this issue by using constant resource identifier for jid, and
as a result Prosody assures to have only one active instance for a
persistent jid.

I still lose the focus as a result of a JVB exception:
http://pastebin.com/yZuCZK0u

It seems to me that it's another one, but related to that.

Boris, could you please give a hint why payload type number could be
used by more than one channel and if it is the issue.

The root of the problem is the same, as far as I see: a new channel is
created, with the "endpoint" attribute set to one that already exists for
the COLIBRI conference (140388). This results in reusing the same transport
bundle, hence the PT warnings (there are now two audio channels with the
same payload types in the same bundle).

The exception you see results from setting the channel parameters
(specifically RTP header extensions) after the stream has been connected.
It shouldn't happen and I will fix it shortly, but it won't fix your
problem.

Regards,
Boris