jigasi
jigasi copied to clipboard
jitsi
Inconsistent behavior/failures with Jigasi/Transcription
Description
We are running into instability issues with Jigasi (and potentially JVB). Everything works OK for a little while, and then (when starting a new conference), we will suddenly see errors in the logs, and notice that transcription fails.
Current behavior
We have spent a while trying to diagnose and debug this issue, but since there are a number of warning and error messages in the logs, it is difficult to pinpoint the cause of the problem. We have noticed a few abnormalities in the logs, such as the following:
We will suddenly get a ton of the following error. This appears in the JVB logs rather frequently, and usually includes a large block of the same type of error:
EndpointMessageTransport: No available transport channel
JVB 2018-08-07 22:34:20.701 FINE: [139] org.jitsi.videobridge.xmpp.ComponentImpl.log() RECV:
DatagramTransportImpl is closed
We have also seen the following error in the Jigasi logs:
java.lang.IllegalStateException: java.io.IOException: org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl is closed! at org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.queueReceive(DatagramTransportImpl.java:299) at org.jitsi.impl.neomedia.transform.dtls.DtlsPacketTransformer.reverseTransformDtls(DtlsPacketTransformer.java:893) at org.jitsi.impl.neomedia.transform.dtls.DtlsPacketTransformer.transformDtls(DtlsPacketTransformer.java:1427) at org.jitsi.impl.neomedia.transform.dtls.DtlsPacketTransformer.transform(DtlsPacketTransformer.java:1373) at org.jitsi.impl.neomedia.transform.dtls.DtlsPacketTransformer.reverseTransform(DtlsPacketTransformer.java:857) at org.jitsi.impl.neomedia.transform.TransformEngineChain$PacketTransformerChain.reverseTransform(TransformEngineChain.java:381) at org.jitsi.impl.neomedia.transform.TransformInputStream.createRawPacket(TransformInputStream.java:85) at org.jitsi.impl.neomedia.RTPConnectorInputStream.runInReceiveThread(RTPConnectorInputStream.java:768) at org.jitsi.impl.neomedia.RTPConnectorInputStream.access$000(RTPConnectorInputStream.java:42) at org.jitsi.impl.neomedia.RTPConnectorInputStream$3.run(RTPConnectorInputStream.java:565) Caused by: java.io.IOException: org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl is closed! at org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.assertNotClosed(DatagramTransportImpl.java:125) at org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.queueReceive(DatagramTransportImpl.java:295) ... 9 more JVB 2018-08-07 21:03:37.435 SEVERE: [6603] org.jitsi.impl.neomedia.RTPConnectorInputStream.log() Failed to receive a packet: java.lang.IllegalStateException: java.io.IOException: org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl is closed! at org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.queueReceive(DatagramTransportImpl.java:299) at org.jitsi.impl.neomedia.transform.dtls.DtlsPacketTransformer.reverseTransformDtls(DtlsPacketTransformer.java:893) at org.jitsi.impl.neomedia.transform.dtls.DtlsPacketTransformer.transformDtls(DtlsPacketTransformer.java:1427) at org.jitsi.impl.neomedia.transform.dtls.DtlsPacketTransformer.transform(DtlsPacketTransformer.java:1373) at org.jitsi.impl.neomedia.transform.dtls.DtlsPacketTransformer.reverseTransform(DtlsPacketTransformer.java:857) at org.jitsi.impl.neomedia.transform.TransformEngineChain$PacketTransformerChain.reverseTransform(TransformEngineChain.java:381) at org.jitsi.impl.neomedia.transform.TransformInputStream.createRawPacket(TransformInputStream.java:85) at org.jitsi.impl.neomedia.RTPConnectorInputStream.runInReceiveThread(RTPConnectorInputStream.java:768) at org.jitsi.impl.neomedia.RTPConnectorInputStream.access$000(RTPConnectorInputStream.java:42) at org.jitsi.impl.neomedia.RTPConnectorInputStream$3.run(RTPConnectorInputStream.java:565) Caused by: java.io.IOException: org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl is closed! at org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.assertNotClosed(DatagramTransportImpl.java:125) at org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.queueReceive(DatagramTransportImpl.java:295) ... 9 more
javax.media.ClockStartedError: deallocate cannot be used on a started controller.
We've also seen the following error in the JVB logs:
2018-08-13 23:54:38.116 SEVERE: [1365] org.jitsi.impl.neomedia.RTPConnectorOutputStream.log() Failed to send a packet to target /172.17.0.1:15544:java.io.IOException: No active socket. 2018-08-13 23:54:38.123 SEVERE: [1320] org.jitsi.impl.neomedia.RTPConnectorOutputStream.log() Failed to send a packet to target /172.17.0.1:15543:java.io.IOException: No active socket. 2018-08-13 23:54:38.127 SEVERE: [1320] org.jitsi.impl.neomedia.RTPConnectorOutputStream.log() Failed to send a packet to target /172.17.0.1:15544:java.io.IOException: No active socket. 2018-08-13 23:54:38.137 SEVERE: [1320] util.UtilActivator.uncaughtException().122 An uncaught exception occurred in thread=Thread[Smack-Single Threaded Executor 0 (2),5,main] and message was: deallocate cannot be used on a started controller. javax.media.ClockStartedError: deallocate cannot be used on a started controller. at net.sf.fmj.media.BasicController.deallocate(BasicController.java:334) at net.sf.fmj.media.BasicPlayer.abortPrefetch(BasicPlayer.java:100) at net.sf.fmj.media.BasicController.deallocate(BasicController.java:353) at org.jitsi.impl.neomedia.device.MediaDeviceSession.closeProcessor(MediaDeviceSession.java:411) at org.jitsi.impl.neomedia.device.MediaDeviceSession.close(MediaDeviceSession.java:367) at org.jitsi.impl.neomedia.device.AudioMixerMediaDevice$MediaStreamMediaDeviceSession.close(AudioMixerMediaDevice.java:1036) at org.jitsi.impl.neomedia.MediaStreamImpl.close(MediaStreamImpl.java:849) at org.jitsi.impl.neomedia.AudioMediaStreamImpl.close(AudioMediaStreamImpl.java:298) at net.java.sip.communicator.service.protocol.media.MediaHandler.setAudioStream(MediaHandler.java:1252) at net.java.sip.communicator.service.protocol.media.MediaHandler.closeStream(MediaHandler.java:638) at net.java.sip.communicator.service.protocol.media.CallPeerMediaHandler.closeStream(CallPeerMediaHandler.java:488) at net.java.sip.communicator.service.protocol.media.CallPeerMediaHandler.close(CallPeerMediaHandler.java:442) at net.java.sip.communicator.impl.protocol.jabber.CallPeerMediaHandlerJabberImpl.close(CallPeerMediaHandlerJabberImpl.java:223) at net.java.sip.communicator.service.protocol.media.MediaAwareCallPeer.setState(MediaAwareCallPeer.java:1068) at net.java.sip.communicator.impl.protocol.jabber.CallPeerJabberImpl.setState(CallPeerJabberImpl.java:1495) at net.java.sip.communicator.service.protocol.AbstractCallPeer.setState(AbstractCallPeer.java:931) at net.java.sip.communicator.impl.protocol.jabber.CallPeerJabberImpl.processSessionTerminate(CallPeerJabberImpl.java:966) at net.java.sip.communicator.impl.protocol.jabber.OperationSetBasicTelephonyJabberImpl.processJingleIQ(OperationSetBasicTelephonyJabberImpl.java:1115) at net.java.sip.communicator.impl.protocol.jabber.OperationSetBasicTelephonyJabberImpl.access$100(OperationSetBasicTelephonyJabberImpl.java:53) at net.java.sip.communicator.impl.protocol.jabber.OperationSetBasicTelephonyJabberImpl$JingleIqSetRequestHandler.handleIQRequest(OperationSetBasicTelephonyJabberImpl.java:1010) at org.jivesoftware.smack.AbstractXMPPConnection$3.run(AbstractXMPPConnection.java:1153) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)
Expected Behavior
These sporadic but consistent failures are preventing transcription in Jigasi from working reliably.
Possible Solution
We are wondering whether these issues might be related to a misconfiguration with ice4j or perhaps a discrepancy with native library versions.
Steps to reproduce
We can reliably reproduce these issues by testing a number of conferences and triggering transcription via Dial.
Environment details
Thanks in advance for all your help and any feedback or suggestions you might have.
Just following up on this issue. One additional question that may be relevant: I noticed in the JVB docs that Jigasi doesn't support multiplexing multiple media streams on a single UDP port, due to the fact that it doesn't support channel-bundle and rtcp-mux. Is this limitation still the case, or has Jigasi since been upgraded to support these features?
I am wondering as perhaps it might explain some of these sporadic error messages we are seeing in the logs, such as occasional errors about a media format not being supported (when it should) or
javax.media.ClockStartedError: deallocate cannot be used on a started controller
Please let me know what you think!
Hi,
Dear Jitsi Team,
Do you plan to fix this issue concerning rtcp-mux as @pfisher mentioned in the comment above.
Thanks in advance,
Hi @pfisher @arts111188 @damencho - just a heads-up that I think this may be closely related to what I'm seeing in https://github.com/jitsi/jitsi-meet/issues/3738 ; in that case I'm using a chromium-webrtc based client to attempt to stream via jitsi-videobridge, but am seeing the same 'SCTP connection with ... not ready yet'
I do see that a connection is accepted by the videobridge:
/var/log/jitsi/jvb.log:JVB 2018-12-29 15:16:36.070 INFO: [235] org.jitsi.videobridge.SctpConnection.log() SCTP socket accepted for endpoint 8ec768f2
... but that connection doesn't become ready:
JVB 2018-12-29 15:16:36.097 WARNING: [234] org.jitsi.videobridge.EndpointMessageTransport.log() SCTP connection with Bunny not ready yet.
# repeated continuously, as per example in this issue
It looks like the section of code that's meant to bring the server socket into a ready state (at least for the version of jitsi-videobridge I'm running) is here:
https://github.com/jitsi/jitsi-videobridge/blob/4b3fd77cac7cc3d45b9bd8ce4217f531092bb5e7/src/main/java/org/jitsi/videobridge/SctpConnection.java#L747-L756
The question is why that isn't being reached, I suppose. Doing a bit more investigation currently.
@damencho Hi ,brother, I have faced the same errors in jigasi logs ,what can i do to fix it ?
###jigasi### 2019-04-26 02:36:29.963 INFO: [89] org.jitsi.jigasi.TranscriptionGatewaySession.log() Transcriber: Media Device Audio 2019-04-26 02:36:29.976 SEVERE: [1319] org.jitsi.impl.neomedia.transform.dtls.DtlsPacketTransformer.log() Failed to connect this DTLS client to a DTLS server! java.io.IOException: org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl is closed! at org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.assertNotClosed(DatagramTransportImpl.java:124) at org.jitsi.impl.neomedia.transform.dtls.DatagramTransportImpl.send(DatagramTransportImpl.java:477) at org.bouncycastle.crypto.tls.DTLSRecordLayer.sendRecord(Unknown Source) at org.bouncycastle.crypto.tls.DTLSRecordLayer.send(Unknown Source) at org.bouncycastle.crypto.tls.DTLSReliableHandshake$RecordLayerBuffer.sendToRecordLayer(Unknown Source) at org.bouncycastle.crypto.tls.DTLSReliableHandshake.writeHandshakeFragment(Unknown Source) at org.bouncycastle.crypto.tls.DTLSReliableHandshake.writeMessage(Unknown Source) at org.bouncycastle.crypto.tls.DTLSReliableHandshake.resendOutboundFlight(Unknown Source) at org.bouncycastle.crypto.tls.DTLSReliableHandshake.receiveMessage(Unknown Source) at org.bouncycastle.crypto.tls.DTLSReliableHandshake.receiveMessageBody(Unknown Source) at org.bouncycastle.crypto.tls.DTLSClientProtocol.clientHandshake(Unknown Source) at org.bouncycastle.crypto.tls.DTLSClientProtocol.connect(Unknown Source) at org.jitsi.impl.neomedia.transform.dtls.DtlsPacketTransformer.runInConnectThread(DtlsPacketTransformer.java:1017) at org.jitsi.impl.neomedia.transform.dtls.DtlsPacketTransformer.access$100(DtlsPacketTransformer.java:41) at org.jitsi.impl.neomedia.transform.dtls.DtlsPacketTransformer$2.run(DtlsPacketTransformer.java:1283) 2019-04-26 02:36:29.978 INFO: [89] org.jitsi.jigasi.JvbConference.callStateChanged().1130 callStateChanged
Which jigasi version are you using? The latest in unstable has even rtcp-mux.
Can you try 234, it had a small change in DtlsPacketTransformer? Do you repro on every run or this is occasionally?