HI,
I was trying to load data using csv file (each file contains 5 million rows of
record which is approx.. 4 GB of data) using COPY command.
In initial stage of loading it was quit fast, but later the load process start
slowing down and showing hardly 1% of CPU usage. My cluster has 5 nodes, each
with 8 core CPU and 32 GB RAM.
When I checked one node's log, I have seen some sever messages which is like
what I have give below.
Can some one help me to understand the error details give below and how can I
improve my data load speed.
[08:51:00,910][INFO][wal-file-archiver%null-#54][FileWriteAheadLogManager]
Copied file
[src=/data/apache-ignite-2.7.5-bin/work/db/wal/node00-18be5852-ed47-40a7-a256-ebbaa3376d39/0000000000000006.wal,
dst=/data/apache-ignite-2.7.5-bin/work/db/wal/archive/node00-18be5852-ed47-40a7-a256-ebbaa3376d39/0000000000003066.wal]
[08:51:00,910][INFO][wal-file-archiver%null-#54][FileWriteAheadLogManager]
Starting to copy WAL segment [absIdx=3067, segIdx=7,
origFile=/data/apache-ignite-2.7.5-bin/work/db/wal/node00-18be5852-ed47-40a7-a256-ebbaa3376d39/0000000000000007.wal,
dstFile=/data/apache-ignite-2.7.5-bin/work/db/wal/archive/node00-18be5852-ed47-40a7-a256-ebbaa3376d39/0000000000003067.wal]
[08:51:08,512][SEVERE][tcp-disco-msg-worker-#2][G] Blocked system-critical
thread has been detected. This can lead to cluster-wide undefined behaviour
[threadName=data-streamer-stripe-2, blockedFor=31s]
[08:51:08,512][WARNING][tcp-disco-msg-worker-#2][G] Thread
[name="data-streamer-stripe-2-#11", id=24, state=WAITING, blockCnt=0,
waitCnt=81018]
Lock [object=java.util.concurrent.locks.ReentrantLock$NonfairSync@23aede76,
ownerName=data-streamer-stripe-4-#13, ownerId=26]
[08:51:08,512][SEVERE][tcp-disco-msg-worker-#2][] Critical system error
detected. Will be handled accordingly to configured handler
[hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0,
super=AbstractFailureHandler [ignoredFailureTypes=[SYSTEM_WORKER_BLOCKED,
SYSTEM_CRITICAL_OPERATION_TIMEOUT]]], failureCtx=FailureContext
[type=SYSTEM_WORKER_BLOCKED, err=class o.a.i.IgniteException: GridWorker
[name=data-streamer-stripe-2, igniteInstanceName=null, finished=false,
heartbeatTs=1568278237174]]]
class org.apache.ignite.IgniteException: GridWorker
[name=data-streamer-stripe-2, igniteInstanceName=null, finished=false,
heartbeatTs=1568278237174]
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1831)
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1826)
at
org.apache.ignite.internal.worker.WorkersRegistry.onIdle(WorkersRegistry.java:233)
at
org.apache.ignite.internal.util.worker.GridWorker.onIdle(GridWorker.java:297)
at
org.apache.ignite.spi.discovery.tcp.ServerImpl$RingMessageWorker.lambda$new$0(ServerImpl.java:2663)
at
org.apache.ignite.spi.discovery.tcp.ServerImpl$MessageWorker.body(ServerImpl.java:7181)
at
org.apache.ignite.spi.discovery.tcp.ServerImpl$RingMessageWorker.body(ServerImpl.java:2700)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at
org.apache.ignite.spi.discovery.tcp.ServerImpl$MessageWorkerThread.body(ServerImpl.java:7119)
at org.apache.ignite.spi.IgniteSpiThread.run(IgniteSpiThread.java:62)
[08:51:08,513][WARNING][tcp-disco-msg-worker-#2][FailureProcessor] No
deadlocked threads detected.
[08:51:08,853][WARNING][tcp-disco-msg-worker-#2][FailureProcessor] Thread dump
at 2019/09/12 08:51:08 UTC
Thread [name="sys-#1257", id=1683, state=TIMED_WAITING, blockCnt=0, waitCnt=1]
Lock
[object=java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@5ece7692,
ownerName=null, ownerId=-1]
at sun.misc.Unsafe.park(Native Method)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at
java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Thread [name="sys-#1256", id=1682, state=TIMED_WAITING, blockCnt=0, waitCnt=1]
Lock
[object=java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@5ece7692,
ownerName=null, ownerId=-1]
at sun.misc.Unsafe.park(Native Method)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at
java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Thread [name="sys-#1255", id=1681, state=TIMED_WAITING, blockCnt=0, waitCnt=1]
Lock
[object=java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@5ece7692,
ownerName=null, ownerId=-1]
at sun.misc.Unsafe.park(Native Method)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at
java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Thread [name="sys-#1254", id=1680, state=TIMED_WAITING, blockCnt=0, waitCnt=1]
Lock
[object=java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@5ece7692,
ownerName=null, ownerId=-1]
at sun.misc.Unsafe.park(Native Method)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at
java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Thread [name="query-#1253", id=1679, state=TIMED_WAITING, blockCnt=0, waitCnt=1]
Lock
[object=java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@5de43f6a,
ownerName=null, ownerId=-1]
at sun.misc.Unsafe.park(Native Method)
at
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at
java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Regards,
Favas
