running into NPE in CallControl.handleIQ — is the Rayo/Dial ProviderManager not getting registered?
Open
pfisher
opened this issue 7 years ago
•
14 comments
I keep getting a NullPointerException in CallControl.handleIQ. I believe the root cause of the issue is in CallControlComponent.handleIQ, when the IQ instance is passed to IQUtils.convert(iq).
The converted IQ that gets returned from IQUtils.convert is null, and I'm guessing that's because the Rayo/Dial Provider isn't getting registered with the ProviderManager. It looks like that's supposed to happen in JigasiBundleActivator.serviceChanged. It does seem like serviceChanged is getting called, but it returns early from that method if the ServiceEvent isn't a ServiceEvent.REGISTERED event, so it never seems to make it down to the initialization code for the appropriate ProviderManagers:
MediaPresenceExtension.registerExtensions(providerManager);
// Register Rayo IQs
new RayoIqProvider().registerRayoIQs(providerManager);
Is there a reason that either the ServiceEvent.REGISTERED isn't getting triggered or handled by the JigasiBundleActivator? Or is there a different root cause for the Rayo/Dial ProviderManager to not get registered in Jigasi?
I'm running exactly what's currently on the master branch. I saw an issue posted here from back in January that mentioned the same exception. The solution seemed to involve using a custom branch that fixed some problems with the assembly step in Maven (and I guess the native lib). I'm running in Docker with Debian stretch (inside a mac). Could there be any issues related to that?
java.lang.NullPointerException
at org.jitsi.jigasi.xmpp.CallControl.handleIQ(CallControl.java:166)
at org.jitsi.jigasi.xmpp.CallControlComponent.handleIQ(CallControlComponent.java:320)
at org.jitsi.jigasi.xmpp.CallControlComponent.handleIQSetImpl(CallControlComponent.java:284)
at org.jitsi.xmpp.component.ComponentBase.handleIQSet(ComponentBase.java:360)
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:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
But the root issue (which is iq being null), seems to happen in IQUtils.convert due to not having a Dial/Rayo provider registered.
To run Jigasi, I'm using jigasi.sh via init.d/jigasi (from the repo). All the env variables seem to be correct and getting set correctly.
Now, I'm noticing a different set of exceptions related to a missing native library. Could one of the libraries not have been generated/compiled? It seems to reference a library called libXss.so, but I don't see that one. Currently, I have:
libhwaddressretriever.so
libunix-0.5.1.so
These are both in: /usr/share/jigasi/lib/native/linux-64/lib/
Is this the correct location, and are these the only needed native dependencies for Jigasi? Could running Docker on a mac be the root of the problem?
Here are the new exceptions I'm seeing:
2018-05-24 09:40:14.874 WARNING: [13] impl.sysactivity.SystemActivityNotifications.().130 Failed to initialize native counterpart
java.lang.UnsatisfiedLinkError: /tmp/jna--1160142225/jna9081024751854941499.tmp: libXss.so.1: cannot open shared object file: No such file or directory
at java.lang.ClassLoader$NativeLibrary.load(Native Method)
at java.lang.ClassLoader.loadLibrary0(ClassLoader.java:1941)
at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1824)
at java.lang.Runtime.load0(Runtime.java:809)
at java.lang.System.load(System.java:1086)
at org.jitsi.util.JNIUtils.loadLibrary(JNIUtils.java:96)
at org.jitsi.util.JNIUtils.loadLibrary(JNIUtils.java:32)
at net.java.sip.communicator.impl.sysactivity.SystemActivityNotifications.(SystemActivityNotifications.java:117)
at net.java.sip.communicator.impl.sysactivity.SystemActivityNotificationsServiceImpl.isSupported(SystemActivityNotificationsServiceImpl.java:606)
at net.java.sip.communicator.impl.sysactivity.SystemActivityNotificationsServiceImpl.start(SystemActivityNotificationsServiceImpl.java:143)
at net.java.sip.communicator.impl.sysactivity.SysActivityActivator.start(SysActivityActivator.java:70)
at org.jitsi.impl.osgi.framework.BundleImpl.start(BundleImpl.java:293)
at org.jitsi.impl.osgi.framework.launch.FrameworkImpl.startLevelChanged(FrameworkImpl.java:460)
at org.jitsi.impl.osgi.framework.startlevel.FrameworkStartLevelImpl$Command.run(FrameworkStartLevelImpl.java:126)
at org.jitsi.impl.osgi.framework.AsyncExecutor.runInThread(AsyncExecutor.java:111)
at org.jitsi.impl.osgi.framework.AsyncExecutor.access$000(AsyncExecutor.java:17)
at org.jitsi.impl.osgi.framework.AsyncExecutor$1.run(AsyncExecutor.java:220)
2018-05-24 09:40:14.907 SEVERE: [13] impl.sysactivity.SystemActivityNotificationsServiceImpl.getCurrentRunningManager().647 Error creating manager
java.lang.UnsatisfiedLinkError: no unix-java in java.library.path
at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1867)
at java.lang.Runtime.loadLibrary0(Runtime.java:870)
at java.lang.System.loadLibrary(System.java:1122)
at cx.ath.matthew.unix.UnixSocket.(UnixSocket.java:40)
at org.freedesktop.dbus.Transport.connect(Unknown Source)
at org.freedesktop.dbus.Transport.(Unknown Source)
at org.freedesktop.dbus.DBusConnection.(Unknown Source)
at org.freedesktop.dbus.DBusConnection.getConnection(Unknown Source)
at net.java.sip.communicator.impl.sysactivity.NetworkManagerListenerImpl.(NetworkManagerListenerImpl.java:56)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at java.lang.Class.newInstance(Class.java:442)
at net.java.sip.communicator.impl.sysactivity.SystemActivityNotificationsServiceImpl.getCurrentRunningManager(SystemActivityNotificationsServiceImpl.java:643)
at net.java.sip.communicator.impl.sysactivity.SystemActivityNotificationsServiceImpl.start(SystemActivityNotificationsServiceImpl.java:154)
at net.java.sip.communicator.impl.sysactivity.SysActivityActivator.start(SysActivityActivator.java:70)
at org.jitsi.impl.osgi.framework.BundleImpl.start(BundleImpl.java:293)
at org.jitsi.impl.osgi.framework.launch.FrameworkImpl.startLevelChanged(FrameworkImpl.java:460)
at org.jitsi.impl.osgi.framework.startlevel.FrameworkStartLevelImpl$Command.run(FrameworkStartLevelImpl.java:126)
at org.jitsi.impl.osgi.framework.AsyncExecutor.runInThread(AsyncExecutor.java:111)
at org.jitsi.impl.osgi.framework.AsyncExecutor.access$000(AsyncExecutor.java:17)
at org.jitsi.impl.osgi.framework.AsyncExecutor$1.run(AsyncExecutor.java:220)
2018-05-24 09:40:14.910 SEVERE: [14] impl.sysactivity.SystemActivityNotificationsServiceImpl.getCurrentRunningManager().647 Error creating manager
java.lang.NoClassDefFoundError: Could not initialize class cx.ath.matthew.unix.UnixSocket
at org.freedesktop.dbus.Transport.connect(Unknown Source)
at org.freedesktop.dbus.Transport.(Unknown Source)
at org.freedesktop.dbus.DBusConnection.(Unknown Source)
at org.freedesktop.dbus.DBusConnection.getConnection(Unknown Source)
at net.java.sip.communicator.impl.sysactivity.NetworkManagerListenerImpl.(NetworkManagerListenerImpl.java:56)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at java.lang.Class.newInstance(Class.java:442)
at net.java.sip.communicator.impl.sysactivity.SystemActivityNotificationsServiceImpl.getCurrentRunningManager(SystemActivityNotificationsServiceImpl.java:643)
at net.java.sip.communicator.impl.sysactivity.SystemActivityNotificationsServiceImpl.isSupported(SystemActivityNotificationsServiceImpl.java:597)
at net.java.sip.communicator.impl.netaddr.NetworkConfigurationWatcher.handleNewSystemActivityNotificationsService(NetworkConfigurationWatcher.java:187)
at net.java.sip.communicator.impl.netaddr.NetworkConfigurationWatcher.serviceChanged(NetworkConfigurationWatcher.java:243)
at org.jitsi.impl.osgi.framework.launch.EventDispatcher$Command.run(EventDispatcher.java:117)
at org.jitsi.impl.osgi.framework.AsyncExecutor.runInThread(AsyncExecutor.java:111)
at org.jitsi.impl.osgi.framework.AsyncExecutor.access$000(AsyncExecutor.java:17)
at org.jitsi.impl.osgi.framework.AsyncExecutor$1.run(AsyncExecutor.java:220)
2018-05-24 09:40:14.919 INFO: [13] impl.packetlogging.PacketLoggingActivator.start().100 Packet Logging Service ...[REGISTERED]
2018-05-24 09:40:14.922 INFO: [13] service.notification.NotificationServiceActivator.start().48 Notification Service...[ STARTED ]
2018-05-24 09:40:14.928 INFO: [13] service.notification.NotificationServiceActivator.start().55 Notification Service ...[REGISTERED]
2018-05-24 09:40:15.372 SEVERE: [13] org.jitsi.impl.neomedia.device.DeviceConfiguration.log() Failed to register custom Renderer org.jitsi.impl.neomedia.jmfext.media.renderer.audio.PulseAudioRenderer with JMF.
java.lang.IllegalStateException: audioSystem
at org.jitsi.impl.neomedia.jmfext.media.renderer.audio.PulseAudioRenderer.(PulseAudioRenderer.java:155)
at org.jitsi.impl.neomedia.jmfext.media.renderer.audio.PulseAudioRenderer.(PulseAudioRenderer.java:135)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at java.lang.Class.newInstance(Class.java:442)
at org.jitsi.impl.neomedia.device.DeviceConfiguration.registerCustomRenderers(DeviceConfiguration.java:1046)
at org.jitsi.impl.neomedia.device.DeviceConfiguration.(DeviceConfiguration.java:365)
at org.jitsi.impl.neomedia.MediaServiceImpl.(MediaServiceImpl.java:160)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at java.lang.Class.newInstance(Class.java:442)
at org.jitsi.impl.libjitsi.LibJitsiImpl$ServiceLock.initializeService(LibJitsiImpl.java:196)
at org.jitsi.impl.libjitsi.LibJitsiImpl$ServiceLock.getService(LibJitsiImpl.java:131)
at org.jitsi.impl.libjitsi.LibJitsiImpl.getService(LibJitsiImpl.java:91)
at org.jitsi.impl.libjitsi.LibJitsiOSGiImpl.getService(LibJitsiOSGiImpl.java:95)
at org.jitsi.service.libjitsi.LibJitsi.invokeGetServiceOnImpl(LibJitsi.java:172)
at org.jitsi.service.libjitsi.LibJitsi.getMediaService(LibJitsi.java:124)
at net.java.sip.communicator.impl.neomedia.NeomediaActivator.start(NeomediaActivator.java:391)
at org.jitsi.impl.osgi.framework.BundleImpl.start(BundleImpl.java:293)
at org.jitsi.impl.osgi.framework.launch.FrameworkImpl.startLevelChanged(FrameworkImpl.java:460)
at org.jitsi.impl.osgi.framework.startlevel.FrameworkStartLevelImpl$Command.run(FrameworkStartLevelImpl.java:126)
at org.jitsi.impl.osgi.framework.AsyncExecutor.runInThread(AsyncExecutor.java:111)
at org.jitsi.impl.osgi.framework.AsyncExecutor.access$000(AsyncExecutor.java:17)
at org.jitsi.impl.osgi.framework.AsyncExecutor$1.run(AsyncExecutor.java:220)
Thanks you so much for all your help. I've been pulling my hair out trying to figure this out!
@pfisher So you just did apt install jigasi and you are seeing this issues without any modifications?
Trying to understand your use case and how to test it. Cause you mentioned the master branch, so I was thinking that you are running it from source, but then you mention "/usr/share/jigasi" which is where the debian package files get installed.
Hi @damencho , I built Jigasi from source, but I followed the instructions for deploying it and have set it up to run on Docker. I also have Jitsi-Meet, Jicofo, and JVB all running in separate docker containers and they all work great. Getting Jigasi to run is our last step, but I've been stuck for a few days. I've been using the source so that I can debug and step through the code to see where things are breaking. It still seems that the root issue is that the Dial/Rayo providerManagers are not getting registered, which ends up causing the IQ to be converted to null in IQUtils.convert (since it can't find the necessary Dial provider).
I just tried apt-get install libxss1, and that seems to have cleared up the error related to that missing dependency. However, I'm still seeing the following exception:
java.lang.UnsatisfiedLinkError: no unix-java in java.library.path
Is it possible that this exception is somehow preventing some initialization step from running? In the JigasiBundleActivator (while stepping through the code in debug), I am seeing a ServiceEvent getting passed to the serviceChanged method of type ServiceEvent.REGISTERED. However, it aborts on line 138 after the service is looked up using osgiContext.getService(ref) (using the .getServiceReference method of the serviceEvent) — since the "looked-up" service isn't an instance of ProtocolProviderService. It seems to instead be an instance of ComponentMain, so it never gets down to the next few lines which attempt to register the RayoIqProvider. Maybe there's another serviceEvent that is supposed to get invoked on the JigasiBundleActivator but never makes it do to some unrelated exception (i.e. the no unix-java in library path)? Is there any reason it doesn't try to register the RayoIqProvider earlier (like, is it worth trying to move that registration to earlier in the serviceChanged method)?
Please let me know what you think. Thank you for all your help!
So JigasiBundleActivator.serviceChanged will receive a registered event for every service registered in osgi using the method bundleContext.registerService. Here are all the bundles that will be started: https://github.com/jitsi/jigasi/blob/b89dffe7628e6976d8776fdddbf32c9826627c96/src/main/java/org/jitsi/jigasi/osgi/JigasiBundleConfig.java#L73, most of the bundles register one or several services and event will be fired for everyone.
JigasiBundleActivator waits to see that there is a ProtocolProviderService registered and when that is available it will proceed with registering the RayoIqProvider. You cannot move it earlier cause you need ProtocolProviderService, if there is no such there is nothing to register.
Maybe something is missing when you are building the source ... or not all jars are available, in order to not be able to load unix-java ... just guessing.
So, I tried re-installing Jigasi and updating the configs, and that seems to have addressed the initial issue. I no longer get the NullPointerException in the CallControl.handleIq method!
It looks like the TranscriptionGateway is getting started now, but I'm still seeing two exceptions and I don't see any transcription events happening yet.
One exception relates to a DBusException. Is DBus used for interprocess communication with other Jitsi services? Currently, I am running Jigasi on its own Docker container so it's isolated from other services. Do I need to have Jigasi co-located with JVB or other Jitsi services?
I am also getting a failed to register custom Renderer exception related to PulseAudio. I saw other posts suggesting that this wasn't an important exception, but I wanted to make sure.
This is the stacktrace for the DBusException:
2018-05-25 09:05:45.966 INFO: [14] impl.netaddr.NetworkConfigurationWatcher.checkNetworkInterfaces().398 Currently Active eth0:[/172.18.0.6]
2018-05-25 09:05:45.969 INFO: [14] impl.dns.DnsUtilActivator.logDNSServers().293 Loading or Reloading resolver config, default DNS servers are: 127.0.0.11,
2018-05-25 09:05:46.031 SEVERE: [13] impl.sysactivity.NetworkManagerListenerImpl.().60 Cannot obtain dbus connection
org.freedesktop.dbus.exceptions.DBusException: Failed to connect to bus No such file or directory
at org.freedesktop.dbus.DBusConnection.(Unknown Source)
at org.freedesktop.dbus.DBusConnection.getConnection(Unknown Source)
at net.java.sip.communicator.impl.sysactivity.NetworkManagerListenerImpl.(NetworkManagerListenerImpl.java:56)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at java.lang.Class.newInstance(Class.java:442)
at net.java.sip.communicator.impl.sysactivity.SystemActivityNotificationsServiceImpl.getCurrentRunningManager(SystemActivityNotificationsServiceImpl.java:643)
at net.java.sip.communicator.impl.sysactivity.SystemActivityNotificationsServiceImpl.start(SystemActivityNotificationsServiceImpl.java:154)
at net.java.sip.communicator.impl.sysactivity.SysActivityActivator.start(SysActivityActivator.java:70)
at org.jitsi.impl.osgi.framework.BundleImpl.start(BundleImpl.java:293)
at org.jitsi.impl.osgi.framework.launch.FrameworkImpl.startLevelChanged(FrameworkImpl.java:460)
at org.jitsi.impl.osgi.framework.startlevel.FrameworkStartLevelImpl$Command.run(FrameworkStartLevelImpl.java:126)
at org.jitsi.impl.osgi.framework.AsyncExecutor.runInThread(AsyncExecutor.java:111)
at org.jitsi.impl.osgi.framework.AsyncExecutor.access$000(AsyncExecutor.java:17)
at org.jitsi.impl.osgi.framework.AsyncExecutor$1.run(AsyncExecutor.java:220)
Thanks again — I think we're getting really close to getting this working!
All these, I think, are harmless, does it work for you like this?
Jigasi re-uses a lot from the desktop client, the NetworkManagerListenerImpl is monitoring whether there is a change in the network while running (laptop disconnects from wifi and connects to wired) so it can reconnect the protocols, but this is not a case for a serverside component, so running without it will be no problem.
It's still not yet working. I think the root cause of the previous issue may have been a missing native dependency. Installing directly from apt-get seems to include the unix-java.so in the lib/native/linux-64 directory. That dependency was missing otherwise, when building from source/maven.
Any other ideas on how to test or debug? It does seem to be successfully connecting. I see connection messages in the prosody logs. However, I don't see any transcription events, and I'm not hitting any of my breakpoints (in transcription code) when remote debugging.
OK, thanks for the heads up! @nikvaessen do you have any suggestions on how to go about debugging transcription? It looks like the transcriptionGateway/session get started but I don't see any transcription or speech events (or any data in /var/lib/jigasi/transcripts)
jitsi
