[
https://issues.apache.org/jira/browse/HBASE-3892?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13047117#comment-13047117
]
gaojinchao commented on HBASE-3892:
-----------------------------------
It didn't reproduce. So, My guess J-D is right. Below logs shows that:
Region server repeated message an interval of 60s. So It should be IPC timeout.
2011-05-08 17:43:45,507 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Connected to master at
C4C1.site:60000
2011-05-08 17:44:45,521 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Connected to master at
C4C1.site:60000
2011-05-08 17:45:45,524 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Connected to master at
C4C1.site:60000
2011-05-08 17:46:45,528 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Connected to master at
C4C1.site:60000
Hmaster logs shows regionServerReport IPC had been closed. It also proved IPC
timeout
2011-05-08 17:52:47,703 WARN org.apache.hadoop.ipc.HBaseServer: IPC Server
Responder, call regionServerReport(serverName=C4C3.site,60020,1304820199474,
load=(requests=0, regions=55, usedHeap=1058, maxHeap=8175),
[Lorg.apache.hadoop.hbase.HMsg;@1453ecec,
[Lorg.apache.hadoop.hbase.HRegionInfo;@11e78461) from 157.5.100.3:37518: output
error
2011-05-08 17:52:47,704 WARN org.apache.hadoop.ipc.HBaseServer: IPC Server
handler 7 on 60000 caught: java.nio.channels.ClosedChannelException
at
sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:126)
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:324)
at
org.apache.hadoop.hbase.ipc.HBaseServer.channelWrite(HBaseServer.java:1341)
at
org.apache.hadoop.hbase.ipc.HBaseServer$Responder.processResponse(HBaseServer.java:727)
at
org.apache.hadoop.hbase.ipc.HBaseServer$Responder.doRespond(HBaseServer.java:792)
at
org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1083)
But I can't dig the root reason.
> Table can't disable
> -------------------
>
> Key: HBASE-3892
> URL: https://issues.apache.org/jira/browse/HBASE-3892
> Project: HBase
> Issue Type: Bug
> Affects Versions: 0.90.3
> Reporter: gaojinchao
> Fix For: 0.90.4
>
> Attachments: AssignmentManager_90v3.patch,
> AssignmentManager_90v4.patch, logs.rar
>
>
> In TimeoutMonitor :
> if node exists and node state is RS_ZK_REGION_CLOSED
> We should send a zk message again when close region is timeout.
> in this case, It may be loss some message.
> I See. It seems like a bug. This is my analysis.
> // disable table and master sent Close message to region server, Region state
> was set PENDING_CLOSE
> 2011-05-08 17:44:25,745 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Sent CLOSE to
> serverName=C4C4.site,60020,1304820199467, load=(requests=0, regions=123,
> usedHeap=4097, maxHeap=8175) for region
> ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.
> 2011-05-08 17:44:45,530 INFO org.apache.hadoop.hbase.master.ServerManager:
> Received REGION_SPLIT:
> ufdr,2011050812#8613817306227#0516,1304845660567.8e9a3b05abe1c3a692999cf5e8dfd9dd.:
> Daughters;
> ufdr,2011050812#8613817306227#0516,1304847764729.5e4bca85c33fa6605ffc9a5c2eb94e62.,
>
> ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.
> from C4C4.site,60020,1304820199467
> 2011-05-08 17:45:45,542 INFO org.apache.hadoop.hbase.master.ServerManager:
> Received REGION_SPLIT:
> ufdr,2011050812#8613817306227#0516,1304845660567.8e9a3b05abe1c3a692999cf5e8dfd9dd.:
> Daughters;
> ufdr,2011050812#8613817306227#0516,1304847764729.5e4bca85c33fa6605ffc9a5c2eb94e62.,
>
> ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.
> from C4C4.site,60020,1304820199467
> // received splitting message and cleared Region state (PENDING_CLOSE)
> 2011-05-08 17:46:45,303 WARN
> org.apache.hadoop.hbase.master.AssignmentManager: Overwriting
> 4418fb197685a21f77e151e401cf8b66 on serverName=C4C4.site,60020,1304820199467,
> load=(requests=0, regions=123, usedHeap=4097, maxHeap=8175)
> 2011-05-08 17:46:45,538 INFO org.apache.hadoop.hbase.master.ServerManager:
> Received REGION_SPLIT:
> ufdr,2011050812#8613817306227#0516,1304845660567.8e9a3b05abe1c3a692999cf5e8dfd9dd.:
> Daughters;
> ufdr,2011050812#8613817306227#0516,1304847764729.5e4bca85c33fa6605ffc9a5c2eb94e62.,
>
> ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.
> from C4C4.site,60020,1304820199467
> 2011-05-08 17:47:45,548 INFO org.apache.hadoop.hbase.master.ServerManager:
> Received REGION_SPLIT:
> ufdr,2011050812#8613817306227#0516,1304845660567.8e9a3b05abe1c3a692999cf5e8dfd9dd.:
> Daughters;
> ufdr,2011050812#8613817306227#0516,1304847764729.5e4bca85c33fa6605ffc9a5c2eb94e62.,
>
> ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.
> from C4C4.site,60020,1304820199467
> 2011-05-08 17:48:45,545 INFO org.apache.hadoop.hbase.master.ServerManager:
> Received REGION_SPLIT:
> ufdr,2011050812#8613817306227#0516,1304845660567.8e9a3b05abe1c3a692999cf5e8dfd9dd.:
> Daughters;
> ufdr,2011050812#8613817306227#0516,1304847764729.5e4bca85c33fa6605ffc9a5c2eb94e62.,
>
> ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.
> from C4C4.site,60020,1304820199467
> 2011-05-08 17:49:46,108 INFO org.apache.hadoop.hbase.master.ServerManager:
> Received REGION_SPLIT:
> ufdr,2011050812#8613817306227#0516,1304845660567.8e9a3b05abe1c3a692999cf5e8dfd9dd.:
> Daughters;
> ufdr,2011050812#8613817306227#0516,1304847764729.5e4bca85c33fa6605ffc9a5c2eb94e62.,
>
> ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.
> from C4C4.site,60020,1304820199467
> 2011-05-08 17:50:46,105 INFO org.apache.hadoop.hbase.master.ServerManager:
> Received REGION_SPLIT:
> ufdr,2011050812#8613817306227#0516,1304845660567.8e9a3b05abe1c3a692999cf5e8dfd9dd.:
> Daughters;
> ufdr,2011050812#8613817306227#0516,1304847764729.5e4bca85c33fa6605ffc9a5c2eb94e62.,
>
> ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.
> from C4C4.site,60020,1304820199467
> 2011-05-08 17:51:46,117 INFO org.apache.hadoop.hbase.master.ServerManager:
> Received REGION_SPLIT:
> ufdr,2011050812#8613817306227#0516,1304845660567.8e9a3b05abe1c3a692999cf5e8dfd9dd.:
> Daughters;
> ufdr,2011050812#8613817306227#0516,1304847764729.5e4bca85c33fa6605ffc9a5c2eb94e62.,
>
> ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.
> from C4C4.site,60020,1304820199467
> 2011-05-08 17:52:46,112 INFO org.apache.hadoop.hbase.master.ServerManager:
> Received REGION_SPLIT:
> ufdr,2011050812#8613817306227#0516,1304845660567.8e9a3b05abe1c3a692999cf5e8dfd9dd.:
> Daughters;
> ufdr,2011050812#8613817306227#0516,1304847764729.5e4bca85c33fa6605ffc9a5c2eb94e62.,
>
> ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.
> from C4C4.site,60020,1304820199467
> 2011-05-08 17:52:47,309 DEBUG org.apache.hadoop.hbase.zookeeper.ZKUtil:
> master:60000-0x22fcd582836003d Retrieved 125 byte(s) of data from znode
> /hbase/unassigned/4418fb197685a21f77e151e401cf8b66 and set watcher;
> region=ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.,
> server=C4C4.site,60020,1304820199467, state=RS_ZK_REGION_CLOSED
> 2011-05-08 17:52:47,388 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling new unassigned
> node: /hbase/unassigned/4418fb197685a21f77e151e401cf8b66
> (region=ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.,
> server=C4C4.site,60020,1304820199467, state=RS_ZK_REGION_CLOSED)
> 2011-05-08 17:52:47,388 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_CLOSED, server=C4C4.site,60020,1304820199467,
> region=4418fb197685a21f77e151e401cf8b66
> // region server had closed region, but the region state had cleared. So it
> printed warning log.
> 2011-05-08 17:52:47,388 WARN
> org.apache.hadoop.hbase.master.AssignmentManager: Received CLOSED for region
> 4418fb197685a21f77e151e401cf8b66 from server C4C4.site,60020,1304820199467
> but region was in the state null and not in expected PENDING_CLOSE or
> CLOSING states
> 2011-05-08 17:52:47,397 WARN
> org.apache.hadoop.hbase.master.AssignmentManager: Overwriting
> 4418fb197685a21f77e151e401cf8b66 on serverName=C4C4.site,60020,1304820199467,
> load=(requests=0, regions=123, usedHeap=4097, maxHeap=8175)
> // The region state was set PENDING_CLOSE again. the table couldn't disable
> and enable.
> 2011-05-08 17:52:47,398 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment of
> region
> ufdr,2011050812#8613817398167#4032,1304847764729.4418fb197685a21f77e151e401cf8b66.
> (offlining)
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
