Slow after 2.12 upgrade

[Tomas Hellberg]

After upgrading to 2.12, Gerrit consistently takes about 5 seconds to load /#/q/status:open (/#/q/status:merged still loads with no delay). Is there a way to troubleshoot this? I don't see anything remarkable in the error_log.

[David Ostrovsky]

Am Montag, 8. Februar 2016 13:12:55 UTC+1 schrieb Tomas Hellberg:

After upgrading to 2.12, Gerrit consistently takes about 5 seconds to load /#/q/status:open (/#/q/status:merged still loads with no delay). Is there a way to troubleshoot this?

You can install Javamelody plugin with database monitoring option: [1]

to correlate database activities with requests.

* [1] https://gerrit.googlesource.com/plugins/javamelody/+/master/src/main/resources/Documentation/database-monitoring.md

[Luca Milanesio]

Upgrading from A to B => B=2.12 and what is your source version A?

For sure there is *much more* DB activity (see [1]) and David's suggestion would allow you to understand *IF* this is the problem you are seeing or not.

Luca.

[1] https://groups.google.com/forum/#!searchin/repo-discuss/db$20queries/repo-discuss/m1mvaM0C8zQ/PowDexvnBQAJ

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

---
You received this message because you are subscribed to the Google Groups "Repo and Gerrit Discussion" group.
To unsubscribe from this group and stop receiving emails from it, send an email to repo-discuss...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Tomas Hellberg]

We came from 2.9 and I will try the Javamelody plugin to see what that tells me.

But what bothers me is that querying open changes is slow, while merged changes completes without delay.

[luca.mi...@gmail.com]

What is the Gerrit query that you find very slow? Have you checked the execution times with or without being logged in?

We (DavidO & me) found some SQL optimisation issues and posted some improvements on master.

Luca

Sent from my iPhone

[Patrick Georgi]

We had similar symptoms on review.coreboot.org. The thing that fixed it for us was to run a garbage collection run over all repos (ssh $server gerrit gc --all).

Am Montag, 8. Februar 2016 13:12:55 UTC+1 schrieb Tomas Hellberg:

[Luca Milanesio]

Are you sure that the *same* repos were running very fast in 2.9 and instead they needed a GC in 2.12?

When you upgrade Gerrit version, repos are the same and aren't changed during the init ... unless I am missing something ...

Luca.

[Edwin Kempin]

Also is it slow when you browse changes anonymously or being logged in?

Edwin Kempin

Software Engineer

eke...@google.com

+16502534437

Google Germany GmbH

Dienerstraße 12

80331 München

Geschäftsführer: Matthew Scott Sucherman, Paul Terence Manicle

Registergericht und -nummer: Hamburg, HRB 86891

Sitz der Gesellschaft: Hamburg

Diese E-Mail ist vertraulich. Wenn Sie nicht der richtige Adressat sind, leiten Sie diese bitte nicht weiter, informieren Sie den Absender und löschen Sie die E-Mail und alle Anhänge. Vielen Dank.

      

This e-mail is confidential. If you are not the right addressee please do not forward it, please inform the sender, and please erase this e-mail including any attachments. Thanks.

[Tomas Hellberg]

The slow query is "/#/q/status:open". Or maybe I should say "was", because today the delay is smaller (but still a noticeable difference between merged and open). I will continue to monitor this

[Tomas Hellberg]

Also is it slow when you browse changes anonymously or being logged in?

Only a small fraction of our projects are visible for anonymous users, so I guess that it won't tell us much. Well, maybe if the delay is still there, we can rule out that the delay is related to the users somehow. I will try this when the problem returns (only a small delay right now). 

[Luca Milanesio]

I have to say that the list of open changes differs a lot in terms of execution if you run with:

- anonymous view

- signed-in view

The signed-in view may include additional information that would require to do operations on either the DB or the changes's Repos or both.

The speed-up you noticed after GCing the repo could be related to that.

There is no caching at Change level atm and thus every view would inevitably need to rebuild the info from scratch *WHEN* not found on the Lucene index (signed-in view).

Luca.

[Edwin Kempin]

On Tue, Feb 9, 2016 at 11:44 AM, Luca Milanesio <luca.mi...@gmail.com> wrote:

I have to say that the list of open changes differs a lot in terms of execution if you run with:

- anonymous view

- signed-in view

The signed-in view may include additional information that would require to do operations on either the DB or the changes's Repos or both.

The speed-up you noticed after GCing the repo could be related to that.

There is no caching at Change level atm and thus every view would inevitably need to rebuild the info from scratch *WHEN* not found on the Lucene index (signed-in view).

Luca.

On 9 Feb 2016, at 10:36, Tomas Hellberg <tom...@gmail.com> wrote:

Also is it slow when you browse changes anonymously or being logged in?

Only a small fraction of our projects are visible for anonymous users, so I guess that it won't tell us much.

Actually this might be the reason for the slowness when the list of open changes is accessed anonymously.

Not sure if this is still the case, but earlier the open changes were retrieved in chunks and then in memory the non-visible changes were filtered out, until there were enough changes to fill the page. If now most open changes are filtered out, because they are not visible to anonymous users, a lot of chunks must be loaded to fill the page and that can take a long time.

But as I said, I'm not sure if it's still implemented like this.

 

Well, maybe if the delay is still there, we can rule out that the delay is related to the users somehow. I will try this when the problem returns (only a small delay right now). 

[Sebastian Schuberth]

On Tuesday, February 9, 2016 at 12:20:52 PM UTC+1, Edwin Kempin wrote:

Only a small fraction of our projects are visible for anonymous users, so I guess that it won't tell us much.

Actually this might be the reason for the slowness when the list of open changes is accessed anonymously.

Not sure if this is still the case, but earlier the open changes were retrieved in chunks and then in memory the non-visible changes were filtered out, until there were enough changes to fill the page. If now most open changes are filtered out, because they are not visible to anonymous users, a lot of chunks must be loaded to fill the page and that can take a long time.

But as I said, I'm not sure if it's still implemented like this.

 

We are in fact seeing the same issue. accessing esp. /#/q/status:merged anonymously is super-slow on Gerrit 2.12.5 (we believe it was much faster in Gerrit 2.12.3). Would you have a pointer to the source code where to check whether non-visible changes are filtered out afterwards (instead of only retrieving visible changes in the first place)?

Regards,
Sebastian

[Edwin Kempin]

They are filtered out while the query against the index is executed. The predicate that does the permission check is ChangeIsVisibleToPredicate [1]. It is automatically added to any index query that requires visibility checking [2,3].

[1] https://gerrit.googlesource.com/gerrit/+/master/gerrit-server/src/main/java/com/google/gerrit/server/query/change/ChangeIsVisibleToPredicate.java

[2] https://gerrit.googlesource.com/gerrit/+/master/gerrit-server/src/main/java/com/google/gerrit/server/query/QueryProcessor.java#175

[3] https://gerrit.googlesource.com/gerrit/+/master/gerrit-server/src/main/java/com/google/gerrit/server/query/change/ChangeQueryProcessor.java#82

 

Regards,
Sebastian

--
--
To unsubscribe, email repo-discuss+unsubscribe@googlegroups.com

More info at http://groups.google.com/group/repo-discuss?hl=en

---
You received this message because you are subscribed to the Google Groups "Repo and Gerrit Discussion" group.

To unsubscribe from this group and stop receiving emails from it, send an email to repo-discuss+unsubscribe@googlegroups.com.

[Sebastian Schuberth]

On Fri, Oct 14, 2016 at 10:38 AM, Edwin Kempin <eke...@google.com> wrote:

>> We are in fact seeing the same issue. accessing esp. /#/q/status:merged
>> anonymously is super-slow on Gerrit 2.12.5 (we believe it was much faster in
>> Gerrit 2.12.3). Would you have a pointer to the source code where to check
>> whether non-visible changes are filtered out afterwards (instead of only
>> retrieving visible changes in the first place)?
>
> They are filtered out while the query against the index is executed. The
> predicate that does the permission check is ChangeIsVisibleToPredicate [1].
> It is automatically added to any index query that requires visibility
> checking [2,3].
>
> [1]
> https://gerrit.googlesource.com/gerrit/+/master/gerrit-server/src/main/java/com/google/gerrit/server/query/change/ChangeIsVisibleToPredicate.java
> [2]
> https://gerrit.googlesource.com/gerrit/+/master/gerrit-server/src/main/java/com/google/gerrit/server/query/QueryProcessor.java#175
> [3]
> https://gerrit.googlesource.com/gerrit/+/master/gerrit-server/src/main/java/com/google/gerrit/server/query/change/ChangeQueryProcessor.java#82

Thanks for these!

--
Sebastian Schuberth

[Martin Waitz]

Am Montag, 8. Februar 2016 13:12:55 UTC+1 schrieb Tomas Hellberg:

After upgrading to 2.12, Gerrit consistently takes about 5 seconds to load /#/q/status:open (/#/q/status:merged still loads with no delay). Is there a way to troubleshoot this? I don't see anything remarkable in the error_log.

We are seeing similar issues with 2.12 here (came from 2.11).
Most of the time, access is normal/fast; then suddenly each request takes seconds.
Restarting the server brings it back to normal.

I think it is related to this thread, but I could not validate it yet:
https://groups.google.com/forum/#!topic/repo-discuss/xx8YlPIC97A

[Bassem Rabil]

We are facing similar slow down with 2.12.4. After investigating thread dumps we found that most of threads are stuck in lucene queries which suddenly slow down [1].

Which version of 2.12 you are running ? What does the process queue looks like upon this slow down ? Can you try to paste here snippets from thread dumps when the server is slow.

Thanks

Bassem

[1] https://groups.google.com/forum/#!topic/repo-discuss/CC0BOKgmHEM

[Martin Waitz]

Am Mittwoch, 19. Oktober 2016 16:05:34 UTC+2 schrieb Bassem Rabil:

Which version of 2.12 you are running ? What does the process queue looks like upon this slow down ? Can you try to paste here snippets from thread dumps when the server is slow.

This was both with 2.12.3 and 2.12.4.
Process queue was normal, no extra entries when the machine is slow.
When slow, one Gerrit thread uses 100% CPU for several seconds to complete one request.
While idle, I could observe a much higher context switching rate of the machine.
When the slowness started, then the machine had ~400 switches/s instead of ~200 switches/s (all between Gerrit threads).
I don't have any stack traces at the moment.