ticsmtc6 commented on issue #1602: TIMEOUT_CLEAN_QUEUE, org.apache.rocketmq.store.ha.HAConnection.ReadSocketService#run this.selector.select(1000) cost 5000+ms URL: https://github.com/apache/rocketmq/issues/1602#issuecomment-557359835 @duhengforever java -version java version "1.8.0_151" uname -a Linux pro-ecs-rocketmq-3-66 3.10.0-693.2.2.el7.x86_64 #1 SMP Tue Sep 12 22:26:13 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux jvm confiuration: -Xms26g -Xmx26g -Xmn14g -XX:+UseG1GC -XX:G1HeapRegionSize=16m -XX:G1ReservePercent=25 -XX:InitiatingHeapOccupancyPercent=30 -XX:SoftRefLRUPolicyMSPerMB=0 -XX:SurvivorRatio=8 -verbose:gc -Xloggc:/dev/shm/mq_gc_%p.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -XX:+PrintAdaptiveSizePolicy -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=30m -XX:-OmitStackTraceInFastThrow -XX:+AlwaysPreTouch -XX:MaxDirectMemorySize=50g -XX:-UseLargePages -XX:-UseBiasedLocking -XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1 gc log: 2019-11-21T18:05:00.909+0800: 1655.004: Total time for which application threads were stopped: 0.0006644 seconds, Stopping threads took: 0.0001931 seconds 2019-11-21T18:05:08.486+0800: 1662.581: Total time for which application threads were stopped: 5.9630721 seconds, Stopping threads took: 0.0001196 seconds 2019-11-21T18:05:08.487+0800: 1662.582: Total time for which application threads were stopped: 0.0006973 seconds, Stopping threads took: 0.0001753 seconds 2019-11-21T18:05:08.487+0800: 1662.582: Total time for which application threads were stopped: 0.0005689 seconds, Stopping threads took: 0.0001733 seconds 2019-11-21T18:05:08.510+0800: 1662.606: [GC pause (G1 Evacuation Pause) (young) 1662.606: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 0, predicted base time: 10.72 ms, remaining time: 189.28 ms, target pause time: 200.00 ms] 1662.606: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 893 regions, survivors: 3 regions, predicted young region time: 8427.79 ms] 1662.606: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 893 regions, survivors: 3 regions, old: 0 regions, predicted pause time: 8438.51 ms, target pause time: 200.00 ms] 1662.636: [G1Ergonomics (Mixed GCs) do not start mixed GCs, reason: candidate old regions not available] , 0.0305605 secs] [Parallel Time: 23.1 ms, GC Workers: 8] [GC Worker Start (ms): Min: 1662606.0, Avg: 1662610.2, Max: 1662625.2, Diff: 19.2] [Ext Root Scanning (ms): Min: 0.0, Avg: 0.6, Max: 1.9, Diff: 1.8, Sum: 4.9] [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0] [Scan RS (ms): Min: 0.1, Avg: 0.2, Max: 0.5, Diff: 0.4, Sum: 1.6] [Code Root Scanning (ms): Min: 0.0, Avg: 0.8, Max: 5.9, Diff: 5.9, Sum: 6.4] [Object Copy (ms): Min: 1.1, Avg: 15.0, Max: 21.2, Diff: 20.1, Sum: 119.7] [Termination (ms): Min: 0.0, Avg: 2.1, Max: 2.4, Diff: 2.4, Sum: 16.9] [Termination Attempts: Min: 1, Avg: 2.1, Max: 3, Diff: 2, Sum: 17] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.3] [GC Worker Total (ms): Min: 3.7, Avg: 18.7, Max: 22.9, Diff: 19.2, Sum: 149.8] [GC Worker End (ms): Min: 1662628.9, Avg: 1662628.9, Max: 1662629.0, Diff: 0.1] [Code Root Fixup: 1.7 ms] [Code Root Purge: 0.0 ms] [Clear CT: 1.2 ms] [Other: 4.5 ms] [Choose CSet: 0.0 ms] [Ref Proc: 2.3 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.2 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 1.3 ms] [Eden: 14.0G(14.0G)->0.0B(13.9G) Survivors: 48.0M->80.0M Heap: 14.0G(26.0G)->67.6M(26.0G)] [Times: user=0.16 sys=0.00, real=0.03 secs] 2019-11-21T18:05:08.541+0800: 1662.636: Total time for which application threads were stopped: 0.0319419 seconds, Stopping threads took: 0.0007202 seconds Corresponding safepoint log: 1655.004: no vm operation [ 192 0 0 ] [ 0 0 0 0 0 ] 0 vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count 1656.618: PrintThreads [ 192 0 0 ] [ 0 0 0 0 5962 ] 0 vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count 1662.581: PrintJNI [ 192 0 0 ] [ 0 0 0 0 0 ] 0 vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count 1662.582: FindDeadlocks [ 192 0 1 ] [ 0 0 0 0 0 ] 0 vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count 1662.604: G1IncCollectionPause [ 192 2 1 ] [ 0 0 0 0 30 ] 1
---------------------------------------------------------------- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. For queries about this service, please contact Infrastructure at: [email protected] With regards, Apache Git Services
