I am working on Spring boot application(Content Management System) which stores multiple files in amazon-s3 repository with the help of jack rabbit oak node structure implementation and all node metadata stores in PostgreSQL 10.4 db. Our application is deployed on Cloud foundry, Wherever application start after pushing some changes, it takes too much time around 4 hours to get started. Upon analyzing, I could see the lots of occurrence of below logs in start-up logs:
{
"@timestamp":"2019-12-03T15:23:28.156+00:00",
"@version":1,"message":"Slow Query Report SQL=select ID, MODIFIED, MODCOUNT, CMODCOUNT,
HASBINARY, DELETEDONCE, VERSION, SDTYPE, SDMAXREVTIME, DATA, BDATA from table_NODES
where ID > ? and ID < ? order by ID FETCH FIRST 1601 ROWS ONLY; time=23329 ms;",
"logger_name":"org.apache.tomcat.jdbc.pool.interceptor.SlowQueryReport",
"thread_name":"main","level":"WARN","level_value":30000
}
Long running query on table_NODES with 1601 hits (limited to 1601),
elapsed time 23335ms (configured QUERYTIMELIMIT 10000),
params minid '1:/3d3ea681-xxxx-4ed7-b68d-7fgfj8ggkl' maxid '1:0' excludeKeyPatterns [] conditions [] limit 1601.
Result range: '1:/3d3ea6fe-xxxx-ghjggb3-4ghvkklh'...'1:/3jsffsd8-810a-xxxx-b51a-XXXXXXXX'.
Read 1323775 chars from DATA and 0 bytes from BDATA. Check calling method.
As I am new for Jack rabbit oak functionality and PostgreSQL, I am not sure what is happening internally while application start-up and why it is taking that much of time. Please help me to get these understanding and how do I can overcome this issue so that application can start up quickly. You can also find below DB configuration logs as well:
{
"@timestamp":"2019-12-03T15:23:25.338+00:00",
"@version":1,"message":"RDBDocumentStore (1.10.2) instantiated for database PostgreSQL 10.4
(Ubuntu 10.4-2.pgdg16.04+1) (10.4), using driver: PostgreSQL JDBC Driver 42.2.2 (42.2),
connecting to: jdbc:postgresql:<connection URL>, properties: {datcollate=C,
pg_encoding_to_char(encoding)=UTF8}, transaction isolation level: TRANSACTION_READ_COMMITTED (2),
.table_nodes: id varchar(512), modified int8, hasbinary int2, deletedonce int2, modcount int8,
cmodcount int8, dsize int8, data varchar(16384), bdata bytea(2147483647), version int2,
sdtype int2, sdmaxrevtime int8 /* {bytea=-2, int2=5, int8=-5, varchar=12
}
*/ /* index table_nodes_mod on public.table_nodes (modified ASC) other (#109582080, p623124),
unique index table_nodes_pkey on public.table_nodes (id ASC) other (#109582080, p2389650),
index table_nodes_sdm on public.table_nodes (sdmaxrevtime ASC) other (#109582080, p487463),
index table_nodes_sdt on public.table_nodes (sdtype ASC) other (#109582080, p474156),
index table_nodes_vsn on public.table_nodes (version ASC) other (#109582080, p473956) */",
"logger_name":"org.apache.jackrabbit.oak.plugins.document.rdb.RDBDocumentStore",
"thread_name":"main","level":"INFO","level_value":20000}
Initialized DocumentNodeStore with clusterNodeId: 387, updateLimit: 100000 (id: 387,
startTime: 1575386605462, machineId: mac:xxxxxxxxxxx, instanceId: /home/vcap/app,
pid: 8, uuid: xxxxxxx-xxxx-xxxx-xxxxx-xxxxxxxxxxxx, readWriteMode: null, leaseCheckMode: STRICT,
state: ACTIVE, oakVersion: 1.10.2, formatVersion: 1.8.0)
