hbase-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Jean-Daniel Cryans (JIRA)" <j...@apache.org>
Subject [jira] Commented: (HBASE-3049) HLog size explosion
Date Mon, 01 Nov 2010 21:08:23 GMT

    [ https://issues.apache.org/jira/browse/HBASE-3049?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12927155#action_12927155
] 

Jean-Daniel Cryans commented on HBASE-3049:
-------------------------------------------

Did some more digging, turns out it's a few factors that contribute to HLog size explosion.
I added some debug lines in HLog (when a roll's requested, when it's preparing it and when
it acquired the lock) to see exactly where we were adding all that data, and here's the explosion
of one log during PE:

{noformat}
2010-11-01 13:34:10,921 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memstore
flush for region 
TestTable,0000984576,1288637489953.64980bd9a7d72aeb13a92b3d68fe893e.; current region memstore
size 101.4m
2010-11-01 13:34:10,921 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished snapshotting,
commencing flushing stores
2010-11-01 13:34:10,944 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Log roll requested,
getLength is 60749074
2010-11-01 13:34:10,992 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Log roll requested,
getLength is 65088262
2010-11-01 13:34:10,992 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Log roll requested,
getLength is 65088262

... hiding about 30 lines of "Log roll requested"!

2010-11-01 13:34:12,054 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Log roll requested,
getLength is 120051310
2010-11-01 13:34:12,135 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Log roll requested,
getLength is 124390498
2010-11-01 13:34:12,135 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Log roll requested,
getLength is 124390498
2010-11-01 13:34:12,155 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed
file at
 hdfs://hbasedev:9000/hbase-trunk/TestTable/64980bd9a7d72aeb13a92b3d68fe893e/.tmp/6522388362622022979
to 
 hdfs://hbasedev:9000/hbase-trunk/TestTable/64980bd9a7d72aeb13a92b3d68fe893e/info/1928466282107782255
2010-11-01 13:34:12,161 INFO org.apache.hadoop.hbase.regionserver.Store: 
 Added hdfs://hbasedev:9000/hbase-trunk/TestTable/64980bd9a7d72aeb13a92b3d68fe893e/info/1928466282107782255,
 entries=87444, sequenceid=51727166, memsize=101.4m, filesize=86.6m to TestTable,0000984576,1288637489953.64980bd9a7d72aeb13a92b3d68fe893e.
2010-11-01 13:34:12,161 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Preparing to
roll, current getLength =124390656
2010-11-01 13:34:12,161 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore
flush of ~101.4m for
 region TestTable,0000984576,1288637489953.64980bd9a7d72aeb13a92b3d68fe893e. in 1240ms, sequenceid=51727166,
compaction requested=true
2010-11-01 13:34:12,211 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Log roll requested,
getLength is 128729824
2010-11-01 13:34:12,211 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Log roll requested,
getLength is 128729824
2010-11-01 13:34:12,215 INFO org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter:
Using syncFs -- HDFS-200
2010-11-01 13:34:12,216 WARN org.apache.hadoop.hbase.regionserver.wal.HLog: Rolling a file
that's more than 20% bigger than it should be:
 logrollsize=31876710, getLength =128729824
2010-11-01 13:34:12,221 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Roll
 /hbase-trunk/.logs/hbasedev,60020,1288643625308/10.10.1.177%3A60020.1288643647366, entries=93,
 filesize=128729824. New hlog /hbase-trunk/.logs/hbasedev,60020,1288643625308/10.10.1.177%3A60020.1288643652161
{noformat}

The first reason we let the log outgrow here is the MemStore flush since we can't do both
at the same time. Then, although not in this specific excerpt, we also let a few inserts come
in when preparing the HLog rolling due to HBASE-2922.

So this may not be a problem since it basically works how it's supposed to... and it means
that under "normal" conditions it's not likely to go way over the log roll size. I suggest
we close this issue.

> HLog size explosion
> -------------------
>
>                 Key: HBASE-3049
>                 URL: https://issues.apache.org/jira/browse/HBASE-3049
>             Project: HBase
>          Issue Type: Bug
>            Reporter: Jean-Daniel Cryans
>             Fix For: 0.90.0
>
>
> Recently I've been seeing some strange behavior around HLogs, HBASE-3038 is an example.
Looking in my oldlogs folder, I see:
> {noformat}
> -rw-r--r--   3 hadoop supergroup  716716459 2010-09-29 01:08 /hbase/.oldlogs/10.20.20.176%3A60020.1285722528252
> -rw-r--r--   3 hadoop supergroup   64841781 2010-09-29 01:10 /hbase/.oldlogs/10.20.20.176%3A60020.1285722620286
> bunch of normally sized HLogs... then
> -rw-r--r--   3 hadoop supergroup  769729956 2010-09-29 01:13 /hbase/.oldlogs/10.20.20.176%3A60020.1285722785347
> {noformat}
> 680MB is way off the 64MB limit. My feeling is that the optimizations I did in the scope
of HBASE-2922 that remove some blocking behavior have the side effect of getting a lot more
data in a lot faster in some edge cases. Need to investigate more.

-- 
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