vlingo / xoom-helloworld

VLINGO XOOM platform SDK "Hello, World!" service that demonstrates the use of the standard components commonly used.
https://vlingo.io
Mozilla Public License 2.0
17 stars 5 forks source link

Build fails #16

Open chytonpide opened 2 years ago

chytonpide commented 2 years ago

Build fails when running test. With skipping tests, The Build success, and the artifact works well. This is a repeated stack trace.

16:19:15.953 [pool-17-thread-15] ERROR i.v.x.a.p.s.DefaultSupervisorOverride - DefaultSupervisorOverride: Failure of: Address[id=24, name=APP-inbound] because: Failed to bind on [0.0.0.0:37372] Action: Resuming.
java.lang.IllegalStateException: Failed to bind on [0.0.0.0:37372]
    at io.vlingo.xoom.wire.fdx.inbound.InboundStreamActor.start(InboundStreamActor.java:61)
    at io.vlingo.xoom.actors.LifeCycle.lambda$sendStart$fe05f96a$1(LifeCycle.java:111)
    at io.vlingo.xoom.actors.LocalMessage.internalDeliver(LocalMessage.java:121)
    at io.vlingo.xoom.actors.LocalMessage.deliver(LocalMessage.java:53)
    at io.vlingo.xoom.actors.plugin.mailbox.concurrentqueue.ConcurrentQueueMailbox.run(ConcurrentQueueMailbox.java:108)
    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:750)
Caused by: reactor.netty.ChannelBindException: Failed to bind on [0.0.0.0:37372]
    Suppressed: java.lang.Exception: #block terminated with an error
        at reactor.core.publisher.BlockingSingleSubscriber.blockingGet(BlockingSingleSubscriber.java:99)
        at reactor.core.publisher.Mono.block(Mono.java:1704)
        at io.vlingo.xoom.wire.fdx.inbound.rsocket.RSocketChannelInboundReader.openFor(RSocketChannelInboundReader.java:90)
        at io.vlingo.xoom.wire.fdx.inbound.InboundStreamActor.start(InboundStreamActor.java:57)
        at io.vlingo.xoom.actors.LifeCycle.lambda$sendStart$fe05f96a$1(LifeCycle.java:111)
        at io.vlingo.xoom.actors.LocalMessage.internalDeliver(LocalMessage.java:121)
        at io.vlingo.xoom.actors.LocalMessage.deliver(LocalMessage.java:53)
        at io.vlingo.xoom.actors.plugin.mailbox.concurrentqueue.ConcurrentQueueMailbox.run(ConcurrentQueueMailbox.java:108)
        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:750)
VaughnVernon commented 2 years ago

@chytonpide It appears that 0.0.0.0:37372 is already in use. Can you please indicate?

chytonpide commented 2 years ago

@VaughnVernon The build is successful on other machines. This is the port state, environment, and hardware profile that the build fails. Is it related to the M1 chip?

❯ lsof -iTCP -sTCP:LISTEN -n -P
COMMAND    PID       USER   FD   TYPE             DEVICE SIZE/OFF NODE NAME
ControlCe  581 kangwhiwon   19u  IPv4 0xf477b38d724ed243      0t0  TCP *:7000 (LISTEN)
ControlCe  581 kangwhiwon   20u  IPv6 0xf477b388a59b073b      0t0  TCP *:7000 (LISTEN)
ControlCe  581 kangwhiwon   21u  IPv4 0xf477b38d724ec7b3      0t0  TCP *:5000 (LISTEN)
ControlCe  581 kangwhiwon   22u  IPv6 0xf477b388a59b0e1b      0t0  TCP *:5000 (LISTEN)
mysqld    1471 kangwhiwon   19u  IPv4 0xf477b38d724e1cd3      0t0  TCP 127.0.0.1:33060 (LISTEN)
mysqld    1471 kangwhiwon   22u  IPv4 0xf477b38d724e2763      0t0  TCP 127.0.0.1:3306 (LISTEN)
com.docke 2652 kangwhiwon   30u  IPv4 0xf477b38d724d3d23      0t0  TCP *:50242 (LISTEN)
vpnkit-br 2685 kangwhiwon    8u  IPv4 0xf477b38d724d3d23      0t0  TCP *:50242 (LISTEN)

❯ mvn -version
Apache Maven 3.8.5 (3599d3414f046de2324203b78ddcf9b5e4388aa0)
Maven home: /Users/kangwhiwon/.sdkman/candidates/maven/current
Java version: 1.8.0_322, vendor: Amazon.com Inc., runtime: /Users/kangwhiwon/Library/Java/JavaVirtualMachines/corretto-1.8.0_322/Contents/Home/jre
Default locale: ko_KR, platform encoding: UTF-8
OS name: "mac os x", version: "12.3.1", arch: "x86_64", family: "mac"

❯ java -version
openjdk version "1.8.0_322"
OpenJDK Runtime Environment Corretto-8.322.06.1 (build 1.8.0_322-b06)
OpenJDK 64-Bit Server VM Corretto-8.322.06.1 (build 25.322-b06, mixed mode)

❯ system_profiler SPHardwareDataType
Hardware:

    Hardware Overview:

      Model Name: MacBook Pro
      Model Identifier: MacBookPro18,2
      Chip: Apple M1 Max
      Total Number of Cores: 10 (8 performance and 2 efficiency)
      Memory: 32 GB
      System Firmware Version: 7459.101.3
      OS Loader Version: 7459.101.3
      Serial Number (system): XXXX
      Hardware UUID: XXXX
      Provisioning UDID: XXXX
      Activation Lock Status: Enabled
VaughnVernon commented 2 years ago

@chytonpide I was going to ask about M1 😃 but I thought it must be an open port. I don't want M1 to be my go-to for all weird problems.

This is a question for @jakzal, who bought the new MBP six months ago. He also did a lot of recent work on xoom-helloworld.

jakzal commented 2 years ago

The ERROR is actually something that's also showing up in our CI. It doesn't make the tests fail though.

Turns out the state wasn't cleaned properly after each test and the world was being reused. Fixed in https://github.com/vlingo/xoom-helloworld/commit/92677c1f1ac0346dbd5009772663e7f1eab9a29a

Hope this solves your problem @chytonpide too.

chytonpide commented 2 years ago

@jakzal Thanks! The error is no longer visible. I found I picked the wrong cause. The problem was that the build process is in an infinite loop. so I can't get the artifact with the mvn clean package command. Tests using givenGreetingWasCreated() its inside are suspicious in GreetingResourceTest. Without these tests, The build was finished. These are repeating messages when the build is in an infinite loop.

17:34:39.877 [pool-37-thread-1] DEBUG io.vlingo.xoom.lattice.grid.GridNode - GRID: Node reported healthy: Id[1] and is healthy: true
17:34:40.050 [pool-37-thread-2] DEBUG i.v.x.l.util.ExpiringHardRefHolder - Starting expired references cleanup at 2022-05-19T08:34:40.050Z ...
17:34:40.051 [pool-37-thread-2] DEBUG i.v.x.l.util.ExpiringHardRefHolder - Finished cleanup of expired references at 2022-05-19T08:34:40.051Z. 0 removed.
17:34:41.055 [pool-37-thread-8] DEBUG i.v.x.l.util.ExpiringHardRefHolder - Starting expired references cleanup at 2022-05-19T08:34:41.055Z ...
17:34:41.056 [pool-37-thread-8] DEBUG i.v.x.l.util.ExpiringHardRefHolder - Finished cleanup of expired references at 2022-05-19T08:34:41.056Z. 0 removed.
17:34:41.880 [pool-37-thread-12] DEBUG i.v.x.c.m.o.OperationalOutboundStreamActor - Broadcasting pulse
17:34:41.881 [pool-37-thread-8] DEBUG io.vlingo.xoom.lattice.grid.GridNode - GRID: Node reported healthy: Id[1] and is healthy: true
17:34:42.061 [pool-37-thread-15] DEBUG i.v.x.l.util.ExpiringHardRefHolder - Starting expired references cleanup at 2022-05-19T08:34:42.061Z ...
17:34:42.061 [pool-37-thread-15] DEBUG i.v.x.l.util.ExpiringHardRefHolder - Finished cleanup of expired references at 2022-05-19T08:34:42.061Z. 0 removed.
17:34:43.066 [pool-37-thread-4] DEBUG i.v.x.l.util.ExpiringHardRefHolder - Starting expired references cleanup at 2022-05-19T08:34:43.066Z ...
17:34:43.067 [pool-37-thread-4] DEBUG i.v.x.l.util.ExpiringHardRefHolder - Finished cleanup of expired references at 2022-05-19T08:34:43.067Z. 0 removed.
17:34:43.883 [pool-37-thread-6] DEBUG i.v.x.c.m.o.OperationalOutboundStreamActor - Broadcasting pulse
17:34:43.884 [pool-37-thread-6] DEBUG io.vlingo.xoom.lattice.grid.GridNode - GRID: Node reported healthy: Id[1] and is healthy: true
17:34:44.071 [pool-37-thread-8] DEBUG i.v.x.l.util.ExpiringHardRefHolder - Starting expired references cleanup at 2022-05-19T08:34:44.071Z ...
17:34:44.071 [pool-37-thread-8] DEBUG i.v.x.l.util.ExpiringHardRefHolder - Finished cleanup of expired references at 2022-05-19T08:34:44.071Z. 0 removed.
17:34:45.076 [pool-37-thread-12] DEBUG i.v.x.l.util.ExpiringHardRefHolder - Starting expired references cleanup at 2022-05-19T08:34:45.076Z ...
17:34:45.077 [pool-37-thread-12] DEBUG i.v.x.l.util.ExpiringHardRefHolder - Finished cleanup of expired references at 2022-05-19T08:34:45.077Z. 0 removed.
jakzal commented 2 years ago

@chytonpide nothing unusual here. Is there anything before it goes into an infinite loop of these log entries?

chytonpide commented 2 years ago

@jakzal This is the full log.

jakzal commented 2 years ago

@chytonpide is it hanging like this every time? I can't see why, to be honest.

chytonpide commented 2 years ago

@jakzal Yes, The build hangs every time. The test that the build hangs on is different each time. Sometimes, It hangs on the 9th test. Sometimes, It hangs on 3rd test.

It seems to be a problem with the execution or terminating timing of threads. This is the build log that I added logging every start and end of test method execution. Its pattern like that ----start-----GreetingResourceTest.itGetsExistingGreetings and ----end-----GreetingResourceTest.itGetsExistingGreetings. This is the thread dump using jstack.

I have tested the build with other machines. MAC(Intel): The build is finished well. Windows(Intel): The build is finished well. I think there will be a chance to test with another MAC(M1) in June. I will test it and comment again.

jakzal commented 2 years ago

Thanks for looking into this in such detail. I also have an M1 Mac and it works fine on mine :/