Description Luca Milanesio 2020-12-19 19:12:02 EST

The problem has been noticed when using JGit with Gerrit v3.1.10.

When a client starts a Git clone (git/https) and breaks the connection, the Gerrit logs contains the following exception:

java.lang.IllegalStateException: Timer already terminated
        at org.eclipse.jgit.util.io.InterruptTimer$AlarmState.begin(InterruptTimer.java:208)
        at org.eclipse.jgit.util.io.InterruptTimer.begin(InterruptTimer.java:125)
        at org.eclipse.jgit.util.io.TimeoutOutputStream.beginWrite(TimeoutOutputStream.java:160)
        at org.eclipse.jgit.util.io.TimeoutOutputStream.write(TimeoutOutputStream.java:124)
        at org.eclipse.jgit.transport.UploadPack$ResponseBufferedOutputStream.write(UploadPack.java:2425)
        at org.eclipse.jgit.transport.SideBandOutputStream.writeBuffer(SideBandOutputStream.java:174)
        at org.eclipse.jgit.transport.SideBandOutputStream.flushBuffer(SideBandOutputStream.java:127)
        at org.eclipse.jgit.transport.SideBandOutputStream.flush(SideBandOutputStream.java:133)
        at org.eclipse.jgit.transport.UploadPack$SideBandErrorWriter.writeError(UploadPack.java:2458)
        at org.eclipse.jgit.transport.UploadPack.upload(UploadPack.java:805)
        at org.eclipse.jgit.http.server.UploadPackServlet.lambda$doPost$0(UploadPackServlet.java:215)
        at org.eclipse.jgit.http.server.UploadPackServlet.defaultUploadPackHandler(UploadPackServlet.java:237)
        at org.eclipse.jgit.http.server.UploadPackServlet.doPost(UploadPackServlet.java:231)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:661)

However, I would have expected to see the real problem that happened traced in the logs.

By adding the following code to JGit:
	public void upload(InputStream input, OutputStream output,
			@Nullable OutputStream messages) throws IOException {
		try {
			uploadWithExceptionPropagation(input, output, messages);
		} catch (ServiceMayNotContinueException err) {
			if (!err.isOutput() && err.getMessage() != null) {
				try {
					errOut.writeError(err.getMessage());
				} catch (IOException e) {
					err.addSuppressed(e);
					throw err;
				}
				err.setOutput();
			}
			throw err;
		} catch (IOException | RuntimeException | Error err) {
			if (rawOut != null) {
				String msg = err instanceof PackProtocolException
						? err.getMessage()
						: JGitText.get().internalServerError;
				try {
					log.error(msg, err);
					errOut.writeError(msg);
				} catch (IOException e) {
					err.addSuppressed(e);
					throw err;
				}
				throw new UploadPackInternalServerErrorException(err);
			}
			throw err;
		}
	}


I then see reported the original *real* problem:

[2020-12-19 14:12:30,804] [HTTP POST /a/a/REDACTED1/git-upload-pack (apipeline from 17.222.32.88)] ERROR org.eclipse.jgit.transport.UploadPack : internal server error
org.eclipse.jetty.io.EofException
        at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:279)
        at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422)
        at org.eclipse.jetty.io.WriteFlusher.completeWrite(WriteFlusher.java:378)
        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:119)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:298)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:773)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:905)
        at java.lang.Thread.run(Thread.java:748)
Caused by: java.io.IOException: Connection reset by peer
        at sun.nio.ch.FileDispatcherImpl.writev0(Native Method)
        at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:51)
        at sun.nio.ch.IOUtil.write(IOUtil.java:148)
        at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:501)
        at java.nio.channels.SocketChannel.write(SocketChannel.java:502)
        at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:273)
        ... 11 more

I do not understand why JGit is trying to notify to the client that the connection has been reset: how can the client be reached if the connection has just been reset?