Commit "Perform change update on multiple threads" c545c0901241314190cac02a24aa95f831dd0572 on master breaks push over http

[Vladimir Berezniker]

Hi All,

When testing latest master we ran into issue where push to gerrit was rejected with internal server error.  I traced this down to commit "Perform change update on multiple threads" c545c0901241314190cac02a24aa95f831dd0572.  Commit introduces the Callable wrapper voa ServletScopes which has a check to ensure that the call does not happen on the HTTP thread, resulting in exception:

java.lang.IllegalStateException: Cannot continue request in the same thread as a HTTP request! 

Reverting this commit allowed gerrit to work again.  Please see the full stack trace below.  

Thank you,

Vladimir

com.google.gwtorm.server.OrmException: Error updating database

        at com.google.gerrit.server.git.ReceiveCommits$1.apply(ReceiveCommits.java:226)

        at com.google.gerrit.server.git.ReceiveCommits$1.apply(ReceiveCommits.java:220)

        at com.google.common.util.concurrent.Futures$MappingCheckedFuture.mapException(Futures.java:1215)

        at com.google.common.util.concurrent.AbstractCheckedFuture.checkedGet(AbstractCheckedFuture.java:85)

        at com.google.gerrit.server.git.ReceiveCommits.insertChangesAndPatchSets(ReceiveCommits.java:675)

        at com.google.gerrit.server.git.ReceiveCommits.processCommands(ReceiveCommits.java:521)

        at com.google.gerrit.server.git.AsyncReceiveCommits$Worker.run(AsyncReceiveCommits.java:90)

        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)

        at com.google.gerrit.server.util.RequestScopePropagator$5.call(RequestScopePropagator.java:196)

        at com.google.gerrit.server.util.RequestScopePropagator$4.call(RequestScopePropagator.java:174)

        at com.google.inject.servlet.ServletScopes$3.call(ServletScopes.java:194)

        at com.google.gerrit.server.util.RequestScopePropagator$1.call(RequestScopePropagator.java:81)

        at com.google.gerrit.server.util.RequestScopePropagator$2.run(RequestScopePropagator.java:113)

        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)

        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)

        at java.util.concurrent.FutureTask.run(FutureTask.java:138)

        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)

        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)

        at com.google.gerrit.server.git.WorkQueue$Task.run(WorkQueue.java:337)

        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

        at java.lang.Thread.run(Thread.java:619)

Caused by: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Cannot continue request in the same thread as a HTTP request!

        at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)

        at java.util.concurrent.FutureTask.get(FutureTask.java:83)

        at com.google.common.util.concurrent.ForwardingFuture.get(ForwardingFuture.java:63)

        at com.google.common.util.concurrent.AbstractCheckedFuture.checkedGet(AbstractCheckedFuture.java:78)

        ... 18 more

Caused by: java.lang.IllegalStateException: Cannot continue request in the same thread as a HTTP request!

        at com.google.inject.internal.util.$Preconditions.checkState(Preconditions.java:142)

        at com.google.inject.servlet.ServletScopes$3.call(ServletScopes.java:187)

        at com.google.gerrit.server.util.RequestScopePropagator$1.call(RequestScopePropagator.java:81)

        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)

        at java.util.concurrent.FutureTask.run(FutureTask.java:138)

        at com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService.execute(MoreExecutors.java:253)

        at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:56)

        at com.google.gerrit.server.git.ReceiveCommits$CreateRequest.insertChange(ReceiveCommits.java:1291)

        at com.google.gerrit.server.git.ReceiveCommits.insertChangesAndPatchSets(ReceiveCommits.java:671)

[Vladimir Berezniker]

Hi Hilton,

I think the reason you are no longer seeing the issues is due to:

[receiver]

changeUpdateThreads = 5

setting.  This avoids hitting the bug as the processing is not done on HTTP thread any more.  The original bug is still there though.  

Regards,

Vladimir

On Thursday, September 13, 2012 5:11:04 PM UTC-4, Hilton Campbell wrote:

We had the exact same issue on our server. Thanks to your pinpointing the offending commit, Vladimir, we were able to find a workaround.

First, as with an earlier version of Gerrit, we added the following method to RequestCleanup.java:

public void reset() {
    ran = false;
}

Then in the RequestContextFilter.java we changed:

try {
    chain.doFilter(request, response);
} finally {
    cleanup.get().run();
}

to:

try {
    chain.doFilter(request, response);
} finally {
    RequestCleanup rc = cleanup.get();
    rc.run();
    rc.reset();
}

Finally, we set the following value in our gerrit.config:

[receiver]

changeUpdateThreads = 5

The setting is documented in the same commit (https://gerrit.googlesource.com/gerrit/+/c545c0901241314190cac02a24aa95f831dd0572%5E%21/#F0). By default it is 1. Presumably by changing it to a larger value, we avoid reusing the same thread.

Thanks,

Hilton

[Vladimir Berezniker]

Hi Jason,

Is the error consistent or occasional? Please post the stack trace from error_log file.

Thank you,

Vladimir

On Thursday, October 4, 2012 5:53:44 PM UTC-4, Jason Huntley wrote:

We also encountered the same issue. I tried setting the following in the git config and the problem didn't go away:

[receiver]

changeUpdateThreads = 5

Other ideas?

[Jason Huntley]

Hi Vladimir,

Here's my stack trace:

[2012-10-04 17:37:59,109] ERROR com.google.gerrit.server.git.ReceiveCommits : Can't insert changes for fade

com.google.gwtorm.server.OrmException: Error updating database
	at com.google.gerrit.server.git.ReceiveCommits$1.apply(ReceiveCommits.java:226)
	at com.google.gerrit.server.git.ReceiveCommits$1.apply(ReceiveCommits.java:220)
	at com.google.common.util.concurrent.Futures$MappingCheckedFuture.mapException(Futures.java:1215)
	at com.google.common.util.concurrent.AbstractCheckedFuture.checkedGet(AbstractCheckedFuture.java:85)
	at com.google.gerrit.server.git.ReceiveCommits.insertChangesAndPatchSets(ReceiveCommits.java:675)
	at com.google.gerrit.server.git.ReceiveCommits.processCommands(ReceiveCommits.java:521)
	at com.google.gerrit.server.git.AsyncReceiveCommits$Worker.run(AsyncReceiveCommits.java:90)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
	at com.google.gerrit.server.util.RequestScopePropagator$5.call(RequestScopePropagator.java:196)
	at com.google.gerrit.server.util.RequestScopePropagator$4.call(RequestScopePropagator.java:174)
	at com.google.inject.servlet.ServletScopes$3.call(ServletScopes.java:194)
	at com.google.gerrit.server.util.RequestScopePropagator$1.call(RequestScopePropagator.java:81)
	at com.google.gerrit.server.util.RequestScopePropagator$2.run(RequestScopePropagator.java:113)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)

	at com.google.gerrit.server.git.WorkQueue$Task.run(WorkQueue.java:337)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

	at java.lang.Thread.run(Thread.java:662)

Caused by: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Cannot continue request in the same thread as a HTTP request!
	at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
	at java.util.concurrent.FutureTask.get(FutureTask.java:83)
	at com.google.common.util.concurrent.ForwardingFuture.get(ForwardingFuture.java:63)
	at com.google.common.util.concurrent.AbstractCheckedFuture.checkedGet(AbstractCheckedFuture.java:78)
	... 18 more
Caused by: java.lang.IllegalStateException: Cannot continue request in the same thread as a HTTP request!
	at com.google.inject.internal.util.$Preconditions.checkState(Preconditions.java:142)
	at com.google.inject.servlet.ServletScopes$3.call(ServletScopes.java:187)
	at com.google.gerrit.server.util.RequestScopePropagator$1.call(RequestScopePropagator.java:81)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService.execute(MoreExecutors.java:253)
	at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:56)
	at com.google.gerrit.server.git.ReceiveCommits$CreateRequest.insertChange(ReceiveCommits.java:1291)
	at com.google.gerrit.server.git.ReceiveCommits.insertChangesAndPatchSets(ReceiveCommits.java:671)

	... 17 more

[Vladimir Berezniker]

Hi Jason,

Line 

at com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService.execute(MoreExecutors.java:253) 

would implie that gerrit is not using the configuration option you mentioned and still runs in HTTP thread mode, rather than using dedicated 5 thread pool.

Regards,

Vladimir

[Jason Huntley]

Here's my config. Am i missing something here?

$ git config -f /c/development/gitserver/gerrit/config/etc/gerrit.config -l

gerrit.basepath=C:\development\gitserver\repository\ha

gerrit.canonicalweburl=http://review.houghtonassociates.com/

gitweb.cgi=C:\development\gitserver\Git\share\gitweb\gitweb.cgi

gitweb.url=https://gitweb.houghtonassociates.com

gitweb.type=custom

gitweb.project=?p=${project};a=summary

gitweb.revision=?p=${project};a=commit;h=${commit}

gitweb.branch=?p=${project};a=shortlog;h=${branch}

gitweb.filehistory=?p=${project};a=history;hb=${branch};f=${file}

download.scheme=http

database.type=POSTGRESQL

database.hostname=sputnik.hacorp.local

database.database=reviewdb

database.username=gerrit2

auth.type=LDAP

ldap.sslverify=true

ldap.server=ldaps://sputnik.hacorp.local:636

ldap.username=CN=Administrator,CN=Users,DC=hacorp,DC=local

ldap.accountbase=CN=Users,DC=hacorp,DC=local

ldap.accountpattern=(&(objectClass=person)(sAMAccountName=${username})(memberOf=

CN=source-control,CN=Users,DC=hacorp,DC=local))

ldap.accountfullname=displayName

ldap.accountemailaddress=mail

ldap.accountsshusername=sAMAccountName

ldap.groupbase=CN=Users,DC=hacorp,DC=local

ldap.groupmemberpattern=(sAMAccountName=${username})

ldap.groupname=cn

sendemail.enable=true

sendemail.smtpserver=127.0.0.1

sendemail.smtpserverport=25

container.user=Administrator

container.javahome=C:\Program Files\Java\jre6

sshd.listenaddress=*:29418

cache.directory=cache

httpd.listenurl=http://*:8080/

receiver.changeupdatethreads=5

[Jason Huntley]

Ok, i found the problem. The initial references have a typeo. Take the 'r' off the reciever section:

[receive]

changeUpdateThreads = 5

[Vladimir Berezniker]

The section should be receive rather than  receiver (no r at the end)