[
https://issues.apache.org/jira/browse/HBASE-1394?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12708220#action_12708220
]
stack commented on HBASE-1394:
------------------------------
TODO: Add disabling the commit log. Bulk uploaders might appreciate this (Ryan
suggestion).
I tried running without logging to see what would happen. The behavior of
HRegionServer changes drastically from walk-in-the-park dawdling to
sprint/rest/sprint/rest, etc. The rate when its flowing is way up, maybe 10x
but then we quickly run up against the flusher; all is paused because memory is
saturated and flushing is taking too long.
It also seems that compactions are overrun -- possibly because of HBASE-1058:
{code}
[st...@aa0-000-13 ~]$ grep 'Too many s'
trunk/logs/hbase-stack-regionserver-aa0-000-13.u.powerset.com.log|grep
1242073708841
2009-05-11 20:29:26,931 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 5, waiting
2009-05-11 20:29:36,388 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 5, waiting
2009-05-11 20:29:41,234 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 6, waiting
2009-05-11 20:29:47,664 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 6, waiting
2009-05-11 20:29:52,046 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 7, waiting
2009-05-11 20:30:11,866 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 8, waiting
2009-05-11 20:30:17,860 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 7, waiting
2009-05-11 20:30:36,076 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 9, waiting
2009-05-11 20:30:55,493 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 8, waiting
2009-05-11 20:30:59,658 [IPC Server handler 9 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 8, waiting
2009-05-11 20:31:11,759 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 10, waiting
2009-05-11 20:32:06,046 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 11, waiting
2009-05-11 20:32:31,661 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 12, waiting
2009-05-11 20:32:51,110 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 13, waiting
2009-05-11 20:33:18,677 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 14, waiting
2009-05-11 20:33:47,818 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 15, waiting
2009-05-11 20:34:01,475 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 9, waiting
2009-05-11 20:34:18,966 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 16, waiting
2009-05-11 20:34:23,467 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 10, waiting
2009-05-11 20:34:46,749 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 17, waiting
2009-05-11 20:35:15,330 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 18, waiting
2009-05-11 20:35:41,234 [IPC Server handler 7 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 19, waiting
2009-05-11 20:35:41,671 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 11, waiting
2009-05-11 20:36:11,554 [IPC Server handler 0 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 12, waiting
2009-05-11 20:36:23,204 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 20, waiting
2009-05-11 20:37:00,864 [IPC Server handler 4 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 13, waiting
2009-05-11 20:37:29,841 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 14, waiting
2009-05-11 20:37:42,480 [IPC Server handler 5 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 14, waiting
2009-05-11 20:37:46,068 [IPC Server handler 5 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 21, waiting
2009-05-11 20:38:09,668 [IPC Server handler 7 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 15, waiting
2009-05-11 20:38:26,761 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 16, waiting
2009-05-11 20:38:38,506 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 22, waiting
2009-05-11 20:38:54,858 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0651581333,1242073708841: 17, waiting
2009-05-11 20:39:36,309 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 23, waiting
2009-05-11 20:40:30,278 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 24, waiting
2009-05-11 20:40:39,268 [IPC Server handler 4 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 25, waiting
2009-05-11 20:41:12,208 [IPC Server handler 1 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 26, waiting
2009-05-11 20:41:32,876 [IPC Server handler 1 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 27, waiting
2009-05-11 20:42:03,696 [IPC Server handler 2 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 28, waiting
2009-05-11 20:42:35,004 [IPC Server handler 1 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 29, waiting
2009-05-11 20:43:21,116 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 30, waiting
2009-05-11 20:44:01,246 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 31, waiting
2009-05-11 20:44:23,626 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 32, waiting
2009-05-11 20:44:47,639 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 33, waiting
2009-05-11 20:45:29,544 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 34, waiting
2009-05-11 20:45:53,016 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 35, waiting
2009-05-11 20:46:00,022 [IPC Server handler 1 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 35, waiting
2009-05-11 20:46:24,341 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 36, waiting
2009-05-11 20:47:11,688 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 37, waiting
2009-05-11 20:47:33,468 [IPC Server handler 7 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 37, waiting
2009-05-11 20:48:07,649 [IPC Server handler 4 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 38, waiting
2009-05-11 20:48:40,982 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 39, waiting
2009-05-11 20:49:22,073 [IPC Server handler 8 on 60021] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 40, waiting
2009-05-11 20:49:22,081 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 40, waiting
2009-05-11 20:49:49,418 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 41, waiting
2009-05-11 20:50:27,648 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 42, waiting
2009-05-11 20:50:55,221 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] INFO
org.apache.hadoop.hbase.regionserver.MemcacheFlusher: Too many store files for
region TestTable,0452156162,1242073708841: 43, waiting
{code}
TODO: Make issues for above after its easy to create because commit log can be
disabled.
> Uploads sometimes fall to 0 requests/second (Binding up on HLog#append?)
> ------------------------------------------------------------------------
>
> Key: HBASE-1394
> URL: https://issues.apache.org/jira/browse/HBASE-1394
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Priority: Critical
> Fix For: 0.20.0
>
> Attachments: loghowlongittookappendinghlog.patch
>
>
> Trying to figure why rate sometimes goes to zero.
> Studying the reginoserver, HLog#append looks like a possible culprit.
> {code}
> "IPC Server handler 7 on 60021" daemon prio=10 tid=0x000000004057dc00
> nid=0x1bc4 in Object.wait() [0x0000000043393000..0x0000000043393b80]
> java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> at java.lang.Object.wait(Object.java:485)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.writeChunk(DFSClient.java:2964)
> - locked <0x00007f9e3e449ff0> (a java.util.LinkedList)
> - locked <0x00007f9e3e449e18> (a
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream)
> at
> org.apache.hadoop.fs.FSOutputSummer.writeChecksumChunk(FSOutputSummer.java:150)
> at org.apache.hadoop.fs.FSOutputSummer.write1(FSOutputSummer.java:100)
> at org.apache.hadoop.fs.FSOutputSummer.write(FSOutputSummer.java:86)
> - locked <0x00007f9e3e449e18> (a
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream)
> at
> org.apache.hadoop.fs.FSDataOutputStream$PositionCache.write(FSDataOutputStream.java:49)
> at java.io.DataOutputStream.write(DataOutputStream.java:90)
> - locked <0x00007f9e434e5588> (a
> org.apache.hadoop.fs.FSDataOutputStream)
> at
> org.apache.hadoop.io.SequenceFile$Writer.append(SequenceFile.java:1020)
> - locked <0x00007f9e434e55c0> (a
> org.apache.hadoop.io.SequenceFile$Writer)
> at
> org.apache.hadoop.io.SequenceFile$Writer.append(SequenceFile.java:984)
> - locked <0x00007f9e434e55c0> (a
> org.apache.hadoop.io.SequenceFile$Writer)
> at org.apache.hadoop.hbase.regionserver.HLog.doWrite(HLog.java:565)
> at org.apache.hadoop.hbase.regionserver.HLog.append(HLog.java:521)
> - locked <0x00007f9dfa376f70> (a java.lang.Object)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.update(HRegion.java:1777)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.batchUpdate(HRegion.java:1348)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.batchUpdate(HRegion.java:1289)
> at
> org.apache.hadoop.hbase.regionserver.HRegionServer.batchUpdates(HRegionServer.java:1727)
> at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:597)
> at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:642)
> at
> org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:911)
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
