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:
Please let me know if you need further information.
Thanks in advance for your help and cheers,
Georg
Have you tried the same thing with Awesome Graphs disabled?
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...
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
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?
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
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.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
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.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
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.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
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.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
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.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
Online forums and learning are now in one easy-to-use experience.
By continuing, you accept the updated Community Terms of Use and acknowledge the Privacy Policy. Your public name, photo, and achievements may be publicly visible and available in search engines.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.