BiglyBT icon indicating copy to clipboard operation
BiglyBT copied to clipboard

upnpmediaserver java.lang.NullPointerException crash at startup

Open bonze82 opened this issue 2 years ago • 6 comments

Randomly crashes at startup with this error: [22:28:26] [stderr] DEBUG::Tue Jul 05 22:28:26 CDT 2022::com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaRendererRemote::fillSinkProtocolList::115: [22:28:26] [stderr] java.lang.NullPointerException at com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaRendererRemote.fillSinkProtocolList(UPnPMediaRendererRemote.java:107)

I always loose all torrents when this crash occurs.

Java 11.0.15 (64 bit) Debian /usr/lib/jvm/java-11-openjdk-amd64

SWT v4942r22, gtk/3.24.24, zoom=100, dpi=96 Linux v5.10.0-15-amd64, amd64 (64 bit) B3.0.0.0/4 az3 debug.zip

bonze82 avatar Jul 06 '22 03:07 bonze82

No idea what's causing your crashes but that NullPointerException doesn't seem to be related :(

parg avatar Jul 06 '22 11:07 parg

So basicly I'm screwed, the only os upgrades I've received in the past month were kernel upgrades and I rolled them back. I think it is a plugin that is causing the crashes. I suspected the i2p plugin but removed and reinstalled bigly to purge that plugin and all but the ones that come preinstalled with bigly. Even removed openjdk restarted and allowed bigly to install what it wanted to install.

Btw this is a virtual box install debian host and vm.

bonze82 avatar Jul 06 '22 21:07 bonze82

Ok managed to get a repeat crash with steps to reproduce.

  1. add torrent(s) from nfs mounted share, old torrents from vuze.
  2. When prior torrent data is present in the completed folder and bigly goes to check the data it crashes after checking ~1.5gb.

It only generates this debug info once no matter how many times it crashes no crashes after the torrents are added will generate the debug info.

[2022-07-06 20:32] Log File Opened for BiglyBT 3.0.0.0 [20:32:42] [stderr] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder". [20:32:42] [stderr] SLF4J: Defaulting to no-operation (NOP) logger implementation [20:32:42] [stderr] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details. [20:32:42] DEBUG::Wed Jul 06 20:32:42 CDT 2022 com/sun/jna/Callback [20:32:44] [stderr] java.net.SocketException: Network is unreachable [20:32:44] [stderr] at java.base/sun.nio.ch.Net.connect0(Native Method) [20:32:44] [stderr] at java.base/sun.nio.ch.Net.connect(Net.java:483) [20:32:44] [stderr] at java.base/sun.nio.ch.DatagramChannelImpl.connect(DatagramChannelImpl.java:851) [20:32:44] [stderr] at lbms.plugins.mldht.kad.utils.AddressUtils.getDefaultRoute(AddressUtils.java:221) [20:32:44] [stderr] at lbms.plugins.mldht.kad.DHT.start(DHT.java:734) [20:32:44] [stderr] at lbms.plugins.mldht.azureus.MlDHTPlugin$9.runSupport(MlDHTPlugin.java:670) [20:32:44] [stderr] at com.biglybt.core.util.AsyncDispatcher$1.run(AsyncDispatcher.java:168) [20:32:44] [stderr] at com.biglybt.core.util.AEThread2$threadWrapper.run(AEThread2.java:317) [20:32:44] [stderr] DEBUG::Wed Jul 06 20:32:44 CDT 2022::com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaRendererRemote::fillSinkProtocolList::115: [20:32:44] [stderr] java.lang.NullPointerException at com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaRendererRemote.fillSinkProtocolList(UPnPMediaRendererRemote.java:107) at com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaRendererRemote.(UPnPMediaRendererRemote.java:81) at com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaServer$25.rootDeviceFound(UPnPMediaServer.java:2848) at com.biglybt.net.upnp.impl.UPnPImpl$1.runSupport(UPnPImpl.java:299) at com.biglybt.core.util.AERunnable.run(AERunnable.java:36) at com.biglybt.core.util.ThreadPool.runIt(ThreadPool.java:336) at com.biglybt.core.util.ThreadPool$threadPoolWorker.run(ThreadPool.java:742) at com.biglybt.core.util.AEThread2$threadWrapper.run(AEThread2.java:317) [20:32:44] [stderr] [20:32:44] [stderr] DEBUG::Wed Jul 06 20:32:44 CDT 2022::com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaRendererRemote::fillSinkProtocolList::115: [20:32:44] [stderr] java.lang.NullPointerException at com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaRendererRemote.fillSinkProtocolList(UPnPMediaRendererRemote.java:107) at com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaRendererRemote.(UPnPMediaRendererRemote.java:81) at com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaServer$25.rootDeviceFound(UPnPMediaServer.java:2848) at com.biglybt.net.upnp.impl.UPnPImpl$1.runSupport(UPnPImpl.java:299) at com.biglybt.core.util.AERunnable.run(AERunnable.java:36) at com.biglybt.core.util.ThreadPool.runIt(ThreadPool.java:336) at com.biglybt.core.util.ThreadPool$threadPoolWorker.run(ThreadPool.java:742) at com.biglybt.core.util.AEThread2$threadWrapper.run(AEThread2.java:317) [20:32:44] [stderr] [20:33:22] [stderr] DEBUG::Wed Jul 06 20:33:22 CDT 2022::com.vuze.plugins.azmsgsync.MsgSyncHandler::receiveMessages::4528: [20:33:22] [stderr] MsgSyncHandler::sync::5197, MsgSyncHandler::access$40::4959, MsgSyncHandler$11::run::5008, MsgSyncHandler$7::run::3190, AEThread2$threadWrapper::run::317 [20:33:22] [stderr] java.lang.ArrayIndexOutOfBoundsException: Index 6 out of bounds for length 6 [20:33:22] [stderr] at java.base/java.math.MutableBigInteger.primitiveLeftShift(MutableBigInteger.java:697) [20:33:22] [stderr] at java.base/java.math.MutableBigInteger.leftShift(MutableBigInteger.java:581) [20:33:22] [stderr] at java.base/java.math.MutableBigInteger.modInverse(MutableBigInteger.java:2232) [20:33:22] [stderr] at java.base/java.math.MutableBigInteger.mutableModInverse(MutableBigInteger.java:2072) [20:33:22] [stderr] at java.base/java.math.BigInteger.modInverse(BigInteger.java:3295) [20:33:22] [stderr] at org.gudy.bouncycastle.math.ec.ECFieldElement$Fp.divide(ECFieldElement.java:94) [20:33:22] [stderr] at org.gudy.bouncycastle.math.ec.ECPoint$Fp.twice(ECPoint.java:290) [20:33:22] [stderr] at org.gudy.bouncycastle.math.ec.FpNafMultiplier.multiply(FpNafMultiplier.java:27) [20:33:22] [stderr] at org.gudy.bouncycastle.math.ec.ECPoint.multiply(ECPoint.java:147) [20:33:22] [stderr] at org.gudy.bouncycastle.crypto.signers.ECDSASigner.verifySignature(ECDSASigner.java:141) [20:33:22] [stderr] at org.gudy.bouncycastle.jce.provider.JDKDSASigner.engineVerify(JDKDSASigner.java:187) [20:33:22] [stderr] at java.base/java.security.Signature.verify(Signature.java:790) [20:33:22] [stderr] at com.vuze.plugins.azmsgsync.MsgSyncHandler.receiveMessages(MsgSyncHandler.java:4468) [20:33:22] [stderr] at com.vuze.plugins.azmsgsync.MsgSyncHandler.sync(MsgSyncHandler.java:5197) [20:33:22] [stderr] at com.vuze.plugins.azmsgsync.MsgSyncHandler.access$40(MsgSyncHandler.java:4959) [20:33:22] [stderr] at com.vuze.plugins.azmsgsync.MsgSyncHandler$11.run(MsgSyncHandler.java:5008) [20:33:22] [stderr] at com.vuze.plugins.azmsgsync.MsgSyncHandler$7.run(MsgSyncHandler.java:3190) [20:33:22] [stderr] at com.biglybt.core.util.AEThread2$threadWrapper.run(AEThread2.java:317) [20:33:22] java.lang.ArrayIndexOutOfBoundsException: Index 6 out of bounds for length 6 at java.base/java.math.MutableBigInteger.primitiveLeftShift(MutableBigInteger.java:697) at java.base/java.math.MutableBigInteger.leftShift(MutableBigInteger.java:581) at java.base/java.math.MutableBigInteger.modInverse(MutableBigInteger.java:2232) at java.base/java.math.MutableBigInteger.mutableModInverse(MutableBigInteger.java:2072) at java.base/java.math.BigInteger.modInverse(BigInteger.java:3295) at org.gudy.bouncycastle.math.ec.ECFieldElement$Fp.divide(ECFieldElement.java:94) at org.gudy.bouncycastle.math.ec.ECPoint$Fp.twice(ECPoint.java:290) at org.gudy.bouncycastle.math.ec.FpNafMultiplier.multiply(FpNafMultiplier.java:27) at org.gudy.bouncycastle.math.ec.ECPoint.multiply(ECPoint.java:147) at org.gudy.bouncycastle.crypto.signers.ECDSASigner.verifySignature(ECDSASigner.java:141) at org.gudy.bouncycastle.jce.provider.JDKDSASigner.engineVerify(JDKDSASigner.java:187) at java.base/java.security.Signature.verify(Signature.java:790) at com.vuze.plugins.azmsgsync.MsgSyncHandler.receiveMessages(MsgSyncHandler.java:4468) at com.vuze.plugins.azmsgsync.MsgSyncHandler.sync(MsgSyncHandler.java:5197) at com.vuze.plugins.azmsgsync.MsgSyncHandler.access$40(MsgSyncHandler.java:4959) at com.vuze.plugins.azmsgsync.MsgSyncHandler$11.run(MsgSyncHandler.java:5008) at com.vuze.plugins.azmsgsync.MsgSyncHandler$7.run(MsgSyncHandler.java:3190) at com.biglybt.core.util.AEThread2$threadWrapper.run(AEThread2.java:317)

[20:33:45] [stderr] DEBUG::Wed Jul 06 20:33:45 CDT 2022::com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaRendererRemote::fillSinkProtocolList::115: [20:33:45] [stderr] com.biglybt.net.upnp.UPnPException: Download failed too recently, ignoring at com.biglybt.net.upnp.impl.UPnPImpl.downloadXMLSupport(UPnPImpl.java:640) at com.biglybt.net.upnp.impl.UPnPImpl.downloadXML(UPnPImpl.java:586) at com.biglybt.net.upnp.impl.services.UPnPServiceImpl.loadDescription(UPnPServiceImpl.java:318) at com.biglybt.net.upnp.impl.services.UPnPServiceImpl.getActions(UPnPServiceImpl.java:143) at com.biglybt.net.upnp.impl.services.UPnPServiceImpl.getAction(UPnPServiceImpl.java:160) at com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaRendererRemote.fillSinkProtocolList(UPnPMediaRendererRemote.java:98) at com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaRendererRemote.(UPnPMediaRendererRemote.java:81) at com.aelitis.azureus.plugins.upnpmediaserver.UPnPMediaServer$25.rootDeviceFound(UPnPMediaServer.java:2848) at com.biglybt.net.upnp.impl.UPnPImpl$1.runSupport(UPnPImpl.java:299) at com.biglybt.core.util.AERunnable.run(AERunnable.java:36) at com.biglybt.core.util.ThreadPool.runIt(ThreadPool.java:336) at com.biglybt.core.util.ThreadPool$threadPoolWorker.run(ThreadPool.java:742) at com.biglybt.core.util.AEThread2$threadWrapper.run(AEThread2.java:317) [20:33:45] [stderr]

bonze82 avatar Jul 07 '22 02:07 bonze82

Another collection of interesting stack traces :)

However, the actual crashes are detailed in the files names hs_err_pidnnnn.log files in your debug.zip. They show the JVM crashing in various randomish places.

MutableBigInteger does make a guest appearance in both but I've never seen either the exception or the crash location before.

I run various VMs in VirtualBox with a Windows host and haven't seen this kind of issue, so I'm a bit lost as to the cause.

parg avatar Jul 07 '22 07:07 parg

I think I figured out where the segfault is occurring and the steps to recreate:

J 3780 c2 sun.security.provider.SHA.implCompress0([BI)V [email protected] (506 bytes) @ 0x00007f7b9ce04418 [0x00007f7b9ce03bc0+0x0000000000000858]

  1. Add a torrent that was downloaded with another software +4gb seems to be the most problematic.
  2. Have Biglybt check the prior downloaded torrent and it crashes, always different places always the exact file in java base.

When the file completes the check, after dozens of crashes, it returns back to normal. Seems the number of files inside the torrent might also be a factor and there is also some corruption to the torrent data that has to be redownloaded which may be causing the crash as well, I had a array loose 20+k worth of data to bad sectors that went unnoticed.

bonze82 avatar Jul 12 '22 02:07 bonze82

hs_err_pid635915.log I can now consistently crash with regression both java 11 and 17 same file same location, logfile 635915. Once the file has been completely rechecked and verified it will crash with another error in logfile 1568941. hs_err_pid1568941.log

bonze82 avatar Jul 14 '22 18:07 bonze82