Manish Joisar
Manish Joisar

Reputation: 1310

MarkLogic Log files showing Restarting XDQPServer,

We are using MarkLogic 9.0-7.2

Recently when we looked at MarkLogic log files, we found that there are lot of logging happening for Restarting XDQPServer, Stopping XDQPServerConnection, Starting domestic XDQPServerConnection.

This is happening on one of the node in 3 node cluster and at the same time there was spike in CPU usage on same node

2019-07-19 02:22:05.730 Info: Merging 12 MB from /data/Forests/test-002-1/00004965 and /data/Forests/test-002-1/00004964 to /data/Forests/test-002-1/00004966, timestamp=15635023204760890
2019-07-19 02:22:05.907 Info: Merged 4 MB at 23 MB/sec to /data/Forests/test-002-1/00004966
2019-07-19 02:22:10.092 Info: Deleted 4 MB at 1559 MB/sec /data/Forests/test-002-1/00004964
2019-07-19 02:22:10.094 Info: Deleted 8 MB at 3340 MB/sec /data/Forests/test-002-1/00004965
2019-07-19 02:33:40.108 Notice: Restarting XDQPServer, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:51376, recvTicks=20, sendTicks=17, sslChange=0
2019-07-19 02:33:40.108 Info: Stopping XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:51366, requests=0, recvTicks=0, sendTicks=14, recvs=45474194, sends=37524064, recvBytes=22595104264, sendBytes=36091745084
2019-07-19 02:33:40.108 Info: Stopping XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:51370, requests=0, recvTicks=0, sendTicks=10, recvs=45782975, sends=37524025, recvBytes=119571059752, sendBytes=36127613500
2019-07-19 02:33:40.108 Info: Stopping XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:51376, requests=0, recvTicks=0, sendTicks=18, recvs=45441834, sends=37524005, recvBytes=22565188068, sendBytes=36066592356
2019-07-19 02:33:42.900 Info: Starting domestic XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:54600
2019-07-19 02:33:43.125 Info: Stopping XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:46748, requests=0, recvTicks=0, sendTicks=0, recvs=4419607, sends=3677988, recvBytes=2305124592, sendBytes=3496374804
giving more
2019-07-19 02:33:43.125 Info: Stopping XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:46754, requests=0, recvTicks=0, sendTicks=0, recvs=4398854, sends=3677936, recvBytes=2407770572, sendBytes=3503131292
2019-07-19 02:33:43.125 Info: Stopping XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:46752, requests=0, recvTicks=0, sendTicks=0, recvs=4398978, sends=3677956, recvBytes=2270303720, sendBytes=3497036524
2019-07-19 02:33:43.176 Info: Starting domestic XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:46886
2019-07-19 02:33:44.807 Info: Starting domestic XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:46888
2019-07-19 02:33:45.085 Info: Starting domestic XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:46890
2019-07-19 02:33:48.372 Info: Starting domestic XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:54602
2019-07-19 02:33:53.633 Info: Saving /data/failover/Forests/test-001-1-2/00004935
2019-07-19 02:33:53.894 Info: Saved 8 MB at 31 MB/sec to /data/failover/Forests/test-001-1-2/00004935
2019-07-19 02:33:53.947 Info: Merging 30 MB from /data/failover/Forests/test-001-1-2/00004934 and /data/failover/Forests/test-001-1-2/00004935 to /data/failover/Forests/test-001-1-2/00004936, timestamp=15635029812437490
2019-07-19 02:34:01.953 Info: Merged 22 MB in 8 sec at 3 MB/sec to /data/failover/Forests/test-001-1-2/00004936
2019-07-19 02:34:04.214 Info: Deleted 22 MB at 6685 MB/sec /data/failover/Forests/test-001-1-2/00004934
2019-07-19 02:34:04.218 Info: Deleted 8 MB at 2427 MB/sec /data/failover/Forests/test-001-1-2/00004935
2019-07-19 02:34:05.041 Info: Stopping XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:46886, requests=0, recvTicks=0, sendTicks=9, recvs=60, sends=66, recvBytes=140384, sendBytes=40020
2019-07-19 02:34:05.041 Info: Stopping XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:46890, requests=0, recvTicks=0, sendTicks=4, recvs=57, sends=20, recvBytes=167120, sendBytes=63332
2019-07-19 02:34:05.041 Info: Stopping XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:46888, requests=0, recvTicks=0, sendTicks=5, recvs=20, sends=36, recvBytes=4456, sendBytes=11980
2019-07-19 02:34:11.127 Info: Starting domestic XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:46894
2019-07-19 02:34:11.156 Info: Starting domestic XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:54610
2019-07-19 02:34:15.017 Info: Starting domestic XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:46896
2019-07-19 02:34:16.447 Info: Starting domestic XDQPServerConnection, client=ip-10-x-xx-xxx.eu-west-1, conn=10.x.xx.xxx:7999-10.x.xx.xxx:46898

Now we want to understand how & what to investigate, what is solution for this?

Upvotes: 1

Views: 429

Answers (1)

Rob S.
Rob S.

Reputation: 3609

When reading log files it's good to keep the log levels in mind. I generally would not recommend you be concerned about any logs messages below a "Warning" level.

XDQP is a proprietary MarkLogic protocol for intra-cluster communication. This knowledge base article should cover everything you need to know about it.

I would bet your CPU spike has more to do with the merge activity in your log. I would not be surprised if you also found someone writing data to those merging forests during this period.

Upvotes: 4

Related Questions