My setup is the following:
server1:
- master
- zookeeper
server2:
- zookeeper
server3:
- zookeeper
server 4 t/m 8
- regionserver
HBase: hbase-0.98.7-hadoop1
Zookeeper: zookeeper-3.4.6
hadoop: 1.2.1
Every night at aprox 00:07 UTC the master and all the regionservers
will
shutdown.
When I monitor server1 with munin, I don't see any extra load
(io,memory,cpu) at that time.
gc.log showed me that the garbage collection is also fast. See
below the
compromised logs. I'm little bit out of options what is causing
this. Does
anyone have a clue what is happening?
Thanks in advice,
Ron
Logs master server1
===================
2014-10-27 23:06:36,503 INFO [master:vps2008:60000-SendThread(
141.105.120.103:2181)] zookeeper.ClientCnxn: Unable to read
additional
data from server sessionid 0x1494ed899bd0211, likely server has
closed
socket, closing socket connection and attempting reconnect
2014-10-27 23:06:37,035 INFO [master:vps2008:60000-SendThread(
141.105.120.102:2181)] zookeeper.ClientCnxn: Opening socket
connection to
server 141.105.120.102/141.105.120.102:2181. Will not attempt to
authenticate using SASL (unknown error)
2014-10-27 23:06:37,036 INFO [master:vps2008:60000-SendThread(
141.105.120.102:2181)] zookeeper.ClientCnxn: Socket connection
established to 141.105.120.102/141.105.120.102:2181, initiating
session
2014-10-27 23:06:37,037 INFO [master:vps2008:60000-SendThread(
141.105.120.102:2181)] zookeeper.ClientCnxn: Unable to read
additional
data from server sessionid 0x1494ed899bd0211, likely server has
closed
socket, closing socket connection and attempting reconnect
2014-10-27 23:06:37,583 INFO [master:vps2008:60000-SendThread(
141.105.121.127:2181)] zookeeper.ClientCnxn: Opening socket
connection to
server 141.105.121.127/141.105.121.127:2181. Will not attempt to
authenticate using SASL (unknown error)
......
2014-10-27 23:47:35,881 INFO [JvmPauseMonitor] util.JvmPauseMonitor:
Detected pause in JVM or host machine (eg GC): pause of
approximately 1068ms
No GCs detected
5x probarly every regionserver:
2014-10-27 23:47:35,937 WARN [RpcServer.reader=9,port=60000]
ipc.RpcServer: RpcServer.listener,port=60000: count of bytes read: 0
java.io.IOException: Connection reset by peer
at sun.nio.ch.FileDispatcherImpl.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
at sun.nio.ch.IOUtil.read(IOUtil.java:197)
at
sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:379)
at org.apache.hadoop.hbase.ipc.RpcServer.channelRead(
RpcServer.java:2244)
at org.apache.hadoop.hbase.ipc.RpcServer$Connection.
readAndProcess(RpcServer.java:1423)
at org.apache.hadoop.hbase.ipc.RpcServer$Listener.doRead(
RpcServer.java:798)
at org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.
doRunLoop(RpcServer.java:589)
at org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.run(
RpcServer.java:564)
at java.util.concurrent.ThreadPoolExecutor.runWorker(
ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(
ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
.....
2014-10-28 00:01:23,798 WARN [master:vps2008:60000.oldLogCleaner]
zookeeper.RecoverableZooKeeper: Possibly transient ZooKeeper,
quorum=
141.105.120.103:2181,141.105.120.102:2181,141.105.121.127:2181,
exception=org.apache.z
ookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /hbase/replication/rs
2014-10-28 00:01:23,798 ERROR [master:vps2008:60000.oldLogCleaner]
zookeeper.RecoverableZooKeeper: ZooKeeper getChildren failed after 4
attempts
2014-10-28 00:01:23,799 WARN [master:vps2008:60000.oldLogCleaner]
master.ReplicationLogCleaner: Aborting ReplicationLogCleaner
because Failed
to get list of replicators
org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /hbase/replication/rs
at org.apache.zookeeper.KeeperException.create(
KeeperException.java:127)
at org.apache.zookeeper.KeeperException.create(
KeeperException.java:51)
at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.
getChildren(RecoverableZooKeeper.java:296)
at org.apache.hadoop.hbase.zookeeper.ZKUtil.
listChildrenNoWatch(ZKUtil.java:573)
at
org.apache.hadoop.hbase.replication.ReplicationStateZKBase.
getListOfReplicators(ReplicationStateZKBase.java:79)
at org.apache.hadoop.hbase.replication.master.
ReplicationLogCleaner.loadHLogsFromQueues(ReplicationLogCleaner.java:88)
at org.apache.hadoop.hbase.replication.master.
ReplicationLogCleaner.getDeletableFiles(ReplicationLogCleaner.java:67)
at org.apache.hadoop.hbase.master.cleaner.CleanerChore.
checkAndDeleteFiles(CleanerChore.java:233)
at org.apache.hadoop.hbase.master.cleaner.CleanerChore.
checkAndDeleteEntries(CleanerChore.java:157)
at org.apache.hadoop.hbase.master.cleaner.CleanerChore.
chore(CleanerChore.java:124)
at org.apache.hadoop.hbase.Chore.run(Chore.java:80)
at java.lang.Thread.run(Thread.java:745)
.....
2014-10-28 00:06:05,997 ERROR
[MASTER_META_SERVER_OPERATIONS-vps2008:60000-0]
handler.MetaServerShutdownHandler: Caught M_META_SERVER_SHUTDOWN,
count=1
java.io.IOException: failed log splitting for
vps2060.directvps.nl,60020,1414414327187,
will retry
at org.apache.hadoop.hbase.master.handler.
MetaServerShutdownHandler.process(MetaServerShutdownHandler.java:84)
at org.apache.hadoop.hbase.executor.EventHandler.run(
EventHandler.java:128)
at java.util.concurrent.ThreadPoolExecutor.runWorker(
ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(
ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.io.IOException: error or interrupted while
splitting logs
in [hdfs://namenode.openindex.io:8020/hbase/WALs/vps2060.
directvps.nl,60020,1414414327187-splitting] Task = installed = 1
done = 0
error = 1
at org.apache.hadoop.hbase.master.SplitLogManager.
splitLogDistributed(SplitLogManager.java:359)
at org.apache.hadoop.hbase.master.MasterFileSystem.
splitLog(MasterFileSystem.java:416)
at org.apache.hadoop.hbase.master.MasterFileSystem.
splitMetaLog(MasterFileSystem.java:308)
at org.apache.hadoop.hbase.master.MasterFileSystem.
splitMetaLog(MasterFileSystem.java:299)
at org.apache.hadoop.hbase.master.handler.
MetaServerShutdownHandler.process(MetaServerShutdownHandler.java:77)
... 4 more
2014-10-28 00:06:05,997 INFO
[MASTER_META_SERVER_OPERATIONS-vps2008:60000-1]
handler.MetaServerShutdownHandler: Splitting hbase:meta logs for
vps2060.directvps.nl,60020,1414414327187
2014-10-28 00:06:06,006 INFO
[MASTER_META_SERVER_OPERATIONS-vps2008:60000-1]
master.SplitLogManager: dead splitlog workers
[vps2060.directvps.nl,60020,
1414414327187]
2014-10-28 00:06:06,021 INFO [main-EventThread]
zookeeper.ClientCnxn:
EventThread shut down
2014-10-28 00:06:06,021 INFO [master:vps2008:60000]
zookeeper.ZooKeeper:
Session: 0x1495400a0370000 closed
2014-10-28 00:06:06,021 INFO [master:vps2008:60000] master.HMaster:
HMaster main thread exiting
2014-10-28 00:06:06,022 ERROR [main] master.HMasterCommandLine:
Master
exiting
java.lang.RuntimeException: HMaster Aborted
at
org.apache.hadoop.hbase.master.HMasterCommandLine.startMaster(
HMasterCommandLine.java:194)
at org.apache.hadoop.hbase.master.HMasterCommandLine.run(
HMasterCommandLine.java:135)
at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:65)
at org.apache.hadoop.hbase.util.ServerCommandLine.doMain(
ServerCommandLine.java:126)
Logs of zookeeper server1:
==========================
2014-10-27 23:06:36,562 [myid:2] - WARN
[QuorumPeer[myid=2]/0:0:0:0:0:
0:0:0:2181:Follower@89] - Exception when following the leader
java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at
java.net.SocketInputStream.read(SocketInputStream.java:152)
at
java.net.SocketInputStream.read(SocketInputStream.java:122)
at
java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
at
java.io.BufferedInputStream.read(BufferedInputStream.java:254)
at java.io.DataInputStream.readInt(DataInputStream.java:387)
at org.apache.jute.BinaryInputArchive.readInt(
BinaryInputArchive.java:63)
at org.apache.zookeeper.server.quorum.QuorumPacket.
deserialize(QuorumPacket.java:83)
at org.apache.jute.BinaryInputArchive.readRecord(
BinaryInputArchive.java:103)
at org.apache.zookeeper.server.quorum.Learner.readPacket(
Learner.java:153)
at org.apache.zookeeper.server.quorum.Follower.followLeader(
Follower.java:85)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(
QuorumPeer.java:786)
2014-10-27 23:06:36,629 [myid:2] - INFO
[QuorumPeer[myid=2]/0:0:0:0:0:
0:0:0:2181:Follower@166] - shutdown called
java.lang.Exception: shutdown Follower
at org.apache.zookeeper.server.quorum.Follower.shutdown(
Follower.java:166)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(
QuorumPeer.java:790)
2014-10-27 23:06:36,630 [myid:2] - INFO
[QuorumPeer[myid=2]/0:0:0:0:0:
0:0:0:2181:FollowerZooKeeperServer@139] - Shutting down
2014-10-27 23:06:36,630 [myid:2] - INFO
[QuorumPeer[myid=2]/0:0:0:0:0:
0:0:0:2181:ZooKeeperServer@441] - shutting down
2014-10-27 23:06:36,630 [myid:2] - INFO
[QuorumPeer[myid=2]/0:0:0:0:0:
0:0:0:2181:FollowerRequestProcessor@105] - Shutting down
2014-10-27 23:06:36,631 [myid:2] - INFO [FollowerRequestProcessor:2:
FollowerRequestProcessor@95] - FollowerRequestProcessor exited loop!
2014-10-27 23:06:36,632 [myid:2] - INFO
[QuorumPeer[myid=2]/0:0:0:0:0:
0:0:0:2181:CommitProcessor@181] - Shutting down
2014-10-27 23:06:36,632 [myid:2] - INFO
[QuorumPeer[myid=2]/0:0:0:0:0:
0:0:0:2181:FinalRequestProcessor@415] - shutdown of request
processor
complete
2014-10-27 23:06:36,632 [myid:2] - INFO
[QuorumPeer[myid=2]/0:0:0:0:0:
0:0:0:2181:SyncRequestProcessor@209] - Shutting down
2014-10-27 23:06:36,633 [myid:2] - INFO [SyncThread:2:
SyncRequestProcessor@187] - SyncRequestProcessor exited!
2014-10-27 23:06:36,633 [myid:2] - INFO
[QuorumPeer[myid=2]/0:0:0:0:0:
0:0:0:2181:QuorumPeer@714] - LOOKING
2014-10-27 23:06:36,635 [myid:2] - INFO [CommitProcessor:2:
CommitProcessor@150] - CommitProcessor exited loop!
2014-10-27 23:06:36,716 [myid:2] - INFO
[QuorumPeer[myid=2]/0:0:0:0:0:
0:0:0:2181:FileSnap@83] - Reading snapshot
/opt/zookeeper/data/version-2/
snapshot.ed00000df4
2014-10-27 23:06:36,774 [myid:2] - INFO [WorkerReceiver[myid=2]:
FastLeaderElection@597] - Notification: 1 (message format version),
1
(n.leader), 0xed00000e01 (n.zxid), 0xf9 (n.round), LOOKING
(n.state), 1
(n.sid), 0xed (
n.peerEpoch) LOOKING (my state)
2014-10-27 23:06:36,816 [myid:2] - INFO
[NIOServerCxn.Factory:0.0.0.0/
0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection
from /
141.105.120.150:47142
2014-10-27 23:06:36,844 [myid:2] - WARN
[NIOServerCxn.Factory:0.0.0.0/
0.0.0.0:2181:NIOServerCnxn@362] - Exception causing close of
session 0x0
due to java.io.IOException: ZooKeeperServer not running
2014-10-27 23:06:36,845 [myid:2] - INFO
[NIOServerCxn.Factory:0.0.0.0/
0.0.0.0:2181:NIOServerCnxn@1007] - Closed socket connection for
client /
141.105.120.150:47142 (no session established for client)
.....
2014-10-28 00:07:18,464 [myid:2] - INFO
[NIOServerCxn.Factory:0.0.0.0/
0.0.0.0:2181:ZooKeeperServer@868] - Client attempting to establish
new
session at /141.105.125.180:56530
2014-10-28 00:07:18,468 [myid:2] - INFO [CommitProcessor:2:
ZooKeeperServer@617] - Established session 0x24954020e470268 with
negotiated timeout 6000 for client /141.105.125.180:56530
2014-10-28 00:07:18,483 [myid:2] - INFO
[NIOServerCxn.Factory:0.0.0.0/
0.0.0.0:2181:NIOServerCnxn@1007] - Closed socket connection for
client /
141.105.125.180:56530 which had sessionid 0x24954020e470268
2014-10-28 00:07:18,632 [myid:2] - INFO
[NIOServerCxn.Factory:0.0.0.0/
0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection
from /
178.21.116.224:45958
2014-10-28 00:07:18,632 [myid:2] - WARN
[NIOServerCxn.Factory:0.0.0.0/
0.0.0.0:2181:ZooKeeperServer@822] - Connection request from old
client /
178.21.116.224:45958; will be dropped if server is in r-o mode
2014-10-28 00:07:18,632 [myid:2] - INFO
[NIOServerCxn.Factory:0.0.0.0/
0.0.0.0:2181:ZooKeeperServer@868] - Client attempting to establish
new
session at /178.21.116.224:45958
2014-10-28 00:07:18,636 [myid:2] - INFO [CommitProcessor:2:
ZooKeeperServer@617] - Established session 0x24954020e470269 with
negotiated timeout 6000 for client /178.21.116.224:45958
2014-10-28 00:07:18,650 [myid:2] - WARN
[NIOServerCxn.Factory:0.0.0.0/
0.0.0.0:2181:NIOServerCnxn@357] - caught end of stream exception
EndOfStreamException: Unable to read additional data from client
sessionid
0x24954020e470269, likely client has closed socket
at org.apache.zookeeper.server.NIOServerCnxn.doIO(
NIOServerCnxn.java:228)
at org.apache.zookeeper.server.NIOServerCnxnFactory.run(
NIOServerCnxnFactory.java:208)
at java.lang.Thread.run(Thread.java:745)
2014-10-28 00:07:18,651 [myid:2] - INFO
[NIOServerCxn.Factory:0.0.0.0/
0.0.0.0:2181:NIOServerCnxn@1007] - Closed socket connection for
client /
178.21.116.224:45958 which had sessionid 0x24954020e470269
Gc log server1 (date and time may differ, but same result is shown
at time
of problem)
============================================================
==========================
2014-10-23T07:39:02.597+0000: 0.334:
[GC2014-10-23T07:39:02.597+0000:
0.334: [ParNew: 4288K->512K(4800K), 0.0068790 secs]
4288K->1288K(15424K),
0.0069880 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2014-10-23T07:39:02.676+0000: 0.413:
[GC2014-10-23T07:39:02.676+0000:
0.413: [ParNew: 4800K->511K(4800K), 0.0136860 secs]
5576K->2274K(15424K),
0.0137620 secs] [Times: user=0.01 sys=0.01, real=0.01 secs]
2014-10-23T07:39:02.759+0000: 0.496:
[GC2014-10-23T07:39:02.759+0000:
0.496: [ParNew: 4790K->511K(4800K), 0.0039330 secs]
6553K->2582K(15424K),
0.0040040 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
...
2014-10-23T07:39:03.621+0000: 1.358:
[GC2014-10-23T07:39:03.621+0000:
1.358: [ParNew: 4799K->512K(4800K), 0.0022680 secs]
9184K->5281K(15424K),
0.0023360 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2014-10-23T07:39:03.803+0000: 1.540:
[GC2014-10-23T07:39:03.803+0000:
1.540: [ParNew: 4800K->512K(4800K), 0.0018700 secs]
9569K->5586K(15424K),
0.0019370 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2014-10-23T07:39:03.915+0000: 1.652:
[GC2014-10-23T07:39:03.915+0000:
1.652: [ParNew: 4800K->512K(4800K), 0.0019160 secs]
9874K->6010K(15424K),
0.0019840 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2014-10-23T07:39:03.918+0000: 1.654: [GC [1 CMS-initial-mark:
5498K(10624K)] 6010K(15424K), 0.0041480 secs] [Times: user=0.00
sys=0.00,
real=0.01 secs] 2014-10-23T07:39:03.922+0000: 1.659:
[CMS-concurrent-mark-start]
2014-10-23T07:39:03.964+0000: 1.701: [CMS-concurrent-mark:
0.038/0.042
secs] [Times: user=0.09 sys=0.00, real=0.04 secs]
2014-10-23T07:39:03.964+0000: 1.701: [CMS-concurrent-preclean-start]
2014-10-23T07:39:03.965+0000: 1.702: [CMS-concurrent-preclean:
0.001/0.001
secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2014-10-23T07:39:03.971+0000: 1.708: [GC[YG occupancy: 1582 K (4800
K)]2014-10-23T07:39:03.971+0000: 1.708: [Rescan (parallel) ,
0.0013900
secs]2014-10-23T07:39:03.972+0000: 1.709: [weak refs processing,
0.0000240 secs]2014-10-23T07:39:03.973+0000: 1.709: [scrub string
table,
0.0001890 secs] [1 CMS-remark: 5498K(10624K)] 7081K(15424K),
0.0016880
secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2014-10-23T07:39:03.973+0000: 1.710: [CMS-concurrent-sweep-start]
2014-10-23T07:39:03.974+0000: 1.711: [CMS-concurrent-sweep:
0.001/0.001
secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2014-10-23T07:39:03.974+0000: 1.711: [CMS-concurrent-reset-start]
2014-10-23T07:39:04.086+0000: 1.823:
[GC2014-10-23T07:39:04.086+0000:
1.823: [ParNew: 4800K->512K(4800K), 0.0016370 secs]
7380K->3450K(15424K),
0.0017180 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2014-10-23T07:39:04.146+0000: 1.883: [CMS-concurrent-reset:
0.170/0.172
secs] [Times: user=0.11 sys=0.16, real=0.17 secs]
2014-10-23T07:39:04.194+0000: 1.931:
[GC2014-10-23T07:39:04.194+0000:
1.931: [ParNew: 4799K->512K(4800K), 0.0015060 secs]
7737K->3610K(15424K),
0.0015850 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2014-10-23T07:39:04.347+0000: 2.084:
[GC2014-10-23T07:39:04.347+0000:
2.084: [ParNew: 4800K->511K(4800K), 0.0019550 secs]
7898K->3849K(15424K),
0.0020250 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2014-10-23T07:39:04.430+0000: 2.167:
[GC2014-10-23T07:39:04.431+0000:
2.167: [ParNew: 4799K->495K(4800K), 0.0021720 secs]
8137K->3981K(15424K),
0.0022710 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
....
secs] 2014-10-23T07:40:05.961+0000: 63.698:
[GC2014-10-23T07:40:05.961+0000:
63.698: [ParNew: 4649K->511K(4800K), 0.0028340 secs]
13309K->9479K(15424K),
0.0029510 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2014-10-23T07:40:14.198+0000: 71.935:
[GC2014-10-23T07:40:14.198+0000:
71.935: [ParNew: 4799K->511K(4800K), 0.0029840 secs]
13767K->9895K(15424K),
0.0030750 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2014-10-23T07:40:14.289+0000: 72.025:
[GC2014-10-23T07:40:14.289+0000:
72.026: [ParNew: 4799K->512K(4800K), 0.0023430 secs]
14183K->10375K(15424K), 0.0024230 secs] [Times: user=0.01 sys=0.00,
real=0.01 secs] 2014-10-23T07:40:14.291+0000: 72.028: [GC [1
CMS-initial-mark: 9863K(10624K)] 10383K(15424K), 0.0009020 secs]
[Times:
user=0.00 sys=0.00, real=0.00 secs] 2014-10-23T07:40:14.292+0000:
72.029:
[CMS-concurrent-mark-start]
2014-10-23T07:40:14.322+0000: 72.059: [CMS-concurrent-mark:
0.030/0.030
secs] [Times: user=0.06 sys=0.00, real=0.03 secs]
2014-10-23T07:40:14.322+0000: 72.059:
[CMS-concurrent-preclean-start]
2014-10-23T07:40:14.322+0000: 72.059: [CMS-concurrent-preclean:
0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2014-10-23T07:40:14.322+0000: 72.059: [CMS-concurrent-abortable-
preclean-start]
CMS: abort preclean due to time 2014-10-23T07:40:19.353+0000:
77.090:
[CMS-concurrent-abortable-preclean: 0.089/5.030 secs] [Times:
user=0.11
sys=0.01, real=5.03 secs] 2014-10-23T07:40:19.353+0000: 77.090:
[GC[YG
occupancy: 3651 K (4800 K)]2014-10-23T07:40:19.354+0000: 77.091:
[Rescan
(parallel) , 0.0020850 secs]2014-10-23T07:40:19.356+0000: 77.093:
[weak
refs processing, 0.0001570 secs]2014-10-23T07:40:19.356+0000:
77.093:
[scrub string table, 0.0004000 secs] [1 CMS-remark: 9863K(10624K)]
13514K(15424K), 0.0034860 secs] [Times: user=0.00 sys=0.00,
real=0.00 secs]
2014-10-23T07:40:19.357+0000: 77.094: [CMS-concurrent-sweep-start]
2014-10-23T07:40:19.360+0000: 77.097: [CMS-concurrent-sweep:
0.003/0.003
secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2014-10-23T07:40:19.361+0000: 77.097: [CMS-concurrent-reset-start]
2014-10-23T07:40:19.362+0000: 77.099: [CMS-concurrent-reset:
0.001/0.001
secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2014-10-23T07:41:56.874+0000: 174.611:
[GC2014-10-23T07:41:56.875+0000:
174.611: [ParNew: 4800K->512K(4800K), 0.0021740 secs]
10761K->6828K(15424K), 0.0022740 secs] [Times: user=0.01 sys=0.00,
real=0.00 secs] 2014-10-23T07:47:21.160+0000: 498.897:
[GC2014-10-23T07:47:21.160+0000: 498.897: [ParNew:
4800K->286K(4800K),
0.0025590 secs] 11116K->7045K(15424K), 0.0026680 secs] [Times:
user=0.00
sys=0.00, real=0.01 secs]
...
2014-10-23T08:39:29.672+0000: 3627.409:
[GC2014-10-23T08:39:29.672+0000:
3627.409: [ParNew: 4705K->512K(4800K), 0.0045100 secs]
12027K->8045K(15424K), 0.0046410 secs] [Times: user=0.01 sys=0.00,
real=0.00 secs] 2014-10-23T08:45:08.685+0000: 3966.422:
[GC2014-10-23T08:45:08.686+0000: 3966.422: [ParNew:
4800K->478K(4800K),
0.0035990 secs] 12333K->8609K(15424K), 0.0036800 secs] [Times:
user=0.01
sys=0.00, real=0.00 secs] Heap
par new generation total 4800K, used 827K [0x00000000b7200000,
0x00000000b7730000, 0x00000000c1860000)
eden space 4288K, 8% used [0x00000000b7200000, 0x00000000b72573b0,
0x00000000b7630000)
from space 512K, 93% used [0x00000000b76b0000, 0x00000000b7727980,
0x00000000b7730000)
to space 512K, 0% used [0x00000000b7630000, 0x00000000b7630000,
0x00000000b76b0000)
concurrent mark-sweep generation total 10624K, used 8130K
[0x00000000c1860000, 0x00000000c22c0000, 0x00000000f5a00000)
concurrent-mark-sweep perm gen total 50636K, used 30752K
[0x00000000f5a00000, 0x00000000f8b73000, 0x0000000100000000)
