Gerrit 2.0.23 Unexpected Restart
Nicholas Mucci
I noticed that Gerrit unexpectedly restarted this morning after I made
a change to the database. I needed to change the name of an LDAP
group, but since the name column in account_groups is set as varchar
(40), I had to change that first. So, I did this:
ALTER TABLE account_groups ALTER COLUMN name type varchar(255);
Then I changed the name of the group:
UPDATE account_groups SET name = 'group_name_longer_than_40chars'
WHERE name = 'group_name_less_than_40chars';
I'm not sure if the restart happened immediately after the ALTER
command, but here's what got written to the logs:
2010-01-21 09:52:04,663::WARN :
com.google.gerrit.server.ldap.LdapRealm - Group
"group_name_less_than_40chars" not found in LDAP.
2010-01-21 09:52:10.576::INFO: Shutdown hook executing
2010-01-21 09:52:10.577::INFO: Graceful shutdown
SelectChann...@127.0.0.1:8081
2010-01-21 09:52:10.880::INFO: Graceful shutdown
org.mortbay.jetty.handler.ContextHandler@781f6226{/javadoc,file:/data/
gerrit/jetty/javadoc/}
2010-01-21 09:52:10.880::INFO: Graceful shutdown
org.mortbay.jetty.webapp.WebAppContext@24f9fdc{/test-jndi,/data/gerrit/
jetty/contexts/test-jndi.d}
2010-01-21 09:52:10.880::INFO: Graceful shutdown
org.mortbay.jetty.webapp.WebAppContext@2c78bc3b{/code-review,jar:file:/
data/gerrit/jetty/webapps/gerrit.war!/}
2010-01-21 09:52:10.881::INFO: Graceful shutdown
org.mortbay.jetty.webapp.WebAppContext@7737627b{/cometd,jar:file:/data/
gerrit/jetty/webapps/cometd.war!/}
2010-01-21 09:52:10.881::INFO: Graceful shutdown
org.mortbay.jetty.webapp.WebAppContext@5522b662{/test-jaas,file:/data/
gerrit/jetty/webapps/test-jaas/}
2010-01-21 09:52:10.881::INFO: Graceful shutdown
org.mortbay.jetty.webapp.WebAppContext@59f40798{/test,file:/data/
gerrit/jetty/webapps/test/}
2010-01-21 09:52:13,336::INFO :
com.google.gerrit.server.ssh.SshDaemon - Stopped Gerrit SSHD
2010-01-21 09:52:13,506::ERROR:
com.google.gerrit.server.cache.SelfPopulatingCache - Cannot lookup
group_foo in "groups"
java.lang.IllegalStateException: The groups Cache is not alive.
at net.sf.ehcache.Cache.checkStatus(Cache.java:1705)
at net.sf.ehcache.Cache.remove(Cache.java:1452)
at net.sf.ehcache.Cache.remove(Cache.java:1390)
at net.sf.ehcache.Cache.remove(Cache.java:1348)
at com.google.gerrit.server.cache.ProxyEhcache.remove
(ProxyEhcache.java:277)
at net.sf.ehcache.constructs.blocking.BlockingCache.put
(BlockingCache.java:502)
at net.sf.ehcache.constructs.blocking.SelfPopulatingCache.get
(SelfPopulatingCache.java:86)
at com.google.gerrit.server.cache.SelfPopulatingCache.get
(SelfPopulatingCache.java:107)
at com.google.gerrit.server.account.GroupCacheImpl.lookup
(GroupCacheImpl.java:135)
at com.google.gerrit.server.ldap.LdapRealm.queryForGroups
(LdapRealm.java:393)
at com.google.gerrit.server.ldap.LdapRealm.queryForGroups
(LdapRealm.java:353)
at com.google.gerrit.server.ldap.LdapRealm.access$000
(LdapRealm.java:66)
at com.google.gerrit.server.ldap.LdapRealm$1.createEntry
(LdapRealm.java:140)
at com.google.gerrit.server.ldap.LdapRealm$1.createEntry
(LdapRealm.java:136)
at com.google.gerrit.server.cache.SelfPopulatingCache
$1.createEntry(SelfPopulatingCache.java:60)
at net.sf.ehcache.constructs.blocking.SelfPopulatingCache.get
(SelfPopulatingCache.java:71)
at com.google.gerrit.server.cache.SelfPopulatingCache.get
(SelfPopulatingCache.java:107)
at com.google.gerrit.server.ldap.LdapRealm.groups
(LdapRealm.java:344)
at com.google.gerrit.server.IdentifiedUser.getEffectiveGroups
(IdentifiedUser.java:162)
at com.google.gerrit.server.project.ProjectControl.canPerform
(ProjectControl.java:189)
at com.google.gerrit.server.project.ProjectControl.isVisible
(ProjectControl.java:116)
at com.google.gerrit.server.project.ChangeControl.isVisible
(ChangeControl.java:115)
at com.google.gerrit.server.mail.OutgoingEmail.isVisibleTo
(OutgoingEmail.java:603)
at com.google.gerrit.server.mail.OutgoingEmail.add
(OutgoingEmail.java:596)
at com.google.gerrit.server.mail.OutgoingEmail.add
(OutgoingEmail.java:507)
at com.google.gerrit.server.mail.ReplacePatchSetSender.init
(ReplacePatchSetSender.java:62)
at com.google.gerrit.server.mail.OutgoingEmail.send
(OutgoingEmail.java:155)
at com.google.gerrit.server.ssh.commands.Receive.doReplace
(Receive.java:1095)
at com.google.gerrit.server.ssh.commands.Receive.doReplaces
(Receive.java:867)
at com.google.gerrit.server.ssh.commands.Receive.access$300
(Receive.java:102)
at com.google.gerrit.server.ssh.commands.Receive$1.onPreReceive
(Receive.java:205)
at org.spearce.jgit.transport.ReceivePack.executeCommands
(ReceivePack.java:748)
at org.spearce.jgit.transport.ReceivePack.service
(ReceivePack.java:503)
at org.spearce.jgit.transport.ReceivePack.receive
(ReceivePack.java:452)
at com.google.gerrit.server.ssh.commands.Receive.runImpl
(Receive.java:239)
at
com.google.gerrit.server.ssh.commands.AbstractGitCommand.service
(AbstractGitCommand.java:61)
at
com.google.gerrit.server.ssh.commands.AbstractGitCommand.access$100
(AbstractGitCommand.java:29)
at com.google.gerrit.server.ssh.commands.AbstractGitCommand
$1.run(AbstractGitCommand.java:45)
at com.google.gerrit.server.ssh.BaseCommand$2.run
(BaseCommand.java:253)
There were several instances of the last illegal state exception where
com.google.gerrit.server.cache.SelfPopulatingCache couldn't look up
random groups in LDAP, even those that weren't related to or specified
as groups in Gerrit.
Gerrit started back up immediately and seems to be working fine now.
I'm curious though, is this expected behavior given the change I made
to the database? Thanks for any insight that can be provided.
-Nick
Shawn Pearce
> I noticed that Gerrit unexpectedly restarted this morning after I made
> a change to the database. I needed to change the name of an LDAP
> group, but since the name column in account_groups is set as varchar
> (40), I had to change that first. So, I did this:
Your database changes shouldn't have triggered a Jetty restart like
your logs show. Something else external caused Jetty to bounce.
No clue. Another admin restarted the process?
> 2010-01-21 09:52:10.576::INFO: Shutdown hook executing
This line means Jetty received a SIGINT or SIGTERM from the host
operating system and is tearing down the JVM in response to that
signal. So the restart wasn't started by Gerrit, or any of its
database interface code.
> com.google.gerrit.server.cache.SelfPopulatingCache - Cannot lookup
> group_foo in "groups"
> java.lang.IllegalStateException: The groups Cache is not alive.
This happened because there were still requests being processed
during the shutdown. The caches were told to stop doing lookups,
but application worker threads were still trying to issue a get
for a group's information. Since the cache isn't serving back any
results, it throws an exception.
Unfortunately this is somewhat normal for a shutdown of a Gerrit
server that is actively serving user requests.
Nicholas Mucci
admin tasks on Gerrit, its not impossible. There's a very small
number of people who could have restarted it, so I'll talk to them.
If nobody else was on the box, I'll let you know.
-Nick
On Jan 21, 3:34 pm, Shawn Pearce <s...@google.com> wrote: