New issue
Advanced search Search tips
Starred by 1 user
Status: Released
Owner:
Closed: Nov 2016
Cc:



Sign in to add a comment
Indexing new changes fails
Project Member Reported by icee...@googlemail.com, Nov 10 2016 Back to list

Affected Version: HEAD of 2.13

What steps will reproduce the problem?
1. Add new change (with Change-Id)
2. restart  gerrit
3. Change is not visible in webui
4. try to reindex the change via ssh:
   Stacktrace as listed below
5. Take gerrit offline and run reinedx offline

Reverting 
https://gerrit-review.googlesource.com/#/c/90631/ fixes this partially:
The changes are still there after a restart, but reindex via ssh yields 'No such change'

Stacktrace
  [2016-11-09 18:29:34,945] [SSH gerrit index changes 18861,1 (pedersen)] ERROR com.google.gerrit.sshd.BaseCommand : Internal server error (user pedersen account 1000000) during gerrit index changes 18861,1
java.lang.NullPointerException
        at com.google.gwtorm.client.KeyUtil.parseFromString(KeyUtil.java:94)
        at com.google.gwtorm.client.IntKey.fromString(IntKey.java:78)
        at com.google.gerrit.reviewdb.client.Change$Id.parse(Change.java:141)
        at com.google.gerrit.sshd.ChangeArgumentParser.changeFromNotesFactory(ChangeArgumentParser.java:101)
        at com.google.gerrit.sshd.ChangeArgumentParser.addChange(ChangeArgumentParser.java:79)
        at com.google.gerrit.sshd.commands.IndexChangesCommand.addChange(IndexChangesCommand.java:45)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.kohsuke.args4j.spi.MethodSetter.addValue(MethodSetter.java:53)
        at org.kohsuke.args4j.spi.StringOptionHandler.parseArguments(StringOptionHandler.java:19)
        at org.kohsuke.args4j.CmdLineParser.parseArgument(CmdLineParser.java:508)
        at com.google.gerrit.util.cli.CmdLineParser.parseArgument(CmdLineParser.java:222)
        at com.google.gerrit.sshd.BaseCommand.parseCommandLine(BaseCommand.java:206)
        at com.google.gerrit.sshd.BaseCommand.parseCommandLine(BaseCommand.java:189)
        at com.google.gerrit.sshd.SshCommand$1.run(SshCommand.java:31)
        at com.google.gerrit.sshd.BaseCommand$TaskThunk.run(BaseCommand.java:442)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at com.google.gerrit.server.git.WorkQueue$Task.run(WorkQueue.java:417)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)



 
Project Member Comment 1 by icee...@googlemail.com, Nov 10 2016
The "no such change" was a fallout from multiple changes with the same change-id.  After deleting the excess changes, indexing via ssh (with 90631 reverted) works fine.
Project Member Comment 2 by luca.mil...@gmail.com, Nov 10 2016
Owner: luca.mil...@gmail.com
It seems that change-id is null, possibly a situation where the parser is going through the list and a null indicates the end of it?

I actually tested with a list of changes and worked fine for me.

What is your exact command line?
gerrit index changes 18861,1 ?
Comment 3 Deleted
Project Member Comment 4 by luca.mil...@gmail.com, Nov 10 2016
The issue is with the ',':
gerrit index changes 18861,1 => NPE
gerrit index changes 18861 => works

The notation 18861,1 indicates a patch-set and not a change.
Is there any reason for indexing a specific patch-set instead of a change? 
Possibly it work working before because of the Lucene index giving a hint for the patch-set as well ... but if you want to rebuild an entry in Lucene does it make sense to use Lucene to get the change?

Even with Lucene it wasn't working properly anyway, but at least didn't crash for NPE.
By looking through Lucene, a reindex of a change with ',' inside its ID would have returned a not found.

I am going to submit a fix to avoid the NPE and give the same behaviour as before: change not found if you include the patch-set with the ','.
Project Member Comment 5 by icee...@googlemail.com, Nov 10 2016
The reindex error seems to be secondary. With  the change applied, new changes are not correctly persisted in the index. There is no stacktrace for that.

And you are correct, it is not that change that causes this problem.
Project Member Comment 6 by luca.mil...@gmail.com, Nov 10 2016
Let me verify this locally.
Project Member Comment 7 by luca.mil...@gmail.com, Nov 10 2016
So, I was able to verify this locally: after restart the change is not there ... but after the SSH gerrit index changes N the index get fixed.

The problem is: how can this regression has been possibly introduced by changing the SSH gerrit index changes command?
Project Member Comment 8 by luca.mil...@gmail.com, Nov 10 2016
Labels: -Priority-3 Priority-1
Escalating to a P1: losing changes from index seems more a P1 to me
Project Member Comment 9 by luca.mil...@gmail.com, Nov 10 2016
Something is telling me that this has to do with the index persistence in a background thread ...

By stopping the VM with a -9, new change is lost from the index.
I need to verify what happens with a graceful shutdown though.

Luca
Project Member Comment 10 by luca.mil...@gmail.com, Nov 10 2016
Labels: -Priority-1 Priority-3
So, I believe that the behavior that is considered "a bug" it is actually the way it works with Lucene :-)

https://gerrit-documentation.storage.googleapis.com/Documentation/2.13.2/config-gerrit.html#index.name.commitWithin

Default commit time is 5', that means if you shut down brutally Gerrit ... you lose the last 5' of changes.

This has nothing to do with my fix on the SSH gerrit index changes command.

Reverting the Priority back to P3.
Project Member Comment 11 by luca.mil...@gmail.com, Nov 11 2016
I tried to configure 1s as flush time for Lucene as follows:

[index "changes_open"]
	commitWithin = 1 sec

[index "changes_closed"]
	commitWithin = 1 sec


Now works like a charm: I confirm then that the behavior that you see and you have attributed as regression to my change ... it is actually the expected way that Gerrit 2.13 should work :-)

I'll keep then this bug as a NPE caused by an invalid change ID.
Project Member Comment 12 by icee...@googlemail.com, Nov 11 2016
Yes, it seems a likely cause. Probably the time with the reverted change was shorter in my case. 
Project Member Comment 13 by icee...@googlemail.com, Nov 11 2016
Something still seems incorrect behaviour in this case, from the doc:

"If negative, commitWithin is disabled. Changes are flushed to disk when the in-memory buffer fills, but only committed and guaranteed to be synced to disk when the process finishes." 

I would assume that this also holds for a normal graceful shutdown. And with a negative commitWithin, the commit is lost from the index.

With commitWithin = -1:
[gvenv] pedersen@resiopc3:src/tmp/gerrittest> bin/gerrit.sh start
Starting Gerrit Code Review: cd -
OK
[gvenv] pedersen@resiopc3:src/tmp/gerrittest> cd -
[gvenv] pedersen@resiopc3:src/tmp/Test2> vi README
[gvenv] pedersen@resiopc3:src/tmp/Test2> git add README
[gvenv] pedersen@resiopc3:src/tmp/Test2> git commit -m 'Test commit'
[master 854cc7a] Test commit
 1 file changed, 1 deletion(-)
[gvenv] pedersen@resiopc3:src/tmp/Test2> git push origin HEAD:refs/for/master
Counting objects: 3, done.
Delta compression using up to 4 threads.
Compressing objects: 100% (3/3), done.
Writing objects: 100% (3/3), 334 bytes | 0 bytes/s, done.
Total 3 (delta 2), reused 0 (delta 0)
remote: Resolving deltas: 100% (2/2)
remote: Processing changes: new: 1, refs: 1, done    
remote: 
remote: New Changes:
remote:   http://localhost:8088/18870 Test commit
remote: 
To ssh://pedersen@localhost:29418/Test2
 * [new branch]      HEAD -> refs/for/master
[gvenv] pedersen@resiopc3:src/tmp/Test2> cd -
>>>>>>>>>>> Change is visible in UI
[gvenv] pedersen@resiopc3:src/tmp/gerrittest> bin/gerrit.sh stop
Stopping Gerrit Code Review: OK
[gvenv] pedersen@resiopc3:src/tmp/gerrittest> bin/gerrit.sh start
Starting Gerrit Code Review: OK
>>>>>>>>>>> Change is not visible
[gvenv] pedersen@resiopc3:src/tmp/gerrittest> ssh localhost -p29418 gerrit index changes 18870
fatal: "18870" no such change
[gvenv] pedersen@resiopc3:src/tmp/gerrittest> 




Project Member Comment 14 by luca.mil...@gmail.com, Nov 11 2016
It would be better to open a separate issue for that.
The NPE is fixed.
Project Member Comment 15 by icee...@googlemail.com, Nov 11 2016
Done: #4919
Labels: FixedIn-2.13.3
Status: Submitted
Status: Released
Sign in to add a comment