search

nvdweem / PCPanel

Third party/community managed controller software for the PCPanel (getpcpanel.com) devices.
Other
89 stars 6 forks source link

OBS connection fails #15

Closed FaNt4zMa closed 1 year ago

FaNt4zMa commented 1 year ago

This could also be reported as bug probably but basically I'd like a button that retry connections to OBS websocket. After closing OBS, PCPanel v1.5 only reconnects to it on opening, it doesnt seem to have some sort of timer to check/retry connection.

I have OBS on my streaming PC (yes I'm the same Fantaz from Reddit) so I don't know if this is an issue on single PC but yeah either a button or a periodic check to establish connection to OBS websocket would be nice. No one leaves OBS opens all the time so I dont understand why it doesnt reconnect automatically already? Thanks!

nvdweem commented 1 year ago

It should already try to reconnect every second when the connection is lost. Could you check the log file to see if there are any errors about OBS? You should be able to go to the logs by navigating to %userprofile%\.pcpanel\logs or by clicking the Settings > Logs > Open logs folder button.

For me when I start OBS, kill it, start it again and close it and starting again, I get logging like this:

2022-11-10 19:25:09.888  INFO 25076 --- [WebSocketClient@1237915210-47] com.getpcpanel.obs.OBS                   : Connected to OBS
2022-11-10 19:25:16.306  WARN 25076 --- [WebSocketClient@1237915210-1534] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1006 and reason 'EofException'
2022-11-10 19:25:28.336  INFO 25076 --- [WebSocketClient@1237915210-1568] com.getpcpanel.obs.OBS                   : Connected to OBS
2022-11-10 19:25:47.280  WARN 25076 --- [WebSocketClient@1237915210-1534] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1001 and reason 'Server stopping.'
2022-11-10 19:25:58.306  INFO 25076 --- [WebSocketClient@1237915210-47] com.getpcpanel.obs.OBS                   : Connected to OBS
FaNt4zMa commented 1 year ago

Maybe its because OBS is on a 2nd PC? But when I launch PCPanel while OBS is already running it connects fine. Then if I kill OBS, start OBS, I get this error (on OBS closing):

2022-11-10 15:55:12.020  WARN 5860 --- [WebSocketClient@2002513634-63] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1001 and reason 'Server stopping.'

Then when it retry connection I get this:

2022-11-10 15:55:28.024 ERROR 5860 --- [OBS Connection Starter] com.getpcpanel.obs.OBS                   : Unknown OBS error

java.util.concurrent.ExecutionException: java.net.SocketTimeoutException: Connect Timeout
    at java.base/java.util.concurrent.CompletableFuture.reportGet(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.CompletableFuture.get(Unknown Source) ~[na:na]
    at io.obswebsocket.community.client.OBSRemoteController.connect(OBSRemoteController.java:343) ~[obs-websocket-java-5.x.x~protocol_update-b9e5082910-1.jar:na]
    at com.getpcpanel.obs.OBS.tryReconnect(OBS.java:172) ~[pcpanel-1.5.jar:1.5]
    at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
Caused by: java.net.SocketTimeoutException: Connect Timeout
    at org.eclipse.jetty.io.ManagedSelector$Connect.run(ManagedSelector.java:955) ~[jetty-io-9.4.49.v20220914.jar:9.4.49.v20220914]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.run(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na]
    ... 1 common frames omitted

And if I go into settings and click the Test for OBS connection, it says "Success!" but doesnt actually connect and throws this error:

2022-11-10 15:49:35.808  WARN 17648 --- [WebSocketClient@526566552-94] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1000 and reason 'null'
FaNt4zMa commented 1 year ago

Note: I also use TouchPortal and it doesn't have issue reconnecting to OBS on the 2nd PC

FaNt4zMa commented 1 year ago

On launch of PCPanel v1.5, I get this error:

2022-11-11 00:43:01.964 ERROR 14208 --- [JavaFX-Launcher] com.github.kwhat.jnativehook             : Unable to extract the native library /com/github/kwhat/jnativehook/lib/windows/x86_64/JNativeHook.dll!

2022-11-11 00:43:01.974 ERROR 14208 --- [JavaFX-Launcher] com.getpcpanel.util.ShortcutHook         : Unable to register global hook, shortcuts will not work

java.lang.UnsatisfiedLinkError: Unable to extract the native library /com/github/kwhat/jnativehook/lib/windows/x86_64/JNativeHook.dll!

    at com.github.kwhat.jnativehook.GlobalScreen.<clinit>(GlobalScreen.java:91) ~[jnativehook-2.2.2.jar:2.2-SNAPSHOT]
    at com.getpcpanel.util.ShortcutHook.init(ShortcutHook.java:45) ~[pcpanel-1.5.jar:1.5]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[na:na]
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na]
    at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]
    at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleElement.invoke(InitDestroyAnnotationBeanPostProcessor.java:389) ~[spring-beans-5.3.23.jar:5.3.23]
    at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleMetadata.invokeInitMethods(InitDestroyAnnotationBeanPostProcessor.java:333) ~[spring-beans-5.3.23.jar:5.3.23]
    at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor.postProcessBeforeInitialization(InitDestroyAnnotationBeanPostProcessor.java:157) ~[spring-beans-5.3.23.jar:5.3.23]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:440) ~[spring-beans-5.3.23.jar:5.3.23]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1796) ~[spring-beans-5.3.23.jar:5.3.23]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:620) ~[spring-beans-5.3.23.jar:5.3.23]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542) ~[spring-beans-5.3.23.jar:5.3.23]
    at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335) ~[spring-beans-5.3.23.jar:5.3.23]
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234) ~[spring-beans-5.3.23.jar:5.3.23]
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333) ~[spring-beans-5.3.23.jar:5.3.23]
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208) ~[spring-beans-5.3.23.jar:5.3.23]
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:955) ~[spring-beans-5.3.23.jar:5.3.23]
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:918) ~[spring-context-5.3.23.jar:5.3.23]
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:583) ~[spring-context-5.3.23.jar:5.3.23]
    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:734) ~[spring-boot-2.7.4.jar:2.7.4]
    at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:408) ~[spring-boot-2.7.4.jar:2.7.4]
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:308) ~[spring-boot-2.7.4.jar:2.7.4]
    at org.springframework.boot.builder.SpringApplicationBuilder.run(SpringApplicationBuilder.java:164) ~[spring-boot-2.7.4.jar:2.7.4]
    at com.getpcpanel.MainFX.init(MainFX.java:22) ~[pcpanel-1.5.jar:1.5]
    at javafx.graphics@18.0.2/com.sun.javafx.application.LauncherImpl.launchApplication1(Unknown Source) ~[javafx.graphics:na]
    at javafx.graphics@18.0.2/com.sun.javafx.application.LauncherImpl.lambda$launchApplication$2(Unknown Source) ~[javafx.graphics:na]
    at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]

Could it have something to do with that? I saw you have a project about java websocket and from my little knowledge and understanding of code, I think it that might be the issue?

Edit: When launching OBS on my main PC, it connects without issue:

2022-11-11 02:35:06.023  INFO 14208 --- [WebSocketClient@1795145900-321] com.getpcpanel.obs.OBS                   : Connected to OBS

So clearly the fact that OBS is on another PC is the issue, but I dont understand why, TouchPortal has no issue. Should I try to installing your software on the streaming PC too?

nvdweem commented 1 year ago

The Unable to register global hook, shortcuts will not work is an exception that I should still fix but only breaks the profile switching using global hotkeys, afaik nobody uses that functionality so haven't put any priority behind it.

I expect that the issue is the SocketTimeoutException from the earlier log. There is a loop that tries to reconnect and I think it gets broken when that exception occurs. It could be that it's worse due to not connecting locally but it should work either way. I'll put it on the list of things to fix.

FaNt4zMa commented 1 year ago

Thanks! In the meantime I'll just restart PCPanel whenever I go to stream, which only happens once or twice a week, so no big deal for now :) I'll try running PCPanel in admin mode to see if that fixes anything and I'll come back to you.

Edit: Did not work

nvdweem commented 1 year ago

The latest snapshot should keep on trying to connect to OBS after it fails.

FaNt4zMa commented 1 year ago

Yes can confirm it keeps on trying, every 3 seconds if I'm not mistaken, which definitly fixed the problem so thank you!

Now the only issue is that the delay is so short that it reconnects twice lmao (because my OBS takes about 10s to open). I did the test twice so im pretty sure its because the delay between retry is too short.

2022-11-13 21:31:18.236  INFO 21884 --- [WebSocketClient@864810499-101] com.getpcpanel.obs.OBS                   : Connected to OBS
2022-11-13 21:31:20.115  INFO 21884 --- [WebSocketClient@864810499-58] com.getpcpanel.obs.OBS                   : Connected to OBS
[...]
2022-11-13 21:32:46.727  INFO 35684 --- [WebSocketClient@619798161-75] com.getpcpanel.obs.OBS                   : Connected to OBS
2022-11-13 21:32:47.721  INFO 35684 --- [WebSocketClient@619798161-58] com.getpcpanel.obs.OBS                   : Connected to OBS

Easy fix would be to just make the delay like 10 seconds :) Thanks again! (Not sure if it actually causes any problem, my PCPanel arrives tomorrow)

nvdweem commented 1 year ago

The easy fix in this case isn't the best fix imo, it'd be just a matter of time before the delay would have to go up again :).

I went with the solution that while connecting, the state is 'connected' so that it won't try to connect in the loop. Putting the delay at 25ms still doesn't trigger double connections for me now.

FaNt4zMa commented 1 year ago

Good solution! Didnt think that could be done, thats way better. Still think the delay at 300ms is kind of short, since it logs every failed attempt, my logs has almost 28k lines, making it a 2.17mb text file lmfao... And its only been running for about 24hrs lol..

nvdweem commented 1 year ago

The delay should be 2500ms, and in your case if it takes 10s to connect, it should be logged every 10s at most. And I had guessed that the exception only occurs when you were closing/starting OBS, not every iteration.

Is the exact error that is being logged still the one in your earlier message? If so I can try and suppress it in favor of a debug statement that will be hidden by default. Also, the logs are gzipped every day and should only be kept 5 days at most, so with 2.17mb for a day it will probably end up being less than 3mb total.

FaNt4zMa commented 1 year ago

Yep, its this error that keeps getting log every attempt:

2022-11-15 14:01:35.047 ERROR 33816 --- [scheduling-1] com.getpcpanel.obs.OBS                   : Unknown OBS error

java.util.concurrent.ExecutionException: java.net.SocketTimeoutException: Connect Timeout
    at java.base/java.util.concurrent.CompletableFuture.reportGet(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.CompletableFuture.get(Unknown Source) ~[na:na]
    at io.obswebsocket.community.client.OBSRemoteController.connect(OBSRemoteController.java:99) ~[client-2.0.0.jar:na]
    at com.getpcpanel.obs.OBS.tryReconnect(OBS.java:61) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at com.getpcpanel.obs.OBS.connect(OBS.java:54) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at jdk.internal.reflect.GeneratedMethodAccessor42.invoke(Unknown Source) ~[na:na]
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na]
    at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]
    at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-5.3.23.jar:5.3.23]
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.3.23.jar:5.3.23]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na]
    at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
Caused by: java.net.SocketTimeoutException: Connect Timeout
    at org.eclipse.jetty.io.ManagedSelector$Connect.run(ManagedSelector.java:955) ~[jetty-io-9.4.49.v20220914.jar:9.4.49.v20220914]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.run(Unknown Source) ~[na:na]
    ... 4 common frames omitted

2022-11-15 14:01:38.049 ERROR 33816 --- [scheduling-1] com.getpcpanel.obs.OBS                   : Unknown OBS error

java.util.concurrent.ExecutionException: java.net.SocketTimeoutException: Connect Timeout
    at java.base/java.util.concurrent.CompletableFuture.reportGet(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.CompletableFuture.get(Unknown Source) ~[na:na]
    at io.obswebsocket.community.client.OBSRemoteController.connect(OBSRemoteController.java:99) ~[client-2.0.0.jar:na]
    at com.getpcpanel.obs.OBS.tryReconnect(OBS.java:61) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at com.getpcpanel.obs.OBS.connect(OBS.java:54) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at jdk.internal.reflect.GeneratedMethodAccessor42.invoke(Unknown Source) ~[na:na]
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na]
    at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]
    at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-5.3.23.jar:5.3.23]
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.3.23.jar:5.3.23]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na]
    at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
Caused by: java.net.SocketTimeoutException: Connect Timeout
    at org.eclipse.jetty.io.ManagedSelector$Connect.run(ManagedSelector.java:955) ~[jetty-io-9.4.49.v20220914.jar:9.4.49.v20220914]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.run(Unknown Source) ~[na:na]
    ... 4 common frames omitted

2022-11-15 14:01:41.049 ERROR 33816 --- [scheduling-1] com.getpcpanel.obs.OBS                   : Unknown OBS error

java.util.concurrent.ExecutionException: java.net.SocketTimeoutException: Connect Timeout
    at java.base/java.util.concurrent.CompletableFuture.reportGet(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.CompletableFuture.get(Unknown Source) ~[na:na]
    at io.obswebsocket.community.client.OBSRemoteController.connect(OBSRemoteController.java:99) ~[client-2.0.0.jar:na]
    at com.getpcpanel.obs.OBS.tryReconnect(OBS.java:61) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at com.getpcpanel.obs.OBS.connect(OBS.java:54) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at jdk.internal.reflect.GeneratedMethodAccessor42.invoke(Unknown Source) ~[na:na]
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na]
    at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]
    at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-5.3.23.jar:5.3.23]
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.3.23.jar:5.3.23]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na]
    at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
Caused by: java.net.SocketTimeoutException: Connect Timeout
    at org.eclipse.jetty.io.ManagedSelector$Connect.run(ManagedSelector.java:955) ~[jetty-io-9.4.49.v20220914.jar:9.4.49.v20220914]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.run(Unknown Source) ~[na:na]
    ... 4 common frames omitted

As you can see, its logged every 3s or so, my txt file now has 52k lines lmao. A debug statetement would prob help keep the logs cleaner and shorter :)

nvdweem commented 1 year ago

I'm looking at the most recent build and it appears that I already made it a debug statement. Judging from the stack this shouldn't be logged anymore already. The OBS.tryReconnect in the log indicates that you are not using the latest snapshot.

FaNt4zMa commented 1 year ago

You'd be right I haven't updated yet. Trying it right now ... After updating it seems to still be logging every failed attempt

2022-11-15 18:56:58.139 ERROR 49308 --- [scheduling-1] com.getpcpanel.obs.OBS                   : Unknown OBS error

java.util.concurrent.ExecutionException: java.net.SocketTimeoutException: Connect Timeout
    at java.base/java.util.concurrent.CompletableFuture.reportGet(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.CompletableFuture.get(Unknown Source) ~[na:na]
    at io.obswebsocket.community.client.OBSRemoteController.connect(OBSRemoteController.java:99) ~[client-2.0.0.jar:na]
    at com.getpcpanel.obs.OBS.doBuildAndConnectObsController(OBS.java:84) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at com.getpcpanel.obs.OBS.buildAndConnectObsController(OBS.java:72) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at com.getpcpanel.obs.OBS.connect(OBS.java:54) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at jdk.internal.reflect.GeneratedMethodAccessor36.invoke(Unknown Source) ~[na:na]
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na]
    at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]
    at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-5.3.23.jar:5.3.23]
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.3.23.jar:5.3.23]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na]
    at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
Caused by: java.net.SocketTimeoutException: Connect Timeout
    at org.eclipse.jetty.io.ManagedSelector$Connect.run(ManagedSelector.java:955) ~[jetty-io-9.4.49.v20220914.jar:9.4.49.v20220914]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.run(Unknown Source) ~[na:na]
    ... 4 common frames omitted

2022-11-15 18:57:01.140 ERROR 49308 --- [scheduling-1] com.getpcpanel.obs.OBS                   : Unknown OBS error

java.util.concurrent.ExecutionException: java.net.SocketTimeoutException: Connect Timeout
    at java.base/java.util.concurrent.CompletableFuture.reportGet(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.CompletableFuture.get(Unknown Source) ~[na:na]
    at io.obswebsocket.community.client.OBSRemoteController.connect(OBSRemoteController.java:99) ~[client-2.0.0.jar:na]
    at com.getpcpanel.obs.OBS.doBuildAndConnectObsController(OBS.java:84) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at com.getpcpanel.obs.OBS.buildAndConnectObsController(OBS.java:72) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at com.getpcpanel.obs.OBS.connect(OBS.java:54) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at jdk.internal.reflect.GeneratedMethodAccessor36.invoke(Unknown Source) ~[na:na]
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na]
    at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]
    at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-5.3.23.jar:5.3.23]
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.3.23.jar:5.3.23]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na]
    at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
Caused by: java.net.SocketTimeoutException: Connect Timeout
    at org.eclipse.jetty.io.ManagedSelector$Connect.run(ManagedSelector.java:955) ~[jetty-io-9.4.49.v20220914.jar:9.4.49.v20220914]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.run(Unknown Source) ~[na:na]
    ... 4 common frames omitted

Should I do a clean install? Also I can confirm no double connection is happening now! Great. I guess we can call this issue resolved. :)

nvdweem commented 1 year ago

It seems that I was looking at the wrong log-statement that was made to be a debug statement. I made another attemt to set the loglevel to debug. If I didn't make another mistake, the SocketTimeoutException should now only trigger debug logging which shouldn't end up in the logfile unless explicitly enabled. If you confirm that the logging is now gone the issue can be closed.

FaNt4zMa commented 1 year ago

Confirmed, it doesn't log the SocketTimeoutException every time now, but sadly now arise a new issues... So for some reason the retry to reconnect it so strong/frequent, it prevents my OBS from opening for like a solid minute... Closing PCPanel makes OBS start immediately... And for some other reason, it seems to double connect again, but not every time... 3 times it happend, two of them are clearly visible the logs, but the 3rd time it didn't log the 2x connections but logged 2x disconnect lmao. Weird behavior. Imo the delay is still too short, it overloads OBS trying to open, I still think a 5000 or 10000ms delay would help fix whats happening right now...

2022-11-16 02:56:13.510  INFO 53124 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : Starting application using Java 17.0.5 on Venom with PID 53124 (started by Fantaz in C:\WINDOWS\system32)
2022-11-16 02:56:13.511  INFO 53124 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : No active profile set, falling back to 1 default profile: "default"
2022-11-16 02:56:14.265  INFO 53124 --- [JavaFX-Launcher] com.getpcpanel.util.FileUtil             : Using root: C:\Users\Fantaz\.pcpanel
2022-11-16 02:56:15.541  INFO 53124 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : Started application in 2.343 seconds (JVM running for 4.339)
2022-11-16 02:56:15.549  INFO 53124 --- [JavaFX Application Thread] com.getpcpanel.MainFX                    : Starting v1.6-SNAPSHOT
2022-11-16 02:56:15.608  INFO 53124 --- [scheduling-1] org.eclipse.jetty.util.log               : Logging initialized @4405ms to org.eclipse.jetty.util.log.Slf4jLog
2022-11-16 02:56:15.689  INFO 53124 --- [JavaFX Application Thread] com.getpcpanel.hid.DeviceScanner         : Starting HID services.
2022-11-16 02:56:15.738  INFO 53124 --- [JavaFX Application Thread] com.getpcpanel.hid.DeviceScanner         : Enumerating attached devices...
2022-11-16 02:56:32.022  WARN 53124 --- [scheduling-1] com.getpcpanel.obs.OBS                   : Unknown OBS error, stack is logged in debug
2022-11-16 02:59:31.950  INFO 53124 --- [Shutdown SleepDetector Hook Thread] c.g.sleepdetection.SleepDetector         : Stopped sleep detector
2022-11-16 02:59:31.952  WARN 53124 --- [scheduling-1] com.getpcpanel.obs.OBS                   : Unknown OBS error, stack is logged in debug
2022-11-16 03:00:09.713  INFO 36500 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : Starting application using Java 17.0.5 on Venom with PID 36500 (started by Fantaz in C:\Users\Fantaz\AppData\Local\PCPanel)
2022-11-16 03:00:09.714  INFO 36500 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : No active profile set, falling back to 1 default profile: "default"
2022-11-16 03:00:10.396  INFO 36500 --- [JavaFX-Launcher] com.getpcpanel.util.FileUtil             : Using root: C:\Users\Fantaz\.pcpanel
2022-11-16 03:00:11.354  INFO 36500 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : Started application in 1.921 seconds (JVM running for 2.431)
2022-11-16 03:00:11.361  INFO 36500 --- [JavaFX Application Thread] com.getpcpanel.MainFX                    : Starting v1.6-SNAPSHOT
2022-11-16 03:00:11.440  INFO 36500 --- [scheduling-1] org.eclipse.jetty.util.log               : Logging initialized @2514ms to org.eclipse.jetty.util.log.Slf4jLog
2022-11-16 03:00:11.492  INFO 36500 --- [JavaFX Application Thread] com.getpcpanel.hid.DeviceScanner         : Starting HID services.
2022-11-16 03:00:11.527  INFO 36500 --- [JavaFX Application Thread] com.getpcpanel.hid.DeviceScanner         : Enumerating attached devices...
2022-11-16 03:00:11.675  INFO 36500 --- [WebSocketClient@315731050-74] com.getpcpanel.obs.OBS                   : Connected to OBS
2022-11-16 03:00:36.537  WARN 36500 --- [WebSocketClient@315731050-72] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1001 and reason 'Server stopping.'
2022-11-16 03:01:16.396  INFO 36500 --- [WebSocketClient@315731050-72] com.getpcpanel.obs.OBS                   : Connected to OBS
2022-11-16 03:01:19.400  INFO 36500 --- [WebSocketClient@315731050-70] com.getpcpanel.obs.OBS                   : Connected to OBS
2022-11-16 03:02:07.380  WARN 36500 --- [WebSocketClient@315731050-74] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1001 and reason 'Server stopping.'
2022-11-16 03:02:07.380  WARN 36500 --- [WebSocketClient@315731050-57] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1001 and reason 'Server stopping.'
2022-11-16 03:02:32.902  INFO 36500 --- [WebSocketClient@315731050-57] com.getpcpanel.obs.OBS                   : Connected to OBS
2022-11-16 03:03:02.555  WARN 36500 --- [WebSocketClient@315731050-74] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1001 and reason 'Server stopping.'
2022-11-16 03:03:57.902  INFO 36500 --- [WebSocketClient@315731050-74] com.getpcpanel.obs.OBS                   : Connected to OBS
2022-11-16 03:03:58.890  INFO 36500 --- [WebSocketClient@315731050-72] com.getpcpanel.obs.OBS                   : Connected to OBS
2022-11-16 03:05:14.675  WARN 36500 --- [WebSocketClient@315731050-59] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1001 and reason 'Server stopping.'
2022-11-16 03:05:14.675  WARN 36500 --- [WebSocketClient@315731050-81] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1001 and reason 'Server stopping.'
2022-11-16 03:05:31.147  WARN 36500 --- [scheduling-1] com.getpcpanel.obs.OBS                   : Unknown OBS error, stack is logged in debug
2022-11-16 03:05:31.147  INFO 36500 --- [Shutdown SleepDetector Hook Thread] c.g.sleepdetection.SleepDetector         : Stopped sleep detector
2022-11-16 03:06:22.552  INFO 38320 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : Starting application using Java 17.0.5 on Venom with PID 38320 (started by Fantaz in C:\Users\Fantaz\AppData\Local\PCPanel)
2022-11-16 03:06:22.553  INFO 38320 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : No active profile set, falling back to 1 default profile: "default"
2022-11-16 03:06:23.190  INFO 38320 --- [JavaFX-Launcher] com.getpcpanel.util.FileUtil             : Using root: C:\Users\Fantaz\.pcpanel
2022-11-16 03:06:24.236  INFO 38320 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : Started application in 1.945 seconds (JVM running for 2.427)
2022-11-16 03:06:24.243  INFO 38320 --- [JavaFX Application Thread] com.getpcpanel.MainFX                    : Starting v1.6-SNAPSHOT
2022-11-16 03:06:24.308  INFO 38320 --- [scheduling-1] org.eclipse.jetty.util.log               : Logging initialized @2495ms to org.eclipse.jetty.util.log.Slf4jLog
2022-11-16 03:06:24.383  INFO 38320 --- [JavaFX Application Thread] com.getpcpanel.hid.DeviceScanner         : Starting HID services.
2022-11-16 03:06:24.422  INFO 38320 --- [JavaFX Application Thread] com.getpcpanel.hid.DeviceScanner         : Enumerating attached devices...
2022-11-16 03:11:14.721  INFO 38320 --- [Shutdown SleepDetector Hook Thread] c.g.sleepdetection.SleepDetector         : Stopped sleep detector
2022-11-16 03:11:14.723  WARN 38320 --- [scheduling-1] com.getpcpanel.obs.OBS                   : Unknown OBS error, stack is logged in debug
2022-11-16 03:14:28.520  INFO 51272 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : Starting application using Java 17.0.5 on Venom with PID 51272 (started by Fantaz in C:\Users\Fantaz\AppData\Local\PCPanel)
2022-11-16 03:14:28.521  INFO 51272 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : No active profile set, falling back to 1 default profile: "default"
2022-11-16 03:14:29.256  INFO 51272 --- [JavaFX-Launcher] com.getpcpanel.util.FileUtil             : Using root: C:\Users\Fantaz\.pcpanel
2022-11-16 03:14:30.454  INFO 51272 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : Started application in 2.222 seconds (JVM running for 2.743)
2022-11-16 03:14:30.463  INFO 51272 --- [JavaFX Application Thread] com.getpcpanel.MainFX                    : Starting v1.6-SNAPSHOT
2022-11-16 03:14:30.563  INFO 51272 --- [scheduling-1] org.eclipse.jetty.util.log               : Logging initialized @2847ms to org.eclipse.jetty.util.log.Slf4jLog
2022-11-16 03:14:30.647  INFO 51272 --- [JavaFX Application Thread] com.getpcpanel.hid.DeviceScanner         : Starting HID services.
2022-11-16 03:14:30.685  INFO 51272 --- [JavaFX Application Thread] com.getpcpanel.hid.DeviceScanner         : Enumerating attached devices...
2022-11-16 03:15:18.233  INFO 51272 --- [WebSocketClient@746542942-88] com.getpcpanel.obs.OBS                   : Connected to OBS
2022-11-16 03:15:33.210  WARN 51272 --- [WebSocketClient@746542942-90] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1001 and reason 'Server stopping.'
2022-11-16 03:17:12.994  INFO 51272 --- [WebSocketClient@746542942-81] com.getpcpanel.obs.OBS                   : Connected to OBS
2022-11-16 03:17:54.832  WARN 51272 --- [WebSocketClient@746542942-91] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1001 and reason 'Server stopping.'
2022-11-16 03:17:54.832  WARN 51272 --- [WebSocketClient@746542942-92] i.o.community.client.OBSCommunicator     : onClose called with unrecognized statusCode 1001 and reason 'Server stopping.'
2022-11-16 03:18:11.502  INFO 51272 --- [WebSocketClient@746542942-91] com.getpcpanel.obs.OBS                   : Connected to OBS
nvdweem commented 1 year ago

I'm still not very much in favor of increasing the delay, but I added an option to do so anyway. I also moved one of the instructions about the socket already being connected as a quick attempt to fix the issue of connecting more than once. That OBS starts up slower when the PCPanel software is started surprises me, I'm not expecting the software to try to connect a bunch of time (your log shows 1s between connects at least) so that shouldn't make OBS startup so slowly.

The delay can be set through an environment variable: System properties > Advanced > Environment variables > New (either user or system) Variable name: PCPANEL_OBS_RATE Variable value: 10000 The value is the delay in ms.

FaNt4zMa commented 1 year ago

I ended up reverting to the previous snapshot because the latest one was less stable... It had weird bugs like OBS sources being in reverse alphabetical order, being able to control my OBS source during the "set-up" screen but then pressing "OK" and it not working...? Relaunching the software/OBS didnt help, as it crashed my stream PC lmfao.. and the software wasn't showing properly how the lights were on the panel too.

TLDR: Previous snapshot didnt cause issue (just got my PCPanel delivered today, so I can finally test), as the secondary connection would eventually get disconnected... Sorry if I made you fix things that didnt need fixing :(

Edit: I got the reverse order "bug" on the previous snapshot too after restarting OBS, so its probably an OBS thing...

FaNt4zMa commented 1 year ago

Hey there, sorry me again! I recently updated my snapshot to 133 and now the OBS connection fails whenever I open the software :( Here's the logs:

2023-02-06T23:07:17.752-05:00  INFO 20252 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : Starting application using Java 19.0.2 with PID 20252 (started by Fantaz in C:\Users\Fantaz\AppData\Local\PCPanel)
2023-02-06T23:07:17.754-05:00  INFO 20252 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : No active profile set, falling back to 1 default profile: "default"
2023-02-06T23:07:18.280-05:00  INFO 20252 --- [JavaFX-Launcher] c.getpcpanel.cpp.windows.SndCtrlWindows  : AudioPolicyConfigFactory is available
2023-02-06T23:07:18.326-05:00  INFO 20252 --- [JavaFX-Launcher] com.getpcpanel.util.FileUtil             : Using root: C:\Users\Fantaz\.pcpanel
2023-02-06T23:07:19.056-05:00  INFO 20252 --- [JavaFX-Launcher] o.s.boot.SpringApplication               : Started application in 1.558 seconds (process running for 2.02)
2023-02-06T23:07:19.061-05:00  INFO 20252 --- [JavaFX Application Thread] com.getpcpanel.MainFX                    : Starting v1.6-SNAPSHOT
2023-02-06T23:07:19.075-05:00 ERROR 20252 --- [scheduling-1] o.s.s.s.TaskUtils$LoggingErrorHandler    : Unexpected error occurred in scheduled task

java.lang.NoClassDefFoundError: org/eclipse/jetty/websocket/client/WebSocketClient
    at io.obswebsocket.community.client.OBSRemoteControllerBuilder.<init>(OBSRemoteControllerBuilder.java:26) ~[client-2.0.0.jar:na]
    at io.obswebsocket.community.client.OBSRemoteController.builder(OBSRemoteController.java:80) ~[client-2.0.0.jar:na]
    at com.getpcpanel.obs.OBS.buildController(OBS.java:176) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at com.getpcpanel.obs.OBS.doBuildAndConnectObsController(OBS.java:114) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at com.getpcpanel.obs.OBS.buildAndConnectObsController(OBS.java:86) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at com.getpcpanel.obs.OBS.connect(OBS.java:68) ~[pcpanel-1.6-SNAPSHOT.jar:1.6-SNAPSHOT]
    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(Unknown Source) ~[na:na]
    at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]
    at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-6.0.3.jar:6.0.3]
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-6.0.3.jar:6.0.3]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na]
    at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
Caused by: java.lang.ClassNotFoundException: org.eclipse.jetty.websocket.client.WebSocketClient
    at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(Unknown Source) ~[na:na]
    at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(Unknown Source) ~[na:na]
    at java.base/java.lang.ClassLoader.loadClass(Unknown Source) ~[na:na]
    ... 16 common frames omitted

2023-02-06T23:07:19.145-05:00  INFO 20252 --- [JavaFX Application Thread] com.getpcpanel.hid.DeviceScanner         : Starting HID services.
2023-02-06T23:07:19.250-05:00  INFO 20252 --- [hid4java event worker] com.getpcpanel.hid.DeviceScanner         : FOUND PCPANEL : HidDevice [path=\\?\hid#vid_0483&pid_a3c5#6&2f364e7c&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}, vendorId=0x483, productId=0xa3c5, serialNumber=5943E9343638, releaseNumber=0x200, manufacturer=PCPanel Holdings LLC, product=PCPanel Pro 1.0, usagePage=0xffffff00, usage=0x1, interfaceNumber=-1]
2023-02-06T23:07:19.250-05:00  INFO 20252 --- [JavaFX Application Thread] com.getpcpanel.hid.DeviceScanner         : Enumerating attached devices...

Do you happen to have a build from back then so I could get it working again? The only reason I had updated in the first place was for the Voicemeeter support for Mute override color...

nvdweem commented 1 year ago

I blindly implemented a fix to the build template I used, but that apparently resulted in an installer that didn't include all required files. This should be fixed in the next build (134).

I don't store older snapshot builds, so if you didn't either then there wouldn't be a way to revert to that older version.

FaNt4zMa commented 1 year ago

I have not sadly.. but hey the latest build worked, only I had to restart the software a few times because it couldn't "see" my device but it still worked..? After 2 restart and deleting the log file, it started working perfectly. Thanks for your quick fix again!