search

hypfvieh / dbus-java

Improved version of java DBus library provided by freedesktop.org (https://dbus.freedesktop.org/doc/dbus-java/)
https://hypfvieh.github.io/dbus-java/
MIT License
185 stars 73 forks source link

org.freedesktop.dbus.test.TestCross unit test has long run time #200

Closed ghost closed 1 year ago

ghost commented 1 year ago

Replicate

cd /tmp
git clone https://github.com/hypfvieh/dbus-java
cd dbus-java
mvn package

Expected

Builds a JAR file.

Actual

The following test takes a long time to run (at least 10 minutes; I cancelled it before it finished):

[INFO] Tests run: 28, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 30.131 s - in org.freedesktop.dbus.test.TestAll
[INFO] Running org.freedesktop.dbus.test.TestCross
12:57:58.326 [main] DEBUG o.f.d.t.tcp.TcpTransportProvider - Created Session address: tcp:host=localhost,port=33663,listen=true,guid=6dfb4f5c986bf263762211550d3018bf
12:57:58.333 [main] INFO  o.f.dbus.test.AbstractDBusBaseTest - Creating TCP based DBus daemon on address tcp:host=localhost,port=33663,listen=true,guid=6dfb4f5c986bf263762211550d3018bf
12:57:58.368 [EmbeddedDBusDaemon-tcp:host=localhost] INFO  o.f.d.c.transports.TransportBuilder - Using transport dbus-java-transport-tcp to connect to tcp:host=localhost,port=33663,listen=true,guid=6dfb4f5c986bf263762211550d3018bf
12:57:58.838 [main] DEBUG o.f.dbus.test.AbstractDBusBaseTest - Waiting for embedded daemon to start: 500 of 30000 ms waited
12:57:58.856 [main] INFO  org.freedesktop.dbus.test.TestCross - >>>>>>>>>> BGN Test: testCross() <<<<<<<<<<
12:57:58.905 [Server Thread] INFO  o.f.d.c.transports.TransportBuilder - Using transport dbus-java-transport-tcp to connect to tcp:host=localhost,port=33663,guid=6dfb4f5c986bf263762211550d3018bf
12:57:58.989 [Server Thread] DEBUG o.f.dbus.transport.tcp.TcpTransport - No alternative ISocketProvider found, using built-in implementation
12:57:58.992 [EmbeddedDBusDaemon-tcp:host=localhost] DEBUG o.f.dbus.transport.tcp.TcpTransport - No alternative ISocketProvider found, using built-in implementation
12:57:59.020 [DBus Sender Thread-1] DEBUG o.f.d.s.m.OutputStreamMessageWriter - <= MethodCall(0,1) { Path=>/org/freedesktop/DBus, Interface=>org.freedesktop.DBus, Member=>Hello, Destination=>org.freedesktop.DBus } { }
12:57:59.034 [DBusDaemonReaderThread] DEBUG o.f.d.s.m.InputStreamMessageReader - => MethodCall(0,1) { Path=>/org/freedesktop/DBus, Interface=>org.freedesktop.DBus, Member=>Hello, Destination=>org.freedesktop.DBus } { }
org.freedesktop.dbus.exceptions.DBusException: No reply within specified time
    at org.freedesktop.dbus.connections.impl.DBusConnection.connect(DBusConnection.java:259)
    at org.freedesktop.dbus.connections.impl.DBusConnectionBuilder.build(DBusConnectionBuilder.java:206)
    at org.freedesktop.dbus.test.TestCross$ServerThread.run(TestCross.java:88)
Exception in thread "Server Thread" org.opentest4j.AssertionFailedError: Exception while server running
    at org.junit.jupiter.api.AssertionUtils.fail(AssertionUtils.java:38)
    at org.junit.jupiter.api.Assertions.fail(Assertions.java:135)
    at org.freedesktop.dbus.test.TestCross$ServerThread.run(TestCross.java:111)

Not sure if this is because of the environment variable value being set:

$ echo $DBUS_SESSION_BUS_ADDRESS 
unix:path=/run/user/1002/bus

I disabled the following test in org.freedesktop.dbus.test.TestCross to allow the build/tests to proceed, then re-ran mvn package:

    public void testCross() throws InterruptedException {

After disabling that test, the unit tests run to completion and a JAR file is built.

hypfvieh commented 1 year ago

I cannot reproduce this problem.

According to the provided log, the test is running using the tcp-transport, therefore the setting of $DBUS_SESSION_BUS_ADDRESS is ignored.

I found a small issue related to notify pending method calls about the disconnect. In that case a Error object should be created but the given exception was null, therefore the constructor of Error failed because it tries to get the class and message from the exception.

But either with or without a patch for the issue above, I cannot reproduce the problem.

If I run the cross test on my private laptop (pretty new Ryzen 7), no issues. Running the same on my work laptop (slow as hell Core i-5) also no issue. Running the test in Github actions also shows no issues in this test. Same for the two unixsocket-based transports - no issues in any setup.

[Edit]: Running the test takes around 30 seconds to be completed, (on my slower machine using tcp-transport). It is faster when using unixsockets (~16 seconds).

ghost commented 1 year ago 
$ git clone https://github.com/hypfvieh/dbus-java/
Cloning into 'dbus-java'...
remote: Enumerating objects: 12685, done.
remote: Counting objects: 100% (1066/1066), done.
remote: Compressing objects: 100% (493/493), done.
remote: Total 12685 (delta 535), reused 804 (delta 465), pack-reused 11619
Receiving objects: 100% (12685/12685), 3.57 MiB | 6.28 MiB/s, done.
Resolving deltas: 100% (6850/6850), done.
$ cd dbus-java/
$ mvn --version
Apache Maven 3.6.3 (cecedd343002696d0abb50b32b541b8a6ba2883f)
Maven home: /opt/maven
Java version: 17.0.3, vendor: Eclipse Adoptium, runtime: /opt/jdk-17.0.3+7
Default locale: en_US, platform encoding: UTF-8
OS name: "linux", version: "4.19.0-21-amd64", arch: "amd64", family: "unix"
$ java --version
openjdk 17.0.3 2022-04-19
OpenJDK Runtime Environment Temurin-17.0.3+7 (build 17.0.3+7)
OpenJDK 64-Bit Server VM Temurin-17.0.3+7 (build 17.0.3+7, mixed mode, sharing)
$ uname -a
Linux hostname 4.19.0-21-amd64 #1 SMP Debian 4.19.249-2 (2022-06-30) x86_64 GNU/Linux
$ mvn package
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary for dbus-java-parent 4.2.2-SNAPSHOT:
[INFO] 
[INFO] dbus-java-parent ................................... SUCCESS [  1.781 s]
[INFO] dbus-java-core ..................................... SUCCESS [ 15.599 s]
[INFO] dbus-java-osgi ..................................... SUCCESS [  4.103 s]
[INFO] dbus-java-transport-jnr-unixsocket ................. SUCCESS [  3.568 s]
[INFO] dbus-java-transport-tcp ............................ SUCCESS [  2.623 s]
[INFO] dbus-java-utils .................................... SUCCESS [  9.033 s]
[INFO] dbus-java-bom ...................................... SUCCESS [  0.032 s]
[INFO] dbus-java-transport-native-unixsocket .............. SUCCESS [  2.477 s]
[INFO] dbus-java-tests .................................... SUCCESS [06:14 min]
[INFO] dbus-java-examples ................................. SUCCESS [  0.882 s]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  06:56 min
[INFO] Finished at: 2023-01-13T10:12:00-08:00
[INFO] ------------------------------------------------------------------------

Cannot reproduce the timeout issue. Could be a sign of a race-condition, could have been a guest VM problem (the development environment is hosted on a Linux VM). Closing for now.