Everything But Audio And Video Works

GaryL · May 14, 2020, 9:33pm

Hello,

I did a fresh install of Debian 10 (“Buster”) as a VMWare virtual machine, and then followed, in order and to the letter, the “Quick Install” instructions, stopping at, but not executing, “Advanced configuration”.

Every capability of Jitsi Meet seems to work, except that the participants cannot see video of each other and cannot hear each other.

I have done the installation twice, once without “Set up Fully Qualified Domain Name (FQDN)” and once with “Set up Fully Qualified Domain Name (FQDN)”, but to no avail. The FQDN is “meet.pmlib.org”, and the internal IP address of the server is 10.1.100.26.

The Firefox Web Developer Console lists the following two, seemingly relevant errors:

[modules/RTC/BridgeChannel.js] <_send>: Bridge Channel send: no opened channel.
[JitsiConference.js] <se.prototype._init/this.e2eping<>: Failed to send E2E ping request or response.

And what I believe to be the relevant portions of jvb.log are below. There were also numerous instances, which I removed, of “Address discovery through STUN failed”.

Based on this, does anyone have any thoughts? Thank you so much!

Not starting the Jetty service for org.jitsi.videobridge.rest.RESTBundleActivator(port=8080)

Not starting the Jetty service for org.jitsi.videobridge.websocket.WebSocketBundleActivator(port=-1)

Octo relay is disabled

[MucClient id=shard hostname=localhost] error connecting

The following addresses failed: ‘localhost:5222’ failed because: localhost/127.0.0.1 exception: java.net.ConnectException: Connection refused (Connection refused)

org.jivesoftware.smack.XMPPException$StreamErrorException: host-unknown

This server does not serve auth.meet.pmlib.org

org.jivesoftware.smack.AbstractXMPPConnection.callConnectionClosedOnErrorListener: Connection XMPPTCPConnection[not-authenticated] (0) closed with error

Failed to create SinglePortUdpHarvester for address 10.1.100.26:10000/udp: java.net.BindException: Address already in use (Bind failed)

damencho · May 14, 2020, 10:32pm

Something else is using port 10000. Maybe webmin? Try stopping it and restart jvb, does it work now?

GaryL · May 15, 2020, 6:05pm

Hello,

Thank you so much for writing back to me.

We have fixed a conflict on port 10000, but I still have no audio and video.

“lsof -i :10000” told me this:

miniserv. 2632 root 5u IPv4 19458 0t0 TCP localhost:webmin (LISTEN)
miniserv. 2632 root 6u IPv4 19459 0t0 UDP *:10000

“netstat -tunlp | grep :10000” told me this:

tcp 0 0 127.0.0.1:10000 0.0.0.0:* LISTEN 2632/perl
udp 0 0 0.0.0.0:10000 0.0.0.0:* 2632/perl

Then, I issued the command “sh webmin stop” while in /etc/init.d/, and issued the command “systemctl disable webmin.service”. On reboot, neither the previously mentioned lsof command nor the previously mentioned netstat command reported anything at all, meaning, I presume, that webmin was successfully stopped. Then, I established a meeting, named “double”, with two participants, but still no audio or video.

“lsof -i :10000” now tells me this:

java 547 jvb 140u IPv6 17715 0t0 UDP 10.1.100.26:10000

“netstat -tunlp | grep :10000” tells me this:

udp6 0 0 10.1.100.26:10000 :::* 547/java

and the jvb.log is attached, again with all instances of “Address discovery through STUN failed” removed.

Any other thoughts? Thank you so much!

OpenJDK 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release.
2020-05-15 17:26:58.970 INFO: [1] NewConfig$1.invoke#88: Loaded NewConfig with origin: merge of system properties,system properties,reference.conf @ jar:file:/usr/share/jitsi-videobridge/jitsi-videobridge.jar!/reference.conf: 1,reference.conf @ jar:file:/usr/share/jitsi-videobridge/lib/jitsi-media-transform-1.0-155-gb6af7e9.jar!/reference.conf: 1
2020-05-15 17:26:58.993 INFO: [1] LegacyConfigFileLoader$Companion.load#40: Attempting to load legacy config file at path /etc/jitsi, videobridge, sip-communicator.properties
2020-05-15 17:26:58.997 INFO: [1] LegacyConfigFileLoader$Companion.load#40: Attempting to load legacy config file at path /etc/jitsi, videobridge, sip-communicator.properties
2020-05-15 17:26:58.999 INFO: [1] JitsiConfig$Companion.reload#40: Reloading.
2020-05-15 17:26:59.016 INFO: [1] NewConfig$1.invoke#88: Loaded NewConfig with origin: merge of system properties,system properties,reference.conf @ jar:file:/usr/share/jitsi-videobridge/jitsi-videobridge.jar!/reference.conf: 1,reference.conf @ jar:file:/usr/share/jitsi-videobridge/lib/jitsi-media-transform-1.0-155-gb6af7e9.jar!/reference.conf: 1
2020-05-15 17:26:59.016 INFO: [1] LegacyConfigFileLoader$Companion.load#40: Attempting to load legacy config file at path /etc/jitsi, videobridge, sip-communicator.properties
2020-05-15 17:26:59.017 INFO: [1] LegacyConfigFileLoader$Companion.load#40: Attempting to load legacy config file at path /etc/jitsi, videobridge, sip-communicator.properties
2020-05-15 17:26:59.058 INFO: [13] ConfigurationActivator.start#45: Registered the LegacyConfigurationServiceShim in OSGi.
2020-05-15 17:26:59.068 INFO: [13] AbstractVersionActivator.start#91: VersionService registered: JVB 2.1.197-g38256192
2020-05-15 17:26:59.118 INFO: [13] AbstractJettyBundleActivator.start#613: Not starting the Jetty service for org.jitsi.videobridge.rest.RESTBundleActivator(port=8080)
2020-05-15 17:26:59.163 INFO: [13] AbstractJettyBundleActivator.start#613: Not starting the Jetty service for org.jitsi.videobridge.websocket.WebSocketBundleActivator(port=-1)
2020-05-15 17:26:59.218 INFO: [13] UlimitCheck.printUlimits#115: Running with open files limit 65000 (hard 65000), thread limit 65000 (hard 65000).
2020-05-15 17:26:59.221 INFO: [13] VideobridgeExpireThread.start#92: Starting with 60 second interval.
2020-05-15 17:26:59.234 WARNING: [13] Videobridge.start#906: No authorized source regexp configured. Will accept requests from any source.
2020-05-15 17:26:59.589 INFO: [13] JitsiConfig$Companion.reload#40: Reloading.
2020-05-15 17:26:59.620 INFO: [13] NewConfig$1.invoke#88: Loaded NewConfig with origin: merge of system properties,system properties,reference.conf @ jar:file:/usr/share/jitsi-videobridge/jitsi-videobridge.jar!/reference.conf: 1,reference.conf @ jar:file:/usr/share/jitsi-videobridge/lib/jitsi-media-transform-1.0-155-gb6af7e9.jar!/reference.conf: 1
2020-05-15 17:26:59.620 INFO: [13] LegacyConfigFileLoader$Companion.load#40: Attempting to load legacy config file at path /etc/jitsi, videobridge, sip-communicator.properties
2020-05-15 17:26:59.621 INFO: [13] LegacyConfigFileLoader$Companion.load#40: Attempting to load legacy config file at path /etc/jitsi, videobridge, sip-communicator.properties
2020-05-15 17:26:59.663 INFO: [13] AbstractHealthCheckService.start#96: Started with interval=10000, timeout=PT30S, maxDuration=PT3S, stickyFailures=false.
2020-05-15 17:26:59.731 INFO: [13] OctoRelayService.start#45: Octo relay is disabled
2020-05-15 17:27:00.504 INFO: [22] [hostname=localhost id=shard] MucClient$1.connected#266: Connected.
2020-05-15 17:27:00.504 INFO: [22] [hostname=localhost id=shard] MucClient.lambda$getConnectAndLoginCallable$7#648: Logging in.
2020-05-15 17:27:00.618 INFO: [22] [hostname=localhost id=shard] MucClient$MucWrapper.join#751: Joined MUC: jvbbrewery@internal.auth.meet.pmlib.org
2020-05-15 17:27:06.241 INFO: [19] org.ice4j.ice.harvest.MappingCandidateHarvesters.initialize: Initialized mapping harvesters (delay=6565ms). stunDiscoveryFailed=true
2020-05-15 17:27:40.184 INFO: [32] Videobridge.createConference#320: create_conf, id=ad47c02205279f59 gid=ff6579 logging=true
2020-05-15 17:27:40.227 INFO: [32] TaskPools.#81: TaskPools detected 4 processors, creating the CPU pool with that many threads
2020-05-15 17:27:40.383 INFO: [32] org.ice4j.ice.harvest.AbstractUdpListener.: Initialized AbstractUdpListener with address 10.1.100.26:10000/udp. Receive buffer size 10485760 (asked for 10485760)
2020-05-15 17:27:40.384 INFO: [32] org.ice4j.ice.harvest.SinglePortUdpHarvester.: Initialized SinglePortUdpHarvester with address 10.1.100.26:10000/udp
2020-05-15 17:27:40.393 INFO: [32] [confId=ad47c02205279f59 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o gid=ff6579 conf_name=double ufrag=3e1k01e8cm162o] Agent.gatherCandidates#662: Gathering candidates for component stream-6ca05bd6.RTP.
2020-05-15 17:27:41.633 INFO: [36] [confId=ad47c02205279f59 gid=ff6579 conf_name=double] Conference.dominantSpeakerChanged#446: ds_change ds_id=6ca05bd6
SCTP JNI load: Linux OS detected
SCTP lib loaded
=====>: org_jitsi_modified_sctp4j_SctpJni.c calling init
=====>: org_jitsi_modified_sctp4j_SctpJni.c about to set SCTP_DEBUG_ALL
2020-05-15 17:27:41.685 INFO: [32] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 conf_name=double] Endpoint.lambda$setTransportInfo$8#1112: Ignoring empty DtlsFingerprint extension:
2020-05-15 17:27:41.687 INFO: [32] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 conf_name=double] Endpoint.describe#1295: Transport description:
01:62:C6:57:96:23:E8:1D:2E:C7:8D:FA:33:85:03:B8:F1:02:D3:AA:16:49:CC:FF:DD:96:40:3B:C5:1D:A9:EB
2020-05-15 17:27:41.690 WARNING: [32] XmppCommon.handleIQRequest#264: Took 1526 ms to handle IQ:
2020-05-15 17:27:42.127 INFO: [32] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] DtlsTransport.setSetupAttribute#116: The remote side is acting as DTLS client, we’ll act as server
2020-05-15 17:27:42.139 INFO: [32] [confId=ad47c02205279f59 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o gid=ff6579 stats_id=Gavin-H7L conf_name=double] IceTransport.startConnectivityEstablishment#182: Starting the Agent without remote candidates.
2020-05-15 17:27:42.139 INFO: [32] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-05-15 17:27:42.140 INFO: [32] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] Agent.initCheckLists#996: Init checklist for stream stream-6ca05bd6
2020-05-15 17:27:42.141 INFO: [32] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] Agent.setState#963: ICE state changed from Waiting to Running.
2020-05-15 17:27:42.141 INFO: [32] [confId=ad47c02205279f59 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o gid=ff6579 stats_id=Gavin-H7L conf_name=double] IceTransport.iceStateChanged#321: ICE state changed old=Waiting new=Running
2020-05-15 17:27:42.142 INFO: [32] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] Agent.startConnectivityEstablishment#775: Trigger checks for pairs that were received before running state
2020-05-15 17:27:42.142 INFO: [32] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] Agent.triggerCheck#1773: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962083765692399615):
LocalCandidate=candidate:1 1 udp 2130706431 10.1.100.26 10000 typ host
RemoteCandidate=candidate:10000 1 udp 1853817087 10.1.3.70 60311 typ prflx
2020-05-15 17:27:42.144 INFO: [32] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-05-15 17:27:42.145 INFO: [32] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] Endpoint.describe#1295: Transport description:
01:62:C6:57:96:23:E8:1D:2E:C7:8D:FA:33:85:03:B8:F1:02:D3:AA:16:49:CC:FF:DD:96:40:3B:C5:1D:A9:EB
2020-05-15 17:27:42.158 INFO: [31] [confId=ad47c02205279f59 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o gid=ff6579 stats_id=Gavin-H7L conf_name=double] IceTransport.startConnectivityEstablishment#182: Starting the Agent without remote candidates.
2020-05-15 17:27:42.158 INFO: [31] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-05-15 17:27:42.159 INFO: [31] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] Agent.initCheckLists#996: Init checklist for stream stream-6ca05bd6
2020-05-15 17:27:42.160 INFO: [31] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-05-15 17:27:42.160 INFO: [31] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] Endpoint.describe#1295: Transport description:
01:62:C6:57:96:23:E8:1D:2E:C7:8D:FA:33:85:03:B8:F1:02:D3:AA:16:49:CC:FF:DD:96:40:3B:C5:1D:A9:EB
2020-05-15 17:27:42.178 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] ConnectivityCheckClient.processSuccessResponse#627: Pair succeeded: 10.1.100.26:10000/udp/host -> 10.1.3.70:60311/udp/prflx (stream-6ca05bd6.RTP).
2020-05-15 17:27:42.179 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L componentId=1 conf_name=double ufrag=3e1k01e8cm162o name=stream-6ca05bd6 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 10.1.3.70:60311/udp
2020-05-15 17:27:42.179 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] ConnectivityCheckClient.processSuccessResponse#636: Pair validated: 10.1.100.26:10000/udp/host -> 10.1.3.70:60311/udp/prflx (stream-6ca05bd6.RTP).
2020-05-15 17:27:42.179 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 10.1.100.26:10000/udp/host -> 10.1.3.70:60311/udp/prflx (stream-6ca05bd6.RTP).
2020-05-15 17:27:42.180 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] Agent.nominate#1846: verify if nominated pair answer again
2020-05-15 17:27:42.181 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] ConnectivityCheckClient.processSuccessResponse#705: IsControlling: true USE-CANDIDATE:false.
2020-05-15 17:27:42.203 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] ConnectivityCheckClient.processSuccessResponse#627: Pair succeeded: 10.1.100.26:10000/udp/host -> 10.1.3.70:60311/udp/prflx (stream-6ca05bd6.RTP).
2020-05-15 17:27:42.203 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] ConnectivityCheckClient.processSuccessResponse#636: Pair validated: 10.1.100.26:10000/udp/host -> 10.1.3.70:60311/udp/prflx (stream-6ca05bd6.RTP).
2020-05-15 17:27:42.203 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] ConnectivityCheckClient.processSuccessResponse#705: IsControlling: true USE-CANDIDATE:true.
2020-05-15 17:27:42.204 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] ConnectivityCheckClient.processSuccessResponse#720: Nomination confirmed for pair: 10.1.100.26:10000/udp/host -> 10.1.3.70:60311/udp/prflx (stream-6ca05bd6.RTP).
2020-05-15 17:27:42.204 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o name=stream-6ca05bd6 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] CheckList.handleNominationConfirmed#406: Selected pair for stream stream-6ca05bd6.RTP: 10.1.100.26:10000/udp/host -> 10.1.3.70:60311/udp/prflx (stream-6ca05bd6.RTP)
2020-05-15 17:27:42.207 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] Agent.checkListStatesUpdated#1937: CheckList of stream stream-6ca05bd6 is COMPLETED
2020-05-15 17:27:42.207 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] Agent.setState#963: ICE state changed from Running to Completed.
2020-05-15 17:27:42.208 INFO: [39] [confId=ad47c02205279f59 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o gid=ff6579 stats_id=Gavin-H7L conf_name=double] IceTransport.iceStateChanged#321: ICE state changed old=Running new=Completed
2020-05-15 17:27:42.208 INFO: [39] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] Endpoint$3.connected#401: ICE connected
2020-05-15 17:27:42.213 INFO: [36] PartitionedByteBufferPool.#88: Initialized a new PartitionedByteBufferPool with 8 partitions.
2020-05-15 17:27:42.213 INFO: [36] PartitionedByteBufferPool.#88: Initialized a new PartitionedByteBufferPool with 8 partitions.
2020-05-15 17:27:42.214 INFO: [36] PartitionedByteBufferPool.#88: Initialized a new PartitionedByteBufferPool with 8 partitions.
2020-05-15 17:27:42.218 INFO: [39] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] Agent.logCandTypes#2045: Harvester used for selected pair for stream-6ca05bd6.RTP: host
2020-05-15 17:27:42.219 INFO: [44] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] DtlsTransport.startDtlsHandshake#98: Starting DTLS handshake
2020-05-15 17:27:42.259 INFO: [44] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] TlsServerImpl.notifyClientVersion#193: Negotiated DTLS version DTLS 1.2
2020-05-15 17:27:42.388 INFO: [44] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] Endpoint$6.handshakeComplete#445: DTLS handshake complete
2020-05-15 17:27:42.399 INFO: [46] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] Endpoint.lambda$acceptSctpConnection$6#944: Attempting to establish SCTP socket connection
2020-05-15 17:27:42.458 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e local_ufrag=8i5851e8cm183n gid=ff6579 conf_name=double ufrag=8i5851e8cm183n] Agent.gatherCandidates#662: Gathering candidates for component stream-afb6d00e.RTP.
2020-05-15 17:27:42.473 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e gid=ff6579 conf_name=double] Endpoint.lambda$setTransportInfo$8#1112: Ignoring empty DtlsFingerprint extension:
2020-05-15 17:27:42.474 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e gid=ff6579 conf_name=double] Endpoint.describe#1295: Transport description:
01:62:C6:57:96:23:E8:1D:2E:C7:8D:FA:33:85:03:B8:F1:02:D3:AA:16:49:CC:FF:DD:96:40:3B:C5:1D:A9:EB
2020-05-15 17:27:43.431 INFO: [47] OpenSslWrapperLoader.#46: jitsisrtp successfully loaded
2020-05-15 17:27:44.035 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e gid=ff6579 stats_id=Wanda-1v0 conf_name=double] DtlsTransport.setSetupAttribute#116: The remote side is acting as DTLS client, we’ll act as server
2020-05-15 17:27:44.036 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e local_ufrag=8i5851e8cm183n gid=ff6579 stats_id=Wanda-1v0 conf_name=double] IceTransport.startConnectivityEstablishment#182: Starting the Agent without remote candidates.
2020-05-15 17:27:44.036 INFO: [31] [confId=ad47c02205279f59 gid=ff6579 stats_id=Wanda-1v0 conf_name=double ufrag=8i5851e8cm183n epId=afb6d00e local_ufrag=8i5851e8cm183n] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-05-15 17:27:44.036 INFO: [31] [confId=ad47c02205279f59 gid=ff6579 stats_id=Wanda-1v0 conf_name=double ufrag=8i5851e8cm183n epId=afb6d00e local_ufrag=8i5851e8cm183n] Agent.initCheckLists#996: Init checklist for stream stream-afb6d00e
2020-05-15 17:27:44.036 INFO: [31] [confId=ad47c02205279f59 gid=ff6579 stats_id=Wanda-1v0 conf_name=double ufrag=8i5851e8cm183n epId=afb6d00e local_ufrag=8i5851e8cm183n] Agent.setState#963: ICE state changed from Waiting to Running.
2020-05-15 17:27:44.037 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e local_ufrag=8i5851e8cm183n gid=ff6579 stats_id=Wanda-1v0 conf_name=double] IceTransport.iceStateChanged#321: ICE state changed old=Waiting new=Running
2020-05-15 17:27:44.037 INFO: [31] [confId=ad47c02205279f59 gid=ff6579 stats_id=Wanda-1v0 conf_name=double ufrag=8i5851e8cm183n epId=afb6d00e local_ufrag=8i5851e8cm183n] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-05-15 17:27:44.038 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e gid=ff6579 stats_id=Wanda-1v0 conf_name=double] Endpoint.describe#1295: Transport description:
01:62:C6:57:96:23:E8:1D:2E:C7:8D:FA:33:85:03:B8:F1:02:D3:AA:16:49:CC:FF:DD:96:40:3B:C5:1D:A9:EB
2020-05-15 17:27:44.367 INFO: [31] [confId=ad47c02205279f59 gid=ff6579 stats_id=Wanda-1v0 componentId=1 conf_name=double ufrag=8i5851e8cm183n name=stream-afb6d00e epId=afb6d00e local_ufrag=8i5851e8cm183n] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-afb6d00e.RTP: 192.168.1.101:50897/udp
2020-05-15 17:27:44.368 INFO: [31] [confId=ad47c02205279f59 gid=ff6579 stats_id=Wanda-1v0 componentId=1 conf_name=double ufrag=8i5851e8cm183n name=stream-afb6d00e epId=afb6d00e local_ufrag=8i5851e8cm183n] Component.updateRemoteCandidates#481: new Pair added: 10.1.100.26:10000/udp/host -> 192.168.1.101:50897/udp/host (stream-afb6d00e.RTP).
2020-05-15 17:27:44.369 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e gid=ff6579 stats_id=Wanda-1v0 conf_name=double] Endpoint.describe#1295: Transport description:
01:62:C6:57:96:23:E8:1D:2E:C7:8D:FA:33:85:03:B8:F1:02:D3:AA:16:49:CC:FF:DD:96:40:3B:C5:1D:A9:EB
2020-05-15 17:27:44.387 INFO: [43] [confId=ad47c02205279f59 gid=ff6579 stats_id=Wanda-1v0 conf_name=double ufrag=8i5851e8cm183n epId=afb6d00e local_ufrag=8i5851e8cm183n] ConnectivityCheckClient$PaceMaker.run#919: Pair failed: 10.1.100.26:10000/udp/host -> 192.168.1.101:50897/udp/host (stream-afb6d00e.RTP)
2020-05-15 17:27:45.219 INFO: [41] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L conf_name=double ufrag=3e1k01e8cm162o epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] Agent.setState#963: ICE state changed from Completed to Terminated.
2020-05-15 17:27:45.219 INFO: [41] [confId=ad47c02205279f59 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o gid=ff6579 stats_id=Gavin-H7L conf_name=double] IceTransport.iceStateChanged#321: ICE state changed old=Completed new=Terminated
Got sctp association state update: 1
sctp is now up. was ready? false
2020-05-15 17:27:47.607 INFO: [46] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] Endpoint$7.onReady#884: SCTP connection is ready, creating the Data channel stack
2020-05-15 17:27:47.613 INFO: [46] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] Endpoint$7.onReady#911: Will wait for the remote side to open the data channel.
2020-05-15 17:27:47.616 INFO: [44] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
2020-05-15 17:27:47.617 INFO: [44] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] Endpoint$7.lambda$onReady$1#892: Remote side opened a data channel.
2020-05-15 17:28:40.492 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e gid=ff6579 stats_id=Wanda-1v0 conf_name=double] AbstractEndpoint.expire#303: Expiring.
2020-05-15 17:28:40.495 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e gid=ff6579 stats_id=Wanda-1v0 conf_name=double] Transceiver.teardown#315: Tearing down
2020-05-15 17:28:40.495 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e gid=ff6579 stats_id=Wanda-1v0 conf_name=double] RtpReceiverImpl.tearDown#287: Tearing down
2020-05-15 17:28:40.496 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e gid=ff6579 stats_id=Wanda-1v0 conf_name=double] RtpSenderImpl.tearDown#263: Tearing down
2020-05-15 17:28:40.498 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e gid=ff6579 stats_id=Wanda-1v0 conf_name=double] DtlsTransport.stop#180: Stopping
2020-05-15 17:28:40.498 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e local_ufrag=8i5851e8cm183n gid=ff6579 stats_id=Wanda-1v0 conf_name=double] IceTransport.stop#235: Stopping
2020-05-15 17:28:40.500 INFO: [31] [confId=ad47c02205279f59 gid=ff6579 stats_id=Wanda-1v0 conf_name=double ufrag=8i5851e8cm183n epId=afb6d00e local_ufrag=8i5851e8cm183n] Agent.setState#963: ICE state changed from Running to Terminated.
2020-05-15 17:28:40.501 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e local_ufrag=8i5851e8cm183n gid=ff6579 stats_id=Wanda-1v0 conf_name=double] IceTransport.iceStateChanged#321: ICE state changed old=Running new=Terminated
2020-05-15 17:28:40.502 INFO: [31] [confId=ad47c02205279f59 gid=ff6579 stats_id=Wanda-1v0 componentId=1 conf_name=double ufrag=8i5851e8cm183n name=stream-afb6d00e epId=afb6d00e local_ufrag=8i5851e8cm183n] MergingDatagramSocket.close#142: Closing.
2020-05-15 17:28:40.503 INFO: [31] [confId=ad47c02205279f59 epId=afb6d00e gid=ff6579 stats_id=Wanda-1v0 conf_name=double] Endpoint.expire#811: Expired.
2020-05-15 17:28:45.200 INFO: [31] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] AbstractEndpoint.expire#303: Expiring.
2020-05-15 17:28:45.201 INFO: [46] [confId=ad47c02205279f59 gid=ff6579 conf_name=double] Conference.dominantSpeakerChanged#446: ds_change ds_id=null
2020-05-15 17:28:45.202 INFO: [31] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] Transceiver.teardown#315: Tearing down
2020-05-15 17:28:45.202 INFO: [31] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] RtpReceiverImpl.tearDown#287: Tearing down
2020-05-15 17:28:45.208 INFO: [31] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] RtpSenderImpl.tearDown#263: Tearing down
2020-05-15 17:28:45.208 INFO: [31] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] DtlsTransport.stop#180: Stopping
2020-05-15 17:28:45.209 INFO: [31] [confId=ad47c02205279f59 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o gid=ff6579 stats_id=Gavin-H7L conf_name=double] IceTransport.stop#235: Stopping
2020-05-15 17:28:45.218 INFO: [31] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L componentId=1 conf_name=double ufrag=3e1k01e8cm162o name=stream-6ca05bd6 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] MergingDatagramSocket.close#142: Closing.
2020-05-15 17:28:45.218 INFO: [38] [confId=ad47c02205279f59 gid=ff6579 stats_id=Gavin-H7L componentId=1 conf_name=double ufrag=3e1k01e8cm162o name=stream-6ca05bd6 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o] MergingDatagramSocket$SocketContainer.runInReaderThread#770: Failed to receive: java.net.SocketException: Socket closed
2020-05-15 17:28:45.219 INFO: [36] [confId=ad47c02205279f59 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o gid=ff6579 stats_id=Gavin-H7L conf_name=double] IceTransport.startReadingData#201: Socket closed, stopping reader
2020-05-15 17:28:45.220 INFO: [31] [confId=ad47c02205279f59 epId=6ca05bd6 gid=ff6579 stats_id=Gavin-H7L conf_name=double] Endpoint.expire#811: Expired.
2020-05-15 17:28:45.220 INFO: [36] [confId=ad47c02205279f59 epId=6ca05bd6 local_ufrag=3e1k01e8cm162o gid=ff6579 stats_id=Gavin-H7L conf_name=double] IceTransport.startReadingData#213: No longer running, stopped reading packets
2020-05-15 17:28:59.222 INFO: [18] VideobridgeExpireThread.expire#144: Running expire()
2020-05-15 17:28:59.222 INFO: [18] VideobridgeExpireThread.expire#150: Conference ad47c02205279f59 should expire, expiring it
2020-05-15 17:28:59.224 INFO: [55] [confId=ad47c02205279f59 gid=ff6579 conf_name=double] Conference.expire#527: Expiring.
2020-05-15 17:28:59.227 INFO: [55] [confId=ad47c02205279f59 gid=ff6579 conf_name=double] Conference.updateStatisticsOnExpire#610: expire_conf,duration=79,has_failed=false,has_partially_failed=true

GaryL · May 15, 2020, 9:14pm

Hello,

One additional thing, which I did just now:

Using nano, I changed our /etc/hostname file, which is one line, to read “meet.pmlib.org” instead of “core”, and I changed our /etc/hosts file from this:

127.0.0.1 localhost
127.0.1.1 core

#Required for IPv6 capable hosts
::1 ip6-localhost ip6-loopback
fe00::0 ip6-localnet
ff00::0 ip6-mcastprefix
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters
ff02::3 ip6-allhosts

to this:

127.0.0.1 localhost meet.pmlib.org
127.0.1.1 core

#Required for IPv6 capable hosts
::1 ip6-localhost ip6-loopback
fe00::0 ip6-localnet
ff00::0 ip6-mcastprefix
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters
ff02::3 ip6-allhosts

and then rebooted.

Still no audio and video.

gpatel-fr · May 15, 2020, 9:32pm

err, why ? are you not behind a NAT ?

GaryL · May 15, 2020, 11:29pm

I restored /etc/hostname and /etc/hosts back to their original versions, rebooted, and then executed the “Advanced Configuration” instructions, namely adding the following two lines to /etc/jitsi/videobridge/sip-communicator.properties:

org.ice4j.ice.harvest.NAT_HARVESTER_LOCAL_ADDRESS=10.1.100.26
org.ice4j.ice.harvest.NAT_HARVESTER_PUBLIC_ADDRESS=65.254.29.187

and commenting out, with a “#” sign, this line:

org.ice4j.ice.harvest.STUN_MAPPING_HARVESTER_ADDRESSES=meet-jit-si-turnrelay.jitsi.net:443

…and, lo and behold, after a reboot, we now have sound and video!

Thanks everyone!

I recall executing the “Advanced Configuration” instructions once before, however, and it did not solve the problem, at that time. But it appears that what solved the problem was the combination of these two things:

a. Shutting down webmin (i.e. stopping webmin from using UDP port 10000)

AND

b. Altering /etc/jitsi/videobridge/sip.communicator.properties

The only other change I made was installing the Debian package “lsof”, but am I correct that that would have absolutely no effect?

Thanks again, everyone!