[jira] [Commented] (OAK-9488) Extra logging in org.apache.jackrabbit.oak.run.DataStoreCommand

["Matt Ryan (Jira)" <ji...@apache.org>]

    [ https://issues.apache.org/jira/browse/OAK-9488?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17423034#comment-17423034 ] 

Matt Ryan commented on OAK-9488:
--------------------------------

I'm assuming the slowness is around the creation of the NodeStoreFixture [0]:
{noformat}
    NodeStoreFixture fixture = NodeStoreFixtureProvider.create(opts);
    closer.register(fixture); {noformat}
I'll add some logging around that and a few other places to try to give a better opportunity to narrow down where the slowness is occurring.  Assuming it is inside the NodeStoreFixture, however, to get more information will require changes down in that layer.

 

[0] - https://github.com/apache/jackrabbit-oak/blob/aca2aaeee7334281500f2b065b8226013f9a97df/oak-run/src/main/java/org/apache/jackrabbit/oak/run/DataStoreCommand.java#L147

> Extra logging in org.apache.jackrabbit.oak.run.DataStoreCommand 
> ----------------------------------------------------------------
>
>                 Key: OAK-9488
>                 URL: https://issues.apache.org/jira/browse/OAK-9488
>             Project: Jackrabbit Oak
>          Issue Type: Improvement
>          Components: segment-azure
>            Reporter: Paul Chibulcuteanu
>            Assignee: Matt Ryan
>            Priority: Minor
>
> Running datastore command to retrieve the index binaries blob IDs from Azure with following options:
> {code}
> 16.06.2021 20:49:50.452 *INFO* [main] o.a.j.oak.run.DataStoreCommand - Command line arguments used for datastore command [--dump-ref --out-dir /opt/out_dir --azureds /DataStore.config --verboseRootPath /oak:index/ --verbosePathInclusionRegex /*/:data,/*/:suggest-data --verbose] 
> 16.06.2021 20:49:50.454 *INFO* [main] o.a.j.oak.run.DataStoreCommand - System properties and vm options passed [-Dsegment.timeout.interval=60, -Dsegment.timeout.execution=325] 
> {code}
> can sometimes take minutes. This operation is usually fast(a few seconds).
> The log of the command only displays little info about what is happening:
> {code}
> 16.06.2021 20:49:50.839 *INFO* [pool-3-thread-1] o.a.j.o.plugins.blob.FileCache - Cache built with [0] files from file system in [0] seconds 
> 16.06.2021 20:54:45.901 *INFO* [main] o.a.j.oak.run.DataStoreCommand - Starting dump of blob references by traversing 
> {code}
> There is no information on where the 5 minutes is spent. It could be a network hiccup, maybe Azure connectivity issues, or too many sessions opened, but there is no way to find out. We should add extra logging in _org.apache.jackrabbit.oak.run.DataStoreCommand_ in order to be able to investigate such slowness cases.



--
This message was sent by Atlassian Jira
(v8.3.4#803005)