Cloudera Community

Support Questions

Find answers, ask questions, and share your expertise
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Show  only  | Search instead for 
Did you mean: 
Advanced Search
Solved Go to solution

Regionserver is not getting started on one of the datanode in 9 node cluster.

avatar
author-rank raja_ray
Expert Contributor

Created ‎03-07-2016 01:53 PM

I have installed Apache Ambari 2.0.0 using HDP distribution. i have 9 node in HA cluster in which 6 is datanodes and other are master node. version of hadoop is 2.6.0 and version of hbase is 0.98.4. i have changed one configuration in hbase-site.xml in ambari(changed HBase Client Maximum key-value Size from 10485760 to 20485760). when i restarting hbase, it is taking too long to respond(around 50 minutes) in ambari and finally getting failed. i tried to restart regionserver manually one by one. it started regionserver successfully on all the slaves except one. surprisingly this particular regionserver is not even getting stopped through ambari. please help! how can i restart hbase sucessfully?

5,529 Views
1 ACCEPTED SOLUTION

avatar
author-rank raja_ray
Expert Contributor

Created ‎03-08-2016 10:02 AM

Hi Artem,

I restarted ambari-agent on the server and then restarted region-server. it worked fine..

View solution in original post

4,611 Views
11 REPLIES 11

avatar
author-rank aervits
Master Mentor

Created ‎03-07-2016 02:06 PM

@Raja Ray please post regionserver logs for that node. Can you also consider upgrading to latest Ambari release as there are fixes on top of 2.0.0, at least 2.0.2 if not 2.1 or 2.2. You can also go to the node where regionserver does not restart and kill the service manually. 

ps aux | grep java

find the pid associated with hbase regionserver then

kill -9 hbasepidnumber
4,334 Views

avatar
author-rank raja_ray
Expert Contributor

Created ‎03-07-2016 03:04 PM

Hi Artem,

I contacted your sales guys, but no one responded. Can you ask your sales guys to contact me at raja.ray@e-arc.in , so that we can discuss/open support account with Hortonworks.

Thanks,

Raja Ray

4,334 Views
0 Kudos

avatar
author-rank aervits
Master Mentor

Created ‎03-07-2016 03:04 PM

@Raja Ray can you provide more information? What's your location and company name?

4,334 Views
0 Kudos

avatar
author-rank raja_ray
Expert Contributor

Created ‎03-08-2016 05:27 AM

Hi Artem,

My organization Name - ARC Document Solutions. Location - Kolkata, India.

Thanks,

Raja Ray

4,334 Views
0 Kudos

avatar
author-rank raja_ray
Expert Contributor

Created ‎03-07-2016 02:23 PM

Hi @Artem Ervits Thank you for prompt response. here is my regionserver log. 

tail -200f hbase-hbase-regionserver-sachadooptst8.corp.mirrorplus.com.log
2016-03-07 03:05:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717882, hits=1588141, hitRatio=92.45%, , cachingAccesses=1606691, cachingHits=1540463, cachingHitsRatio=95.88%, evictions=1070952, evicted=57078, evictedPerRun=0.05329650640487671
2016-03-07 03:05:45,130 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:57230; # active connections: 3
2016-03-07 03:07:45,155 DEBUG [RpcServer.reader=4,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:57230 because read count=-1. Number of active connections: 3
2016-03-07 03:10:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717890, hits=1588149, hitRatio=92.45%, , cachingAccesses=1606699, cachingHits=1540471, cachingHitsRatio=95.88%, evictions=1070982, evicted=57078, evictedPerRun=0.053295012563467026
2016-03-07 03:10:45,137 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:57315; # active connections: 3
2016-03-07 03:12:45,165 DEBUG [RpcServer.reader=5,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:57315 because read count=-1. Number of active connections: 3
2016-03-07 03:12:58,556 DEBUG [regionserver60020.compactionChecker] compactions.RatioBasedCompactionPolicy: Skipping major compaction of org.apache.hadoop.hbase.regionserver.compactions.ExploringCompactionPolicy@551a16c8 because one (major) compacted file only and oldestTime 10123427453ms is < ttl=9223372036854775807
2016-03-07 03:12:58,556 DEBUG [regionserver60020.compactionChecker] compactions.RatioBasedCompactionPolicy: Skipping major compaction of org.apache.hadoop.hbase.regionserver.compactions.ExploringCompactionPolicy@23cdd01e because one (major) compacted file only and oldestTime 9699207092ms is < ttl=9223372036854775807
2016-03-07 03:12:58,556 DEBUG [regionserver60020.compactionChecker] compactions.RatioBasedCompactionPolicy: Skipping major compaction of org.apache.hadoop.hbase.regionserver.compactions.ExploringCompactionPolicy@1d1a73ef because one (major) compacted file only and oldestTime 8724522920ms is < ttl=9223372036854775807
2016-03-07 03:14:56,676 DEBUG [regionserver60020.logRoller] regionserver.LogRoller: Hlog roll period 3600000ms elapsed
2016-03-07 03:14:56,766 INFO  [regionserver60020.logRoller] wal.FSHLog: Rolled WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457345696551 with entries=144, filesize=43.9 K; new WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457349296676
2016-03-07 03:15:18,334 DEBUG [RpcServer.reader=1,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: Caught exception while reading:Connection reset by peer
2016-03-07 03:15:18,334 DEBUG [RpcServer.reader=1,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.118:45269 because read count=-1. Number of active connections: 2
2016-03-07 03:15:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717898, hits=1588157, hitRatio=92.45%, , cachingAccesses=1606707, cachingHits=1540479, cachingHitsRatio=95.88%, evictions=1071012, evicted=57078, evictedPerRun=0.05329351872205734
2016-03-07 03:15:45,132 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:57400; # active connections: 2
2016-03-07 03:17:45,160 DEBUG [RpcServer.reader=6,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:57400 because read count=-1. Number of active connections: 2
2016-03-07 03:20:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717906, hits=1588165, hitRatio=92.45%, , cachingAccesses=1606715, cachingHits=1540487, cachingHitsRatio=95.88%, evictions=1071042, evicted=57078, evictedPerRun=0.05329202860593796
2016-03-07 03:20:45,133 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:57485; # active connections: 2
2016-03-07 03:20:48,252 DEBUG [RS_OPEN_META-sachadooptst8:60020-0-MetaLogRoller] regionserver.LogRoller: Hlog roll period 3600000ms elapsed
2016-03-07 03:20:48,348 INFO  [RS_OPEN_META-sachadooptst8:60020-0-MetaLogRoller] wal.FSHLog: Rolled WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457346048045.meta with entries=26, filesize=9.7 K; new WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457349648252.meta
2016-03-07 03:20:48,348 DEBUG [RS_OPEN_META-sachadooptst8:60020-0-MetaLogRoller] wal.FSHLog: log file is ready for archiving hdfs://hanamenode/apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457346048045.meta
2016-03-07 03:22:45,156 DEBUG [RpcServer.reader=7,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:57485 because read count=-1. Number of active connections: 2
2016-03-07 03:25:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717914, hits=1588173, hitRatio=92.45%, , cachingAccesses=1606723, cachingHits=1540495, cachingHitsRatio=95.88%, evictions=1071072, evicted=57078, evictedPerRun=0.053290534764528275
2016-03-07 03:25:45,133 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:57569; # active connections: 2
2016-03-07 03:27:45,158 DEBUG [RpcServer.reader=8,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:57569 because read count=-1. Number of active connections: 2
2016-03-07 03:30:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717922, hits=1588181, hitRatio=92.45%, , cachingAccesses=1606731, cachingHits=1540503, cachingHitsRatio=95.88%, evictions=1071102, evicted=57078, evictedPerRun=0.05328904092311859
2016-03-07 03:30:45,133 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:57654; # active connections: 2
2016-03-07 03:32:45,159 DEBUG [RpcServer.reader=9,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:57654 because read count=-1. Number of active connections: 2
2016-03-07 03:35:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717930, hits=1588189, hitRatio=92.45%, , cachingAccesses=1606739, cachingHits=1540511, cachingHitsRatio=95.88%, evictions=1071132, evicted=57078, evictedPerRun=0.05328755080699921
2016-03-07 03:35:45,135 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:57738; # active connections: 2
2016-03-07 03:37:45,173 DEBUG [RpcServer.reader=0,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:57738 because read count=-1. Number of active connections: 2
2016-03-07 03:40:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717938, hits=1588197, hitRatio=92.45%, , cachingAccesses=1606747, cachingHits=1540519, cachingHitsRatio=95.88%, evictions=1071162, evicted=57078, evictedPerRun=0.05328605696558952
2016-03-07 03:40:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:57823; # active connections: 2
2016-03-07 03:42:45,158 DEBUG [RpcServer.reader=1,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:57823 because read count=-1. Number of active connections: 2
2016-03-07 03:44:08,577 INFO  [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region TSO,,1446725479469.2b52162cdfbefa7fdcce179b9a942c06. after a delay of 11783
2016-03-07 03:44:18,577 INFO  [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region TSO,,1446725479469.2b52162cdfbefa7fdcce179b9a942c06. after a delay of 21528
2016-03-07 03:44:20,360 DEBUG [MemStoreFlusher.1] regionserver.HRegion: Started memstore flush for TSO,,1446725479469.2b52162cdfbefa7fdcce179b9a942c06., current region memstore size 50.4 K
2016-03-07 03:44:20,464 INFO  [MemStoreFlusher.1] regionserver.DefaultStoreFlusher: Flushed, sequenceid=175615, memsize=50.4 K, hasBloomFilter=true, into tmp file hdfs://hanamenode/apps/hbase/data/data/default/TSO/2b52162cdfbefa7fdcce179b9a942c06/.tmp/a9f6a181fd4a475f89f7fc33113b2e2d
2016-03-07 03:44:20,480 DEBUG [MemStoreFlusher.1] regionserver.HRegionFileSystem: Committing store file hdfs://hanamenode/apps/hbase/data/data/default/TSO/2b52162cdfbefa7fdcce179b9a942c06/.tmp/a9f6a181fd4a475f89f7fc33113b2e2d as hdfs://hanamenode/apps/hbase/data/data/default/TSO/2b52162cdfbefa7fdcce179b9a942c06/1/a9f6a181fd4a475f89f7fc33113b2e2d
2016-03-07 03:44:20,503 INFO  [MemStoreFlusher.1] regionserver.HStore: Added hdfs://hanamenode/apps/hbase/data/data/default/TSO/2b52162cdfbefa7fdcce179b9a942c06/1/a9f6a181fd4a475f89f7fc33113b2e2d, entries=161, sequenceid=175615, filesize=31.3 K
2016-03-07 03:44:20,505 INFO  [MemStoreFlusher.1] regionserver.HRegion: Finished memstore flush of ~50.4 K/51576, currentsize=0/0 for region TSO,,1446725479469.2b52162cdfbefa7fdcce179b9a942c06. in 145ms, sequenceid=175615, compaction requested=false
2016-03-07 03:45:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717946, hits=1588205, hitRatio=92.45%, , cachingAccesses=1606755, cachingHits=1540527, cachingHitsRatio=95.88%, evictions=1071192, evicted=57078, evictedPerRun=0.05328456684947014
2016-03-07 03:45:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:57907; # active connections: 2
2016-03-07 03:47:45,158 DEBUG [RpcServer.reader=2,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:57907 because read count=-1. Number of active connections: 2
2016-03-07 03:50:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717954, hits=1588213, hitRatio=92.45%, , cachingAccesses=1606763, cachingHits=1540535, cachingHitsRatio=95.88%, evictions=1071222, evicted=57078, evictedPerRun=0.053283073008060455
2016-03-07 03:50:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:57992; # active connections: 2
2016-03-07 03:52:45,159 DEBUG [RpcServer.reader=3,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:57992 because read count=-1. Number of active connections: 2
2016-03-07 03:55:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717962, hits=1588221, hitRatio=92.45%, , cachingAccesses=1606771, cachingHits=1540543, cachingHitsRatio=95.88%, evictions=1071252, evicted=57078, evictedPerRun=0.05328157916665077
2016-03-07 03:55:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:58076; # active connections: 2
2016-03-07 03:57:45,167 DEBUG [RpcServer.reader=4,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:58076 because read count=-1. Number of active connections: 2
2016-03-07 04:00:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717970, hits=1588229, hitRatio=92.45%, , cachingAccesses=1606779, cachingHits=1540551, cachingHitsRatio=95.88%, evictions=1071282, evicted=57078, evictedPerRun=0.05328008905053139
2016-03-07 04:00:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:58162; # active connections: 2
2016-03-07 04:02:45,156 DEBUG [RpcServer.reader=5,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:58162 because read count=-1. Number of active connections: 2
2016-03-07 04:05:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717978, hits=1588237, hitRatio=92.45%, , cachingAccesses=1606787, cachingHits=1540559, cachingHitsRatio=95.88%, evictions=1071312, evicted=57078, evictedPerRun=0.053278595209121704
2016-03-07 04:05:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:58246; # active connections: 2
2016-03-07 04:07:45,157 DEBUG [RpcServer.reader=6,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:58246 because read count=-1. Number of active connections: 2
2016-03-07 04:10:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717986, hits=1588245, hitRatio=92.45%, , cachingAccesses=1606795, cachingHits=1540567, cachingHitsRatio=95.88%, evictions=1071342, evicted=57078, evictedPerRun=0.05327710509300232
2016-03-07 04:10:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:58331; # active connections: 2
2016-03-07 04:12:45,173 DEBUG [RpcServer.reader=7,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:58331 because read count=-1. Number of active connections: 2
2016-03-07 04:14:56,805 DEBUG [regionserver60020.logRoller] regionserver.LogRoller: Hlog roll period 3600000ms elapsed
2016-03-07 04:14:56,895 INFO  [regionserver60020.logRoller] wal.FSHLog: Rolled WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457349296676 with entries=2, filesize=539; new WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457352896805
2016-03-07 04:14:56,895 DEBUG [regionserver60020.logRoller] wal.FSHLog: log file is ready for archiving hdfs://hanamenode/apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457345696551
2016-03-07 04:14:56,895 DEBUG [regionserver60020.logRoller] wal.FSHLog: log file is ready for archiving hdfs://hanamenode/apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457349296676
2016-03-07 04:15:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1717994, hits=1588253, hitRatio=92.45%, , cachingAccesses=1606803, cachingHits=1540575, cachingHitsRatio=95.88%, evictions=1071372, evicted=57078, evictedPerRun=0.053275611251592636
2016-03-07 04:15:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:58415; # active connections: 2
2016-03-07 04:17:45,159 DEBUG [RpcServer.reader=8,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:58415 because read count=-1. Number of active connections: 2
2016-03-07 04:20:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1718002, hits=1588261, hitRatio=92.45%, , cachingAccesses=1606811, cachingHits=1540583, cachingHitsRatio=95.88%, evictions=1071402, evicted=57078, evictedPerRun=0.05327412113547325
2016-03-07 04:20:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:58500; # active connections: 2
2016-03-07 04:20:48,403 DEBUG [RS_OPEN_META-sachadooptst8:60020-0-MetaLogRoller] regionserver.LogRoller: Hlog roll period 3600000ms elapsed
2016-03-07 04:20:48,479 INFO  [RS_OPEN_META-sachadooptst8:60020-0-MetaLogRoller] wal.FSHLog: Rolled WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457349648252.meta with entries=0, filesize=91; new WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457353248403.meta
2016-03-07 04:20:48,479 DEBUG [RS_OPEN_META-sachadooptst8:60020-0-MetaLogRoller] wal.FSHLog: log file is ready for archiving hdfs://hanamenode/apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457349648252.meta
2016-03-07 04:22:45,156 DEBUG [RpcServer.reader=9,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:58500 because read count=-1. Number of active connections: 2
2016-03-07 04:25:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1718010, hits=1588269, hitRatio=92.45%, , cachingAccesses=1606819, cachingHits=1540591, cachingHitsRatio=95.88%, evictions=1071432, evicted=57078, evictedPerRun=0.05327263101935387
2016-03-07 04:25:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:58584; # active connections: 2
2016-03-07 04:27:45,156 DEBUG [RpcServer.reader=0,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:58584 because read count=-1. Number of active connections: 2
2016-03-07 04:30:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1718018, hits=1588277, hitRatio=92.45%, , cachingAccesses=1606827, cachingHits=1540599, cachingHitsRatio=95.88%, evictions=1071462, evicted=57078, evictedPerRun=0.05327113717794418
2016-03-07 04:30:45,135 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:58669; # active connections: 2
2016-03-07 04:32:45,159 DEBUG [RpcServer.reader=1,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:58669 because read count=-1. Number of active connections: 2
2016-03-07 04:35:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1718026, hits=1588285, hitRatio=92.45%, , cachingAccesses=1606835, cachingHits=1540607, cachingHitsRatio=95.88%, evictions=1071492, evicted=57078, evictedPerRun=0.0532696470618248
2016-03-07 04:35:45,135 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:58753; # active connections: 2
2016-03-07 04:37:45,157 DEBUG [RpcServer.reader=2,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:58753 because read count=-1. Number of active connections: 2
2016-03-07 04:40:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1718034, hits=1588293, hitRatio=92.45%, , cachingAccesses=1606843, cachingHits=1540615, cachingHitsRatio=95.88%, evictions=1071522, evicted=57078, evictedPerRun=0.053268153220415115
2016-03-07 04:40:45,135 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:58838; # active connections: 2
2016-03-07 04:42:45,160 DEBUG [RpcServer.reader=3,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:58838 because read count=-1. Number of active connections: 2
2016-03-07 04:45:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1718042, hits=1588301, hitRatio=92.45%, , cachingAccesses=1606851, cachingHits=1540623, cachingHitsRatio=95.88%, evictions=1071552, evicted=57078, evictedPerRun=0.05326666310429573
2016-03-07 04:45:45,136 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:58922; # active connections: 2
2016-03-07 04:47:45,163 DEBUG [RpcServer.reader=4,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:58922 because read count=-1. Number of active connections: 2
2016-03-07 04:50:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1718050, hits=1588309, hitRatio=92.45%, , cachingAccesses=1606859, cachingHits=1540631, cachingHitsRatio=95.88%, evictions=1071582, evicted=57078, evictedPerRun=0.053265172988176346
2016-03-07 04:50:45,135 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59007; # active connections: 2
2016-03-07 04:52:45,158 DEBUG [RpcServer.reader=5,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59007 because read count=-1. Number of active connections: 2
2016-03-07 04:55:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.46 MB, free=325.14 MB, max=401.60 MB, blockCount=368, accesses=1718058, hits=1588317, hitRatio=92.45%, , cachingAccesses=1606867, cachingHits=1540639, cachingHitsRatio=95.88%, evictions=1071612, evicted=57078, evictedPerRun=0.05326368287205696
2016-03-07 04:55:37,101 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.117:51004; # active connections: 2
2016-03-07 04:55:37,952 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.116:36322; # active connections: 3
2016-03-07 04:55:45,135 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59091; # active connections: 4
2016-03-07 04:57:39,764 DEBUG [RpcServer.reader=6,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.117:51004 because read count=-1. Number of active connections: 4
2016-03-07 04:57:41,787 DEBUG [RpcServer.reader=7,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.116:36322 because read count=-1. Number of active connections: 3
2016-03-07 04:57:45,202 DEBUG [RpcServer.reader=8,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59091 because read count=-1. Number of active connections: 2
2016-03-07 04:59:46,294 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.117:51037; # active connections: 2
2016-03-07 04:59:48,110 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.116:36377; # active connections: 3
2016-03-07 05:00:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.47 MB, free=325.13 MB, max=401.60 MB, blockCount=370, accesses=1718088, hits=1588345, hitRatio=92.45%, , cachingAccesses=1606897, cachingHits=1540667, cachingHitsRatio=95.88%, evictions=1071642, evicted=57078, evictedPerRun=0.05326218903064728
2016-03-07 05:00:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59177; # active connections: 4
2016-03-07 05:01:48,130 DEBUG [RpcServer.reader=0,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.116:36377 because read count=-1. Number of active connections: 4
2016-03-07 05:01:48,138 DEBUG [RpcServer.reader=9,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.117:51037 because read count=-1. Number of active connections: 3
2016-03-07 05:02:45,188 DEBUG [RpcServer.reader=1,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59177 because read count=-1. Number of active connections: 2
2016-03-07 05:04:36,679 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.116:36440; # active connections: 2
2016-03-07 05:04:37,448 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.117:51079; # active connections: 3
2016-03-07 05:05:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.47 MB, free=325.13 MB, max=401.60 MB, blockCount=370, accesses=1718102, hits=1588359, hitRatio=92.45%, , cachingAccesses=1606911, cachingHits=1540681, cachingHitsRatio=95.88%, evictions=1071672, evicted=57078, evictedPerRun=0.05326069891452789
2016-03-07 05:05:45,133 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59261; # active connections: 4
2016-03-07 05:06:37,374 DEBUG [RpcServer.reader=2,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.116:36440 because read count=-1. Number of active connections: 4
2016-03-07 05:06:37,521 DEBUG [RpcServer.reader=3,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.117:51079 because read count=-1. Number of active connections: 3
2016-03-07 05:07:45,156 DEBUG [RpcServer.reader=4,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59261 because read count=-1. Number of active connections: 2
2016-03-07 05:10:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.47 MB, free=325.13 MB, max=401.60 MB, blockCount=370, accesses=1718110, hits=1588367, hitRatio=92.45%, , cachingAccesses=1606919, cachingHits=1540689, cachingHitsRatio=95.88%, evictions=1071702, evicted=57078, evictedPerRun=0.05325920879840851
2016-03-07 05:10:45,132 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59346; # active connections: 2
2016-03-07 05:12:45,156 DEBUG [RpcServer.reader=5,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59346 because read count=-1. Number of active connections: 2
2016-03-07 05:14:56,961 DEBUG [regionserver60020.logRoller] regionserver.LogRoller: Hlog roll period 3600000ms elapsed
2016-03-07 05:14:57,043 INFO  [regionserver60020.logRoller] wal.FSHLog: Rolled WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457352896805 with entries=0, filesize=91; new WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457356496961
2016-03-07 05:14:57,043 DEBUG [regionserver60020.logRoller] wal.FSHLog: log file is ready for archiving hdfs://hanamenode/apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457352896805
2016-03-07 05:15:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.47 MB, free=325.13 MB, max=401.60 MB, blockCount=370, accesses=1718118, hits=1588375, hitRatio=92.45%, , cachingAccesses=1606927, cachingHits=1540697, cachingHitsRatio=95.88%, evictions=1071732, evicted=57078, evictedPerRun=0.053257718682289124
2016-03-07 05:15:45,133 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59430; # active connections: 2
2016-03-07 05:17:45,157 DEBUG [RpcServer.reader=6,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59430 because read count=-1. Number of active connections: 2
2016-03-07 05:20:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.47 MB, free=325.13 MB, max=401.60 MB, blockCount=370, accesses=1718126, hits=1588383, hitRatio=92.45%, , cachingAccesses=1606935, cachingHits=1540705, cachingHitsRatio=95.88%, evictions=1071762, evicted=57078, evictedPerRun=0.05325622484087944
2016-03-07 05:20:45,133 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59515; # active connections: 2
2016-03-07 05:20:48,530 DEBUG [RS_OPEN_META-sachadooptst8:60020-0-MetaLogRoller] regionserver.LogRoller: Hlog roll period 3600000ms elapsed
2016-03-07 05:20:48,642 INFO  [RS_OPEN_META-sachadooptst8:60020-0-MetaLogRoller] wal.FSHLog: Rolled WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457353248403.meta with entries=0, filesize=91; new WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457356848531.meta
2016-03-07 05:20:48,642 DEBUG [RS_OPEN_META-sachadooptst8:60020-0-MetaLogRoller] wal.FSHLog: log file is ready for archiving hdfs://hanamenode/apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457353248403.meta
2016-03-07 05:22:45,157 DEBUG [RpcServer.reader=7,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59515 because read count=-1. Number of active connections: 2
2016-03-07 05:25:10,101 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59588; # active connections: 2
2016-03-07 05:25:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.59 MB, free=325.01 MB, max=401.60 MB, blockCount=371, accesses=1718136, hits=1588392, hitRatio=92.45%, , cachingAccesses=1606945, cachingHits=1540714, cachingHitsRatio=95.88%, evictions=1071792, evicted=57078, evictedPerRun=0.053254734724760056
2016-03-07 05:25:45,133 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59602; # active connections: 3
2016-03-07 05:27:10,138 DEBUG [RpcServer.reader=8,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59588 because read count=-1. Number of active connections: 3
2016-03-07 05:27:45,156 DEBUG [RpcServer.reader=9,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59602 because read count=-1. Number of active connections: 2
2016-03-07 05:29:56,451 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.115:39173; # active connections: 2
2016-03-07 05:30:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.59 MB, free=325.01 MB, max=401.60 MB, blockCount=371, accesses=1718150, hits=1588406, hitRatio=92.45%, , cachingAccesses=1606959, cachingHits=1540728, cachingHitsRatio=95.88%, evictions=1071822, evicted=57078, evictedPerRun=0.05325324460864067
2016-03-07 05:30:45,133 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59689; # active connections: 3
2016-03-07 05:31:56,570 DEBUG [RpcServer.reader=0,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.115:39173 because read count=-1. Number of active connections: 3
2016-03-07 05:32:45,156 DEBUG [RpcServer.reader=1,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59689 because read count=-1. Number of active connections: 2
2016-03-07 05:34:28,795 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59756; # active connections: 2
2016-03-07 05:35:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.59 MB, free=325.01 MB, max=401.60 MB, blockCount=371, accesses=1718160, hits=1588416, hitRatio=92.45%, , cachingAccesses=1606969, cachingHits=1540738, cachingHitsRatio=95.88%, evictions=1071852, evicted=57078, evictedPerRun=0.053251754492521286
2016-03-07 05:35:45,133 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59776; # active connections: 3
2016-03-07 05:35:49,902 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.115:39226; # active connections: 4
2016-03-07 05:36:28,814 DEBUG [RpcServer.reader=2,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59756 because read count=-1. Number of active connections: 4
2016-03-07 05:37:37,201 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59812; # active connections: 4
2016-03-07 05:37:45,163 DEBUG [RpcServer.reader=3,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59776 because read count=-1. Number of active connections: 4
2016-03-07 05:37:49,929 DEBUG [RpcServer.reader=4,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.115:39226 because read count=-1. Number of active connections: 3
2016-03-07 05:38:53,688 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.115:39254; # active connections: 3
2016-03-07 05:39:14,596 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.117:51345; # active connections: 4
2016-03-07 05:39:16,154 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.116:36843; # active connections: 5
2016-03-07 05:39:35,681 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.116:36858; # active connections: 6
2016-03-07 05:39:37,221 DEBUG [RpcServer.reader=5,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59812 because read count=-1. Number of active connections: 6
2016-03-07 05:40:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.97 MB, free=324.63 MB, max=401.60 MB, blockCount=381, accesses=1718224, hits=1588470, hitRatio=92.45%, , cachingAccesses=1607033, cachingHits=1540792, cachingHitsRatio=95.88%, evictions=1071882, evicted=57078, evictedPerRun=0.0532502643764019
2016-03-07 05:40:39,184 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59867; # active connections: 6
2016-03-07 05:40:45,135 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59869; # active connections: 7
2016-03-07 05:40:53,740 DEBUG [RpcServer.reader=6,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.115:39254 because read count=-1. Number of active connections: 7
2016-03-07 05:41:27,579 DEBUG [RpcServer.reader=8,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.116:36843 because read count=-1. Number of active connections: 6
2016-03-07 05:41:29,967 DEBUG [RpcServer.reader=7,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.117:51345 because read count=-1. Number of active connections: 5
2016-03-07 05:41:35,911 DEBUG [RpcServer.reader=9,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.116:36858 because read count=-1. Number of active connections: 4
2016-03-07 05:42:12,544 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.115:39281; # active connections: 4
2016-03-07 05:42:39,203 DEBUG [RpcServer.reader=0,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59867 because read count=-1. Number of active connections: 4
2016-03-07 05:42:45,158 DEBUG [RpcServer.reader=1,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59869 because read count=-1. Number of active connections: 3
2016-03-07 05:44:12,577 DEBUG [RpcServer.reader=2,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.115:39281 because read count=-1. Number of active connections: 2
2016-03-07 05:44:15,551 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59927; # active connections: 2
2016-03-07 05:45:20,276 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.116:36931; # active connections: 3
2016-03-07 05:45:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.97 MB, free=324.63 MB, max=401.60 MB, blockCount=381, accesses=1718240, hits=1588486, hitRatio=92.45%, , cachingAccesses=1607049, cachingHits=1540808, cachingHitsRatio=95.88%, evictions=1071912, evicted=57078, evictedPerRun=0.053248774260282516
2016-03-07 05:45:45,133 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:59957; # active connections: 4
2016-03-07 05:46:15,570 DEBUG [RpcServer.reader=3,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59927 because read count=-1. Number of active connections: 4
2016-03-07 05:47:20,295 DEBUG [RpcServer.reader=4,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.116:36931 because read count=-1. Number of active connections: 3
2016-03-07 05:47:45,156 DEBUG [RpcServer.reader=5,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:59957 because read count=-1. Number of active connections: 2
2016-03-07 05:50:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.97 MB, free=324.63 MB, max=401.60 MB, blockCount=381, accesses=1718248, hits=1588494, hitRatio=92.45%, , cachingAccesses=1607057, cachingHits=1540816, cachingHitsRatio=95.88%, evictions=1071942, evicted=57078, evictedPerRun=0.05324728414416313
2016-03-07 05:50:45,132 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:60042; # active connections: 2
2016-03-07 05:51:19,175 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.117:51442; # active connections: 3
2016-03-07 05:52:45,154 DEBUG [RpcServer.reader=6,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:60042 because read count=-1. Number of active connections: 3
2016-03-07 05:53:19,221 DEBUG [RpcServer.reader=7,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.117:51442 because read count=-1. Number of active connections: 2
2016-03-07 05:55:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.97 MB, free=324.63 MB, max=401.60 MB, blockCount=381, accesses=1718258, hits=1588504, hitRatio=92.45%, , cachingAccesses=1607067, cachingHits=1540826, cachingHitsRatio=95.88%, evictions=1071972, evicted=57078, evictedPerRun=0.05324579402804375
2016-03-07 05:55:45,132 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:60126; # active connections: 2
2016-03-07 05:55:54,601 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.115:39402; # active connections: 3
2016-03-07 05:57:45,154 DEBUG [RpcServer.reader=8,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:60126 because read count=-1. Number of active connections: 3
2016-03-07 05:57:54,625 DEBUG [RpcServer.reader=9,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.115:39402 because read count=-1. Number of active connections: 2
2016-03-07 05:59:38,658 DEBUG [regionserver60020.compactionChecker] compactions.RatioBasedCompactionPolicy: Skipping major compaction of org.apache.hadoop.hbase.regionserver.compactions.ExploringCompactionPolicy@551a16c8 because one (major) compacted file only and oldestTime 10133427556ms is < ttl=9223372036854775807
2016-03-07 05:59:38,659 DEBUG [regionserver60020.compactionChecker] compactions.RatioBasedCompactionPolicy: Skipping major compaction of org.apache.hadoop.hbase.regionserver.compactions.ExploringCompactionPolicy@23cdd01e because one (major) compacted file only and oldestTime 9709207195ms is < ttl=9223372036854775807
2016-03-07 05:59:38,659 DEBUG [regionserver60020.compactionChecker] compactions.RatioBasedCompactionPolicy: Skipping major compaction of org.apache.hadoop.hbase.regionserver.compactions.ExploringCompactionPolicy@16786b76 because one (major) compacted file only and oldestTime 10712941435ms is < ttl=9223372036854775807
2016-03-07 05:59:38,659 DEBUG [regionserver60020.compactionChecker] compactions.RatioBasedCompactionPolicy: Skipping major compaction of org.apache.hadoop.hbase.regionserver.compactions.ExploringCompactionPolicy@1d1a73ef because one (major) compacted file only and oldestTime 8734523023ms is < ttl=9223372036854775807
2016-03-07 06:00:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.97 MB, free=324.63 MB, max=401.60 MB, blockCount=381, accesses=1718268, hits=1588514, hitRatio=92.45%, , cachingAccesses=1607077, cachingHits=1540836, cachingHitsRatio=95.88%, evictions=1072002, evicted=57078, evictedPerRun=0.05324430391192436
2016-03-07 06:00:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:60213; # active connections: 2
2016-03-07 06:02:45,159 DEBUG [RpcServer.reader=0,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:60213 because read count=-1. Number of active connections: 2
2016-03-07 06:05:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.97 MB, free=324.63 MB, max=401.60 MB, blockCount=381, accesses=1718276, hits=1588522, hitRatio=92.45%, , cachingAccesses=1607085, cachingHits=1540844, cachingHitsRatio=95.88%, evictions=1072032, evicted=57078, evictedPerRun=0.05324281379580498
2016-03-07 06:05:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:60297; # active connections: 2
2016-03-07 06:07:45,172 DEBUG [RpcServer.reader=1,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:60297 because read count=-1. Number of active connections: 2
2016-03-07 06:10:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.97 MB, free=324.63 MB, max=401.60 MB, blockCount=381, accesses=1718284, hits=1588530, hitRatio=92.45%, , cachingAccesses=1607093, cachingHits=1540852, cachingHitsRatio=95.88%, evictions=1072062, evicted=57078, evictedPerRun=0.05324132367968559
2016-03-07 06:10:45,135 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:60383; # active connections: 2
2016-03-07 06:12:45,162 DEBUG [RpcServer.reader=2,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:60383 because read count=-1. Number of active connections: 2
2016-03-07 06:14:57,093 DEBUG [regionserver60020.logRoller] regionserver.LogRoller: Hlog roll period 3600000ms elapsed
2016-03-07 06:14:57,194 INFO  [regionserver60020.logRoller] wal.FSHLog: Rolled WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457356496961 with entries=6, filesize=1.2 K; new WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457360097093
2016-03-07 06:15:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.97 MB, free=324.63 MB, max=401.60 MB, blockCount=381, accesses=1718292, hits=1588538, hitRatio=92.45%, , cachingAccesses=1607101, cachingHits=1540860, cachingHitsRatio=95.88%, evictions=1072092, evicted=57078, evictedPerRun=0.05323983356356621
2016-03-07 06:15:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:60467; # active connections: 2
2016-03-07 06:17:45,160 DEBUG [RpcServer.reader=3,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: DISCONNECTING client 192.168.133.114:60467 because read count=-1. Number of active connections: 2
2016-03-07 06:20:28,126 DEBUG [LruStats #0] hfile.LruBlockCache: Total=76.97 MB, free=324.63 MB, max=401.60 MB, blockCount=381, accesses=1718300, hits=1588546, hitRatio=92.45%, , cachingAccesses=1607109, cachingHits=1540868, cachingHitsRatio=95.88%, evictions=1072122, evicted=57078, evictedPerRun=0.05323834344744682
2016-03-07 06:20:45,134 DEBUG [RpcServer.listener,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: connection from 192.168.133.114:60551; # active connections: 2
2016-03-07 06:20:48,693 DEBUG [RS_OPEN_META-sachadooptst8:60020-0-MetaLogRoller] regionserver.LogRoller: Hlog roll period 3600000ms elapsed
2016-03-07 06:20:48,807 INFO  [RS_OPEN_META-sachadooptst8:60020-0-MetaLogRoller] wal.FSHLog: Rolled WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457356848531.meta with entries=0, filesize=91; new WAL /apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457360448693.meta
2016-03-07 06:20:48,807 DEBUG [RS_OPEN_META-sachadooptst8:60020-0-MetaLogRoller] wal.FSHLog: log file is ready for archiving hdfs://hanamenode/apps/hbase/data/WALs/sachadooptst8.corp.mirrorplus.com,60020,1446639027217/sachadooptst8.corp.mirrorplus.com%2C60020%2C1446639027217.1457356848531.meta
4,334 Views
0 Kudos

avatar
author-rank aervits
Master Mentor

Created ‎03-07-2016 02:28 PM

@Raja Ray your regionserver log doesn't say anything, can you paste the ambari server logs errors when you try to restart this regionserver?

4,334 Views
0 Kudos

avatar
author-rank raja_ray
Expert Contributor

Created ‎03-07-2016 02:41 PM

Hi Artem Ervits,

Below is ambari server logs-

06 Mar 2016 22:50:34,101  INFO [qtp-client-276235] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 22:50:34,412  INFO [qtp-client-272936] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 22:50:34,761  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName hostPopup-pagination-displayLength-admin
06 Mar 2016 22:50:38,889  INFO [qtp-client-272936] PersistKeyValueService:82 - Looking for keyName mainHostAlertsController-pagination-displayLength-admin
06 Mar 2016 22:50:42,627  INFO [qtp-ambari-agent-278652] HeartBeatHandler:637 - State of service component HBASE_REGIONSERVER of service HBASE of cluster HACluster has changed from STARTING to INSTALLED at host sachadooptst5.corp.mirrorplus.com
06 Mar 2016 22:50:52,865  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName mainAlertInstancesController-pagination-displayLength-admin
06 Mar 2016 22:50:59,441  INFO [qtp-client-269821] PersistKeyValueService:82 - Looking for keyName mainHostAlertsController-pagination-displayLength-admin
06 Mar 2016 22:51:01,146  INFO [qtp-ambari-agent-278652] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_REGIONSERVER, host sachadooptst5.corp.mirrorplus.com
06 Mar 2016 22:52:20,493  INFO [qtp-client-272799] PersistKeyValueService:82 - Looking for keyName user-pref-admin-dashboard
06 Mar 2016 23:10:21,639 ERROR [qtp-client-272799] MetricsReportPropertyProvider:183 - Error getting timeline metrics. Can not connect to collector, socket error.
06 Mar 2016 23:10:21,648 ERROR [qtp-client-276235] MetricsReportPropertyProvider:183 - Error getting timeline metrics. Can not connect to collector, socket error.
06 Mar 2016 23:10:21,844 ERROR [qtp-client-272936] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
06 Mar 2016 23:10:22,146 ERROR [qtp-client-276237] MetricsReportPropertyProvider:183 - Error getting timeline metrics. Can not connect to collector, socket error.
06 Mar 2016 23:10:25,949 ERROR [qtp-client-269821] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
06 Mar 2016 23:17:16,443  INFO [qtp-client-276235] PersistKeyValueService:82 - Looking for keyName time-range-service-HBASE
06 Mar 2016 23:19:10,719  INFO [qtp-client-269821] StackAdvisorRunner:47 - Script=/var/lib/ambari-server/resources/scripts/stack_advisor.py, actionDirectory=/var/run/ambari-server/stack-recommendations/39, command=validate-configurations
06 Mar 2016 23:19:10,758  INFO [qtp-client-269821] StackAdvisorRunner:61 - Stack-advisor output=/var/run/ambari-server/stack-recommendations/39/stackadvisor.out, error=/var/run/ambari-server/stack-recommendations/39/stackadvisor.err
06 Mar 2016 23:19:11,093  INFO [qtp-client-269821] StackAdvisorRunner:69 - Stack advisor output files
06 Mar 2016 23:19:11,094  INFO [qtp-client-269821] StackAdvisorRunner:70 -     advisor script stdout: StackAdvisor implementation for stack HDP, version 2.0.6 was loaded
StackAdvisor implementation for stack HDP, version 2.1 was loaded
StackAdvisor implementation for stack HDP, version 2.2 was loaded
Returning HDP22StackAdvisor implementation
06 Mar 2016 23:19:11,094  INFO [qtp-client-269821] StackAdvisorRunner:71 -     advisor script stderr: 
06 Mar 2016 23:19:11,461  INFO [qtp-client-272799] AmbariManagementControllerImpl:1176 - Received a updateCluster request, clusterId=2, clusterName=HACluster, securityType=null, request={ clusterName=HACluster, clusterId=2, provisioningState=null, securityType=null, stackVersion=HDP-2.2, desired_scv=null, hosts=[] }
06 Mar 2016 23:19:11,462  INFO [qtp-client-272799] AmbariManagementControllerImpl:1258 - Applying configuration with tag 'version1457335144601' to cluster 'HACluster'
06 Mar 2016 23:19:31,602  INFO [qtp-client-272936] AmbariManagementControllerImpl:2911 - Received action execution request, clusterName=HACluster, request=isCommand :true, action :null, command :RESTART, inputs :{}, resourceFilters: [RequestResourceFilter{serviceName='HBASE', componentName='HBASE_MASTER', hostNames=[sachadooptst2.corp.mirrorplus.com, sachadooptst3.corp.mirrorplus.com, sachadooptst4.corp.mirrorplus.com]}, RequestResourceFilter{serviceName='HBASE', componentName='HBASE_REGIONSERVER', hostNames=[sacfilechkstg10.corp.mirrorplus.com, sachadooptst4.corp.mirrorplus.com, sachadooptst5.corp.mirrorplus.com, sachadooptst6.corp.mirrorplus.com, sachadooptst7.corp.mirrorplus.com, sachadooptst8.corp.mirrorplus.com]}, RequestResourceFilter{serviceName='HBASE', componentName='HBASE_CLIENT', hostNames=[sacfilechkstg10.corp.mirrorplus.com, sachadooptst4.corp.mirrorplus.com, sachadooptst5.corp.mirrorplus.com, sachadooptst6.corp.mirrorplus.com, sachadooptst7.corp.mirrorplus.com, sachadooptst8.corp.mirrorplus.com]}], exclusive: false, clusterName :HACluster
06 Mar 2016 23:19:32,015  INFO [qtp-client-276235] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 23:19:32,330  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 23:19:48,928  INFO [qtp-ambari-agent-278777] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_CLIENT, host sacfilechkstg10.corp.mirrorplus.com
06 Mar 2016 23:19:51,378  INFO [qtp-ambari-agent-278777] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_CLIENT, host sachadooptst5.corp.mirrorplus.com
06 Mar 2016 23:19:51,888  INFO [qtp-ambari-agent-278777] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_CLIENT, host sachadooptst7.corp.mirrorplus.com
06 Mar 2016 23:19:53,693  INFO [qtp-ambari-agent-278768] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_CLIENT, host sachadooptst4.corp.mirrorplus.com
06 Mar 2016 23:19:54,795  INFO [qtp-ambari-agent-278777] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_CLIENT, host sachadooptst6.corp.mirrorplus.com
06 Mar 2016 23:20:11,484  INFO [qtp-ambari-agent-278768] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_REGIONSERVER, host sacfilechkstg10.corp.mirrorplus.com
06 Mar 2016 23:20:14,316 ERROR [alert-event-bus-2] AmbariJpaLocalTxnInterceptor:114 - [DETAILED ERROR] Rollback reason: 
Local Exception Stack: 
Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '683' for key 'PRIMARY'
Error Code: 1062
Call: INSERT INTO alert_history (alert_id, alert_instance, alert_label, alert_state, alert_text, alert_timestamp, cluster_id, component_name, host_name, service_name, alert_definition_id) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
bind => [11 parameters bound]
at org.eclipse.persistence.exceptions.DatabaseException.sqlException(DatabaseException.java:331)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeDirectNoSelect(DatabaseAccessor.java:900)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeNoSelect(DatabaseAccessor.java:962)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:631)
at org.eclipse.persistence.internal.databaseaccess.ParameterizedSQLBatchWritingMechanism.executeBatch(ParameterizedSQLBatchWritingMechanism.java:149)
at org.eclipse.persistence.internal.databaseaccess.ParameterizedSQLBatchWritingMechanism.executeBatchedStatements(ParameterizedSQLBatchWritingMechanism.java:134)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.writesCompleted(DatabaseAccessor.java:1836)
at org.eclipse.persistence.internal.sessions.AbstractSession.writesCompleted(AbstractSession.java:4244)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.writesCompleted(UnitOfWorkImpl.java:5594)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.acquireWriteLocks(UnitOfWorkImpl.java:1646)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitTransactionAfterWriteChanges(UnitOfWorkImpl.java:1614)
at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.commitRootUnitOfWork(RepeatableWriteUnitOfWork.java:284)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitAndResume(UnitOfWorkImpl.java:1169)
at org.eclipse.persistence.internal.jpa.transaction.EntityTransactionImpl.commit(EntityTransactionImpl.java:132)
at org.apache.ambari.server.orm.AmbariJpaLocalTxnInterceptor.invoke(AmbariJpaLocalTxnInterceptor.java:91)
at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72)
at com.google.inject.internal.InterceptorStackCallback.intercept(InterceptorStackCallback.java:52)
at org.apache.ambari.server.orm.dao.AlertsDAO$EnhancerByGuice$fb387e16.create(<generated>)
at org.apache.ambari.server.events.listeners.alerts.AlertReceivedListener.onAlertEvent(AlertReceivedListener.java:183)
at sun.reflect.GeneratedMethodAccessor106.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.google.common.eventbus.EventHandler.handleEvent(EventHandler.java:74)
at com.google.common.eventbus.EventBus.dispatch(EventBus.java:314)
at com.google.common.eventbus.AsyncEventBus.access$001(AsyncEventBus.java:34)
at com.google.common.eventbus.AsyncEventBus$1.run(AsyncEventBus.java:100)
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: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '683' for key 'PRIMARY'
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.Util.getInstance(Util.java:386)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1040)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3597)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3529)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1990)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2151)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2625)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2119)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2415)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2333)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2318)
at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeDirectNoSelect(DatabaseAccessor.java:890)
... 27 more
06 Mar 2016 23:20:14,317 ERROR [alert-event-bus-2] AmbariJpaLocalTxnInterceptor:122 - [DETAILED ERROR] Internal exception (1) : 
com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '683' for key 'PRIMARY'
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.Util.getInstance(Util.java:386)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1040)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3597)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3529)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1990)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2151)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2625)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2119)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2415)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2333)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2318)
at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeDirectNoSelect(DatabaseAccessor.java:890)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeNoSelect(DatabaseAccessor.java:962)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:631)
at org.eclipse.persistence.internal.databaseaccess.ParameterizedSQLBatchWritingMechanism.executeBatch(ParameterizedSQLBatchWritingMechanism.java:149)
at org.eclipse.persistence.internal.databaseaccess.ParameterizedSQLBatchWritingMechanism.executeBatchedStatements(ParameterizedSQLBatchWritingMechanism.java:134)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.writesCompleted(DatabaseAccessor.java:1836)
at org.eclipse.persistence.internal.sessions.AbstractSession.writesCompleted(AbstractSession.java:4244)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.writesCompleted(UnitOfWorkImpl.java:5594)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.acquireWriteLocks(UnitOfWorkImpl.java:1646)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitTransactionAfterWriteChanges(UnitOfWorkImpl.java:1614)
at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.commitRootUnitOfWork(RepeatableWriteUnitOfWork.java:284)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitAndResume(UnitOfWorkImpl.java:1169)
at org.eclipse.persistence.internal.jpa.transaction.EntityTransactionImpl.commit(EntityTransactionImpl.java:132)
at org.apache.ambari.server.orm.AmbariJpaLocalTxnInterceptor.invoke(AmbariJpaLocalTxnInterceptor.java:91)
at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72)
at com.google.inject.internal.InterceptorStackCallback.intercept(InterceptorStackCallback.java:52)
at org.apache.ambari.server.orm.dao.AlertsDAO$EnhancerByGuice$fb387e16.create(<generated>)
at org.apache.ambari.server.events.listeners.alerts.AlertReceivedListener.onAlertEvent(AlertReceivedListener.java:183)
at sun.reflect.GeneratedMethodAccessor106.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.google.common.eventbus.EventHandler.handleEvent(EventHandler.java:74)
at com.google.common.eventbus.EventBus.dispatch(EventBus.java:314)
at com.google.common.eventbus.AsyncEventBus.access$001(AsyncEventBus.java:34)
at com.google.common.eventbus.AsyncEventBus$1.run(AsyncEventBus.java:100)
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)
06 Mar 2016 23:20:18,351  INFO [qtp-ambari-agent-278768] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_REGIONSERVER, host sachadooptst5.corp.mirrorplus.com
06 Mar 2016 23:20:22,145  INFO [qtp-ambari-agent-278768] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_MASTER, host sachadooptst3.corp.mirrorplus.com
06 Mar 2016 23:20:27,310  INFO [qtp-ambari-agent-278768] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_MASTER, host sachadooptst4.corp.mirrorplus.com
06 Mar 2016 23:20:34,953  INFO [qtp-ambari-agent-278768] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_REGIONSERVER, host sachadooptst7.corp.mirrorplus.com
06 Mar 2016 23:20:45,704  INFO [qtp-ambari-agent-278768] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_REGIONSERVER, host sachadooptst6.corp.mirrorplus.com
06 Mar 2016 23:20:51,422  INFO [qtp-ambari-agent-278768] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_REGIONSERVER, host sachadooptst4.corp.mirrorplus.com
06 Mar 2016 23:20:52,251  INFO [qtp-ambari-agent-278768] HeartBeatHandler:547 - Updating applied config on service HBASE, component HBASE_MASTER, host sachadooptst2.corp.mirrorplus.com
06 Mar 2016 23:23:22,919  INFO [qtp-client-272936] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 23:24:02,678  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 23:25:00,599  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 23:26:10,100  INFO [qtp-client-272799] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 23:28:15,573  INFO [qtp-client-272936] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 23:28:56,392  INFO [qtp-client-272799] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 23:29:25,940  INFO [qtp-client-269821] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 23:33:30,819  INFO [qtp-client-269821] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 23:37:42,010  INFO [qtp-client-272936] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
06 Mar 2016 23:44:34,500  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_CLIENT, actionId:35-0 timed out
06 Mar 2016 23:44:34,500  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:35-0 timed out
06 Mar 2016 23:58:31,894  INFO [qtp-client-276237] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 00:01:50,670  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 00:02:09,354  INFO [qtp-client-276235] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 00:07:29,381  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 00:07:32,309  INFO [qtp-client-276237] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 00:09:36,977  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_CLIENT, actionId:35-0 timed out
07 Mar 2016 00:09:36,978  WARN [ambari-action-scheduler] ActionScheduler:587 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_CLIENT, actionId:35-0 expired
07 Mar 2016 00:09:36,985  WARN [ambari-action-scheduler] ActionScheduler:679 - Unable to transition to failed state.
org.apache.ambari.server.state.fsm.InvalidStateTransitionException: Invalid event: HOST_SVCCOMP_OP_FAILED at INSTALLED
at org.apache.ambari.server.state.fsm.StateMachineFactory.doTransition(StateMachineFactory.java:297)
at org.apache.ambari.server.state.fsm.StateMachineFactory.access$300(StateMachineFactory.java:39)
at org.apache.ambari.server.state.fsm.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:440)
at org.apache.ambari.server.state.svccomphost.ServiceComponentHostImpl.handleEvent(ServiceComponentHostImpl.java:887)
at org.apache.ambari.server.orm.AmbariJpaLocalTxnInterceptor.invoke(AmbariJpaLocalTxnInterceptor.java:68)
at org.apache.ambari.server.actionmanager.ActionScheduler.transitionToFailedState(ActionScheduler.java:662)
at org.apache.ambari.server.actionmanager.ActionScheduler.processInProgressStage(ActionScheduler.java:593)
at org.apache.ambari.server.actionmanager.ActionScheduler.doWork(ActionScheduler.java:282)
at org.apache.ambari.server.actionmanager.ActionScheduler.run(ActionScheduler.java:195)
at java.lang.Thread.run(Thread.java:745)
07 Mar 2016 00:09:36,985  INFO [ambari-action-scheduler] ActionScheduler:597 - Removing command from queue, host=sachadooptst8.corp.mirrorplus.com, commandId=35-0 
07 Mar 2016 00:09:36,986  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:35-0 timed out
07 Mar 2016 00:09:36,986  WARN [ambari-action-scheduler] ActionScheduler:587 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:35-0 expired
07 Mar 2016 00:09:36,990  WARN [ambari-action-scheduler] ActionScheduler:679 - Unable to transition to failed state.
org.apache.ambari.server.state.fsm.InvalidStateTransitionException: Invalid event: HOST_SVCCOMP_OP_FAILED at STARTED
at org.apache.ambari.server.state.fsm.StateMachineFactory.doTransition(StateMachineFactory.java:297)
at org.apache.ambari.server.state.fsm.StateMachineFactory.access$300(StateMachineFactory.java:39)
at org.apache.ambari.server.state.fsm.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:440)
at org.apache.ambari.server.state.svccomphost.ServiceComponentHostImpl.handleEvent(ServiceComponentHostImpl.java:887)
at org.apache.ambari.server.orm.AmbariJpaLocalTxnInterceptor.invoke(AmbariJpaLocalTxnInterceptor.java:68)
at org.apache.ambari.server.actionmanager.ActionScheduler.transitionToFailedState(ActionScheduler.java:662)
at org.apache.ambari.server.actionmanager.ActionScheduler.processInProgressStage(ActionScheduler.java:593)
at org.apache.ambari.server.actionmanager.ActionScheduler.doWork(ActionScheduler.java:282)
at org.apache.ambari.server.actionmanager.ActionScheduler.run(ActionScheduler.java:195)
at java.lang.Thread.run(Thread.java:745)
07 Mar 2016 00:09:36,990  INFO [ambari-action-scheduler] ActionScheduler:597 - Removing command from queue, host=sachadooptst8.corp.mirrorplus.com, commandId=35-0 
07 Mar 2016 00:16:04,260  INFO [qtp-client-272936] PersistKeyValueService:82 - Looking for keyName user-pref-admin-dashboard
07 Mar 2016 00:16:12,635  INFO [qtp-client-276237] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 00:16:32,199  INFO [qtp-client-276237] PersistKeyValueService:82 - Looking for keyName time-range-service-HBASE
07 Mar 2016 00:16:43,872  INFO [qtp-client-276237] AmbariManagementControllerImpl:2911 - Received action execution request, clusterName=HACluster, request=isCommand :true, action :null, command :RESTART, inputs :{}, resourceFilters: [RequestResourceFilter{serviceName='HBASE', componentName='HBASE_CLIENT', hostNames=[sachadooptst8.corp.mirrorplus.com]}, RequestResourceFilter{serviceName='HBASE', componentName='HBASE_REGIONSERVER', hostNames=[sachadooptst8.corp.mirrorplus.com]}], exclusive: false, clusterName :HACluster
07 Mar 2016 00:16:44,216  INFO [qtp-client-276235] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 00:16:44,533  INFO [qtp-client-272799] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 00:17:13,076  INFO [qtp-client-276235] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 00:19:07,032  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 00:19:07,829  INFO [qtp-client-272936] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 00:41:46,390  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_CLIENT, actionId:36-0 timed out
07 Mar 2016 00:41:46,390  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:36-0 timed out
07 Mar 2016 01:03:48,483 ERROR [qtp-client-276237] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:03:55,622 ERROR [qtp-client-272799] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:03:57,427 ERROR [qtp-client-276235] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:04,101 ERROR [qtp-client-277246] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:08,101 ERROR [qtp-client-269821] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:08,340 ERROR [qtp-client-276237] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:09,872 ERROR [qtp-client-272799] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:10,480 ERROR [qtp-client-276235] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:14,348 ERROR [qtp-client-277246] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:14,416 ERROR [qtp-client-272936] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:18,659 ERROR [qtp-client-276237] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:18,723 ERROR [qtp-client-279446] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:20,185 ERROR [qtp-client-269821] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:20,796 ERROR [qtp-client-272799] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:24,677 ERROR [qtp-client-277246] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:24,734 ERROR [qtp-client-272936] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:31,185 ERROR [qtp-client-276237] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:31,411 ERROR [qtp-client-279446] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:31,920 ERROR [qtp-client-276235] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:32,322 ERROR [qtp-client-269821] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:34,991 ERROR [qtp-client-277246] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:35,044 ERROR [qtp-client-272799] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:54,781 ERROR [qtp-client-276235] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:54,801 ERROR [qtp-client-272799] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:54,803 ERROR [qtp-client-269821] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:54,803 ERROR [qtp-client-277246] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:54,803 ERROR [qtp-client-272936] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:04:54,810 ERROR [qtp-client-276237] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:05:10,782 ERROR [qtp-client-277246] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:05:10,810 ERROR [qtp-client-276237] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:05:10,810 ERROR [qtp-client-279446] MetricsPropertyProvider:201 - Error getting timeline metrics.
07 Mar 2016 01:05:10,828 ERROR [qtp-client-272799] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:05:10,828 ERROR [qtp-client-272936] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:05:11,298 ERROR [qtp-client-276235] MetricsPropertyProvider:201 - Error getting timeline metrics.
07 Mar 2016 01:05:26,811 ERROR [qtp-client-272799] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:05:26,821 ERROR [qtp-client-276235] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:05:26,821 ERROR [qtp-client-279446] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:05:26,824 ERROR [qtp-client-272936] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:05:26,825 ERROR [qtp-client-277246] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:05:26,827 ERROR [qtp-client-276237] MetricsPropertyProvider:201 - Error getting timeline metrics. Can not connect to collector, socket error.
07 Mar 2016 01:06:48,470  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_CLIENT, actionId:36-0 timed out
07 Mar 2016 01:06:48,471  WARN [ambari-action-scheduler] ActionScheduler:587 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_CLIENT, actionId:36-0 expired
07 Mar 2016 01:06:48,474  WARN [ambari-action-scheduler] ActionScheduler:679 - Unable to transition to failed state.
org.apache.ambari.server.state.fsm.InvalidStateTransitionException: Invalid event: HOST_SVCCOMP_OP_FAILED at INSTALLED
at org.apache.ambari.server.state.fsm.StateMachineFactory.doTransition(StateMachineFactory.java:297)
at org.apache.ambari.server.state.fsm.StateMachineFactory.access$300(StateMachineFactory.java:39)
at org.apache.ambari.server.state.fsm.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:440)
at org.apache.ambari.server.state.svccomphost.ServiceComponentHostImpl.handleEvent(ServiceComponentHostImpl.java:887)
at org.apache.ambari.server.orm.AmbariJpaLocalTxnInterceptor.invoke(AmbariJpaLocalTxnInterceptor.java:68)
at org.apache.ambari.server.actionmanager.ActionScheduler.transitionToFailedState(ActionScheduler.java:662)
at org.apache.ambari.server.actionmanager.ActionScheduler.processInProgressStage(ActionScheduler.java:593)
at org.apache.ambari.server.actionmanager.ActionScheduler.doWork(ActionScheduler.java:282)
at org.apache.ambari.server.actionmanager.ActionScheduler.run(ActionScheduler.java:195)
at java.lang.Thread.run(Thread.java:745)
07 Mar 2016 01:06:48,474  INFO [ambari-action-scheduler] ActionScheduler:597 - Removing command from queue, host=sachadooptst8.corp.mirrorplus.com, commandId=36-0 
07 Mar 2016 01:06:48,475  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:36-0 timed out
07 Mar 2016 01:06:48,475  WARN [ambari-action-scheduler] ActionScheduler:587 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:36-0 expired
07 Mar 2016 01:06:48,480  WARN [ambari-action-scheduler] ActionScheduler:679 - Unable to transition to failed state.
org.apache.ambari.server.state.fsm.InvalidStateTransitionException: Invalid event: HOST_SVCCOMP_OP_FAILED at STARTED
at org.apache.ambari.server.state.fsm.StateMachineFactory.doTransition(StateMachineFactory.java:297)
at org.apache.ambari.server.state.fsm.StateMachineFactory.access$300(StateMachineFactory.java:39)
at org.apache.ambari.server.state.fsm.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:440)
at org.apache.ambari.server.state.svccomphost.ServiceComponentHostImpl.handleEvent(ServiceComponentHostImpl.java:887)
at org.apache.ambari.server.orm.AmbariJpaLocalTxnInterceptor.invoke(AmbariJpaLocalTxnInterceptor.java:68)
at org.apache.ambari.server.actionmanager.ActionScheduler.transitionToFailedState(ActionScheduler.java:662)
at org.apache.ambari.server.actionmanager.ActionScheduler.processInProgressStage(ActionScheduler.java:593)
at org.apache.ambari.server.actionmanager.ActionScheduler.doWork(ActionScheduler.java:282)
at org.apache.ambari.server.actionmanager.ActionScheduler.run(ActionScheduler.java:195)
at java.lang.Thread.run(Thread.java:745)
07 Mar 2016 01:06:48,480  INFO [ambari-action-scheduler] ActionScheduler:597 - Removing command from queue, host=sachadooptst8.corp.mirrorplus.com, commandId=36-0 
07 Mar 2016 01:16:46,185  INFO [qtp-client-279446] PersistKeyValueService:82 - Looking for keyName CLUSTER_CURRENT_STATUS
07 Mar 2016 02:17:05,259  INFO [qtp-client-279573] PersistKeyValueService:82 - Looking for keyName CLUSTER_CURRENT_STATUS
07 Mar 2016 02:25:23,379  INFO [qtp-client-279573] PersistKeyValueService:82 - Looking for keyName CLUSTER_CURRENT_STATUS
07 Mar 2016 02:25:44,776  INFO [qtp-client-279677] AmbariManagementControllerImpl:2911 - Received action execution request, clusterName=HACluster, request=isCommand :true, action :null, command :RESTART, inputs :{}, resourceFilters: [RequestResourceFilter{serviceName='HBASE', componentName='HBASE_CLIENT', hostNames=[sachadooptst8.corp.mirrorplus.com]}, RequestResourceFilter{serviceName='HBASE', componentName='HBASE_REGIONSERVER', hostNames=[sachadooptst8.corp.mirrorplus.com]}], exclusive: false, clusterName :HACluster
07 Mar 2016 02:25:45,115  INFO [qtp-client-279573] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 02:25:45,434  INFO [qtp-client-279781] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 02:25:45,822  INFO [qtp-client-279677] PersistKeyValueService:82 - Looking for keyName hostPopup-pagination-displayLength-admin
07 Mar 2016 02:42:53,450  INFO [qtp-client-279677] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 02:43:13,884  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName user-pref-admin-dashboard
07 Mar 2016 02:43:23,232  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 02:43:28,545  INFO [ambari-action-scheduler] ActionDBAccessorImpl:176 - Aborting command. Hostname sachadooptst8.corp.mirrorplus.com role HBASE_CLIENT requestId null taskId 484 stageId null
07 Mar 2016 02:43:28,545  INFO [ambari-action-scheduler] ActionDBAccessorImpl:176 - Aborting command. Hostname sachadooptst8.corp.mirrorplus.com role HBASE_REGIONSERVER requestId null taskId 485 stageId null
07 Mar 2016 02:43:36,023  INFO [qtp-client-279781] AbstractResourceProvider:638 - Received a updateService request, clusterName=HACluster, serviceName=HBASE, request=clusterName=HACluster, serviceName=HBASE, desiredState=INSTALLED
07 Mar 2016 02:43:36,464  INFO [qtp-client-279464] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 02:43:36,774  INFO [qtp-client-279573] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 02:50:55,663  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName mainAlertInstancesController-pagination-displayLength-admin
07 Mar 2016 02:51:16,339  INFO [qtp-client-279464] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 03:08:38,454  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:38-0 timed out
07 Mar 2016 03:15:39,070  INFO [qtp-client-279677] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 03:16:04,391  INFO [ambari-action-scheduler] ActionDBAccessorImpl:176 - Aborting command. Hostname sachadooptst8.corp.mirrorplus.com role HBASE_REGIONSERVER requestId null taskId 491 stageId null
07 Mar 2016 03:16:04,392  INFO [ambari-action-scheduler] ActionDBAccessorImpl:176 - Aborting command. Hostname sachadooptst2.corp.mirrorplus.com role HBASE_MASTER requestId null taskId 492 stageId null
07 Mar 2016 03:16:04,392  INFO [ambari-action-scheduler] ActionDBAccessorImpl:176 - Aborting command. Hostname sachadooptst3.corp.mirrorplus.com role HBASE_MASTER requestId null taskId 493 stageId null
07 Mar 2016 03:16:04,392  INFO [ambari-action-scheduler] ActionDBAccessorImpl:176 - Aborting command. Hostname sachadooptst4.corp.mirrorplus.com role HBASE_MASTER requestId null taskId 494 stageId null
07 Mar 2016 03:16:10,689  INFO [qtp-client-279573] PersistKeyValueService:82 - Looking for keyName time-range-service-HBASE
07 Mar 2016 03:16:41,902  INFO [qtp-client-279464] AbstractResourceProvider:755 - Received a updateHostComponent request, clusterName=HACluster, serviceName=HBASE, componentName=HBASE_REGIONSERVER, hostname=sachadooptst8.corp.mirrorplus.com, request={ clusterName=HACluster, serviceName=HBASE, componentName=HBASE_REGIONSERVER, hostname=sachadooptst8.corp.mirrorplus.com, desiredState=INSTALLED, desiredStackId=null, staleConfig=null, adminState=null}
07 Mar 2016 03:16:42,251  INFO [qtp-client-279677] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 03:16:42,664  INFO [qtp-client-279781] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 03:40:29,327  INFO [qtp-client-279677] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 03:41:44,271  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:39-0 timed out
07 Mar 2016 03:43:12,793  INFO [qtp-client-279464] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 04:06:46,561  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:39-0 timed out
07 Mar 2016 04:06:46,561  WARN [ambari-action-scheduler] ActionScheduler:587 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:39-0 expired
07 Mar 2016 04:06:46,567  INFO [ambari-action-scheduler] ActionScheduler:597 - Removing command from queue, host=sachadooptst8.corp.mirrorplus.com, commandId=39-0 
07 Mar 2016 04:07:52,742  INFO [qtp-client-279781] PersistKeyValueService:82 - Looking for keyName user-pref-admin-dashboard
07 Mar 2016 04:07:54,990  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName time-range-service-HBASE
07 Mar 2016 04:08:21,362  INFO [qtp-client-279677] AmbariManagementControllerImpl:2911 - Received action execution request, clusterName=HACluster, request=isCommand :true, action :null, command :RESTART, inputs :{}, resourceFilters: [RequestResourceFilter{serviceName='HBASE', componentName='HBASE_REGIONSERVER', hostNames=[sachadooptst8.corp.mirrorplus.com]}], exclusive: false, clusterName :HACluster
07 Mar 2016 04:08:21,708  INFO [qtp-client-280367] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 04:08:22,015  INFO [qtp-client-279464] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 04:33:23,650  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:40-0 timed out
07 Mar 2016 04:56:55,855  INFO [qtp-client-279677] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 04:58:26,012  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:40-0 timed out
07 Mar 2016 04:58:26,012  WARN [ambari-action-scheduler] ActionScheduler:587 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:40-0 expired
07 Mar 2016 04:58:26,016  WARN [ambari-action-scheduler] ActionScheduler:679 - Unable to transition to failed state.
org.apache.ambari.server.state.fsm.InvalidStateTransitionException: Invalid event: HOST_SVCCOMP_OP_FAILED at STARTED
at org.apache.ambari.server.state.fsm.StateMachineFactory.doTransition(StateMachineFactory.java:297)
at org.apache.ambari.server.state.fsm.StateMachineFactory.access$300(StateMachineFactory.java:39)
at org.apache.ambari.server.state.fsm.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:440)
at org.apache.ambari.server.state.svccomphost.ServiceComponentHostImpl.handleEvent(ServiceComponentHostImpl.java:887)
at org.apache.ambari.server.orm.AmbariJpaLocalTxnInterceptor.invoke(AmbariJpaLocalTxnInterceptor.java:68)
at org.apache.ambari.server.actionmanager.ActionScheduler.transitionToFailedState(ActionScheduler.java:662)
at org.apache.ambari.server.actionmanager.ActionScheduler.processInProgressStage(ActionScheduler.java:593)
at org.apache.ambari.server.actionmanager.ActionScheduler.doWork(ActionScheduler.java:282)
at org.apache.ambari.server.actionmanager.ActionScheduler.run(ActionScheduler.java:195)
at java.lang.Thread.run(Thread.java:745)
07 Mar 2016 04:58:26,017  INFO [ambari-action-scheduler] ActionScheduler:597 - Removing command from queue, host=sachadooptst8.corp.mirrorplus.com, commandId=40-0 
07 Mar 2016 05:03:44,562  INFO [qtp-client-277246] AmbariManagementControllerImpl:2911 - Received action execution request, clusterName=HACluster, request=isCommand :true, action :null, command :RESTART, inputs :{}, resourceFilters: [RequestResourceFilter{serviceName='HBASE', componentName='HBASE_CLIENT', hostNames=[sachadooptst8.corp.mirrorplus.com]}, RequestResourceFilter{serviceName='HBASE', componentName='HBASE_REGIONSERVER', hostNames=[sachadooptst8.corp.mirrorplus.com]}], exclusive: false, clusterName :HACluster
07 Mar 2016 05:03:45,303  INFO [qtp-client-280794] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 05:03:45,703  INFO [qtp-client-279781] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 05:08:06,547  INFO [qtp-client-280796] PersistKeyValueService:82 - Looking for keyName user-pref-admin-dashboard
07 Mar 2016 05:08:08,358  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 05:08:28,026  INFO [qtp-client-279781] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 05:28:46,925  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_CLIENT, actionId:41-0 timed out
07 Mar 2016 05:28:46,926  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:41-0 timed out
07 Mar 2016 05:41:18,873  INFO [qtp-client-280796] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 05:41:36,077  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName time-range-service-HBASE
07 Mar 2016 05:47:46,546  INFO [qtp-client-279677] PersistKeyValueService:82 - Looking for keyName user-pref-admin-dashboard
07 Mar 2016 05:53:49,422  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_CLIENT, actionId:41-0 timed out
07 Mar 2016 05:53:49,423  WARN [ambari-action-scheduler] ActionScheduler:587 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_CLIENT, actionId:41-0 expired
07 Mar 2016 05:53:49,426  WARN [ambari-action-scheduler] ActionScheduler:679 - Unable to transition to failed state.
org.apache.ambari.server.state.fsm.InvalidStateTransitionException: Invalid event: HOST_SVCCOMP_OP_FAILED at INSTALLED
at org.apache.ambari.server.state.fsm.StateMachineFactory.doTransition(StateMachineFactory.java:297)
at org.apache.ambari.server.state.fsm.StateMachineFactory.access$300(StateMachineFactory.java:39)
at org.apache.ambari.server.state.fsm.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:440)
at org.apache.ambari.server.state.svccomphost.ServiceComponentHostImpl.handleEvent(ServiceComponentHostImpl.java:887)
at org.apache.ambari.server.orm.AmbariJpaLocalTxnInterceptor.invoke(AmbariJpaLocalTxnInterceptor.java:68)
at org.apache.ambari.server.actionmanager.ActionScheduler.transitionToFailedState(ActionScheduler.java:662)
at org.apache.ambari.server.actionmanager.ActionScheduler.processInProgressStage(ActionScheduler.java:593)
at org.apache.ambari.server.actionmanager.ActionScheduler.doWork(ActionScheduler.java:282)
at org.apache.ambari.server.actionmanager.ActionScheduler.run(ActionScheduler.java:195)
at java.lang.Thread.run(Thread.java:745)
07 Mar 2016 05:53:49,427  INFO [ambari-action-scheduler] ActionScheduler:597 - Removing command from queue, host=sachadooptst8.corp.mirrorplus.com, commandId=41-0 
07 Mar 2016 05:53:49,427  INFO [ambari-action-scheduler] ActionScheduler:585 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:41-0 timed out
07 Mar 2016 05:53:49,427  WARN [ambari-action-scheduler] ActionScheduler:587 - Host:sachadooptst8.corp.mirrorplus.com, role:HBASE_REGIONSERVER, actionId:41-0 expired
07 Mar 2016 05:53:49,431  WARN [ambari-action-scheduler] ActionScheduler:679 - Unable to transition to failed state.
org.apache.ambari.server.state.fsm.InvalidStateTransitionException: Invalid event: HOST_SVCCOMP_OP_FAILED at STARTED
at org.apache.ambari.server.state.fsm.StateMachineFactory.doTransition(StateMachineFactory.java:297)
at org.apache.ambari.server.state.fsm.StateMachineFactory.access$300(StateMachineFactory.java:39)
at org.apache.ambari.server.state.fsm.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:440)
at org.apache.ambari.server.state.svccomphost.ServiceComponentHostImpl.handleEvent(ServiceComponentHostImpl.java:887)
at org.apache.ambari.server.orm.AmbariJpaLocalTxnInterceptor.invoke(AmbariJpaLocalTxnInterceptor.java:68)
at org.apache.ambari.server.actionmanager.ActionScheduler.transitionToFailedState(ActionScheduler.java:662)
at org.apache.ambari.server.actionmanager.ActionScheduler.processInProgressStage(ActionScheduler.java:593)
at org.apache.ambari.server.actionmanager.ActionScheduler.doWork(ActionScheduler.java:282)
at org.apache.ambari.server.actionmanager.ActionScheduler.run(ActionScheduler.java:195)
at java.lang.Thread.run(Thread.java:745)
07 Mar 2016 05:53:49,432  INFO [ambari-action-scheduler] ActionScheduler:597 - Removing command from queue, host=sachadooptst8.corp.mirrorplus.com, commandId=41-0 
07 Mar 2016 06:01:30,452  INFO [qtp-client-279677] PersistKeyValueService:82 - Looking for keyName time-range-service-HBASE
07 Mar 2016 06:01:53,172  INFO [qtp-client-276237] AmbariManagementControllerImpl:2911 - Received action execution request, clusterName=HACluster, request=isCommand :true, action :null, command :RESTART, inputs :{}, resourceFilters: [RequestResourceFilter{serviceName='HBASE', componentName='HBASE_CLIENT', hostNames=[sachadooptst8.corp.mirrorplus.com]}, RequestResourceFilter{serviceName='HBASE', componentName='HBASE_REGIONSERVER', hostNames=[sachadooptst8.corp.mirrorplus.com]}], exclusive: false, clusterName :HACluster
07 Mar 2016 06:01:53,566  INFO [qtp-client-280794] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 06:01:54,033  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 06:25:58,994  INFO [qtp-client-276237] PersistKeyValueService:82 - Looking for keyName user-pref-admin-dashboard
07 Mar 2016 06:26:02,254  INFO [qtp-client-276237] PersistKeyValueService:82 - Looking for keyName time-range-service-HBASE
07 Mar 2016 06:26:05,882  INFO [qtp-client-280796] PersistKeyValueService:82 - Looking for keyName admin-settings-show-bg-admin
07 Mar 2016 06:26:11,550  INFO [ambari-action-scheduler] ActionDBAccessorImpl:176 - Aborting command. Hostname sachadooptst8.corp.mirrorplus.com role HBASE_CLIENT requestId null taskId 499 stageId null
07 Mar 2016 06:26:11,550  INFO [ambari-action-scheduler] ActionDBAccessorImpl:176 - Aborting command. Hostname sachadooptst8.corp.mirrorplus.com role HBASE_REGIONSERVER requestId null taskId 500 stageId null
07 Mar 2016 06:26:43,434  INFO [qtp-client-281397] PersistKeyValueService:82 - Looking for keyName user-pref-admin-dashboard
07 Mar 2016 06:26:45,104  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName time-range-service-HBASE
07 Mar 2016 06:27:10,431  INFO [qtp-client-280794] PersistKeyValueService:82 - Looking for keyName user-pref-admin-dashboard
07 Mar 2016 06:27:23,429  INFO [qtp-client-276237] PersistKeyValueService:82 - Looking for keyName mainHostAlertsController-pagination-displayLength-admin
07 Mar 2016 06:27:39,402  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName user-pref-admin-dashboard
07 Mar 2016 06:27:43,877  INFO [qtp-client-281397] PersistKeyValueService:82 - Looking for keyName time-range-service-HBASE
07 Mar 2016 06:29:36,340  INFO [qtp-client-277246] PersistKeyValueService:82 - Looking for keyName user-pref-admin-dashboard
07 Mar 2016 06:29:38,839  INFO [qtp-client-279677] PersistKeyValueService:82 - Looking for keyName time-range-service-HBASE
07 Mar 2016 06:29:58,245  INFO [qtp-client-280794] PersistKeyValueService:82 - Looking for keyName mainHostAlertsController-pagination-displayLength-admin
07 Mar 2016 06:38:25,532  INFO [qtp-client-280796] PersistKeyValueService:82 - Looking for keyName user-pref-admin-dashboard

Thanks,

Raja

4,334 Views
0 Kudos

avatar
author-rank aervits
Master Mentor

Created ‎03-07-2016 02:48 PM

do you have support account? I suggest you open up a ticket as it needs more exhaustive look at your environment. If you're saying you can't restart one RS, try my commands to kill the RS and start it with Ambari. Then make sure all configs are up to date and run a service check. This is a drastic measure so proceed with caution, at your own risk. @Raja Ray

4,334 Views

avatar
author-rank raja_ray
Expert Contributor

Created ‎03-08-2016 10:02 AM

Hi Artem,

I restarted ambari-agent on the server and then restarted region-server. it worked fine..

4,612 Views
Announcements
What's New @ Cloudera
[RELEASED] Cloudera Streaming Analytics 1.14 for Cloudera Pu...
What's New @ Cloudera
Cloudera Data Engineering 1.23: Access Spark from Your Favor...
What's New @ Cloudera
HBase REST server scaling support is Generally Available
What's New @ Cloudera
New CLI option in the update-database command
What's New @ Cloudera
New Action menu item in the Cloudera Operational Database UI
View More Announcements