No push possible via HTTP

[Lars Klonowski]

When performing a push via HTTP, the git Client recieves the following
error:
fatal: The remote end hung up unexpectedly
fatal: The remote end hung up unexpectedly
error: RPC failed; result=22, HTTP code = 500

In the error_log can be found the following:
[2012-04-13 11:36:15,905] WARN org.eclipse.jetty.util.log : /gerrit/p/
testProject/git-receive-pack
java.lang.IllegalStateException: Request has already been cleaned up
at
com.google.gerrit.server.RequestCleanup.add(RequestCleanup.java:42)
at
com.google.gerrit.server.config.RequestScopedReviewDbProvider.get(RequestScopedReviewDbProvider.java:
48)
at
com.google.gerrit.server.config.RequestScopedReviewDbProvider.get(RequestScopedReviewDbProvider.java:
27)
... (rest of the stack trace)

When I debugged into it, I found that Gerrit recieves a GET request
and a POST request. The GET request responds normally, but the POST
request is split in two.
This results in the RequestCleanupFilter calling RequestCleanup.run in
the finally-block of the first POST request and afterwards the
RequestScopedReviewDbProvider tries to perform RequestCleanup.add on
the same object within the second POST request. Then the exception
above is thrown, as the cleanup was already run.

I cannot tell why the POST request seems to be send twice and why both
POST requests use the same RequestCleanup object.
The only quick way I found to help me out of this, was to add a reset
method to RequestCleanup, which sets the boolean ran flag back to
false and which is called in the finally-block of the
RequestCleanupFilter after the run method.

[Shawn Pearce]

What version of Gerrit is this?

The Git clients usually send two POSTs during a push to
/git-receive-pack, one is a small 4 byte probe to see if
authentication is setup right, and the second is the real payload.
These shouldn't be using the same RequsetCleanup instance, those are
supposed to be per-request entities.

[Tobias Kaatz]

On Friday, April 13, 2012 5:40:20 PM UTC+2, Shawn Pearce wrote:

We tried it with 2.2, 2.3-rc0 and 2.3 ... always the same. 

[Lars Klonowski]

Yes, as Tobias said. I encountered this problem with version 2.2.2 at
first.
As I had made some customisations to the code, I asked Tobias to test
if the problem also occurrs in the standard 2.3-rc0 version he uses.
Since this was the case, we tried upgrading the 2.3-rc0 version to
2.3, but this didn't help either.

[Charles-Henri de Boysson]

Hi,

I am experiencing the same issue with push over HTTP: the git client receives a "HTTP 500" error and I can find this in the error_log:

java.lang.IllegalStateException: Request has already been cleaned up

        at com.google.gerrit.server.RequestCleanup.add(RequestCleanup.java:42)

        at com.google.gerrit.server.config.RequestScopedReviewDbProvider.get(RequestScopedReviewDbProvider.java:48)

        at com.google.gerrit.server.config.RequestScopedReviewDbProvider.get(RequestScopedReviewDbProvider.java:27)

        at com.google.inject.BoundProviderFactory.get(BoundProviderFactory.java:58)

        at com.google.inject.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:45)

        at com.google.inject.InjectorImpl.callInContext(InjectorImpl.java:811)

[ ... snip ... ]

I tried with the 2.3 and 2.4-rc0 releases.

Did anyone find a cause / solution for this?

Thanks,

[Lars Klonowski]

On 30 Apr., 03:29, Charles-Henri de Boysson <cea...@gmail.com> wrote:
> Did anyone find a cause / solution for this?

Unfortunately, I didn't find any other solution up to now as the
programmatical hack I described in my first post:

> The only quick way I found to help me out of this, was to add a reset
> method to RequestCleanup, which sets the boolean ran flag back to
> false and which is called in the finally-block of the
> RequestCleanupFilter after the run method.

I still couldn't figure out if this is a general problem or if it
comes from some wrong configuration or system setup.
But it looks like a bug to me, as we encountered this with several
versions on different systems with different configurations.

[Anselm R Garbe]

Thanks for your suggestion. I replicated the suggestion for gerrit 2.3 (as I experienced a similar issue in my setup) and can provide the following diff for those who also experience this annoyance:

$ git diff

diff --git a/gerrit-httpd/src/main/java/com/google/gerrit/httpd/RequestCleanupFilter.java b/gerrit-httpd/src/main/java/com/google/gerrit/httpd/RequestCleanupFilter.java

index 0e6a567..ad0baec 100644

--- a/gerrit-httpd/src/main/java/com/google/gerrit/httpd/RequestCleanupFilter.java

+++ b/gerrit-httpd/src/main/java/com/google/gerrit/httpd/RequestCleanupFilter.java

@@ -53,7 +53,9 @@ class RequestCleanupFilter implements Filter {

     try {

       chain.doFilter(request, response);

     } finally {

-      cleanup.get().run();

+      RequestCleanup rc = cleanup.get();

+      rc.run();

+      rc.reset();

     }

   }

 }

diff --git a/gerrit-server/src/main/java/com/google/gerrit/server/RequestCleanup.java b/gerrit-server/src/main/java/com/google/gerrit/server/RequestCleanup.java

index d836646..94adf6e 100644

--- a/gerrit-server/src/main/java/com/google/gerrit/server/RequestCleanup.java

+++ b/gerrit-server/src/main/java/com/google/gerrit/server/RequestCleanup.java

@@ -58,4 +58,8 @@ public class RequestCleanup implements Runnable {

       }

     }

   }

+

+  public void reset() {

+       ran = false;

+  }

 }

--garbeam

[Lars Klonowski]

I created a bug issue for this problem, maybe there is a less hacky
solution out there:
http://code.google.com/p/gerrit/issues/detail?id=1408

[Thomas Wilhelm]

Maybe it is servlet container dependent? If I'm not wrong you are using Jetty and so do I getting the same error. I also don't think it's a minor problem because it prevents me to use Gerrit at all.

[Vladimir Berezniker]

In my case I am running using the embeded Jetty in the was of the Gerrit master synced today.

From what I can tell RequestScopedReviewDbProvider is bound to be an instance per request, however it is being used across two different requests, therefore it holds reference to RequestCleanup object that has does the cleanup already and is no longer valid.  To me this would indicate a problem either in Guice or in Jetty.  Not quite done debugging this, but maybe someone with more expirience in this area knows what is up meanwhile.

Regards,

Vladimir

On Tuesday, June 19, 2012 1:43:16 PM UTC-4, Hilton Campbell wrote:

I'm having this exact same problem.

[Vladimir Berezniker]

Hi All,

Tracked the manifestation of the problem to the code in the com.google.inject.servlet.ServletScopes.  Within the following block:

 synchronized (request) {

            Object obj = request.getAttribute(name);

            if (NullObject.INSTANCE == obj) {

              return null;

            }

The RequestCleanup instance returned is the value from the previous request.

But I am very confused as to proper solution as both RequestCleanup and CacheBasedWebSession (that keeps currently logged in username) have the same RequestScoped scope, but logically I would think they would have different lifecycles.  Hopefully someone can chime in with where my thinking is going wrong.  Meanwhile I put a horrible hack inside the RequestContextFilter that ensures that stale RequestCleanup object does not stick around:

  for(String attributeName : Collections.list((Enumeration<String>)request.getAttributeNames()))

    {

      if(attributeName.startsWith("Key[type=com.google.gerrit.server.RequestCleanup"))

      {

        request.removeAttribute(attributeName);

      }

    }

Regards,

Vladimir

[Spencer Oliver]

Hi,

Another casualty of this bug, so thought i would post to keep the numbers up.
This is causing major problems for some of our project devs, as they are stuck behind firewalls that only allow http to the outside world.

I would love to help  but i am just a simple embedded c dev, so java is not my strong point.
We are running gerrit 2.4.2 and can provide more details if required.

Cheers
Spen

[lucamilanesio]

Hi Vladimir,

actually I think you are right: the problem IMHO is in the assumption made by Guice-Servlet (V2.0) that two requests have to be "hosted" in two different threads. (GuiceFilter stores the context in a ThreadLocal)

Bug to be fixed then in Guice-Servlet.

@Shawn: do you have any Guice guy around @Mountain View to validate this assumption / analysis ?

Luca.

[Luca Milanesio]

Use of Jetty thread pooling has the side effect of two posts (or get) being hosted at different times but potentially on the same pooled thread :-(

This causes the RequestCleanup failing  for the second get/post, as it was used before in the same pooled thread.

Request scope is not fully respected by Guice then in case of Thread pooling implemented at Servlet container level (very common for prod environments)

It would be nice to have this analysis validated for getting a proper fix (and not hacks) into the mainstream code-base :-)

Luca

--
To unsubscribe, email repo-discuss...@googlegroups.com
More info at http://groups.google.com/group/repo-discuss?hl=en

[Luca Milanesio]

Hi Stephan,

I am worried about all the other points in the code where Gerrit assumed that @Request scoped objects were unique per request ... and unfortunately reused across threads :-(

Your fix make sense to me and should solve this specific problem: I think that for Gerrit 2.5 is the only way to go ... unless Shawn is able to catch some Guice guys in GooglePlex and discuss this issue.

In my case I just removed the 'run' check as we know that this instance could be used multiple times because of thread pooling.

Luca

On 14 Sep 2012, at 04:50, Stephan Heilner <stephan...@gmail.com> wrote:

I was able to fix the problem by building gerrit from source (2.5-rc0) with the following changes:

Add this new method to RequestCleanup.java: 

public void reset() {

ran = false;

}

Then in RequestContextFilter.java (in the finally) change:

} finally {

cleanup.get().run();

}

to:

} finally {

RequestCleanup rc = cleanup.get();

rc.run();

rc.reset();

}

Compile then in your etc/gerrit.config file, add the following:

[receive]

        changeUpdateThreads = 5

That should do the trick!

Stephan

[Philipp Altmann]

Hi Stephan,

would it possible for you to push the change to gerrit for review?

Cheers

Philipp 

Am Freitag, 14. September 2012 05:50:25 UTC+2 schrieb Stephan Heilner:

I was able to fix the problem by building gerrit from source (2.5-rc0) with the following changes:

Add this new method to RequestCleanup.java: 

public void reset() {

ran = false;

}

Then in RequestContextFilter.java (in the finally) change:

} finally {

cleanup.get().run();

}

to:

} finally {

RequestCleanup rc = cleanup.get();

rc.run();

rc.reset();

}

Compile then in your etc/gerrit.config file, add the following:

[receive]

        changeUpdateThreads = 5

That should do the trick!

Stephan

On Monday, September 10, 2012 12:19:00 PM UTC-6, lucamilanesio wrote:

[Vladimir Berezniker]

Hi Luca,

Looking at the code of the GuiceFilter, it seems to be able to cope with same thread being reused, as it stashes the old context until all the processing is completed.  I have not had a chance to debug further, but it did seem like Jetty was not cleaning up attributes in HttpServletRequest on subsequent requests, which resulted in ServletScopes returning objects from the previous request.

I will post more when I get a change to look at it more.

Regards,

Vladimir

The relevant bit of code from GuiceFilter:

public void doFilter(ServletRequest servletRequest,

      ServletResponse servletResponse, FilterChain filterChain)

      throws IOException, ServletException {

    Context previous = localContext.get();

    // Prefer the injected pipeline, but fall back on the static one for web.xml users.

    FilterPipeline filterPipeline = null != injectedPipeline ? injectedPipeline : pipeline;

    try {

      localContext.set(new Context((HttpServletRequest) servletRequest,

          (HttpServletResponse) servletResponse));

      //dispatch across the servlet pipeline, ensuring web.xml's filterchain is honored

      filterPipeline.dispatch(servletRequest, servletResponse, filterChain);

    } finally {

      localContext.set(previous);

[Vladimir Berezniker]

Hi All,

I believe I tracked down the root cause of this issue:

It is the interaction of the code between ProjectQoSFilter and RequestContextFilter.  The relevant events and threads involved in handling git over http request are:

* Threads:

(HTTP-T1)- is the Jetty HTTP request thread that is invoked when original HTTP request is made

(SSH-T1) - is any free thread from SSH thread pool 

(HTTP-T2) - is the Jetty HTTP request thread where the HTTP request is actually process when continuation is resumed. 

* Steps

1. (HTTP-T1) RequestContextFilter.doFilter is invoked, which in turn calls chain.doFilter(request, response);

2. (HTTP-T1) ProjectQoSFilter.doFilter is invoked, which suspends the request and queues task for Ssh thread pool (see step #4)

As there will be 3 threads involed.  I'll go with the route where the original http request thread  (HTTP-T1) unwinds faster than continuation thread (SSH-T1) becomes available. As this is the case where the client will receive the internal server error and makes the explanation simpler. However, strictly speaking the order of the events could be different, due to multithreading.

3. (HTTP-T1) The control returns to RequestContextFilter.doFilter  where RequestCleanup.run is called

4. (SSH-T1) ProjectQoSFilter.TaskThunk.run is executed, it calls Jetty instructing it to resume the continuation and blocks the thread waiting on "lock" object.

5. (HTTP-T2) Jetty executes resumes the original HTTP request.

5a. (HTTP-T2) RequestContextFilter.doFilter is invoked, which in turn calls chain.doFilter(request, response);

5b. (HTTP-T2) ProjectQoSFilter.doFilter is invoked, which detects that this is a resumed continuation and passed execution onto the next filter in the chain.

* This is the code path that triggers the exception

5c. (HTTP-T2) AsyncReceiveCommits.<init> calls ReceiveCommits.Factory.create which requires Guice to call RequestScopedReviewDbProvider.get. This in turn gets a hold of the current instance of RequestCleanup and calls add() on it.  However because RequestContextFilter already invoked RequestCleanup.run in  (step #3), the exception is thrown

5d. (HTTP-T2) ProjectQoSFilter.doFilter final block is invoked which signals "lock" object and returns.

5e. (SSH-T1) TaskThunk.run returns from waiting on "lock" object and completes, thus freeing up the ssh thread

Now onto solutions:

  * The ProjectQoSFilter is bound in the Daemon.createWebInjector method only in case where ssh daemon is enabled. Therefore, one can solve this issue by passing the --disable-sshd switch when starting gerrit. Which is what I used in my case as I have no need for ssh.

As for proper fix, I would defer this to Gerrit experts, but if I had to do it I would either:

* Rearranged the order of filters so that ProjectQoSFilter would execute before the filter responsible for clean up, but this can get tricky as ProjectQoSFilter uses current user information to determine which queue to use, which means that authentication/session filters had to have been executed before. 

Or a more practical approach would be to:

* Alter RequestContextFilter.doFilter clean up logic to prevent it from running cleanup in the thread where request was suspended.

      } finally {

        cleanup.get().run();

      }

to something like:

      } finally {

        final Continuation cont = ContinuationSupport.getContinuation(request); 

        if (!cont.isSuspended()) { 

          cleanup.get().run();

        }

      }

Hope this helps,

Vladimir

[zivkov]

Since the Gerrit server at Eclipse had the same issue, see [1],  I debugged it further and found

out that this error will occur always when Jetty Continuations are used.

However, the continuations are only used when the ProjectQos filter is used and this

filter is only used if the path to the repository starts with "/p".

In my local Gerrit I could push successfully to: http://localhost:8080/test

and I could reproduce the issue when pushing to the http://localhost:8080/p/test

What Vladimir wrote below is true: when the error happens the same instance of

the RequestCleanup will receive call to the run() method from two different threads.

This will, however, only happen when the ProjectQosFilter is involved.

The ProjectQosFilter was introduced as a workaround for Jetty's HTTP Parser crash.

Maybe we don't need it any more?

Saša

[1] https://bugs.eclipse.org/bugs/show_bug.cgi?id=393735

[Shawn Pearce]

On Wed, Nov 28, 2012 at 8:58 AM, zivkov <ziv...@gmail.com> wrote:
> Since the Gerrit server at Eclipse had the same issue, see [1], I debugged
> it further and found
> out that this error will occur always when Jetty Continuations are used.
> However, the continuations are only used when the ProjectQos filter is used
> and this
> filter is only used if the path to the repository starts with "/p".
>
> In my local Gerrit I could push successfully to: http://localhost:8080/test
> and I could reproduce the issue when pushing to the
> http://localhost:8080/p/test
>
> What Vladimir wrote below is true: when the error happens the same instance
> of
> the RequestCleanup will receive call to the run() method from two different
> threads.
> This will, however, only happen when the ProjectQosFilter is involved.
>
> The ProjectQosFilter was introduced as a workaround for Jetty's HTTP Parser
> crash.
> Maybe we don't need it any more?

Actually it was added to schedule git operations on the same thread
pool as the SSH operations, so they all competed fairly for server
resources.

[Saša Živkov]

Is it then intentional that ProjectQoSFilter is used when pushing via "/p/..."

and not used when the "/p/" prefix omitted?

[Luca Milanesio]

We have experienced the problem with either "/p/..." or without it.

It was related to request / thread pooling and typically Servlet containers do pool threads across requests.

Luca.

[Shawn Pearce]

No. This is a bug. ProjectQoSFilter should be using the
GitSmartHttpTools.isGitClient() to test if its a Git request or a
normal web request.