search

heronarts / LX

Core library for 3D LED lighting engines
https://chromatik.co/
Other
41 stars 25 forks source link

Intermittent LXAudioInput bug: 'Cannot enter synchronized block because "this.inputThread" is null' #93

Closed andrewlook closed 1 year ago

andrewlook commented 1 year ago

Hi @mcslee, first of all thanks for all the awesome work you're doing with LX/Chromatik.

I'm working on some audio patterns for Titanic's End, I believe you're familiar with some of the folks involved.

When I’m piping stereo input into LX (using Soundflower or Loopback), particularly if I'm switching between audio input sources in the LX UI, I’ve had a couple of intermittent issues where my sound suddenly stops and I get an error popup saying: Cannot enter synchronized block because "this.inputThread" is null

It seems to go away when I restart LX, but it’s happened a couple times now. The stack trace is coming from LX code, so I figured it was worth mentioning here in case you or other LX users have run into anything similar.

Here's the full stack trace:

java.lang.NullPointerException: Cannot enter synchronized block because "this.inputThread" is null
    at heronarts.lx.audio.LXAudioInput.start(LXAudioInput.java:212)
    at heronarts.lx.audio.LXAudioEngine.onParameterChanged(LXAudioEngine.java:91)
    at heronarts.lx.parameter.LXListenableParameter.setValue(LXListenableParameter.java:222)
    at heronarts.lx.parameter.LXListenableParameter.setValue(LXListenableParameter.java:205)
    at heronarts.lx.parameter.BooleanParameter.setValue(BooleanParameter.java:70)
    at heronarts.lx.parameter.BooleanParameter.setNormalized(BooleanParameter.java:93)
    at heronarts.lx.parameter.BooleanParameter.setNormalized(BooleanParameter.java:24)
    at heronarts.lx.command.LXCommand$Parameter$SetNormalized.perform(LXCommand.java:588)
    at heronarts.lx.command.LXCommandEngine.perform(LXCommandEngine.java:60)
    at heronarts.glx.ui.component.UIButton.setActive(UIButton.java:498)
    at heronarts.glx.ui.component.UIButton.setActive(UIButton.java:477)
    at heronarts.glx.ui.component.UIButton.onMousePressed(UIButton.java:424)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:624)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UI2dScrollContainer.mousePressed(UI2dScrollContainer.java:241)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UI$UIRoot.mousePressed(UI.java:153)
    at heronarts.glx.ui.UI.mouseEvent(UI.java:1007)
    at heronarts.glx.InputDispatch.dispatch(InputDispatch.java:230)
    at heronarts.lx.LXEngine._processInputEvents(LXEngine.java:982)
    at heronarts.lx.LXEngine.processInputEvents(LXEngine.java:958)
    at heronarts.lx.LXEngine.access$1600(LXEngine.java:63)
    at heronarts.lx.LXEngine$ExecutorService.lambda$start$1(LXEngine.java:652)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
    at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)
mcslee commented 1 year ago

Thanks for catching this. I think I can see how to fix, though not 100% sure why it'd get into the state where this can happen. Is there any other log output when this happens?

Particularly, did you see any error like any of these?

LX.error("LXAudioInput device is not available, audio input will not work: " + device); LX.error("Audio device does not support mono/stereo 16-bit input: " + device); LX.error(x, "Exception opening audio input line and starting audio input thread");

andrewlook commented 1 year ago

Thanks for the quick response here - One thing I can say for sure is that the issue came up when I was calling eq.getAveragef().

I haven't been able to reliably reproduce it, but I think I saw a stack trace once above the one I shared. It might have been this one: "Audio device does not support mono/stereo 16-bit input: "

If I'm able to reproduce again I'll keep an eye out for it and share here.

andrewlook commented 1 year ago

@mcslee I got a better stack trace this time - I was switching between audio inputs (from my MacBook microphone to a virtual audio device powered by Loopback so I could pipe Spotify straight into LX) and I got the error popups.

Here's the stack traces (I think the first line is unrelated, I tend to see that when I'm running LX locally and it's probably sending packets out looking for midi/artnet devices that aren't there).

[LX 2023/08/07 17:20:34] Calls to DatagramSocket.send() appear to be unexpectedly blocking, you may be sending to an unresolvable address or network queues may be saturated. If you are on Linux/Raspberry-Pi, consult the following URL for guidance on relevant kernel parameters: https://github.com/heronarts/LXStudio/wiki/Raspberry-Pi

[LX 2023/08/07 17:38:10] Exception opening audio input line and starting audio input thread
javax.sound.sampled.LineUnavailableException: line with format PCM_SIGNED 44100.0 Hz, 16 bit, mono, 2 bytes/frame, little-endian not supported.
    at java.desktop/com.sun.media.sound.DirectAudioDevice$DirectDL.implOpen(DirectAudioDevice.java:484)
    at java.desktop/com.sun.media.sound.AbstractDataLine.open(AbstractDataLine.java:115)
    at heronarts.lx.audio.LXAudioInput.open(LXAudioInput.java:193)
    at heronarts.lx.audio.LXAudioInput.onParameterChanged(LXAudioInput.java:161)
    at heronarts.lx.parameter.LXListenableParameter.setValue(LXListenableParameter.java:222)
    at heronarts.lx.parameter.LXListenableParameter.setValue(LXListenableParameter.java:205)
    at heronarts.lx.command.LXCommand$Parameter$SetValue.perform(LXCommand.java:386)
    at heronarts.lx.command.LXCommandEngine.perform(LXCommandEngine.java:60)
    at heronarts.glx.ui.component.UIDropMenu$1.onContextAction(UIDropMenu.java:119)
    at heronarts.glx.ui.component.UIContextMenu.onMousePressed(UIContextMenu.java:195)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:624)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UI2dScrollContext.mousePressed(UI2dScrollContext.java:235)
    at heronarts.glx.ui.UI$UIContextOverlay.mousePressed(UI.java:498)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UI$UIRoot.mousePressed(UI.java:153)
    at heronarts.glx.ui.UI.mouseEvent(UI.java:1007)
    at heronarts.glx.InputDispatch.dispatch(InputDispatch.java:230)
    at heronarts.lx.LXEngine._processInputEvents(LXEngine.java:982)
    at heronarts.lx.LXEngine.processInputEvents(LXEngine.java:958)
    at heronarts.lx.LXEngine.access$1600(LXEngine.java:63)
    at heronarts.lx.LXEngine$ExecutorService.lambda$start$1(LXEngine.java:652)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
    at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)

[LX 2023/08/07 17:38:29] Unexpected error performing action heronarts.lx.command.LXCommand$Parameter$SetValue@6ee761e5 - bad internal state?
java.lang.NullPointerException: Cannot enter synchronized block because "this.inputThread" is null
    at heronarts.lx.audio.LXAudioInput.close(LXAudioInput.java:232)
    at heronarts.lx.audio.LXAudioInput.onParameterChanged(LXAudioInput.java:159)
    at heronarts.lx.parameter.LXListenableParameter.setValue(LXListenableParameter.java:222)
    at heronarts.lx.parameter.LXListenableParameter.setValue(LXListenableParameter.java:205)
    at heronarts.lx.command.LXCommand$Parameter$SetValue.perform(LXCommand.java:386)
    at heronarts.lx.command.LXCommandEngine.perform(LXCommandEngine.java:60)
    at heronarts.glx.ui.component.UIDropMenu$1.onContextAction(UIDropMenu.java:119)
    at heronarts.glx.ui.component.UIContextMenu.onMousePressed(UIContextMenu.java:195)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:624)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UI2dScrollContext.mousePressed(UI2dScrollContext.java:235)
    at heronarts.glx.ui.UI$UIContextOverlay.mousePressed(UI.java:498)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UI$UIRoot.mousePressed(UI.java:153)
    at heronarts.glx.ui.UI.mouseEvent(UI.java:1007)
    at heronarts.glx.InputDispatch.dispatch(InputDispatch.java:230)
    at heronarts.lx.LXEngine._processInputEvents(LXEngine.java:982)
    at heronarts.lx.LXEngine.processInputEvents(LXEngine.java:958)
    at heronarts.lx.LXEngine.access$1600(LXEngine.java:63)
    at heronarts.lx.LXEngine$ExecutorService.lambda$start$1(LXEngine.java:652)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
    at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)

[LX 2023/08/07 17:43:28] Unexpected error performing action heronarts.lx.command.LXCommand$Parameter$SetNormalized@372efffb - bad internal state?
java.lang.IllegalStateException: Cannot stop() LXAudioInput before open()
    at heronarts.lx.audio.LXAudioInput.stop(LXAudioInput.java:219)
    at heronarts.lx.audio.LXAudioEngine.onParameterChanged(LXAudioEngine.java:94)
    at heronarts.lx.parameter.LXListenableParameter.setValue(LXListenableParameter.java:222)
    at heronarts.lx.parameter.LXListenableParameter.setValue(LXListenableParameter.java:205)
    at heronarts.lx.parameter.BooleanParameter.setValue(BooleanParameter.java:70)
    at heronarts.lx.parameter.BooleanParameter.setNormalized(BooleanParameter.java:93)
    at heronarts.lx.parameter.BooleanParameter.setNormalized(BooleanParameter.java:24)
    at heronarts.lx.command.LXCommand$Parameter$SetNormalized.perform(LXCommand.java:588)
    at heronarts.lx.command.LXCommandEngine.perform(LXCommandEngine.java:60)
    at heronarts.glx.ui.component.UIButton.setActive(UIButton.java:498)
    at heronarts.glx.ui.component.UIButton.setActive(UIButton.java:477)
    at heronarts.glx.ui.component.UIButton.onMousePressed(UIButton.java:424)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:624)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UI2dScrollContainer.mousePressed(UI2dScrollContainer.java:241)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UIObject.mousePressed(UIObject.java:598)
    at heronarts.glx.ui.UI$UIRoot.mousePressed(UI.java:153)
    at heronarts.glx.ui.UI.mouseEvent(UI.java:1007)
    at heronarts.glx.InputDispatch.dispatch(InputDispatch.java:230)
    at heronarts.lx.LXEngine._processInputEvents(LXEngine.java:982)
    at heronarts.lx.LXEngine.processInputEvents(LXEngine.java:958)
    at heronarts.lx.LXEngine.access$1600(LXEngine.java:63)
    at heronarts.lx.LXEngine$ExecutorService.lambda$start$1(LXEngine.java:652)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
    at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)

hope this is helpful somehow!

mcslee commented 1 year ago

Awesome thanks - this is super helpful and confirms what I was assuming created the issue here. This gives me a clear path to fix (and will try to improve the logging as well).

Totally fine to ignore that first error message, it's unrelated and I have actually already made a change in the latest branch to not spit out that error so easily all the time (https://github.com/heronarts/LX/commit/4bc1115f9c7d3ba113a459ed19258caea4d97b1e)

mcslee commented 1 year ago

I believe the fixes here should resolve these issues: https://github.com/heronarts/LX/commit/1302a9d44bd472c73a7f2c7df361ba9b02a2786c

I can't exactly test your specific use case, because I don't have an audio device on my system generating that particular error upon opening, but I think this is going to do it.

I think @jkbelcher is managing the LX library build update process for TE - might ping him to get this integrated into your latest.

andrewlook commented 1 year ago

Amazing! Thank you SO much @mcslee for getting this fixed so quickly, especially with the burn right around the corner. I really appreciate it (and all the work you've done with LX/Chromatik, it's really a joy to work with).

jkbelcher commented 1 year ago

TE libs updated!