[HBASE-2922] HLog preparation and cleanup are done under the updateLock, major slowdown

• Type: Improvement
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 0.20.6, 0.89.20100621
• Fix Version/s: 0.90.0
• Hadoop Flags: Reviewed
• Assignee: Jean-Daniel Cryans
• Reporter: Jean-Daniel Cryans
• Created: 16/Aug/10 23:31
• Updated: 20/Nov/15 12:41
• Resolved: 21/Aug/10 00:27

Description

Something I've seen quite often in our production environment:

2010-08-16 16:17:27,104 INFO org.apache.hadoop.hbase.regionserver.HLog: removing old hlog file /hbase/.logs/rs22,60020,1280909840873/hlog.dat.1282000385321 whose highest sequence/edit id is 64837079950
2010-08-16 16:17:27,286 INFO org.apache.hadoop.hbase.regionserver.HLog: removing old hlog file /hbase/.logs/rs22,60020,1280909840873/hlog.dat.1282000392770 whose highest sequence/edit id is 64837088260
2010-08-16 16:17:27,452 INFO org.apache.hadoop.hbase.regionserver.HLog: removing old hlog file /hbase/.logs/rs22,60020,1280909840873/hlog.dat.1282000399300 whose highest sequence/edit id is 64837096566
2010-08-16 16:17:27,635 INFO org.apache.hadoop.hbase.regionserver.HLog: removing old hlog file /hbase/.logs/rs22,60020,1280909840873/hlog.dat.1282000406997 whose highest sequence/edit id is 64837104865
2010-08-16 16:17:27,827 INFO org.apache.hadoop.hbase.regionserver.HLog: removing old hlog file /hbase/.logs/rs22,60020,1280909840873/hlog.dat.1282000413803 whose highest sequence/edit id is 64837113153
2010-08-16 16:17:27,993 INFO org.apache.hadoop.hbase.regionserver.HLog: removing old hlog file /hbase/.logs/rs22,60020,1280909840873/hlog.dat.1282000421709 whose highest sequence/edit id is 64837121467
2010-08-16 16:17:28,160 INFO org.apache.hadoop.hbase.regionserver.HLog: removing old hlog file /hbase/.logs/rs22,60020,1280909840873/hlog.dat.1282000427333 whose highest sequence/edit id is 64837129775
2010-08-16 16:17:28,432 INFO org.apache.hadoop.hbase.regionserver.HLog: removing old hlog file /hbase/.logs/rs22,60020,1280909840873/hlog.dat.1282000434365 whose highest sequence/edit id is 64837138074
2010-08-16 16:17:28,518 INFO org.apache.hadoop.hbase.regionserver.HLog: removing old hlog file /hbase/.logs/rs22,60020,1280909840873/hlog.dat.1282000440347 whose highest sequence/edit id is 64837146376
2010-08-16 16:17:28,612 WARN org.apache.hadoop.hbase.regionserver.HLog: IPC Server handler 39 on 60020 took 1801ms appending an edit to hlog; editcount=0
2010-08-16 16:17:28,615 WARN org.apache.hadoop.hbase.regionserver.HLog: IPC Server handler 37 on 60020 took 1804ms appending an edit to hlog; editcount=1
2010-08-16 16:17:28,615 WARN org.apache.hadoop.hbase.regionserver.HLog: IPC Server handler 25 on 60020 took 1805ms appending an edit to hlog; editcount=2
...
2010-08-16 16:17:28,619 WARN org.apache.hadoop.hbase.regionserver.HLog: IPC Server handler 41 on 60020 took 1875ms appending an edit to hlog; editcount=50
2010-08-16 16:17:28,619 WARN org.apache.hadoop.hbase.regionserver.HLog: IPC Server handler 24 on 60020 took 1876ms appending an edit to hlog; editcount=51
2010-08-16 16:17:28,619 WARN org.apache.hadoop.hbase.regionserver.HLog: IPC Server handler 48 on 60020 took 1881ms appending an edit to hlog; editcount=54

And looking at HLog.rollWriter, we roll then cleanup those unused hlog files under updateLock, which blocks all the appenders (as shown). We should only do the first part under that lock