Skip to content

Inadequate wait strategy? #91

Closed
#107
Closed
Inadequate wait strategy?#91
#107
Labels
bugSomething isn't working

Description

@Mahoney
Mahoney
opened on Mar 11, 2024

Using 0.6.0 with rockstorm/git-server:2.43 we have a flaky test on GitHub Actions.

All of our tests start a new container, but it's always the first test to start a git container that fails, we can see it's just after the pull.

It has thrown both an org.apache.sshd.common.SshException: Session is closed and a java.io.IOException: Broken pipe.

Relevant logs:

INFO  [2024-03-11 12:01:50,645] req= tc.rockstorm/git-server:2.43: Pulling docker image: rockstorm/git-server:2.43. Please be patient; this may take some time but only needs to be done once.
INFO  [2024-03-11 12:01:50,873] req= tc.rockstorm/git-server:2.43: Starting to pull image
INFO  [2024-03-11 12:01:50,873] req= tc.rockstorm/git-server:2.43: Pulling image layers:  0 pending,  0 downloaded,  0 extracted, (0 bytes/0 bytes)
INFO  [2024-03-11 12:01:51,030] req= tc.rockstorm/git-server:2.43: Pulling image layers:  9 pending,  1 downloaded,  0 extracted, (1 KB/? MB)
INFO  [2024-03-11 12:01:51,032] req= tc.rockstorm/git-server:2.43: Pulling image layers:  8 pending,  2 downloaded,  0 extracted, (4 KB/? MB)
INFO  [2024-03-11 12:01:51,103] req= tc.rockstorm/git-server:2.43: Pulling image layers:  7 pending,  3 downloaded,  0 extracted, (81 KB/? MB)
INFO  [2024-03-11 12:01:51,123] req= tc.rockstorm/git-server:2.43: Pulling image layers:  6 pending,  4 downloaded,  0 extracted, (81 KB/? MB)
INFO  [2024-03-11 12:01:51,163] req= tc.rockstorm/git-server:2.43: Pulling image layers:  5 pending,  5 downloaded,  0 extracted, (4 MB/? MB)
INFO  [2024-03-11 12:01:51,197] req= tc.rockstorm/git-server:2.43: Pulling image layers:  4 pending,  6 downloaded,  0 extracted, (4 MB/? MB)
INFO  [2024-03-11 12:01:51,212] req= tc.rockstorm/git-server:2.43: Pulling image layers:  3 pending,  7 downloaded,  0 extracted, (4 MB/? MB)
INFO  [2024-03-11 12:01:51,268] req= tc.rockstorm/git-server:2.43: Pulling image layers:  2 pending,  8 downloaded,  0 extracted, (4 MB/? MB)
INFO  [2024-03-11 12:01:51,285] req= tc.rockstorm/git-server:2.43: Pulling image layers:  1 pending,  9 downloaded,  0 extracted, (4 MB/? MB)
INFO  [2024-03-11 12:01:51,536] req= tc.rockstorm/git-server:2.43: Pulling image layers:  1 pending,  9 downloaded,  1 extracted, (7 MB/? MB)
INFO  [2024-03-11 12:01:51,554] req= tc.rockstorm/git-server:2.43: Pulling image layers:  1 pending,  9 downloaded,  2 extracted, (7 MB/? MB)
INFO  [2024-03-11 12:01:51,567] req= tc.rockstorm/git-server:2.43: Pulling image layers:  1 pending,  9 downloaded,  3 extracted, (7 MB/? MB)
INFO  [2024-03-11 12:01:51,596] req= tc.rockstorm/git-server:2.43: Pulling image layers:  1 pending,  9 downloaded,  4 extracted, (7 MB/? MB)
INFO  [2024-03-11 12:01:51,609] req= tc.rockstorm/git-server:2.43: Pulling image layers:  1 pending,  9 downloaded,  5 extracted, (7 MB/? MB)
INFO  [2024-03-11 12:01:51,618] req= tc.rockstorm/git-server:2.43: Pulling image layers:  1 pending,  9 downloaded,  6 extracted, (7 MB/? MB)
INFO  [2024-03-11 12:01:51,629] req= tc.rockstorm/git-server:2.43: Pulling image layers:  1 pending,  9 downloaded,  7 extracted, (7 MB/? MB)
INFO  [2024-03-11 12:01:51,638] req= tc.rockstorm/git-server:2.43: Pulling image layers:  1 pending,  9 downloaded,  8 extracted, (7 MB/? MB)
INFO  [2024-03-11 12:01:51,650] req= tc.rockstorm/git-server:2.43: Pulling image layers:  1 pending,  9 downloaded,  9 extracted, (7 MB/? MB)
INFO  [2024-03-11 12:01:51,654] req= tc.rockstorm/git-server:2.43: Image rockstorm/git-server:2.43 pull took PT1.009099217S
INFO  [2024-03-11 12:01:51,656] req= tc.rockstorm/git-server:2.43: Creating container for image: rockstorm/git-server:2.43
INFO  [2024-03-11 12:01:51,703] req= tc.rockstorm/git-server:2.43: Container rockstorm/git-server:2.43 is starting: 82c6b6499b53ec7f43e329e0433538a4e8a055bb18c334e00b865940d45d5673
INFO  [2024-03-11 12:01:52,458] req= tc.rockstorm/git-server:2.43: Container rockstorm/git-server:2.43 started in PT0.801877892S

INFO  [2024-03-11 12:01:53,267] req= mocklab.system.git.JGitOperations: Failed to ls remote repository ssh://git@localhost:32843/srv/git/testRepo.git
org.apache.sshd.common.SshException: Session is closed
	at org.apache.sshd.client.session.ClientUserAuthService.preClose(ClientUserAuthService.java:433)
	at org.apache.sshd.common.util.closeable.AbstractCloseable.close(AbstractCloseable.java:94)
	at org.apache.sshd.common.util.closeable.ParallelCloseable.doClose(ParallelCloseable.java:65)
	at org.apache.sshd.common.util.closeable.SimpleCloseable.close(SimpleCloseable.java:63)
	at org.apache.sshd.common.util.closeable.SequentialCloseable$1.operationComplete(SequentialCloseable.java:56)
	at org.apache.sshd.common.util.closeable.SequentialCloseable$1.operationComplete(SequentialCloseable.java:45)
	at org.apache.sshd.common.util.closeable.SequentialCloseable.doClose(SequentialCloseable.java:69)
	at org.apache.sshd.common.util.closeable.SimpleCloseable.close(SimpleCloseable.java:63)
	at org.apache.sshd.common.util.closeable.AbstractInnerCloseable.doCloseImmediately(AbstractInnerCloseable.java:48)
	at org.apache.sshd.common.util.closeable.AbstractCloseable.close(AbstractCloseable.java:95)
	at org.apache.sshd.common.session.helpers.SessionHelper.exceptionCaught(SessionHelper.java:1298)
	at org.apache.sshd.client.session.ClientSessionImpl.exceptionCaught(ClientSessionImpl.java:164)
	at org.apache.sshd.common.session.helpers.AbstractSessionIoHandler.exceptionCaught(AbstractSessionIoHandler.java:53)
	at org.apache.sshd.common.io.nio2.Nio2Session.exceptionCaught(Nio2Session.java:208)
	at org.apache.sshd.common.io.nio2.Nio2Session.handleWriteCycleFailure(Nio2Session.java:590)
	at org.apache.sshd.common.io.nio2.Nio2Session$2.onFailed(Nio2Session.java:548)
	at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$failed$1(Nio2CompletionHandler.java:46)
	at java.base/java.security.AccessController.doPrivileged(AccessController.java:318)
	at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.failed(Nio2CompletionHandler.java:45)
	at java.base/sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:131)
	at java.base/sun.nio.ch.Invoker$2.run(Invoker.java:221)
	at java.base/sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:113)
	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:840)
Wrapped by: org.apache.sshd.common.SshException: Session is closed
	at org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:141)
	at org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:56)
	at org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:35)
	at org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:74)
	at org.eclipse.jgit.transport.sshd.SshdSession.connect(SshdSession.java:172)
	at org.eclipse.jgit.transport.sshd.SshdSession.connect(SshdSession.java:101)
	at org.eclipse.jgit.transport.sshd.SshdSessionFactory.getSession(SshdSessionFactory.java:260)
	... 35 common frames omitted
Wrapped by: org.eclipse.jgit.errors.TransportException: ssh://git@localhost:32843/srv/git/testRepo.git: Session is closed
	at org.eclipse.jgit.transport.sshd.SshdSessionFactory.getSession(SshdSessionFactory.java:267)
	at mocklab.system.git.KeysProvidedSshdSessionFactory.access$getSession$s-1587098576(JGitOperations.kt:429)
	at mocklab.system.git.KeysProvidedSshdSessionFactory$getSession$1.invoke(JGitOperations.kt:448)
	at mocklab.system.git.KeysProvidedSshdSessionFactory$getSession$1.invoke(JGitOperations.kt:448)
	at mocklab.security.keys.InstrumentedKeyEncrypterKt.time$lambda$0(InstrumentedKeyEncrypter.kt:27)
	at io.micrometer.core.instrument.composite.CompositeTimer.recordCallable(CompositeTimer.java:129)
	at mocklab.security.keys.InstrumentedKeyEncrypterKt.time(InstrumentedKeyEncrypter.kt:27)
	at mocklab.system.git.KeysProvidedSshdSessionFactory.getSession(JGitOperations.kt:448)
	at mocklab.system.git.KeysProvidedSshdSessionFactory.getSession(JGitOperations.kt:429)
	at org.eclipse.jgit.transport.SshTransport.getSession(SshTransport.java:107)
	at org.eclipse.jgit.transport.TransportGitSsh$SshFetchConnection.<init>(TransportGitSsh.java:279)
	at org.eclipse.jgit.transport.TransportGitSsh.openFetch(TransportGitSsh.java:152)
	at org.eclipse.jgit.api.LsRemoteCommand.execute(LsRemoteCommand.java:170)
	... 23 common frames omitted

And the other time:

INFO  [2024-03-11 05:06:16,605] req= mocklab.system.git.JGitOperations: Failed to ls remote repository ssh://git@localhost:32839/srv/git/testRepo.git
java.io.IOException: Broken pipe
	at java.base/sun.nio.ch.FileDispatcherImpl.write0(Native Method)
	at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:62)
	at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:132)
	at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:97)
	at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:60)
	at java.base/sun.nio.ch.UnixAsynchronousSocketChannelImpl.implWrite(UnixAsynchronousSocketChannelImpl.java:713)
	at java.base/sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:382)
	at java.base/sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:399)
	at org.apache.sshd.common.io.nio2.Nio2Session.doWriteCycle(Nio2Session.java:534)
	at org.apache.sshd.common.io.nio2.Nio2Session.startWriting(Nio2Session.java:516)
	at org.apache.sshd.common.io.nio2.Nio2Session.writeBuffer(Nio2Session.java:191)
	at org.apache.sshd.common.session.helpers.AbstractSession.doWritePacket(AbstractSession.java:1154)
	at org.apache.sshd.common.session.helpers.KeyExchangeMessageHandler.writePacket(KeyExchangeMessageHandler.java:246)
	at org.apache.sshd.common.session.helpers.AbstractSession.writePacket(AbstractSession.java:1066)
	at org.apache.sshd.common.session.helpers.AbstractSession.sendKexInit(AbstractSession.java:1773)
	at org.apache.sshd.client.session.AbstractClientSession.sendKexInit(AbstractClientSession.java:578)
	at org.apache.sshd.common.session.helpers.AbstractSession.sendKexInit(AbstractSession.java:2664)
	at org.eclipse.jgit.internal.transport.sshd.JGitClientSession.sendKexInit(JGitClientSession.java:193)
	at org.apache.sshd.client.session.AbstractClientSession.initializeKeyExchangePhase(AbstractClientSession.java:319)
	at org.apache.sshd.client.session.ClientSessionImpl.<init>(ClientSessionImpl.java:98)
	at org.eclipse.jgit.internal.transport.sshd.JGitClientSession.<init>(JGitClientSession.java:107)
	at org.eclipse.jgit.internal.transport.sshd.JGitSshClient$JGitSessionFactory.doCreateSession(JGitSshClient.java:415)
	at org.apache.sshd.client.session.SessionFactory.doCreateSession(SessionFactory.java:31)
	at org.apache.sshd.common.session.helpers.AbstractSessionFactory.createSession(AbstractSessionFactory.java:47)
	at org.apache.sshd.common.session.helpers.AbstractSessionIoHandler.sessionCreated(AbstractSessionIoHandler.java:40)
	at org.apache.sshd.common.io.nio2.Nio2Connector$ConnectionCompletionHandler.onCompleted(Nio2Connector.java:216)
	at org.apache.sshd.common.io.nio2.Nio2Connector$ConnectionCompletionHandler.onCompleted(Nio2Connector.java:182)
	at org.apache.sshd.common.io.nio2.Nio2Connector.lambda$connect$1(Nio2Connector.java:111)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	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:840)
Wrapped by: org.apache.sshd.common.SshException: [ssh-connection]: Failed (IOException) to execute: Broken pipe
	at org.apache.sshd.common.future.AbstractSshFuture.lambda$verifyResult$2(AbstractSshFuture.java:146)
	at org.apache.sshd.common.future.AbstractSshFuture.formatExceptionMessage(AbstractSshFuture.java:206)
	at org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:145)
	at org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:56)
	at org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:35)
	at org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:74)
	at org.eclipse.jgit.transport.sshd.SshdSession.connect(SshdSession.java:172)
	at org.eclipse.jgit.transport.sshd.SshdSession.connect(SshdSession.java:101)
	at org.eclipse.jgit.transport.sshd.SshdSessionFactory.getSession(SshdSessionFactory.java:260)
	... 35 common frames omitted
Wrapped by: org.eclipse.jgit.errors.TransportException: ssh://git@localhost:32839/srv/git/testRepo.git: [ssh-connection]: Failed (IOException) to execute: Broken pipe
	at org.eclipse.jgit.transport.sshd.SshdSessionFactory.getSession(SshdSessionFactory.java:267)
	at mocklab.system.git.KeysProvidedSshdSessionFactory.access$getSession$s-1587098576(JGitOperations.kt:429)
	at mocklab.system.git.KeysProvidedSshdSessionFactory$getSession$1.invoke(JGitOperations.kt:448)
	at mocklab.system.git.KeysProvidedSshdSessionFactory$getSession$1.invoke(JGitOperations.kt:448)
	at mocklab.security.keys.InstrumentedKeyEncrypterKt.time$lambda$0(InstrumentedKeyEncrypter.kt:27)
	at io.micrometer.core.instrument.composite.CompositeTimer.recordCallable(CompositeTimer.java:129)
	at mocklab.security.keys.InstrumentedKeyEncrypterKt.time(InstrumentedKeyEncrypter.kt:27)
	at mocklab.system.git.KeysProvidedSshdSessionFactory.getSession(JGitOperations.kt:448)
	at mocklab.system.git.KeysProvidedSshdSessionFactory.getSession(JGitOperations.kt:429)
	at org.eclipse.jgit.transport.SshTransport.getSession(SshTransport.java:107)
	at org.eclipse.jgit.transport.TransportGitSsh$SshFetchConnection.<init>(TransportGitSsh.java:279)
	at org.eclipse.jgit.transport.TransportGitSsh.openFetch(TransportGitSsh.java:152)
	at org.eclipse.jgit.api.LsRemoteCommand.execute(LsRemoteCommand.java:170)
	... 23 common frames omitted

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions