[jitsi-dev] Crashing Videobridge?


#1

Hello,

What is going in here? It appears that the JVB is crashing, citing "Too
many open files".

As far as I can tell, the server was not used at the time of the crash, nor
had it for a couple of days.

Does the health check consume resources that it does not release?

- Guus

2017.03.01 04:16:10 DEBUG [pool-5-thread-12]:
org.jitsi.videobridge.xmpp.ComponentImpl - (serving component
‘JitsiVideobridge’) Responding to IQ (packetId l3Sdl-31688) with: <iq
type=“result” id=“l3Sdl-31688” from=“jitsi-videobridge.goodbytes.nl” to="
focus@goodbytes.nl/focus1305362139329797"><query xmlns="
http://jabber.org/protocol/disco#info"><identity category=“component”
type=“conference” name=“JitsiVideobridge”/><feature var="
http://jabber.org/protocol/disco#info"/><feature
var=“urn:xmpp:ping”/><feature var=“jabber:iq:last”/><feature
var=“urn:xmpp:time”/><feature var=“http://jitsi.org/protocol/colibri”/><feature
var=“http://jitsi.org/protocol/healthcheck”/><feature
var=“urn:xmpp:jingle:apps:dtls:0”/><feature
var=“urn:xmpp:jingle:transports:ice-udp:1”/><feature
var=“urn:xmpp:jingle:transports:raw-udp:1”/><feature
var=“jabber:iq:version”/></query></iq>
2017.03.01 04:16:15 DEBUG [pool-5-thread-14]:
org.jitsi.videobridge.xmpp.ComponentImpl - (serving component
‘JitsiVideobridge’) Processing IQ (packetId l3Sdl-31690): <iq type=“result”
id=“l3Sdl-31690” from=“goodbytes.nl” to=“jitsi-videobridge.goodbytes.nl”/>
2017.03.01 04:16:15 INFO [pool-5-thread-14]:
org.jitsi.videobridge.xmpp.ComponentImpl - RECV: <iq type=“result”
id=“l3Sdl-31690” from=“goodbytes.nl” to=“jitsi-videobridge.goodbytes.nl”/>
2017.03.01 04:16:15 DEBUG [pool-10-thread-5]:
org.jitsi.jicofo.xmpp.FocusComponent - (serving component ‘Jitsi Meet
Focus’) Processing IQ (packetId l3Sdl-31691): <iq type=“result”
id=“l3Sdl-31691” from=“goodbytes.nl” to=“focus.goodbytes.nl”/>
2017.03.01 04:16:15 DEBUG [pool-10-thread-6]:
org.jitsi.jicofo.xmpp.FocusComponent - (serving component ‘Jitsi Meet
Focus’) Processing IQ (packetId l3Sdl-31692): <iq type=“result”
id=“l3Sdl-31692” from=“godbytes.nl” to=“focus.goodbytes.nl”/>
2017.03.01 04:16:20 DEBUG [pool-5-thread-15]:
org.jitsi.videobridge.xmpp.ComponentImpl - (serving component
‘JitsiVideobridge’) Processing IQ (packetId l3Sdl-31693): <iq
id=“l3Sdl-31693” to=“jitsi-videobridge.goodbytes.nl” type=“get” from="
focus@goodbytes.nl/focus1305362139329797"><healthcheck xmlns="
http://jitsi.org/protocol/healthcheck"/></iq>
2017.03.01 04:16:20 DEBUG [pool-5-thread-15]:
org.jitsi.videobridge.xmpp.ComponentImpl - (serving component
‘JitsiVideobridge’) Processing IQ request (packetId l3Sdl-31693).
2017.03.01 04:16:20 INFO [pool-5-thread-15]:
org.jitsi.videobridge.xmpp.ComponentImpl - RECV: <iq id=“l3Sdl-31693” to="
jitsi-videobridge.goodbytes.nl" type=“get” from="
focus@goodbytes.nl/focus1305362139329797"><healthcheck xmlns="
http://jitsi.org/protocol/healthcheck"/></iq>
2017.03.01 04:16:20 INFO [pool-5-thread-15]:
org.jitsi.videobridge.Videobridge - CAT=stat
create_conf,conf_id=d3ca2c5173006f8e
conf_name=null,logging=false,conf_count=1,ch_count=0,v_streams=0
2017.03.01 04:16:20 INFO [pool-5-thread-15]:
org.jitsi.impl.neomedia.MediaStreamImpl -
Receive stream stats: discarded RTP packets: 0
Receive stream stats: decoded with FEC: 0
2017.03.01 04:16:20 INFO [pool-5-thread-15]:
org.jitsi.impl.neomedia.MediaStreamImpl -
Receive stream stats: discarded RTP packets: 0
Receive stream stats: decoded with FEC: 0
2017.03.01 04:16:20 INFO [pool-5-thread-15]:
org.jitsi.impl.neomedia.MediaStreamImpl -
Receive stream stats: discarded RTP packets: 0
Receive stream stats: decoded with FEC: 0
2017.03.01 04:16:20 WARN [pool-5-thread-15]: org.jitsi.videobridge.Channel
- Failed to close the MediaStream/stream of channel b88b66dc204cc55c of
content video of conference d3ca2c5173006f8e!
java.lang.NullPointerException
        at org.jitsi.videobridge.RtpChannel.closeStream(RtpChannel.java:645)
        at org.jitsi.videobridge.Channel.expire(Channel.java:383)
        at org.jitsi.videobridge.RtpChannel.expire(RtpChannel.java:1714)
        at org.jitsi.videobridge.VideoChannel.expire(VideoChannel.java:386)
        at org.jitsi.videobridge.Content.expire(Content.java:394)
        at org.jitsi.videobridge.Conference.expire(Conference.java:690)
        at org.jitsi.videobridge.health.Health.check(Health.java:168)
        at
org.jitsi.videobridge.Videobridge.handleHealthCheckIQ(Videobridge.java:1129)
        at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQRequest(ComponentImpl.java:433)
        at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQ(ComponentImpl.java:343)
        at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQ(ComponentImpl.java:295)
        at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQGetImpl(ComponentImpl.java:394)
        at
org.jitsi.xmpp.component.ComponentBase.handleIQGet(ComponentBase.java:315)
        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:1142)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
2017.03.01 04:16:20 INFO [pool-5-thread-15]:
org.jitsi.videobridge.xmpp.ComponentImpl - SENT: <iq id=“l3Sdl-31693” to="
focus@goodbytes.nl/focus1305362139329797" from="
jitsi-videobridge.goodbytes.nl" type=“error”><healthcheck xmlns="
http://jitsi.org/protocol/healthcheck"></healthcheck><error code=“500”
type=“WAIT”><internal-server-error
xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”></internal-server-error><text
xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”
xml:lang=“en”>java.net.SocketException: Too many open files (Error creating
socket)</text></error></iq>
2017.03.01 04:16:20 DEBUG [pool-5-thread-15]:
org.jitsi.videobridge.xmpp.ComponentImpl - (serving component
‘JitsiVideobridge’) Responding to IQ (packetId l3Sdl-31693) with: <iq
id=“l3Sdl-31693” to=“focus@goodbytes.nl/focus1305362139329797” from="
jitsi-videobridge.goodbytes.nl" type=“error”><healthcheck xmlns="
http://jitsi.org/protocol/healthcheck"></healthcheck><error code=“500”
type=“WAIT”><internal-server-error
xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”></internal-server-error><text
xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”
xml:lang=“en”>java.net.SocketException: Too many open files (Error creating
socket)</text></error></iq>
2017.03.01 04:16:20 WARN [pool-9-thread-1]: org.jitsi.jicofo.JvbDoctor -
Health check failed on: jitsi-videobridge.goodbytes.nl error: <error
code=“500” type=“WAIT”><internal-server-error
xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”/><text xml:lang=“en”
xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”>java.net.SocketException: Too
many open files (Error creating socket)</text></error>
2017.03.01 04:16:20 INFO [pool-7-thread-1]:
org.jitsi.jicofo.BridgeSelector - Removing JVB:
jitsi-videobridge.goodbytes.nl
2017.03.01 04:16:20 INFO [pool-7-thread-1]: org.jitsi.jicofo.JvbDoctor -
Stopping health-check task for: jitsi-videobridge.goodbytes.nl


#2

Hi,

We have seen a problem like this and Boris tried to fix it:
https://github.com/jitsi/ice4j/commit/cefd96450947bad93eff9d4b5fc95af25dcb9ae3
Which is jvb build 882.
But I have seen in the last month several reports with issue like this one.
What we saw is not releasing some sockets while health checking, we
need to further investigate this.

Thanks
damencho

···

On Thu, Mar 2, 2017 at 8:12 AM, Guus der Kinderen <guus.der.kinderen@gmail.com> wrote:

Hello,

What is going in here? It appears that the JVB is crashing, citing "Too many
open files".

As far as I can tell, the server was not used at the time of the crash, nor
had it for a couple of days.

Does the health check consume resources that it does not release?

- Guus

2017.03.01 04:16:10 DEBUG [pool-5-thread-12]:
org.jitsi.videobridge.xmpp.ComponentImpl - (serving component
‘JitsiVideobridge’) Responding to IQ (packetId l3Sdl-31688) with: <iq
type=“result” id=“l3Sdl-31688” from=“jitsi-videobridge.goodbytes.nl”
to=“focus@goodbytes.nl/focus1305362139329797”><query
xmlns=“http://jabber.org/protocol/disco#info”><identity category=“component”
type=“conference” name=“JitsiVideobridge”/><feature
var=“http://jabber.org/protocol/disco#info”/><feature
var=“urn:xmpp:ping”/><feature var=“jabber:iq:last”/><feature
var=“urn:xmpp:time”/><feature
var=“http://jitsi.org/protocol/colibri”/><feature
var=“http://jitsi.org/protocol/healthcheck”/><feature
var=“urn:xmpp:jingle:apps:dtls:0”/><feature
var=“urn:xmpp:jingle:transports:ice-udp:1”/><feature
var=“urn:xmpp:jingle:transports:raw-udp:1”/><feature
var=“jabber:iq:version”/></query></iq>
2017.03.01 04:16:15 DEBUG [pool-5-thread-14]:
org.jitsi.videobridge.xmpp.ComponentImpl - (serving component
‘JitsiVideobridge’) Processing IQ (packetId l3Sdl-31690): <iq type=“result”
id=“l3Sdl-31690” from=“goodbytes.nl” to=“jitsi-videobridge.goodbytes.nl”/>
2017.03.01 04:16:15 INFO [pool-5-thread-14]:
org.jitsi.videobridge.xmpp.ComponentImpl - RECV: <iq type=“result”
id=“l3Sdl-31690” from=“goodbytes.nl” to=“jitsi-videobridge.goodbytes.nl”/>
2017.03.01 04:16:15 DEBUG [pool-10-thread-5]:
org.jitsi.jicofo.xmpp.FocusComponent - (serving component ‘Jitsi Meet
Focus’) Processing IQ (packetId l3Sdl-31691): <iq type=“result”
id=“l3Sdl-31691” from=“goodbytes.nl” to=“focus.goodbytes.nl”/>
2017.03.01 04:16:15 DEBUG [pool-10-thread-6]:
org.jitsi.jicofo.xmpp.FocusComponent - (serving component ‘Jitsi Meet
Focus’) Processing IQ (packetId l3Sdl-31692): <iq type=“result”
id=“l3Sdl-31692” from=“godbytes.nl” to=“focus.goodbytes.nl”/>
2017.03.01 04:16:20 DEBUG [pool-5-thread-15]:
org.jitsi.videobridge.xmpp.ComponentImpl - (serving component
‘JitsiVideobridge’) Processing IQ (packetId l3Sdl-31693): <iq
id=“l3Sdl-31693” to=“jitsi-videobridge.goodbytes.nl” type=“get”
from=“focus@goodbytes.nl/focus1305362139329797”><healthcheck
xmlns=“http://jitsi.org/protocol/healthcheck”/></iq>
2017.03.01 04:16:20 DEBUG [pool-5-thread-15]:
org.jitsi.videobridge.xmpp.ComponentImpl - (serving component
‘JitsiVideobridge’) Processing IQ request (packetId l3Sdl-31693).
2017.03.01 04:16:20 INFO [pool-5-thread-15]:
org.jitsi.videobridge.xmpp.ComponentImpl - RECV: <iq id=“l3Sdl-31693”
to=“jitsi-videobridge.goodbytes.nl” type=“get”
from=“focus@goodbytes.nl/focus1305362139329797”><healthcheck
xmlns=“http://jitsi.org/protocol/healthcheck”/></iq>
2017.03.01 04:16:20 INFO [pool-5-thread-15]:
org.jitsi.videobridge.Videobridge - CAT=stat
create_conf,conf_id=d3ca2c5173006f8e
conf_name=null,logging=false,conf_count=1,ch_count=0,v_streams=0
2017.03.01 04:16:20 INFO [pool-5-thread-15]:
org.jitsi.impl.neomedia.MediaStreamImpl -
Receive stream stats: discarded RTP packets: 0
Receive stream stats: decoded with FEC: 0
2017.03.01 04:16:20 INFO [pool-5-thread-15]:
org.jitsi.impl.neomedia.MediaStreamImpl -
Receive stream stats: discarded RTP packets: 0
Receive stream stats: decoded with FEC: 0
2017.03.01 04:16:20 INFO [pool-5-thread-15]:
org.jitsi.impl.neomedia.MediaStreamImpl -
Receive stream stats: discarded RTP packets: 0
Receive stream stats: decoded with FEC: 0
2017.03.01 04:16:20 WARN [pool-5-thread-15]: org.jitsi.videobridge.Channel
- Failed to close the MediaStream/stream of channel b88b66dc204cc55c of
content video of conference d3ca2c5173006f8e!
java.lang.NullPointerException
        at org.jitsi.videobridge.RtpChannel.closeStream(RtpChannel.java:645)
        at org.jitsi.videobridge.Channel.expire(Channel.java:383)
        at org.jitsi.videobridge.RtpChannel.expire(RtpChannel.java:1714)
        at org.jitsi.videobridge.VideoChannel.expire(VideoChannel.java:386)
        at org.jitsi.videobridge.Content.expire(Content.java:394)
        at org.jitsi.videobridge.Conference.expire(Conference.java:690)
        at org.jitsi.videobridge.health.Health.check(Health.java:168)
        at
org.jitsi.videobridge.Videobridge.handleHealthCheckIQ(Videobridge.java:1129)
        at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQRequest(ComponentImpl.java:433)
        at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQ(ComponentImpl.java:343)
        at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQ(ComponentImpl.java:295)
        at
org.jitsi.videobridge.xmpp.ComponentImpl.handleIQGetImpl(ComponentImpl.java:394)
        at
org.jitsi.xmpp.component.ComponentBase.handleIQGet(ComponentBase.java:315)
        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:1142)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
2017.03.01 04:16:20 INFO [pool-5-thread-15]:
org.jitsi.videobridge.xmpp.ComponentImpl - SENT: <iq id=“l3Sdl-31693”
to=“focus@goodbytes.nl/focus1305362139329797”
from=“jitsi-videobridge.goodbytes.nl” type=“error”><healthcheck
xmlns=“http://jitsi.org/protocol/healthcheck”></healthcheck><error
code=“500” type=“WAIT”><internal-server-error
xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”></internal-server-error><text
xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”
xml:lang=“en”>java.net.SocketException: Too many open files (Error creating
socket)</text></error></iq>
2017.03.01 04:16:20 DEBUG [pool-5-thread-15]:
org.jitsi.videobridge.xmpp.ComponentImpl - (serving component
‘JitsiVideobridge’) Responding to IQ (packetId l3Sdl-31693) with: <iq
id=“l3Sdl-31693” to=“focus@goodbytes.nl/focus1305362139329797”
from=“jitsi-videobridge.goodbytes.nl” type=“error”><healthcheck
xmlns=“http://jitsi.org/protocol/healthcheck”></healthcheck><error
code=“500” type=“WAIT”><internal-server-error
xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”></internal-server-error><text
xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”
xml:lang=“en”>java.net.SocketException: Too many open files (Error creating
socket)</text></error></iq>
2017.03.01 04:16:20 WARN [pool-9-thread-1]: org.jitsi.jicofo.JvbDoctor -
Health check failed on: jitsi-videobridge.goodbytes.nl error: <error
code=“500” type=“WAIT”><internal-server-error
xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”/><text xml:lang=“en”
xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”>java.net.SocketException: Too
many open files (Error creating socket)</text></error>
2017.03.01 04:16:20 INFO [pool-7-thread-1]: org.jitsi.jicofo.BridgeSelector
- Removing JVB: jitsi-videobridge.goodbytes.nl
2017.03.01 04:16:20 INFO [pool-7-thread-1]: org.jitsi.jicofo.JvbDoctor -
Stopping health-check task for: jitsi-videobridge.goodbytes.nl

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