WARNING [3ad54] {engines} slow background settings sync

My Environment

ArangoDB Version:        3.8.1
Storage Engine:             RocksDB
Deployment Mode:       Single Server
Deployment Strategy:   Manual Start
Configuration:               default settings
Infrastructure:               AWS c5a.12xlarge
Operating System:        Ubuntu 64-bit
Total RAM in your machine:        128 GB
Disks in use:        1x SSD 60 GB
Used Package:              N/A

Component, Query & Data
Affected feature:
AQL query (if applicable):
AQL explain and/or profile (if applicable):
Dataset:
Size of your Dataset on disk:
44M     /var/lib/arangodb3/engine-rocksdb/journals/archive
204M    /var/lib/arangodb3/engine-rocksdb/journals
15G     /var/lib/arangodb3/engine-rocksdb
15G     /var/lib/arangodb3
Steps to reproduce
Problem:
2021-11-09T18:17:57Z [7615] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'PrimaryIndex' to let background writes catch up
2021-11-09T18:18:02Z [7615] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'PrimaryIndex'
2021-11-09T18:18:14Z [7615] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'VPackIndex' to let background writes catch up
2021-11-09T18:18:23Z [7615] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'default' to let background writes catch up
2021-11-09T18:20:09Z [7615] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'VPackIndex'
2021-11-09T18:20:10Z [7615] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'default'
2021-11-09T18:24:48Z [7615] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'VPackIndex' to let background writes catch up
2021-11-09T18:24:50Z [7615] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'default' to let background writes catch up
2021-11-09T18:25:31Z [7615] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'VPackIndex'
2021-11-09T18:28:33Z [7615] WARNING [9123d] {engines} rocksdb has stopped incoming writes to column family 'default' to let background writes catch up
2021-11-09T18:28:54Z [7615] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'default'
2021-11-09T18:28:54Z [7615] WARNING [3ad54] {engines} slow background settings sync: 23.310444 s
2021-11-09T18:37:01Z [7615] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'VPackIndex' to let background writes catch up
2021-11-09T18:37:06Z [7615] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'default' to let background writes catch up
2021-11-09T18:37:35Z [7615] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'default'
2021-11-09T18:37:39Z [7615] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'VPackIndex'
2021-11-09T18:42:14Z [7615] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'default' to let background writes catch up
2021-11-09T18:46:09Z [7615] WARNING [9123d] {engines} rocksdb has stopped incoming writes to column family 'default' to let background writes catch up
2021-11-09T18:47:03Z [7615] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'default'
2021-11-09T18:47:03Z [7615] WARNING [3ad54] {engines} slow background settings sync: 55.883286 s
2021-11-09T18:47:14Z [7615] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5189 ms ago, threshold value: 5000 ms
2021-11-09T18:47:21Z [7615] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6707 ms ago, threshold value: 5000 ms

Expected result:

as already commented, https://github.com/arangodb/arangodb/issues/13156#issuecomment-964445325 is a duplicate of this, I've re-opened that one. thanks.

as already commented, #13156 (comment) is a duplicate of this, I've re-opened that one. thanks.

In fact I think these are similar but different issues. I receive this error during execution, not shutdown...
Only sometimes I have problems on shutdown, my bigger issues happens after startup.
As you can see in the logs below, i have a "SLOW QUERY" problem that only stops after ~ 1 hour after database initialization (from 04:47 to 05:57).
And that's because I've blocked the requests that triggered this query and let only some a few selected ones execute so it don't hang the whole system. If I let all pass thru the system becomes totally unusuable.
After the slow queries problem was gone then I finally let all the requests execute.
What happens in this 1 hour and how can I avoid this issue?
Is it caching or something like that? Can I force that to happen faster?
(At startup the db is using ~ 10 GB of RAM. After this first problematic hour the total RAM used by arangodb3 is 35 GB)
Please reopen this issue @dothebart .
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Config::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Greetings::prepare
2021-11-13T04:47:23Z [2710] INFO [e52b0] {general} ArangoDB 3.8.2 [linux] 64bit, using jemalloc, build tags/v3.8.2-0-gd1ea701248, VPack 0.1.35, RocksDB 6.8.0, ICU 64.2, V8 7.9.317, OpenSSL 1.1.1l  24 Aug 2021
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} LogBuffer::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Metrics::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Random::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} GreetingsPhase::prepare
2021-11-13T04:47:23Z [2710] DEBUG [12f47] {startup} Prepare for phase GreetingsPhase completed
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} CpuUsage::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Daemon::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} FileDescriptors::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Language::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} MaxMapCount::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Environment::prepare
2021-11-13T04:47:23Z [2710] INFO [75ddc] {general} detected operating system: Linux version 5.11.0-1021-aws (buildd@lcy01-amd64-001) (gcc (Ubuntu 9.3.0-17ubuntu1~20.04) 9.3.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #22~20.04.2-Ubuntu SMP Wed Oct 27 21:27:13 UTC 2021
2021-11-13T04:47:23Z [2710] INFO [25362] {memory} Available physical memory:<PHONE_NUMBER>08 bytes, available cores: 48
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Nonce::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Privilege::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Scheduler::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} ServerSecurity::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Temp::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} DatabasePath::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} LanguageCheck::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Sharding::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Ssl::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Supervisor::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} BasicsPhase::prepare
2021-11-13T04:47:23Z [2710] DEBUG [12f47] {startup} Prepare for phase BasicsPhase completed
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Authentication::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} CacheManager::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} EngineSelector::prepare
2021-11-13T04:47:23Z [2710] DEBUG [98b5c] {startup} looking for previously selected engine in file '/var/lib/arangodb3/ENGINE'
2021-11-13T04:47:23Z [2710] INFO [144fe] {general} using storage engine 'rocksdb'
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} InitDatabase::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Lockfile::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} ReplicationMetrics::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} TimeZone::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} TransactionManager::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} ViewTypes::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} ClusterEngine::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} RocksDBOption::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} RocksDBEngine::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} StorageEngine::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Database::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Flush::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} SystemDatabase::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} ServerId::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} CheckVersion::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} RocksDBRecoveryManager::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Replication::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} DatabasePhase::prepare
2021-11-13T04:47:23Z [2710] DEBUG [12f47] {startup} Prepare for phase DatabasePhase completed
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Cluster::prepare
2021-11-13T04:47:23Z [2710] INFO [3bb7d] {cluster} Starting up with role SINGLE
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Maintenance::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} ReplicationTimeout::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} ClusterPhase::prepare
2021-11-13T04:47:23Z [2710] DEBUG [12f47] {startup} Prepare for phase ClusterPhase completed
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Action::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} V8Platform::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} V8Security::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} V8Dealer::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} V8Phase::prepare
2021-11-13T04:47:23Z [2710] DEBUG [12f47] {startup} Prepare for phase V8Phase completed
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} QueryRegistry::prepare
2021-11-13T04:47:23Z [2710] INFO [f6e0e] {aql} memory limit per AQL query automatically set to<PHONE_NUMBER>5 bytes. to modify this value, please adjust the startup option `--query.memory-limit`
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Aql::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} AQLFunctions::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} OptimizerRules::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} ArangoSearchAnalyzer::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} ArangoSearch::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Pregel::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} AQLPhase::prepare
2021-11-13T04:47:23Z [2710] DEBUG [12f47] {startup} Prepare for phase AQLPhase completed
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} SslServer::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Upgrade::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Server::prepare
2021-11-13T04:47:23Z [2710] TRACE [34163] {startup} raising privileges
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Endpoint::prepare
2021-11-13T04:47:23Z [2710] TRACE [8d23d] {startup} dropping privileges
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} GeneralServer::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Network::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} ServerPhase::prepare
2021-11-13T04:47:23Z [2710] DEBUG [12f47] {startup} Prepare for phase ServerPhase completed
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} FoxxQueues::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Bootstrap::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Fortune::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Frontend::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} FoxxPhase::prepare
2021-11-13T04:47:23Z [2710] DEBUG [12f47] {startup} Prepare for phase FoxxPhase completed
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} AgencyPhase::prepare
2021-11-13T04:47:23Z [2710] DEBUG [12f47] {startup} Prepare for phase AgencyPhase completed
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Console::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Script::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} SoftShutdown::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} FinalPhase::prepare
2021-11-13T04:47:23Z [2710] DEBUG [12f47] {startup} Prepare for phase FinalPhase completed
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} ClusterUpgrade::prepare
2021-11-13T04:47:23Z [2710] TRACE [d4e57] {startup} Ttl::prepare
2021-11-13T04:47:23Z [2710] TRACE [3e03b] {startup} ApplicationServer::disableDependentFeatures
2021-11-13T04:47:23Z [2710] TRACE [8ef64] {startup} ApplicationServer::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} CommunicationPhase::start
2021-11-13T04:47:23Z [2710] DEBUG [d730b] {startup} Start for phase CommunicationPhase completed
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} SharedPRNG::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} ShellColors::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Version::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Logger::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Config::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Greetings::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} LogBuffer::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Metrics::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Random::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} GreetingsPhase::start
2021-11-13T04:47:23Z [2710] DEBUG [d730b] {startup} Start for phase GreetingsPhase completed
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} CpuUsage::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Daemon::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} FileDescriptors::start
2021-11-13T04:47:23Z [2710] INFO [a1c60] {syscall} file-descriptors (nofiles) hard limit is 131072, soft limit is 131072
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Language::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} MaxMapCount::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Environment::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Nonce::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Privilege::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Scheduler::start
2021-11-13T04:47:23Z [2710] DEBUG [14e6f] {startup} scheduler has started
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} ServerSecurity::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Temp::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} DatabasePath::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} LanguageCheck::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Sharding::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Ssl::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Supervisor::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} BasicsPhase::start
2021-11-13T04:47:23Z [2710] DEBUG [d730b] {startup} Start for phase BasicsPhase completed
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Authentication::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} CacheManager::start
2021-11-13T04:47:23Z [2710] DEBUG [13894] {startup} cache manager has started
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} EngineSelector::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} InitDatabase::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Lockfile::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} ReplicationMetrics::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} TimeZone::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} TransactionManager::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} ViewTypes::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} RocksDBOption::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} RocksDBEngine::start
2021-11-13T04:47:23Z [2710] DEBUG [528b8] {startup} found existing column families: default, Documents, PrimaryIndex, EdgeIndex, VPackIndex, GeoIndex, FulltextIndex
2021-11-13T04:47:23Z [2710] TRACE [a9cc7] {startup} getting existing databases
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} StorageEngine::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Database::start
2021-11-13T04:47:23Z [2710] TRACE [a9cc7] {startup} getting existing databases
2021-11-13T04:47:23Z [2710] WARNING [66770] {engines} dropping failed index '8623357350'
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Flush::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} SystemDatabase::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} ServerId::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} CheckVersion::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} RocksDBRecoveryManager::start
2021-11-13T04:47:23Z [2710] INFO [fe333] {engines} RocksDB recovery starting, scanning WAL starting from sequence number<PHONE_NUMBER>
2021-11-13T04:47:23Z [2710] INFO [a4ec8] {engines} RocksDB recovery finished, WAL entries scanned: 139, max tick found in WAL:<PHONE_NUMBER>, last HLC value: 0
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Replication::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} DatabasePhase::start
2021-11-13T04:47:23Z [2710] DEBUG [d730b] {startup} Start for phase DatabasePhase completed
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Cluster::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Maintenance::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} ReplicationTimeout::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} ClusterPhase::start
2021-11-13T04:47:23Z [2710] DEBUG [d730b] {startup} Start for phase ClusterPhase completed
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Action::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} V8Platform::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} V8Security::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} V8Dealer::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} V8Phase::start
2021-11-13T04:47:23Z [2710] DEBUG [d730b] {startup} Start for phase V8Phase completed
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} QueryRegistry::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Aql::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} AQLFunctions::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} OptimizerRules::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} ArangoSearchAnalyzer::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} ArangoSearch::start
2021-11-13T04:47:23Z [2710] INFO [c1b63] {arangosearch} ArangoSearch maintenance: [8..8] commit thread(s), [8..8] consolidation thread(s)
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Pregel::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} AQLPhase::start
2021-11-13T04:47:23Z [2710] DEBUG [d730b] {startup} Start for phase AQLPhase completed
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} SslServer::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Upgrade::start
2021-11-13T04:47:23Z [2710] DEBUG [3da0f] {startup} found VERSION file '/var/lib/arangodb3/VERSION-1', content: {"version":30802,"tasks":{"createSystemCollectionsAndIndices":true,"createSystemStatisticsDBServer":true,"dropLegacyAnalyzersCollection":true,"renameReplicationApplierStateFiles":true,"upgradeArangoSearch0_1":true}}\n
2021-11-13T04:47:23Z [2710] DEBUG [e9cc3] {startup} version match: last version 30802, current version 30802
2021-11-13T04:47:23Z [2710] DEBUG [ffe7f] {startup} Upgrade: already executed, skipping createSystemCollectionsAndIndices
2021-11-13T04:47:23Z [2710] DEBUG [ffe7f] {startup} Upgrade: already executed, skipping createSystemStatisticsDBServer
2021-11-13T04:47:23Z [2710] DEBUG [fd4e0] {startup} Upgrade: DB system, skipping addDefaultUserOther
2021-11-13T04:47:23Z [2710] DEBUG [ffe7f] {startup} Upgrade: already executed, skipping renameReplicationApplierStateFiles
2021-11-13T04:47:23Z [2710] DEBUG [ffe7f] {startup} Upgrade: already executed, skipping dropLegacyAnalyzersCollection
2021-11-13T04:47:23Z [2710] DEBUG [ffe7f] {startup} Upgrade: already executed, skipping upgradeArangoSearch0_1
2021-11-13T04:47:23Z [2710] DEBUG [cc057] {startup} Upgrade: cluster mismatch, skipping upgradeArangoSearchLinkCollectionName
2021-11-13T04:47:23Z [2710] DEBUG [e5a77] {startup} Upgrade: writing VERSION file
2021-11-13T04:47:23Z [2710] DEBUG [3da0f] {startup} found VERSION file '/var/lib/arangodb3/VERSION-327', content: {"version":30802,"tasks":{"addDefaultUserOther":true,"createSystemCollectionsAndIndices":true,"renameReplicationApplierStateFiles":true,"upgradeArangoSearch0_1":true}}\n
2021-11-13T04:47:23Z [2710] DEBUG [e9cc3] {startup} version match: last version 30802, current version 30802
2021-11-13T04:47:23Z [2710] DEBUG [ffe7f] {startup} Upgrade: already executed, skipping createSystemCollectionsAndIndices
2021-11-13T04:47:23Z [2710] DEBUG [bb1ef] {startup} Upgrade: DB not system, skipping createSystemStatisticsDBServer
2021-11-13T04:47:23Z [2710] DEBUG [ffe7f] {startup} Upgrade: already executed, skipping addDefaultUserOther
2021-11-13T04:47:23Z [2710] DEBUG [ffe7f] {startup} Upgrade: already executed, skipping renameReplicationApplierStateFiles
2021-11-13T04:47:23Z [2710] DEBUG [bb1ef] {startup} Upgrade: DB not system, skipping dropLegacyAnalyzersCollection
2021-11-13T04:47:23Z [2710] DEBUG [ffe7f] {startup} Upgrade: already executed, skipping upgradeArangoSearch0_1
2021-11-13T04:47:23Z [2710] DEBUG [cc057] {startup} Upgrade: cluster mismatch, skipping upgradeArangoSearchLinkCollectionName
2021-11-13T04:47:23Z [2710] DEBUG [e5a77] {startup} Upgrade: writing VERSION file
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Server::start
2021-11-13T04:47:23Z [2710] TRACE [7031b] {startup} server operation mode: SERVER
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Endpoint::start
2021-11-13T04:47:23Z [2710] INFO [6ea38] {general} using endpoint 'http+tcp://<IP_ADDRESS>:8529' for non-encrypted requests
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} GeneralServer::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Network::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} ServerPhase::start
2021-11-13T04:47:23Z [2710] DEBUG [d730b] {startup} Start for phase ServerPhase completed
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} FoxxQueues::start
2021-11-13T04:47:23Z [2710] TRACE [27b63] {startup} Bootstrap::start
2021-11-13T04:47:23Z [2710] DEBUG [e0c8b] {startup} Running server/server.js
2021-11-13T04:47:24Z [2710] INFO [cf3f4] {general} ArangoDB (version 3.8.2 [linux]) is ready for business. Have fun!
2021-11-13T04:47:24Z [2710] TRACE [27b63] {startup} Fortune::start
2021-11-13T04:47:24Z [2710] TRACE [27b63] {startup} Frontend::start
2021-11-13T04:47:24Z [2710] TRACE [27b63] {startup} FoxxPhase::start
2021-11-13T04:47:24Z [2710] DEBUG [d730b] {startup} Start for phase FoxxPhase completed
2021-11-13T04:47:24Z [2710] TRACE [27b63] {startup} AgencyPhase::start
2021-11-13T04:47:24Z [2710] DEBUG [d730b] {startup} Start for phase AgencyPhase completed
2021-11-13T04:47:24Z [2710] TRACE [27b63] {startup} Console::start
2021-11-13T04:47:24Z [2710] TRACE [27b63] {startup} Script::start
2021-11-13T04:47:24Z [2710] TRACE [27b63] {startup} SoftShutdown::start
2021-11-13T04:47:24Z [2710] TRACE [27b63] {startup} FinalPhase::start
2021-11-13T04:47:24Z [2710] DEBUG [d730b] {startup} Start for phase FinalPhase completed
2021-11-13T04:47:24Z [2710] TRACE [27b63] {startup} ClusterUpgrade::start
2021-11-13T04:47:24Z [2710] TRACE [27b63] {startup} Ttl::start
2021-11-13T04:47:24Z [2710] TRACE [f86df] {startup} ApplicationServer::wait

2021-11-13T04:50:23Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727460913, exit code: 0, took: 28.836989 s
2021-11-13T04:51:53Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727464393, exit code: 0, took: 58.807261 s
2021-11-13T04:52:08Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727464349, exit code: 0, took: 75.564460 s
2021-11-13T04:52:35Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727464297, exit code: 0, took: 102.792239 s
2021-11-13T04:53:41Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727464266, exit code: 0, took: 169.514640 s
2021-11-13T04:53:51Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727464452, exit code: 0, took: 176.860716 s
2021-11-13T04:54:36Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727464224, exit code: 0, took: 224.230918 s
2021-11-13T04:55:13Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727464203, exit code: 0, took: 262.127833 s
2021-11-13T04:56:51Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727486027, exit code: 0, took: 57.954378 s
2021-11-13T04:58:18Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727485749, exit code: 0, took: 146.510142 s
2021-11-13T05:00:19Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727485712, exit code: 0, took: 267.613283 s
2021-11-13T05:00:25Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727535172, exit code: 0, took: 13.477427 s
2021-11-13T05:00:28Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 8338 ms ago, threshold value: 5000 ms
2021-11-13T05:00:31Z [2710] WARNING [3ad54] {engines} slow background settings sync: 8.471071 s
2021-11-13T05:00:33Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727535105, exit code: 0, took: 21.550821 s
2021-11-13T05:00:41Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 10176 ms ago, threshold value: 5000 ms
2021-11-13T05:00:48Z [2710] WARNING [3ad54] {engines} slow background settings sync: 14.642996 s
2021-11-13T05:01:06Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 18021 ms ago, threshold value: 5000 ms
2021-11-13T05:01:07Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727535065, exit code: 0, took: 55.305171 s
2021-11-13T05:01:19Z [2710] WARNING [3ad54] {engines} slow background settings sync: 28.505375 s
2021-11-13T05:01:28Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6905 ms ago, threshold value: 5000 ms
2021-11-13T05:01:33Z [2710] WARNING [3ad54] {engines} slow background settings sync: 11.138544 s
2021-11-13T05:01:55Z [2710] WARNING [3ad54] {engines} slow background settings sync: 19.787990 s
2021-11-13T05:02:03Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 8277 ms ago, threshold value: 5000 ms
2021-11-13T05:02:30Z [2710] WARNING [3ad54] {engines} slow background settings sync: 31.938416 s
2021-11-13T05:02:46Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 15489 ms ago, threshold value: 5000 ms
2021-11-13T05:03:04Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727534843
2021-11-13T05:03:07Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727535195
2021-11-13T05:03:11Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727535260
2021-11-13T05:03:11Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727535195, exit code: 1500, took: 178.802615 s
2021-11-13T05:03:13Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727560999, exit code: 0, took: 75.096549 s
2021-11-13T05:03:14Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727535260, exit code: 1500, took: 181.967878 s
2021-11-13T05:03:15Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727534843, exit code: 1500, took: 184.543482 s
2021-11-13T05:03:21Z [2710] WARNING [3ad54] {engines} slow background settings sync: 49.227549 s
2021-11-13T05:03:27Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6066 ms ago, threshold value: 5000 ms
2021-11-13T05:03:29Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727558051, exit code: 0, took: 93.596233 s
2021-11-13T05:03:58Z [2710] WARNING [3ad54] {engines} slow background settings sync: 34.124299 s
2021-11-13T05:04:09Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 10571 ms ago, threshold value: 5000 ms
2021-11-13T05:04:12Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727557247, exit code: 0, took: 136.693151 s
2021-11-13T05:04:40Z [2710] WARNING [3ad54] {engines} slow background settings sync: 39.888507 s
2021-11-13T05:04:54Z [2710] WARNING [3ad54] {engines} slow background settings sync: 11.438776 s
2021-11-13T05:05:37Z [2710] WARNING [3ad54] {engines} slow background settings sync: 40.304030 s
2021-11-13T05:05:43Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5616 ms ago, threshold value: 5000 ms
2021-11-13T05:06:05Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727535290
2021-11-13T05:06:08Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727559801
2021-11-13T05:06:08Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727560895, exit code: 0, took: 250.754188 s
2021-11-13T05:06:09Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727559801, exit code: 1500, took: 252.797588 s
2021-11-13T05:06:13Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727535290, exit code: 1500, took: 360.477940 s
2021-11-13T05:06:14Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727560977
2021-11-13T05:06:16Z [2710] WARNING [3ad54] {engines} slow background settings sync: 36.477302 s
2021-11-13T05:06:17Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727560977
2021-11-13T05:06:17Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727560977, exit code: 1500, took: 259.353200 s
2021-11-13T05:06:24Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.793969 s
2021-11-13T05:06:32Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.205118 s
2021-11-13T05:06:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T05:06:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T05:06:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T05:06:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T05:06:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T05:06:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T05:06:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T05:06:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T05:06:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T05:08:14Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727642973, exit code: 0, took: 38.660378 s
2021-11-13T05:08:19Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727642840, exit code: 0, took: 44.494591 s
2021-11-13T05:08:44Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727643087, exit code: 0, took: 67.702713 s
2021-11-13T05:09:20Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727663137, exit code: 0, took: 15.288759 s
2021-11-13T05:09:26Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727663396, exit code: 0, took: 20.441422 s
2021-11-13T05:09:29Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5544 ms ago, threshold value: 5000 ms
2021-11-13T05:10:20Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727663057
2021-11-13T05:10:23Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727663057, exit code: 1500, took: 78.866125 s
2021-11-13T05:10:53Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727686475, exit code: 0, took: 16.105672 s
2021-11-13T05:10:57Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727686502, exit code: 0, took: 19.940273 s
2021-11-13T05:11:07Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727686112, exit code: 0, took: 31.633807 s
2021-11-13T05:11:07Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727686091, exit code: 0, took: 31.732911 s
2021-11-13T05:11:35Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727686150, exit code: 0, took: 58.825221 s
2021-11-13T05:12:18Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.094199 s
2021-11-13T05:12:26Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.275934 s
2021-11-13T05:12:41Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727700278
2021-11-13T05:12:42Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727700278, exit code: 1500, took: 63.444522 s
2021-11-13T05:13:06Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727700088
2021-11-13T05:13:07Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727700088, exit code: 1500, took: 89.080441 s
2021-11-13T05:13:31Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727722802, exit code: 0, took: 18.411425 s
2021-11-13T05:13:33Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727723062, exit code: 0, took: 18.046528 s
2021-11-13T05:13:41Z [2710] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'VPackIndex' to let background writes catch up
2021-11-13T05:13:58Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727722916, exit code: 0, took: 44.454497 s
2021-11-13T05:14:10Z [2710] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'default' to let background writes catch up
2021-11-13T05:14:10Z [2710] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'Documents' to let background writes catch up
2021-11-13T05:14:19Z [2710] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'PrimaryIndex' to let background writes catch up
2021-11-13T05:14:35Z [2710] WARNING [3ad54] {engines} slow background settings sync: 12.550088 s
2021-11-13T05:14:45Z [2710] WARNING [3ad54] {engines} slow background settings sync: 8.046264 s
2021-11-13T05:15:09Z [2710] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'Documents'
2021-11-13T05:15:09Z [2710] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'PrimaryIndex'
2021-11-13T05:15:11Z [2710] WARNING [3ad54] {engines} slow background settings sync: 22.636143 s
2021-11-13T05:15:29Z [2710] WARNING [3ad54] {engines} slow background settings sync: 8.663911 s
2021-11-13T05:15:43Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 9988 ms ago, threshold value: 5000 ms
2021-11-13T05:15:47Z [2710] WARNING [3ad54] {engines} slow background settings sync: 15.813662 s
2021-11-13T05:15:49Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727736596, exit code: 0, took: 97.344272 s
2021-11-13T05:15:58Z [2710] WARNING [3ad54] {engines} slow background settings sync: 8.109456 s
2021-11-13T05:16:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T05:16:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T05:16:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T05:16:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T05:16:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T05:16:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T05:16:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T05:16:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T05:16:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T05:17:21Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727736414
2021-11-13T05:17:22Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727736414, exit code: 1500, took: 190.910572 s
2021-11-13T05:18:33Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727784439
2021-11-13T05:18:33Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727784439, exit code: 1500, took: 57.106658 s
2021-11-13T05:18:35Z [2710] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'default'
2021-11-13T05:18:40Z [2710] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'VPackIndex'
2021-11-13T05:18:59Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727799136, exit code: 0, took: 15.905703 s
2021-11-13T05:19:01Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.538136 s
2021-11-13T05:19:08Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6544 ms ago, threshold value: 5000 ms
2021-11-13T05:19:10Z [2710] WARNING [3ad54] {engines} slow background settings sync: 6.188541 s
2021-11-13T05:19:15Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5343 ms ago, threshold value: 5000 ms
2021-11-13T05:19:19Z [2710] WARNING [3ad54] {engines} slow background settings sync: 6.459326 s
2021-11-13T05:19:27Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 8061 ms ago, threshold value: 5000 ms
2021-11-13T05:19:31Z [2710] WARNING [3ad54] {engines} slow background settings sync: 10.432604 s
2021-11-13T05:19:40Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 7899 ms ago, threshold value: 5000 ms
2021-11-13T05:19:41Z [2710] WARNING [3ad54] {engines} slow background settings sync: 6.861912 s
2021-11-13T05:19:54Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5205 ms ago, threshold value: 5000 ms
2021-11-13T05:20:01Z [2710] WARNING [3ad54] {engines} slow background settings sync: 9.959449 s
2021-11-13T05:20:06Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727798603, exit code: 0, took: 85.067008 s
2021-11-13T05:20:08Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 7627 ms ago, threshold value: 5000 ms
2021-11-13T05:20:15Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727798874, exit code: 0, took: 93.374297 s
2021-11-13T05:20:15Z [2710] WARNING [3ad54] {engines} slow background settings sync: 11.985763 s
2021-11-13T05:20:24Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 7699 ms ago, threshold value: 5000 ms
2021-11-13T05:20:25Z [2710] WARNING [3ad54] {engines} slow background settings sync: 7.377613 s
2021-11-13T05:21:07Z [2710] WARNING [90113] {queries} killing AQL query 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8727798878
2021-11-13T05:21:08Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727798878, exit code: 1500, took: 146.752989 s
2021-11-13T05:21:42Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727839992, exit code: 0, took: 10.580221 s
2021-11-13T05:21:44Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727840291, exit code: 0, took: 11.177254 s
2021-11-13T05:21:45Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727840167, exit code: 0, took: 12.390246 s
2021-11-13T05:21:48Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727840017, exit code: 0, took: 16.108110 s
2021-11-13T05:23:18Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727862710, exit code: 0, took: 10.986016 s
2021-11-13T05:23:35Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727866903, exit code: 0, took: 12.123166 s
2021-11-13T05:23:35Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727867352, exit code: 0, took: 10.959460 s
2021-11-13T05:23:41Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727867561, exit code: 0, took: 16.778802 s
2021-11-13T05:24:07Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727873216, exit code: 0, took: 16.142761 s
2021-11-13T05:24:08Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 7054 ms ago, threshold value: 5000 ms
2021-11-13T05:24:09Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727873381, exit code: 0, took: 17.497531 s
2021-11-13T05:24:12Z [2710] WARNING [3ad54] {engines} slow background settings sync: 8.265217 s
2021-11-13T05:24:20Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.276752 s
2021-11-13T05:25:12Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727873359, exit code: 0, took: 81.050613 s
2021-11-13T05:25:38Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727896759, exit code: 0, took: 13.137513 s
2021-11-13T05:26:03Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5416 ms ago, threshold value: 5000 ms
2021-11-13T05:26:06Z [2710] WARNING [3ad54] {engines} slow background settings sync: 6.058964 s
2021-11-13T05:26:07Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727896704, exit code: 0, took: 42.585038 s
2021-11-13T05:26:11Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5271 ms ago, threshold value: 5000 ms
2021-11-13T05:26:20Z [2710] WARNING [3ad54] {engines} slow background settings sync: 11.317223 s
2021-11-13T05:26:27Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727896418, exit code: 0, took: 62.775816 s
2021-11-13T05:26:27Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 7249 ms ago, threshold value: 5000 ms
2021-11-13T05:26:28Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727896718, exit code: 0, took: 63.487413 s
2021-11-13T05:26:28Z [2710] WARNING [3ad54] {engines} slow background settings sync: 6.132976 s
2021-11-13T05:26:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T05:26:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T05:26:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T05:26:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T05:26:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T05:26:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T05:26:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T05:26:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T05:26:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T05:26:59Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727896959, exit code: 0, took: 93.274516 s
2021-11-13T05:27:19Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727921677, exit code: 0, took: 11.849908 s
2021-11-13T05:27:21Z [2710] WARNING [3ad54] {engines} slow background settings sync: 7.052318 s
2021-11-13T05:27:26Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727921588, exit code: 0, took: 18.991252 s
2021-11-13T05:27:28Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727916464, exit code: 0, took: 42.508396 s
2021-11-13T05:27:28Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.049078 s
2021-11-13T05:27:50Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727921616, exit code: 0, took: 42.639438 s
2021-11-13T05:28:18Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727931201, exit code: 0, took: 21.856338 s
2021-11-13T05:28:48Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727936582, exit code: 0, took: 24.702474 s
2021-11-13T05:29:13Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727936555, exit code: 0, took: 49.321692 s
2021-11-13T05:30:03Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 8622 ms ago, threshold value: 5000 ms
2021-11-13T05:30:05Z [2710] WARNING [3ad54] {engines} slow background settings sync: 9.285627 s
2021-11-13T05:30:13Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 8016 ms ago, threshold value: 5000 ms
2021-11-13T05:30:18Z [2710] WARNING [3ad54] {engines} slow background settings sync: 10.739455 s
2021-11-13T05:30:26Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 7422 ms ago, threshold value: 5000 ms
2021-11-13T05:30:27Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727952823, exit code: 0, took: 46.127495 s
2021-11-13T05:30:29Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727952931, exit code: 0, took: 47.030050 s
2021-11-13T05:30:29Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727952885, exit code: 0, took: 47.963169 s
2021-11-13T05:30:31Z [2710] WARNING [3ad54] {engines} slow background settings sync: 11.081732 s
2021-11-13T05:30:42Z [2710] WARNING [3ad54] {engines} slow background settings sync: 7.997999 s
2021-11-13T05:31:01Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727969830, exit code: 0, took: 11.697186 s
2021-11-13T05:31:19Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727948465, exit code: 0, took: 118.724494 s
2021-11-13T05:32:04Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727986179, exit code: 0, took: 15.075325 s
2021-11-13T05:32:04Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6650 ms ago, threshold value: 5000 ms
2021-11-13T05:32:05Z [2710] WARNING [3ad54] {engines} slow background settings sync: 7.010623 s
2021-11-13T05:32:05Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727986803, exit code: 0, took: 14.455991 s
2021-11-13T05:32:11Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6638 ms ago, threshold value: 5000 ms
2021-11-13T05:32:14Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727986521, exit code: 0, took: 25.126022 s
2021-11-13T05:32:14Z [2710] WARNING [3ad54] {engines} slow background settings sync: 7.127341 s
2021-11-13T05:32:41Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727994692, exit code: 0, took: 18.566915 s
2021-11-13T05:33:09Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727994841, exit code: 0, took: 45.763336 s
2021-11-13T05:33:14Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727994813, exit code: 0, took: 50.839145 s
2021-11-13T05:33:15Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5160 ms ago, threshold value: 5000 ms
2021-11-13T05:33:17Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.171826 s
2021-11-13T05:33:20Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8727994581, exit code: 0, took: 57.373865 s
2021-11-13T05:33:50Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728008457, exit code: 0, took: 13.447983 s
2021-11-13T05:33:52Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728008400, exit code: 0, took: 15.461017 s
2021-11-13T05:34:01Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728008635, exit code: 0, took: 23.859147 s
2021-11-13T05:34:38Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728008412, exit code: 0, took: 61.413419 s
2021-11-13T05:35:44Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728033504, exit code: 0, took: 18.564027 s
2021-11-13T05:35:44Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728032897, exit code: 0, took: 20.870259 s
2021-11-13T05:35:47Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728032926, exit code: 0, took: 23.428545 s
2021-11-13T05:36:12Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728040231, exit code: 0, took: 12.315993 s
2021-11-13T05:36:43Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728047868, exit code: 0, took: 11.471005 s
2021-11-13T05:36:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T05:36:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T05:36:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T05:36:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T05:36:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T05:36:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T05:36:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T05:36:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T05:36:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T05:36:55Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728048286, exit code: 0, took: 21.506824 s
2021-11-13T05:37:50Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728064158, exit code: 0, took: 20.217126 s
2021-11-13T05:38:02Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728069908, exit code: 0, took: 10.708924 s
2021-11-13T05:38:20Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728073243, exit code: 0, took: 14.682239 s
2021-11-13T05:38:23Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728073961, exit code: 0, took: 14.640557 s
2021-11-13T05:38:30Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728073803, exit code: 0, took: 22.881192 s
2021-11-13T05:38:49Z [2710] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'VPackIndex' to let background writes catch up
2021-11-13T05:39:22Z [2710] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'default' to let background writes catch up
2021-11-13T05:39:30Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728088635, exit code: 0, took: 11.511614 s
2021-11-13T05:39:32Z [2710] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'VPackIndex'
2021-11-13T05:39:33Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728088832, exit code: 0, took: 14.133028 s
2021-11-13T05:39:54Z [2710] WARNING [3ad54] {engines} slow background settings sync: 14.412310 s
2021-11-13T05:40:36Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728099907, exit code: 0, took: 23.472734 s
2021-11-13T05:40:50Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728106159, exit code: 0, took: 10.260471 s
2021-11-13T05:40:55Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728107014, exit code: 0, took: 11.498106 s
2021-11-13T05:40:56Z [2710] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'PrimaryIndex' to let background writes catch up
2021-11-13T05:41:12Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728111093, exit code: 0, took: 10.862040 s
2021-11-13T05:41:15Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728110862, exit code: 0, took: 13.701666 s
2021-11-13T05:41:15Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728110847, exit code: 0, took: 13.742582 s
2021-11-13T05:41:18Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728110650, exit code: 0, took: 18.286807 s
2021-11-13T05:41:36Z [2710] WARNING [3ad54] {engines} slow background settings sync: 16.705151 s
2021-11-13T05:41:45Z [2710] WARNING [3ad54] {engines} slow background settings sync: 6.843655 s
2021-11-13T05:42:00Z [2710] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'PrimaryIndex'
2021-11-13T05:42:01Z [2710] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'default'
2021-11-13T05:42:02Z [2710] WARNING [3ad54] {engines} slow background settings sync: 14.150123 s
2021-11-13T05:42:15Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 8483 ms ago, threshold value: 5000 ms
2021-11-13T05:42:17Z [2710] WARNING [3ad54] {engines} slow background settings sync: 13.407636 s
2021-11-13T05:42:27Z [2710] WARNING [3ad54] {engines} slow background settings sync: 7.103341 s
2021-11-13T05:42:33Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5382 ms ago, threshold value: 5000 ms
2021-11-13T05:42:36Z [2710] WARNING [3ad54] {engines} slow background settings sync: 6.619682 s
2021-11-13T05:42:39Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728120742, exit code: 0, took: 38.518449 s
2021-11-13T05:42:44Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6605 ms ago, threshold value: 5000 ms
2021-11-13T05:42:45Z [2710] WARNING [3ad54] {engines} slow background settings sync: 6.812675 s
2021-11-13T05:42:51Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5749 ms ago, threshold value: 5000 ms
2021-11-13T05:42:53Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.461491 s
2021-11-13T05:43:20Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728123216, exit code: 0, took: 74.393022 s
2021-11-13T05:43:28Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728138902, exit code: 0, took: 19.707539 s
2021-11-13T05:44:15Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728152100, exit code: 0, took: 16.456992 s
2021-11-13T05:44:17Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728153666, exit code: 0, took: 13.634767 s
2021-11-13T05:45:12Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728168150, exit code: 0, took: 10.759009 s
2021-11-13T05:46:17Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728182064, exit code: 0, took: 12.163513 s
2021-11-13T05:46:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T05:46:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T05:46:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T05:46:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T05:46:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T05:46:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T05:46:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T05:46:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T05:46:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T05:46:57Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728191721, exit code: 0, took: 11.450172 s
2021-11-13T05:47:06Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728193393, exit code: 0, took: 11.123082 s
2021-11-13T05:47:12Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728191456, exit code: 0, took: 28.179212 s
2021-11-13T05:47:14Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728192432, exit code: 0, took: 23.898290 s
2021-11-13T05:50:23Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728239340, exit code: 0, took: 12.496440 s
2021-11-13T05:50:50Z [2710] WARNING [8bcee] {queries} slow query: 'FOR p IN phones FOR l IN call_log FILTER p.number == @value FILTER l._id IN p.callLogs SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"value":"xxxxxxxxxx"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8728246907, exit code: 0, took: 10.981241 s
2021-11-13T05:56:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T05:56:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T05:56:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T05:56:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T05:56:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T05:56:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T05:56:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T05:56:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T05:56:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T06:06:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T06:06:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T06:06:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T06:06:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T06:06:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T06:06:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T06:06:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T06:06:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T06:06:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T06:16:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T06:16:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T06:16:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T06:16:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T06:16:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T06:16:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T06:16:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T06:16:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T06:16:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T06:26:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T06:26:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T06:26:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T06:26:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T06:26:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T06:26:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T06:26:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T06:26:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T06:26:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T06:28:55Z [2710] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'default' to let background writes catch up
2021-11-13T06:32:26Z [2710] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'default'
2021-11-13T06:36:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T06:36:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T06:36:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T06:36:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T06:36:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T06:36:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T06:36:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T06:36:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T06:36:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T06:39:02Z [2710] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'default' to let background writes catch up
2021-11-13T06:41:19Z [2710] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'default'
2021-11-13T06:46:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T06:46:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T06:46:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T06:46:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T06:46:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T06:46:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T06:46:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T06:46:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T06:46:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T06:56:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T06:56:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T06:56:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T06:56:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T06:56:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T06:56:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T06:56:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T06:56:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T06:56:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T07:06:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T07:06:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T07:06:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T07:06:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T07:06:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T07:06:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T07:06:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T07:06:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T07:06:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T07:16:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T07:16:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T07:16:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T07:16:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T07:16:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T07:16:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T07:16:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T07:16:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T07:16:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T07:26:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T07:26:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T07:26:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T07:26:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T07:26:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T07:26:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T07:26:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T07:26:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T07:26:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T07:36:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T07:36:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T07:36:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T07:36:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T07:36:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T07:36:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T07:36:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T07:36:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T07:36:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T07:46:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T07:46:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T07:46:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T07:46:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T07:46:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T07:46:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T07:46:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T07:46:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T07:46:54Z [2710] INFO [99d80] {general} --------------------------

2021-11-13T07:51:24Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8699914512","value":"553188117998"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729918995, exit code: 0, took: 10.829776 s
2021-11-13T07:53:26Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8729922537
2021-11-13T07:53:36Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8717478344","value":"5511954014460"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729922537, exit code: 1500, took: 92.606734 s
2021-11-13T07:54:24Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8729929503
2021-11-13T07:54:24Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8729929449
2021-11-13T07:54:24Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8729927180
2021-11-13T07:54:24Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8729930171
2021-11-13T07:54:24Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8729926774
2021-11-13T07:54:28Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8727361605","value":"5215554643807"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729929449, exit code: 1500, took: 34.057927 s
2021-11-13T07:54:30Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8724637902","value":"31616143316"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729927180, exit code: 1500, took: 73.543249 s
2021-11-13T07:54:30Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8721141889","value":"51987699082"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729926774, exit code: 1500, took: 84.203502 s
2021-11-13T07:54:33Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8729931052
2021-11-13T07:54:33Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8729929503
2021-11-13T07:54:33Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8729930171
2021-11-13T07:54:36Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8689865907","value":"6281263721679"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729930171, exit code: 1500, took: 30.575698 s
2021-11-13T07:54:37Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8709835969","value":"34641125881"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729929503, exit code: 1500, took: 41.835218 s
2021-11-13T07:54:40Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8724637902","value":"31616143316"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729931052, exit code: 1500, took: 19.295501 s
2021-11-13T07:55:14Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8710295356","value":"491774980964"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729932136, exit code: 0, took: 33.762615 s
2021-11-13T07:56:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T07:56:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T07:56:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T07:56:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T07:56:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T07:56:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T07:56:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T07:56:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T07:56:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T07:58:56Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8690604180","value":"919168135666"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729949404, exit code: 0, took: 37.758261 s
2021-11-13T08:00:57Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6288 ms ago, threshold value: 5000 ms
2021-11-13T08:01:00Z [2710] WARNING [3ad54] {engines} slow background settings sync: 7.145323 s
2021-11-13T08:01:08Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 7149 ms ago, threshold value: 5000 ms
2021-11-13T08:01:10Z [2710] WARNING [3ad54] {engines} slow background settings sync: 7.416645 s
2021-11-13T08:01:16Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8685265684","value":"5212471304407"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729972294, exit code: 0, took: 49.760927 s
2021-11-13T08:01:47Z [2710] WARNING [3ad54] {engines} slow background settings sync: 6.471993 s
2021-11-13T08:01:52Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8717478344","value":"5511954014460"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729988606, exit code: 0, took: 17.244489 s
2021-11-13T08:01:57Z [2710] WARNING [3ad54] {engines} slow background settings sync: 7.632417 s
2021-11-13T08:02:05Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.088176 s
2021-11-13T08:02:26Z [2710] WARNING [3ad54] {engines} slow background settings sync: 6.449417 s
2021-11-13T08:02:36Z [2710] WARNING [3ad54] {engines} slow background settings sync: 7.093182 s
2021-11-13T08:02:43Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 7299 ms ago, threshold value: 5000 ms
2021-11-13T08:02:46Z [2710] WARNING [3ad54] {engines} slow background settings sync: 8.488904 s
2021-11-13T08:02:53Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6238 ms ago, threshold value: 5000 ms
2021-11-13T08:02:59Z [2710] WARNING [3ad54] {engines} slow background settings sync: 9.566334 s
2021-11-13T08:03:08Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 9293 ms ago, threshold value: 5000 ms
2021-11-13T08:03:08Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8691712125","value":"6281348245673"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729973953, exit code: 0, took: 154.329422 s
2021-11-13T08:03:13Z [2710] WARNING [3ad54] {engines} slow background settings sync: 11.899182 s
2021-11-13T08:03:18Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5255 ms ago, threshold value: 5000 ms
2021-11-13T08:03:21Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.322092 s
2021-11-13T08:03:27Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5710 ms ago, threshold value: 5000 ms
2021-11-13T08:03:29Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.338366 s
2021-11-13T08:03:35Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6705 ms ago, threshold value: 5000 ms
2021-11-13T08:03:40Z [2710] WARNING [3ad54] {engines} slow background settings sync: 8.824692 s
2021-11-13T08:03:51Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 11015 ms ago, threshold value: 5000 ms
2021-11-13T08:03:59Z [2710] WARNING [3ad54] {engines} slow background settings sync: 16.380606 s
2021-11-13T08:04:05Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6472 ms ago, threshold value: 5000 ms
2021-11-13T08:04:26Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 20172 ms ago, threshold value: 5000 ms
2021-11-13T08:04:26Z [2710] WARNING [3ad54] {engines} slow background settings sync: 24.183036 s
2021-11-13T08:04:35Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 9011 ms ago, threshold value: 5000 ms
2021-11-13T08:04:36Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8689315386","value":"447881841875"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730023144, exit code: 0, took: 36.529438 s
2021-11-13T08:05:11Z [2710] WARNING [3ad54] {engines} slow background settings sync: 42.444144 s
2021-11-13T08:05:18Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730013830
2021-11-13T08:05:18Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730009423
2021-11-13T08:05:18Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8729985583
2021-11-13T08:05:18Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 7499 ms ago, threshold value: 5000 ms
2021-11-13T08:05:25Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8721746498","value":"5511962598021"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8729985583, exit code: 1500, took: 241.708541 s
2021-11-13T08:05:26Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8689664314","value":"491791095219"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730013830, exit code: 1500, took: 129.373998 s
2021-11-13T08:05:27Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8601029793","value":"34610218249"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730009423, exit code: 1500, took: 147.365172 s
2021-11-13T08:05:29Z [2710] WARNING [3ad54] {engines} slow background settings sync: 15.921443 s
2021-11-13T08:06:29Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730056607
2021-11-13T08:06:35Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8720861080","value":"16066220836"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730056607, exit code: 1500, took: 29.100045 s
2021-11-13T08:06:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T08:06:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T08:06:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T08:06:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T08:06:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T08:06:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T08:06:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T08:06:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T08:06:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T08:08:11Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730085457
2021-11-13T08:08:11Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730074928
2021-11-13T08:08:14Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8717115675","value":"56936769792"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730085457, exit code: 1500, took: 18.100613 s
2021-11-13T08:08:19Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8701228000","value":"919886087903"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730074928, exit code: 1500, took: 59.107583 s
2021-11-13T08:09:56Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8712612155","value":"393290520847"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730111985, exit code: 0, took: 17.617013 s
2021-11-13T08:11:50Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730134777
2021-11-13T08:11:50Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730125957
2021-11-13T08:12:01Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8721010949","value":"5512981478835"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730134777, exit code: 1500, took: 53.403310 s
2021-11-13T08:12:02Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8697327565","value":"558499819704"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730125957, exit code: 1500, took: 86.369705 s
2021-11-13T08:12:27Z [2710] WARNING [3ad54] {engines} slow background settings sync: 7.039830 s
2021-11-13T08:12:39Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6205 ms ago, threshold value: 5000 ms
2021-11-13T08:12:43Z [2710] WARNING [3ad54] {engines} slow background settings sync: 8.392215 s
2021-11-13T08:12:51Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 7288 ms ago, threshold value: 5000 ms
2021-11-13T08:12:54Z [2710] WARNING [3ad54] {engines} slow background settings sync: 8.325210 s
2021-11-13T08:13:02Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8692829492","value":"554499585058"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730147386, exit code: 0, took: 61.704853 s
2021-11-13T08:13:03Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 8555 ms ago, threshold value: 5000 ms
2021-11-13T08:13:09Z [2710] WARNING [3ad54] {engines} slow background settings sync: 12.144523 s
2021-11-13T08:13:21Z [2710] WARNING [3ad54] {engines} slow background settings sync: 9.893286 s
2021-11-13T08:13:28Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6194 ms ago, threshold value: 5000 ms
2021-11-13T08:13:34Z [2710] WARNING [3ad54] {engines} slow background settings sync: 10.438037 s
2021-11-13T08:13:34Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6654 ms ago, threshold value: 5000 ms
2021-11-13T08:13:37Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8711935795","value":"34679806436"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730156143, exit code: 0, took: 60.899500 s
2021-11-13T08:13:41Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6672 ms ago, threshold value: 5000 ms
2021-11-13T08:13:46Z [2710] WARNING [3ad54] {engines} slow background settings sync: 9.238029 s
2021-11-13T08:13:59Z [2710] WARNING [3ad54] {engines} slow background settings sync: 10.018005 s
2021-11-13T08:14:04Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5727 ms ago, threshold value: 5000 ms
2021-11-13T08:14:06Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8721010949","value":"5512981478835"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730154864, exit code: 0, took: 93.207270 s
2021-11-13T08:14:11Z [2710] WARNING [3ad54] {engines} slow background settings sync: 9.742630 s
2021-11-13T08:14:16Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5038 ms ago, threshold value: 5000 ms
2021-11-13T08:14:21Z [2710] WARNING [3ad54] {engines} slow background settings sync: 7.399734 s
2021-11-13T08:14:26Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5632 ms ago, threshold value: 5000 ms
2021-11-13T08:14:29Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.771334 s
2021-11-13T08:14:35Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5605 ms ago, threshold value: 5000 ms
2021-11-13T08:14:38Z [2710] WARNING [3ad54] {engines} slow background settings sync: 6.688020 s
2021-11-13T08:14:51Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8716131093","value":"56992157926"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730151729, exit code: 0, took: 152.512148 s
2021-11-13T08:15:15Z [2710] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'VPackIndex' to let background writes catch up
2021-11-13T08:15:37Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5121 ms ago, threshold value: 5000 ms
2021-11-13T08:15:46Z [2710] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'default' to let background writes catch up
2021-11-13T08:16:31Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 10733 ms ago, threshold value: 5000 ms
2021-11-13T08:16:32Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730210999
2021-11-13T08:16:32Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730193415
2021-11-13T08:16:33Z [2710] WARNING [3ad54] {engines} slow background settings sync: 10.632769 s
2021-11-13T08:16:36Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8689664314","value":"491791095219"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730210999, exit code: 1500, took: 45.304468 s
2021-11-13T08:16:38Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8700028057","value":"917893707140"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730193415, exit code: 1500, took: 105.294816 s
2021-11-13T08:16:40Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 6956 ms ago, threshold value: 5000 ms
2021-11-13T08:16:53Z [2710] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'VPackIndex'
2021-11-13T08:16:54Z [2710] INFO [9123e] {engines} rocksdb is resuming normal writes for column family 'default'
2021-11-13T08:16:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T08:16:54Z [2710] INFO [99d80] {general} Running compaction task...
2021-11-13T08:16:54Z [2710] INFO [99d80] {general} Compacting access...
2021-11-13T08:16:54Z [2710] INFO [99d80] {general} Compacting accounts...
2021-11-13T08:16:54Z [2710] INFO [99d80] {general} Compacting addresses...
2021-11-13T08:16:54Z [2710] INFO [99d80] {general} Compacting products...
2021-11-13T08:16:54Z [2710] INFO [99d80] {general} Compacting phones...
2021-11-13T08:16:54Z [2710] INFO [99d80] {general} Compacting call_log...
2021-11-13T08:16:54Z [2710] INFO [99d80] {general} --------------------------
2021-11-13T08:18:03Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.521832 s
2021-11-13T08:18:25Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 7604 ms ago, threshold value: 5000 ms
2021-11-13T08:18:30Z [2710] WARNING [3ad54] {engines} slow background settings sync: 9.365467 s
2021-11-13T08:18:35Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5016 ms ago, threshold value: 5000 ms
2021-11-13T08:18:44Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730247074
2021-11-13T08:18:44Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730245209
2021-11-13T08:18:49Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8726434811","value":"61400626717"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730245209, exit code: 0, took: 55.333322 s
2021-11-13T08:18:49Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8683427158","value":"447827975781"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730247074, exit code: 1500, took: 51.249804 s
2021-11-13T08:20:49Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730285803
2021-11-13T08:20:49Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730278263
2021-11-13T08:20:53Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8686548524","value":"34646443926"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730278263, exit code: 1500, took: 49.269092 s
2021-11-13T08:20:53Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8686548524","value":"34646443926"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730285803, exit code: 1500, took: 17.822588 s
2021-11-13T08:22:08Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5521 ms ago, threshold value: 5000 ms
2021-11-13T08:22:11Z [2710] WARNING [3ad54] {engines} slow background settings sync: 6.766105 s
2021-11-13T08:22:27Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 13678 ms ago, threshold value: 5000 ms
2021-11-13T08:22:29Z [2710] WARNING [3ad54] {engines} slow background settings sync: 14.782792 s
2021-11-13T08:22:33Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8723925170","value":"5511957624935"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730310039, exit code: 0, took: 21.434510 s
2021-11-13T08:22:34Z [2710] INFO [5b708] {engines} last RocksDB WAL sync happened longer ago than configured threshold. last sync happened 5610 ms ago, threshold value: 5000 ms
2021-11-13T08:22:42Z [2710] WARNING [3ad54] {engines} slow background settings sync: 10.403591 s
2021-11-13T08:22:49Z [2710] WARNING [3ad54] {engines} slow background settings sync: 5.094525 s
2021-11-13T08:22:59Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730317589
2021-11-13T08:22:59Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730299459
2021-11-13T08:22:59Z [2710] WARNING [90113] {queries} killing AQL query 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', id:<PHONE_NUMBER>, token: QRY8730289988
2021-11-13T08:23:00Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8707081142","value":"39335201903"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730317589, exit code: 1500, took: 14.693691 s
2021-11-13T08:23:00Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8718574267","value":"5511951964465"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730299459, exit code: 1500, took: 91.459476 s
2021-11-13T08:23:01Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8708793580","value":"351968985893"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730289988, exit code: 1500, took: 130.033775 s
2021-11-13T08:23:17Z [2710] WARNING [8bcee] {queries} slow query: 'LET shIds = FLATTEN(FOR p IN phones FILTER p.number == @value RETURN p.callLogs) FOR l IN call_log FILTER l._id IN shIds FILTER l._key < @before SORT `l`.`_key` DESC LIMIT 0, 100 RETURN l', bind vars: {"before":"8707081142","value":"39335201903"}, database: db_log, user: admin, id:<PHONE_NUMBER>, token: QRY8730322538, exit code: 0, took: 12.896533 s
2021-11-13T08:24:35Z [2710] WARNING [9123c] {engines} rocksdb is slowing incoming writes to column family 'default' to let background writes catch up