hbase-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "stack (JIRA)" <j...@apache.org>
Subject [jira] Commented: (HBASE-1394) Uploads sometimes fall to 0 requests/second (Binding up on HLog#append?)
Date Mon, 11 May 2009 21:06:46 GMT

    [ 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}
[stack@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.


Mime
View raw message