Uploaded image for project: 'Bitbucket Data Center'
  1. Bitbucket Data Center
  2. BSERV-6960

Reduce overly-aggressive error logging for Git HTTP hosting

    XMLWordPrintable

Details

    • Suggestion
    • Resolution: Fixed
    • 3.6.1
    • Git Hosting
    • None
    • We collect Bitbucket feedback from various sources, and we evaluate what we've collected when planning our product roadmap. To understand how this piece of feedback will be reviewed, see our Implementation of New Features Policy.

    Description

      When cloning/pulling from or pushing to a Git repository via HTTP, socket-related errors can result in the server logs including big stack traces related to issues copying hosting input or output. These lines are logged as errors but are actually harmless.

      Stash should log these occurrences, to facilitate debugging, but it should do so in a way that doesn't overemphasizes them.

      For the reference of sysadmins, the three most common errors shown are:

      2014-12-23 14:12:53,425 ERROR [http-nio-127.0.0.1-7990-exec-44] jdoe @XKS5ANx852x115773x3 1.1.1.1,127.0.0.1 "POST /scm/project/repository.git/git-upload-pack HTTP/1.1" c.a.s.i.s.g.p.h.GitSmartExitHandler Request for repo 'repository' of project 'PROJECT' from '10.10.10.10' failed: read process '/usr/libexec/git-core/git-http-backend' caused an exception
2014-12-23 14:12:53,433 DEBUG [http-nio-127.0.0.1-7990-exec-44] jdoe @XKS5ANx852x115773x3 1.1.1.1,127.0.0.1 "POST /scm/project/repository.git/git-upload-pack HTTP/1.1" c.a.s.i.s.g.p.h.GitSmartExitHandler process error: 
com.atlassian.utils.process.ProcessException: Failed to copy SCM hosting process output to response output stream.
	at com.atlassian.stash.web.cgi.CgiOutputHandler.process(CgiOutputHandler.java:43) ~[CgiOutputHandler.class:na]
	at com.atlassian.stash.scm.SummarizingProcessHandler$DelegatingInputStreamHandler.process(SummarizingProcessHandler.java:184) ~[SummarizingProcessHandler$DelegatingInputStreamHandler.class:na]
	at com.atlassian.stash.scm.SummarizingProcessHandler$DelegatingInputStreamHandler.process(SummarizingProcessHandler.java:166) ~[SummarizingProcessHandler$DelegatingInputStreamHandler.class:na]
	at com.atlassian.stash.scm.SummarizingProcessHandler.processOutput(SummarizingProcessHandler.java:92) ~[SummarizingProcessHandler.class:na]
	at com.atlassian.utils.process.ExternalProcessImpl$OutputHandlerRunnable.process(ExternalProcessImpl.java:764) ~[ExternalProcessImpl$OutputHandlerRunnable.class:na]
	at com.atlassian.utils.process.ExternalProcessImpl$AbstractHandlerRunnable.doTask(ExternalProcessImpl.java:677) ~[ExternalProcessImpl$AbstractHandlerRunnable.class:na]
	at com.atlassian.utils.process.LatchedRunnable.run(LatchedRunnable.java:158) ~[LatchedRunnable.class:na]
	at com.atlassian.stash.internal.concurrent.StateTransferringExecutor$StateTransferringRunnable.run(StateTransferringExecutor.java:69) ~[StateTransferringExecutor$StateTransferringRunnable.class:na]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_65]
	at java.lang.Thread.run(Thread.java:745) ~[na:1.7.0_65]
	... 1 frame trimmed
Caused by: org.apache.catalina.connector.ClientAbortException: java.net.SocketTimeoutException
	at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:389) ~[catalina.jar:8.0.9]
	at com.atlassian.stash.web.cgi.BaseCgiHandler.copyStream(BaseCgiHandler.java:36) ~[BaseCgiHandler.class:na]
	at com.atlassian.stash.web.cgi.CgiOutputHandler.process(CgiOutputHandler.java:41) ~[CgiOutputHandler.class:na]
	... 10 common frames omitted
Caused by: java.net.SocketTimeoutException: null
	at org.apache.tomcat.util.net.NioBlockingSelector.write(NioBlockingSelector.java:134) ~[tomcat-coyote.jar:8.0.9]
	... 12 common frames omitted

      2014-05-09 12:09:36,105 ERROR [http-bio-8443-exec-10265] jdoe 729x1804891x4 16w5u1y 1.1.1.1 "GET /scm/project/repository.git/info/refs HTTP/1.1" c.a.s.i.s.g.p.h.GitSmartExitHandler Request for repo 'repository' of project 'PROJECT' from '10.10.10.10' failed: read process '/usr/bin/git http-backend ' caused an exception
2014-05-09 12:09:36,113 DEBUG [http-bio-8443-exec-10265] jdoe 729x1804891x4 16w5u1y 1.1.1.1 "GET /scm/project/repository.git/info/refs HTTP/1.1" c.a.s.i.s.g.p.h.GitSmartExitHandler process error: 
com.atlassian.utils.process.ProcessException: Failed to copy SCM hosting process output to response output stream.
	at com.atlassian.stash.web.cgi.CgiOutputHandler.process(CgiOutputHandler.java:43) ~[stash-scm-common-2.10.1.jar:na]
	at com.atlassian.stash.scm.SummarizingProcessHandler$DelegatingInputStreamHandler.process(SummarizingProcessHandler.java:184) ~[stash-spi-2.10.1.jar:na]
	at com.atlassian.stash.scm.SummarizingProcessHandler$DelegatingInputStreamHandler.process(SummarizingProcessHandler.java:166) ~[stash-spi-2.10.1.jar:na]
	at com.atlassian.stash.scm.SummarizingProcessHandler.processOutput(SummarizingProcessHandler.java:92) ~[stash-spi-2.10.1.jar:na]
	at com.atlassian.utils.process.ExternalProcessImpl$OutputHandlerRunnable.process(ExternalProcessImpl.java:764) ~[atlassian-processutils-1.6.0-m1.jar:na]
	at com.atlassian.utils.process.ExternalProcessImpl$AbstractHandlerRunnable.doTask(ExternalProcessImpl.java:677) ~[atlassian-processutils-1.6.0-m1.jar:na]
	at com.atlassian.utils.process.LatchedRunnable.run(LatchedRunnable.java:158) ~[atlassian-processutils-1.6.0-m1.jar:na]
	at com.atlassian.stash.internal.concurrent.StateTransferringExecutor$StateTransferringRunnable.run(StateTransferringExecutor.java:69) ~[stash-platform-2.10.1.jar:na]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_45]
	at java.lang.Thread.run(Thread.java:744) ~[na:1.7.0_45]
	... 1 frame trimmed
Caused by: org.apache.catalina.connector.ClientAbortException: null
	at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:413) ~[catalina.jar:7.0.47]
	at com.atlassian.stash.web.cgi.BaseCgiHandler.copyStream(BaseCgiHandler.java:36) ~[stash-scm-common-2.10.1.jar:na]
	at com.atlassian.stash.web.cgi.CgiOutputHandler.process(CgiOutputHandler.java:41) ~[stash-scm-common-2.10.1.jar:na]
	... 10 common frames omitted
Caused by: java.net.SocketException: Connection reset

      2014-10-08 08:31:14,816 ERROR [http-nio-127.0.0.1-7990-exec-27] jdoe @1G344EPx511x13780x6 1.1.1.1,127.0.0.1 "POST /scm/project/repository.git/git-receive-pack HTTP/1.1" c.a.s.i.s.g.p.h.GitSmartExitHandler Request for repo 'repository' of project 'PROJECT' from '10.10.10.10' failed: write process '/usr/libexec/git-core/git-http-backend' caused an exception
2014-10-08 08:31:14,821 DEBUG [http-nio-127.0.0.1-7990-exec-27] jdoe @1G344EPx511x13780x6 1.1.1.1,127.0.0.1 "POST /scm/project/repository.git/git-receive-pack HTTP/1.1" c.a.s.i.s.g.p.h.GitSmartExitHandler process error:
com.atlassian.utils.process.ProcessException: java.lang.RuntimeException: Failed to copy request input stream to SCM hosting process input.
        at com.atlassian.utils.process.ExternalProcessImpl.handleHandlerError(ExternalProcessImpl.java:476) ~[ExternalProcessImpl.class:na]
        at com.atlassian.utils.process.ExternalProcessImpl.access$100(ExternalProcessImpl.java:18) ~[ExternalProcessImpl.class:na]
        at com.atlassian.utils.process.ExternalProcessImpl$AbstractHandlerRunnable.onError(ExternalProcessImpl.java:684) ~[ExternalProcessImpl$AbstractHandlerRunnable.class:na]
        at com.atlassian.utils.process.ExternalProcessImpl$InputHandlerRunnable.onError(ExternalProcessImpl.java:743) ~[ExternalProcessImpl$InputHandlerRunnable.class:na]
        at com.atlassian.utils.process.ExternalProcessImpl$AbstractHandlerRunnable.doTask(ExternalProcessImpl.java:679) ~[ExternalProcessImpl$AbstractHandlerRunnable.class:na]
        at com.atlassian.utils.process.LatchedRunnable.run(LatchedRunnable.java:158) ~[LatchedRunnable.class:na]
        at com.atlassian.stash.internal.concurrent.StateTransferringExecutor$StateTransferringRunnable.run(StateTransferringExecutor.java:69) ~[StateTransferringExecutor$StateTransferringRunnable.class:na]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_55]
        at java.lang.Thread.run(Thread.java:744) ~[na:1.7.0_55]
        ... 1 frame trimmed
Caused by: java.lang.RuntimeException: Failed to copy request input stream to SCM hosting process input.
        at com.atlassian.stash.web.cgi.CgiInputHandler.process(CgiInputHandler.java:30) ~[CgiInputHandler.class:na]
        at com.atlassian.stash.scm.SummarizingProcessHandler$DelegatingOutputStreamHandler.process(SummarizingProcessHandler.java:216) ~[SummarizingProcessHandler$DelegatingOutputStreamHandler.class:na]
        at com.atlassian.stash.scm.SummarizingProcessHandler.provideInput(SummarizingProcessHandler.java:96) ~[SummarizingProcessHandler.class:na]
        at com.atlassian.utils.process.ExternalProcessImpl$InputHandlerRunnable.process(ExternalProcessImpl.java:749) ~[ExternalProcessImpl$InputHandlerRunnable.class:na]
        at com.atlassian.utils.process.ExternalProcessImpl$AbstractHandlerRunnable.doTask(ExternalProcessImpl.java:677) ~[ExternalProcessImpl$AbstractHandlerRunnable.class:na]
        ... 5 common frames omitted
Caused by: java.io.IOException: Broken pipe
        at java.io.FileOutputStream.writeBytes(Native Method) ~[na:1.7.0_55]
        at java.io.FileOutputStream.write(FileOutputStream.java:345) ~[na:1.7.0_55]
        at java.io.BufferedOutputStream.write(BufferedOutputStream.java:122) ~[na:1.7.0_55]
        at com.atlassian.stash.web.cgi.BaseCgiHandler.copyStream(BaseCgiHandler.java:36) ~[BaseCgiHandler.class:na]
        at com.atlassian.stash.web.cgi.CgiInputHandler.process(CgiInputHandler.java:28) ~[CgiInputHandler.class:na]
        ... 9 common frames omitted

      Attachments

        Activity

          People

            bturner Bryan Turner (Inactive)
            bturner Bryan Turner (Inactive)
            Votes:
            1 Vote for this issue
            Watchers:
            5 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: