Debugging a slow CATMAID interface

[Daniel Witvliet]

Hello there!

We recently did a major overhaul to our server, which included installing new hardware, reinstalling the OS (Ubuntu 14.04 -> 18.04), updating an old CATMAID instance (2017.05.17 -> 2018.11.09), merging two CATMAID databases, installing SSL, and moving the server to a new building/network. Everything was installed and optimized as suggested by the official documentation, served by Nginx/uWSGI.

Everything seems to work well and is very fast with one exception: the skeleton tracing is occasionally slow to update in the main view. When going to a new section or panning/zooming the view, the image tiles update almost instantly, but the tracing often lags a second or two behind. The issue is most evident when panning (see attached video1), but also often happens in other cases (see attached video2). However, the issue is not always present; see attached video3 where the first update is slow (tiles load much faster than tracing), but the second update is fast (tracing loads before or at the same time as tiles); neither requests are cached.

We have no good ideas on how to approach this issue. It seems to be an issue with the interface rather than the database, since the HTTP requests fetching the tracing data are always fast (<100ms). Instead, there seems to be a delay in sending the request, which results in the lag (e.g. see video2). However, with all of our recent changes to the server, we are simply not sure where to start debugging.

Do you have any ideas on how we might approach this issue?

[Albert Cardona]

Hi Daniel,

Did you run, in psql, "vacuum analyze", and also maybe "vacuum full"? At least the first one should make a difference.

Albert

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

<video1_pan.mp4>

<video2_next_slow.mp4>

<video3_next_slow_fast.mp4>

[Daniel Witvliet]

Hi Albert,

Thanks for the reply! I tried running both, but no significant change.

The issue seems to be more dependent on dragging/panning than we first thought. If we simply go through the sections without any dragging, everything is working as fast as expected. However, as soon as the view is dragged, there is a time period of ~1 second in which the tracing is waiting to for the time to end before sending a request to update the layout. Even just a single middle-click is enough to trigger a request that starts the unresponsive time period. Any other request (e.g. zoom in/out or going from one section to the next) is fine, as long as it isn't triggered in this unresponsive time period. 

I have attached another video that shows the behavior. The first four requests are fast because no dragging is done. The next two requests are slow because they are initiated immediately after a middle-click. Then, another four requests are fast because no dragging is done. As far as we can tell, all requests are identical (same parameters) with the exception of (z1, z2) for every other request.

To unsubscribe from this group and stop receiving emails from it, send an email to cat...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

<video1_pan.mp4>

<video2_next_slow.mp4>

<video3_next_slow_fast.mp4>

[Albert Cardona]

Perhaps has to do with the node update strategy specified in settings.py? Tom Kazimiers is the one to ask about this.

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

For more options, visit https://groups.google.com/d/optout.

<video4.mp4>

[Daniel Witvliet]

As far as I can tell, the only manual options set related to updating nodes is NODE_PROVIDERS = ['postgis3d'], which is the default option anyway. Changing this to a different provider (e.g. postgis2d or cached_msgpack after caching node quires) does not make a difference to the issue. I have attached the entire settings file here in case you want to have a look.

I will try to play around the code to see if I can determine the limiting factor for the "unresponsive time period' and then post back here with any updates.

<video4.mp4>

[Daniel Witvliet]

I found the underlying issue. Although it turns out not to be an actual issue, but a new feature. The new version of CATMAID introduced the option "Update tracing data while panning" for the tracing overlay. This option is disabled by default, resulting in a one second delay whenever a mouseup event is triggered by the middle or right mouse button. Simply enabling this option fixes the issue entirely.

To avoid a similar confusion for other users, I might suggest either enabling this option by default or ensuring that the delay is only triggered when the view is actually panned, instead of on every mouseup event.