Unexpected exceptions while cloning

Hi all,

one of our users reported problems during a stress test involving cloning repositories from our Stash instance. The problem occurred repeatedly on executing the stress test. Here's the users error message:

14:58:35 Started by upstream project "*****" build number 161
14:58:35 originally caused by:
14:58:35 Started by upstream project "***" build number 229
14:58:35 originally caused by:
14:58:35   Started by timer
14:58:35 Building remotely on ******* (docker swarm linux) in workspace /home/***/system/3
14:58:35 > git rev-parse --is-inside-work-tree # timeout=10
14:58:35 Fetching changes from the remote Git repository
14:58:35 > git config remote.origin.url ssh://git@***:7999/***/***.git # timeout=10
14:58:35 Fetching upstream changes from ssh://git@***:7999/***/***.git
14:58:35 > git --version # timeout=10
14:58:35 using GIT_SSH to set credentials 
14:58:35 > git fetch --tags --progress ssh://git@***:7999/***/***.git +refs/heads/*:refs/remotes/origin/*
14:58:36 ERROR: Error fetching remote repo 'origin'
14:58:36 ERROR: Error fetching remote repo 'origin'
14:58:36 Skipping publisher since build result is FAILURE
14:58:36 Recording test results
14:58:36 ERROR: Publisher hudson.tasks.junit.JUnitResultArchiver aborted due to exception
14:58:36 hudson.AbortException: Test reports were found but none of them are new. Did tests run? 
14:58:36 For example, /home/***/fsroot/workspace/***/label/docker/system/3/products/linux-gcc-32-ninja-debug/profiling/***/src/FrancaProfilingService_fidl_test.xml is 16 min old

And here's the corresponding excerpt from the server log:

354217 2015-01-15 14:58:36,300 DEBUG [threadpool:thread-2633054] ASF1HI @Y3BODBx898x4426466x6 10r1j0h 10.34.106.188 SSH - git-upload-pack '/asf/asf.git' c.a.s.i.s.g.p.ssh.GitSshExitHandler Exception from process was:
354218 com.atlassian.utils.process.ProcessException: java.lang.RuntimeException: Failed to copy stream from git process to ssh client
354219     at com.atlassian.utils.process.ExternalProcessImpl.handleHandlerError(ExternalProcessImpl.java:476) ~[ExternalProcessImpl.class:na]
354220     at com.atlassian.utils.process.ExternalProcessImpl.access$100(ExternalProcessImpl.java:18) ~[ExternalProcessImpl.class:na]
354221     at com.atlassian.utils.process.ExternalProcessImpl$AbstractHandlerRunnable.onError(ExternalProcessImpl.java:684) ~[ExternalProcessImpl$AbstractHandlerRunnable.class:na]
354222     at com.atlassian.utils.process.ExternalProcessImpl$AbstractHandlerRunnable.doTask(ExternalProcessImpl.java:679) ~[ExternalProcessImpl$AbstractHandlerRunnable.class:na]
354223     at com.atlassian.utils.process.LatchedRunnable.run(LatchedRunnable.java:158) ~[LatchedRunnable.class:na]
354224     at com.atlassian.utils.process.ExternalProcessImpl$AsynchronousOutputHandlerRunnable.run(ExternalProcessImpl.java:698) ~[ExternalProcessImpl$AsynchronousOutputHandlerRunnable.class:na]
354225     at com.atlassian.stash.internal.concurrent.StateTransferringExecutor$StateTransferringRunnable.run(StateTransferringExecutor.java:69) ~[StateTransferringExecutor$StateTransferringRunnable.class:na]
354226     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_72]
354227     at java.lang.Thread.run(Thread.java:745) ~[na:1.7.0_72]
354228     ... 1 frame trimmed
354229 Caused by: java.lang.RuntimeException: Failed to copy stream from git process to ssh client
354230     at com.atlassian.stash.internal.scm.git.protocol.ssh.GitSshOutputHandler.process(GitSshOutputHandler.java:42) ~[na:na]
354231     at com.atlassian.stash.scm.SummarizingProcessHandler$DelegatingInputStreamHandler.process(SummarizingProcessHandler.java:184) ~[SummarizingProcessHandler$DelegatingInputStreamHandler.class:na]
354232     at com.atlassian.stash.scm.SummarizingProcessHandler$DelegatingInputStreamHandler.process(SummarizingProcessHandler.java:166) ~[SummarizingProcessHandler$DelegatingInputStreamHandler.class:na]
354233     at com.atlassian.stash.scm.SummarizingProcessHandler.processOutput(SummarizingProcessHandler.java:92) ~[SummarizingProcessHandler.class:na]
354234     at com.atlassian.utils.process.ExternalProcessImpl$OutputHandlerRunnable.process(ExternalProcessImpl.java:764) ~[ExternalProcessImpl$OutputHandlerRunnable.class:na]
354235     at com.atlassian.utils.process.ExternalProcessImpl$AbstractHandlerRunnable.doTask(ExternalProcessImpl.java:677) ~[ExternalProcessImpl$AbstractHandlerRunnable.class:na]
354236     ... 6 common frames omitted
354237 Caused by: java.io.InterruptedIOException: null
354238     at java.io.PipedInputStream.awaitSpace(PipedInputStream.java:276) ~[na:1.7.0_72]
354239     at java.io.PipedInputStream.receive(PipedInputStream.java:232) ~[na:1.7.0_72]
354240     at java.io.PipedOutputStream.write(PipedOutputStream.java:149) ~[na:1.7.0_72]
354241     at com.atlassian.stash.internal.scm.git.protocol.ssh.GitSshOutputHandler.process(GitSshOutputHandler.java:34) ~[na:na]
354242     ... 11 common frames omitted
354243 2015-01-15 14:58:36,306 DEBUG [NioProcessor-2]  c.a.s.s.c.s.CachingSshUploadPackRequest ASF/asf Canceling SSH git-upload-pack
354244 2015-01-15 14:58:36,306 DEBUG [NioProcessor-4]  c.a.s.s.c.s.CachingSshUploadPackRequest ASF/asf Canceling SSH git-upload-pack
354245 2015-01-15 14:58:36,321 DEBUG [ssh-scm-request-handler] ASF1HI @Y3BODBx898x4426466x6 10r1j0h 10.34.106.188 SSH - git-upload-pack '/asf/asf.git' c.a.s.s.c.s.CachingSshUploadPackRequest [ASF/asf[509]] Exception encountered while processing a git-upload-pack request
354246 java.io.IOException: Premature EOF detected. Expected 93 bytes, but only 15 were available
354247     at com.atlassian.stash.scm.cache.git.GitUtils.checkBytesRead(GitUtils.java:146) ~[na:na]
354248     at com.atlassian.stash.scm.cache.git.GitUtils.readPacket(GitUtils.java:139) ~[na:na]
354249     at com.atlassian.stash.scm.cache.ssh.UploadPackProxy.copyUntilFlush(UploadPackProxy.java:271) ~[na:na]
354250     at com.atlassian.stash.scm.cache.ssh.UploadPackProxy.streamRefs(UploadPackProxy.java:233) ~[na:na]
354251     at com.atlassian.stash.scm.cache.ssh.CachingSshUploadPackRequest.handleRequest(CachingSshUploadPackRequest.java:151) ~[na:na]
354252     at com.atlassian.stash.internal.ssh.server.SshScmRequestCommandAdapter$ScmRequestRunnable$1.withRequest(SshScmRequestCommandAdapter.java:289) [stash-ssh-3.3.2_1412807880000.jar:na]
354253     at com.atlassian.stash.internal.ssh.server.SshScmRequestCommandAdapter$ScmRequestRunnable$1.withRequest(SshScmRequestCommandAdapter.java:277) [stash-ssh-3.3.2_1412807880000.jar:na]
354254     at com.atlassian.stash.internal.request.DefaultRequestManager.doAsRequest(DefaultRequestManager.java:84) [DefaultRequestManager.class:na]
354255     at com.atlassian.stash.internal.ssh.server.SshScmRequestCommandAdapter$ScmRequestRunnable.run(SshScmRequestCommandAdapter.java:277) [stash-ssh-3.3.2_1412807880000.jar:na]
354256     at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64) [stash-ssh-3.3.2_1412807880000.jar:na]
354257     at com.atlassian.stash.internal.concurrent.StateTransferringExecutor$StateTransferringRunnable.run(StateTransferringExecutor.java:69) [StateTransferringExecutor$StateTransferringRunnable.class:na]
354258     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [na:1.7.0_72]
354259     at java.util.concurrent.FutureTask.run(FutureTask.java:262) [na:1.7.0_72]

 

Can you advise when the root cause of the problem might be and how we can fix the issue?

 

Here are the details on our installation:

  • OS: RHEL6
  • Stash: 3.3.2
  • git: 1.7.11.3

Please let me know if you need further information.

Thanks in advance for your help and cheers,

Georg

4 answers

This widget could not be displayed.

Looks like one of your plugins (something to do with Hudson/Jenkins and/or JUnit) is malfunctioning. You need to either disable it or fix it.

I find your answer misleading. Please take a look at the jenkins log at the beginning:

14:58:36 ERROR: Error fetching remote repo 'origin'
14:58:36 ERROR: Error fetching remote repo 'origin'

Here it says it can't fetch from the repo. Aftewards jenkins fails to parse junit reports because the project was not build due to the above error.

We see this error every now and then during our stress test. It seems like Stash is not always serving request well under load.

Sorry about that, you wrote "Here's the users error message", there was nothing about all this happening in Jenkins. To the point: check the resource usage of Stash while you are running this test. Also, this: https://confluence.atlassian.com/display/STASH/Scaling+Stash might be useful.

I have to agree with Christoph here.

This widget could not be displayed.

Hey Balazs. Our Stash server currently does not have profiling activated. But I found this in the log:

    2015-01-15 14:58:14,928 INFO [hz.hazelcast.HealthMonitor] com.hazelcast.util.HealthMonitor [10.3.133.199]:5701 [bamboo-agent] [3.3-RC3] memory.used=532.8M, memory.free=145.7M, memory.total=678.5M, memory.max=683.0M, memory.used /total=78.52%, memory.used/max=78.00%, load.process=3.00%, load.system=4.00%, load.systemAverage=9.00%, thread.count=229, thread.peakCount=335, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.query.s ize=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operation.size=0, executor.q.priorityOperation.size=0, executor.q.response.size=0, operations.remote.size=1, operations.running.size=0 , proxy.count=1260, clientEndpoint.count=0, connection.active.count=0, connection.count=0

Is this what you're looking for and if yes, do you see a load problem?

I have also activated profiling now. Christoph and I will collaborate to get a picture of the load situation at the time of a crash.

I don't work for Atlassian :) If you cannot spot the problem in the logs yourself, I think you should open a support request and they will help you.

This widget could not be displayed.

We are also experiencing this problem, when running from the commandline in parallel (100x):

git fetch --all
git fetch --tags

 

Then we get the exception in the **/var/atlassian/application-data/stash/log/atlassian-stash.log**

2015-03-09 07:37:51,314 WARN  [ssh-scm-request-handler]  c.a.s.i.s.s.SshScmRequestCommandAdapter Exception encountered handling SSH command 'git-upload-pack '/our/repository.git''
java.io.IOException: Premature EOF detected. Expected 69 bytes, but only -1 were available
        at com.atlassian.stash.scm.cache.git.GitUtils.checkBytesRead(GitUtils.java:146) ~[na:na]
        at com.atlassian.stash.scm.cache.git.GitUtils.readPacket(GitUtils.java:139) ~[na:na]
        at com.atlassian.stash.scm.cache.ssh.UploadPackProxy.copyUntilFlush(UploadPackProxy.java:271) ~[na:na]
        at com.atlassian.stash.scm.cache.ssh.UploadPackProxy.streamRefs(UploadPackProxy.java:233) ~[na:na]
        at com.atlassian.stash.scm.cache.ssh.CachingSshUploadPackRequest.handleRequest(CachingSshUploadPackRequest.java:151) ~[na:na]
        at com.atlassian.stash.internal.ssh.server.SshScmRequestCommandAdapter$ScmRequestRunnable$1.withRequest(SshScmRequestCommandAdapter.java:281) ~[stash-ssh-3.7.0.jar:na]
        at com.atlassian.stash.internal.ssh.server.SshScmRequestCommandAdapter$ScmRequestRunnable$1.withRequest(SshScmRequestCommandAdapter.java:268) ~[stash-ssh-3.7.0.jar:na]
        at com.atlassian.stash.internal.request.DefaultRequestManager.doAsRequest(DefaultRequestManager.java:85) ~[stash-service-impl-3.7.0.jar:na]
        at com.atlassian.stash.internal.ssh.server.SshScmRequestCommandAdapter$ScmRequestRunnable.perform(SshScmRequestCommandAdapter.java:268) [stash-ssh-3.7.0.jar:na]
        at com.atlassian.stash.internal.ssh.server.SshScmRequestCommandAdapter$ScmRequestRunnable.perform(SshScmRequestCommandAdapter.java:238) [stash-ssh-3.7.0.jar:na]
        at com.atlassian.stash.internal.user.DefaultEscalatedSecurityContext.call(DefaultEscalatedSecurityContext.java:60) [stash-service-impl-3.7.0.jar:na]
        at com.atlassian.stash.internal.ssh.server.SshScmRequestCommandAdapter$ScmRequestRunnable.run(SshScmRequestCommandAdapter.java:312) [stash-ssh-3.7.0.jar:na]
        at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64) [stash-ssh-3.7.0.jar:na]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_76]
        at java.lang.Thread.run(Thread.java:745) [na:1.7.0_76]
        ... 26 frames trimmed

 

 

 When running monitoring on the JVM, we see that we have allocated 2gb memory, but stash only uses about 300mb when this happens. The CPU usage is also low.

 

PS: We do have the "Awesome Graphs for Stash" plugin enabled...

 

This widget could not be displayed.

Have you tried the same thing with Awesome Graphs disabled?

Suggest an answer

Log in or Sign up to answer
Community showcase
Published Aug 21, 2018 in Bitbucket

Branch Management with Bitbucket

As a project manager, I have discovered that different developers want to bring their previous branching method with them when they join the team. Some developers are used to performing individual wo...

1,312 views 8 11
Read article

Atlassian User Groups

Connect with like-minded Atlassian users at free events near you!

Find a group

Connect with like-minded Atlassian users at free events near you!

Find my local user group

Unfortunately there are no AUG chapters near you at the moment.

Start an AUG

You're one step closer to meeting fellow Atlassian users at your local meet up. Learn more about AUGs

Groups near you