vlingo/xoom-helloworld

Build fails

chytonpide opened this issue · 10 comments

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)

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

@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

@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.

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 92677c1

Hope this solves your problem @chytonpide too.

@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.

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

@jakzal This is the full log.

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

@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.

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