You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "stack (JIRA)" <ji...@apache.org> on 2010/12/01 20:20:12 UTC
[jira] Created: (HBASE-3294) WARN
org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?)
org.apache.hadoop.hbase.regionserver.StoreScanner@76607d3d
WARN org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?) org.apache.hadoop.hbase.regionserver.StoreScanner@76607d3d
---------------------------------------------------------------------------------------------------------------------------------------
Key: HBASE-3294
URL: https://issues.apache.org/jira/browse/HBASE-3294
Project: HBase
Issue Type: Bug
Reporter: stack
Fix For: 0.90.0
We see this ugly message in running hbase. Its a little disorientating. I added stack traces around the call to close. Here are the two I see (The WARN message is the bad one... the INFO is the good case). Looks like compaction is the one that triggers the WARN.
{code}
2010-12-01 18:20:28,307 WARN org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?) org.apache.hadoop.hbase.regionserver.StoreScanner@68faedc7
java.io.IOException: WHY
at org.apache.hadoop.hbase.regionserver.Store.deleteChangedReaderObserver(Store.java:583)
at org.apache.hadoop.hbase.regionserver.StoreScanner.close(StoreScanner.java:204)
at org.apache.hadoop.hbase.regionserver.StoreScanner.next(StoreScanner.java:242)
at org.apache.hadoop.hbase.regionserver.StoreScanner.next(StoreScanner.java:326)
at org.apache.hadoop.hbase.regionserver.Store.compact(Store.java:939)
at org.apache.hadoop.hbase.regionserver.Store.compact(Store.java:748)
at org.apache.hadoop.hbase.regionserver.HRegion.compactStores(HRegion.java:753)
at org.apache.hadoop.hbase.regionserver.HRegion.compactStores(HRegion.java:698)
at org.apache.hadoop.hbase.regionserver.CompactSplitThread.run(CompactSplitThread.java:81)
2010-12-01 18:21:18,103 INFO org.apache.hadoop.hbase.regionserver.Store: CLOSE org.apache.hadoop.hbase.regionserver.StoreScanner@3dca256e
java.io.IOException: WHY
at org.apache.hadoop.hbase.regionserver.Store.deleteChangedReaderObserver(Store.java:592)
at org.apache.hadoop.hbase.regionserver.StoreScanner.close(StoreScanner.java:204)
at org.apache.hadoop.hbase.regionserver.KeyValueHeap.close(KeyValueHeap.java:192)
at org.apache.hadoop.hbase.regionserver.HRegion$RegionScanner.close(HRegion.java:2361)
at org.apache.hadoop.hbase.regionserver.HRegion.get(HRegion.java:2945)
at org.apache.hadoop.hbase.regionserver.HRegion.get(HRegion.java:2844)
at org.apache.hadoop.hbase.regionserver.HRegionServer.get(HRegionServer.java:1566)
at sun.reflect.GeneratedMethodAccessor5.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:570)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1036)
{code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-3294) WARN
org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?)
org.apache.hadoop.hbase.regionserver.StoreScanner@76607d3d
Posted by "ryan rawson (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-3294?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12965825#action_12965825 ]
ryan rawson commented on HBASE-3294:
------------------------------------
It might be due to this code:
KeyValue kvReturn = this.current.next();
KeyValue kvNext = this.current.peek();
if (kvNext == null) {
this.current.close();
...
If a store scanner comes to the end of it's scan, it will automatically call close() on itself. This will deregister the changed reader observer. Then the heap will also call close() which will redo that operation.
Removing the 'this.current.close()' code isn't really possible because this heap is used on both StoreScanner and StoreFileScanner, and we want the close() semantics in there. The StoreFileScanner doesn't work in the same way as well.
We should just remove the message, don't even bother checking for existence because it doesn't matter, the important part is we are no longer registered.
> WARN org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?) org.apache.hadoop.hbase.regionserver.StoreScanner@76607d3d
> ---------------------------------------------------------------------------------------------------------------------------------------
>
> Key: HBASE-3294
> URL: https://issues.apache.org/jira/browse/HBASE-3294
> Project: HBase
> Issue Type: Bug
> Reporter: stack
> Fix For: 0.90.0
>
>
> We see this ugly message in running hbase. Its a little disorientating. I added stack traces around the call to close. Here are the two I see (The WARN message is the bad one... the INFO is the good case). Looks like compaction is the one that triggers the WARN.
> {code}
> 2010-12-01 18:20:28,307 WARN org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?) org.apache.hadoop.hbase.regionserver.StoreScanner@68faedc7
> java.io.IOException: WHY
> at org.apache.hadoop.hbase.regionserver.Store.deleteChangedReaderObserver(Store.java:583)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.close(StoreScanner.java:204)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.next(StoreScanner.java:242)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.next(StoreScanner.java:326)
> at org.apache.hadoop.hbase.regionserver.Store.compact(Store.java:939)
> at org.apache.hadoop.hbase.regionserver.Store.compact(Store.java:748)
> at org.apache.hadoop.hbase.regionserver.HRegion.compactStores(HRegion.java:753)
> at org.apache.hadoop.hbase.regionserver.HRegion.compactStores(HRegion.java:698)
> at org.apache.hadoop.hbase.regionserver.CompactSplitThread.run(CompactSplitThread.java:81)
> 2010-12-01 18:21:18,103 INFO org.apache.hadoop.hbase.regionserver.Store: CLOSE org.apache.hadoop.hbase.regionserver.StoreScanner@3dca256e
> java.io.IOException: WHY
> at org.apache.hadoop.hbase.regionserver.Store.deleteChangedReaderObserver(Store.java:592)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.close(StoreScanner.java:204)
> at org.apache.hadoop.hbase.regionserver.KeyValueHeap.close(KeyValueHeap.java:192)
> at org.apache.hadoop.hbase.regionserver.HRegion$RegionScanner.close(HRegion.java:2361)
> at org.apache.hadoop.hbase.regionserver.HRegion.get(HRegion.java:2945)
> at org.apache.hadoop.hbase.regionserver.HRegion.get(HRegion.java:2844)
> at org.apache.hadoop.hbase.regionserver.HRegionServer.get(HRegionServer.java:1566)
> at sun.reflect.GeneratedMethodAccessor5.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:570)
> at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1036)
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-3294) WARN
org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?)
org.apache.hadoop.hbase.regionserver.StoreScanner@76607d3d
Posted by "Jonathan Gray (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-3294?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12965816#action_12965816 ]
Jonathan Gray commented on HBASE-3294:
--------------------------------------
I've seen this up on my cluster with some regularity.
> WARN org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?) org.apache.hadoop.hbase.regionserver.StoreScanner@76607d3d
> ---------------------------------------------------------------------------------------------------------------------------------------
>
> Key: HBASE-3294
> URL: https://issues.apache.org/jira/browse/HBASE-3294
> Project: HBase
> Issue Type: Bug
> Reporter: stack
> Fix For: 0.90.0
>
>
> We see this ugly message in running hbase. Its a little disorientating. I added stack traces around the call to close. Here are the two I see (The WARN message is the bad one... the INFO is the good case). Looks like compaction is the one that triggers the WARN.
> {code}
> 2010-12-01 18:20:28,307 WARN org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?) org.apache.hadoop.hbase.regionserver.StoreScanner@68faedc7
> java.io.IOException: WHY
> at org.apache.hadoop.hbase.regionserver.Store.deleteChangedReaderObserver(Store.java:583)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.close(StoreScanner.java:204)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.next(StoreScanner.java:242)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.next(StoreScanner.java:326)
> at org.apache.hadoop.hbase.regionserver.Store.compact(Store.java:939)
> at org.apache.hadoop.hbase.regionserver.Store.compact(Store.java:748)
> at org.apache.hadoop.hbase.regionserver.HRegion.compactStores(HRegion.java:753)
> at org.apache.hadoop.hbase.regionserver.HRegion.compactStores(HRegion.java:698)
> at org.apache.hadoop.hbase.regionserver.CompactSplitThread.run(CompactSplitThread.java:81)
> 2010-12-01 18:21:18,103 INFO org.apache.hadoop.hbase.regionserver.Store: CLOSE org.apache.hadoop.hbase.regionserver.StoreScanner@3dca256e
> java.io.IOException: WHY
> at org.apache.hadoop.hbase.regionserver.Store.deleteChangedReaderObserver(Store.java:592)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.close(StoreScanner.java:204)
> at org.apache.hadoop.hbase.regionserver.KeyValueHeap.close(KeyValueHeap.java:192)
> at org.apache.hadoop.hbase.regionserver.HRegion$RegionScanner.close(HRegion.java:2361)
> at org.apache.hadoop.hbase.regionserver.HRegion.get(HRegion.java:2945)
> at org.apache.hadoop.hbase.regionserver.HRegion.get(HRegion.java:2844)
> at org.apache.hadoop.hbase.regionserver.HRegionServer.get(HRegionServer.java:1566)
> at sun.reflect.GeneratedMethodAccessor5.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:570)
> at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1036)
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Resolved: (HBASE-3294) WARN
org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?)
org.apache.hadoop.hbase.regionserver.StoreScanner@76607d3d
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-3294?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
stack resolved HBASE-3294.
--------------------------
Resolution: Fixed
Assignee: stack
Committed trunk and branch.
> WARN org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?) org.apache.hadoop.hbase.regionserver.StoreScanner@76607d3d
> ---------------------------------------------------------------------------------------------------------------------------------------
>
> Key: HBASE-3294
> URL: https://issues.apache.org/jira/browse/HBASE-3294
> Project: HBase
> Issue Type: Bug
> Reporter: stack
> Assignee: stack
> Fix For: 0.90.0
>
>
> We see this ugly message in running hbase. Its a little disorientating. I added stack traces around the call to close. Here are the two I see (The WARN message is the bad one... the INFO is the good case). Looks like compaction is the one that triggers the WARN.
> {code}
> 2010-12-01 18:20:28,307 WARN org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?) org.apache.hadoop.hbase.regionserver.StoreScanner@68faedc7
> java.io.IOException: WHY
> at org.apache.hadoop.hbase.regionserver.Store.deleteChangedReaderObserver(Store.java:583)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.close(StoreScanner.java:204)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.next(StoreScanner.java:242)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.next(StoreScanner.java:326)
> at org.apache.hadoop.hbase.regionserver.Store.compact(Store.java:939)
> at org.apache.hadoop.hbase.regionserver.Store.compact(Store.java:748)
> at org.apache.hadoop.hbase.regionserver.HRegion.compactStores(HRegion.java:753)
> at org.apache.hadoop.hbase.regionserver.HRegion.compactStores(HRegion.java:698)
> at org.apache.hadoop.hbase.regionserver.CompactSplitThread.run(CompactSplitThread.java:81)
> 2010-12-01 18:21:18,103 INFO org.apache.hadoop.hbase.regionserver.Store: CLOSE org.apache.hadoop.hbase.regionserver.StoreScanner@3dca256e
> java.io.IOException: WHY
> at org.apache.hadoop.hbase.regionserver.Store.deleteChangedReaderObserver(Store.java:592)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.close(StoreScanner.java:204)
> at org.apache.hadoop.hbase.regionserver.KeyValueHeap.close(KeyValueHeap.java:192)
> at org.apache.hadoop.hbase.regionserver.HRegion$RegionScanner.close(HRegion.java:2361)
> at org.apache.hadoop.hbase.regionserver.HRegion.get(HRegion.java:2945)
> at org.apache.hadoop.hbase.regionserver.HRegion.get(HRegion.java:2844)
> at org.apache.hadoop.hbase.regionserver.HRegionServer.get(HRegionServer.java:1566)
> at sun.reflect.GeneratedMethodAccessor5.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:570)
> at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1036)
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-3294) WARN
org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?)
org.apache.hadoop.hbase.regionserver.StoreScanner@76607d3d
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-3294?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12965844#action_12965844 ]
stack commented on HBASE-3294:
------------------------------
OK... I'll apply the below to address this issue:
{code}
stack@sv2borg180:~/trunk$ svn diff
Index: src/main/java/org/apache/hadoop/hbase/regionserver/Store.java
===================================================================
--- src/main/java/org/apache/hadoop/hbase/regionserver/Store.java (revision 1041161)
+++ src/main/java/org/apache/hadoop/hbase/regionserver/Store.java (working copy)
@@ -579,9 +579,8 @@
* @param o Observer no longer interested in changes in set of Readers.
*/
void deleteChangedReaderObserver(ChangedReadersObserver o) {
- if (!this.changedReaderObservers.remove(o)) {
- LOG.warn("Not in set (double-remove?) " + o);
- }
+ // We don't check if observer present; it may not be (legitimately)
+ this.changedReaderObservers.remove(o);
}
//////////////////////////////////////////////////////////////////////////////
Index: src/main/java/org/apache/hadoop/hbase/catalog/MetaEditor.java
===================================================================
--- src/main/java/org/apache/hadoop/hbase/catalog/MetaEditor.java (revision 1041161)
+++ src/main/java/org/apache/hadoop/hbase/catalog/MetaEditor.java (working copy)
@@ -204,8 +204,8 @@
delete.deleteColumns(HConstants.CATALOG_FAMILY, qualifier);
catalogTracker.waitForMetaServerConnectionDefault().
delete(CatalogTracker.META_REGION, delete);
- LOG.info("Deleted daughter " + daughter.getRegionNameAsString() +
- " " + Bytes.toString(qualifier) + " reference in parent " +
+ LOG.info("Deleted daughter reference " + daughter.getRegionNameAsString() +
+ ", qualifier=" + Bytes.toString(qualifier) + ", from parent " +
parent.getRegionNameAsString());
}
{code}
The latter change is a fix to a log message that confused Ryan... lumping it in here.
> WARN org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?) org.apache.hadoop.hbase.regionserver.StoreScanner@76607d3d
> ---------------------------------------------------------------------------------------------------------------------------------------
>
> Key: HBASE-3294
> URL: https://issues.apache.org/jira/browse/HBASE-3294
> Project: HBase
> Issue Type: Bug
> Reporter: stack
> Fix For: 0.90.0
>
>
> We see this ugly message in running hbase. Its a little disorientating. I added stack traces around the call to close. Here are the two I see (The WARN message is the bad one... the INFO is the good case). Looks like compaction is the one that triggers the WARN.
> {code}
> 2010-12-01 18:20:28,307 WARN org.apache.hadoop.hbase.regionserver.Store: Not in set (double-remove?) org.apache.hadoop.hbase.regionserver.StoreScanner@68faedc7
> java.io.IOException: WHY
> at org.apache.hadoop.hbase.regionserver.Store.deleteChangedReaderObserver(Store.java:583)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.close(StoreScanner.java:204)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.next(StoreScanner.java:242)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.next(StoreScanner.java:326)
> at org.apache.hadoop.hbase.regionserver.Store.compact(Store.java:939)
> at org.apache.hadoop.hbase.regionserver.Store.compact(Store.java:748)
> at org.apache.hadoop.hbase.regionserver.HRegion.compactStores(HRegion.java:753)
> at org.apache.hadoop.hbase.regionserver.HRegion.compactStores(HRegion.java:698)
> at org.apache.hadoop.hbase.regionserver.CompactSplitThread.run(CompactSplitThread.java:81)
> 2010-12-01 18:21:18,103 INFO org.apache.hadoop.hbase.regionserver.Store: CLOSE org.apache.hadoop.hbase.regionserver.StoreScanner@3dca256e
> java.io.IOException: WHY
> at org.apache.hadoop.hbase.regionserver.Store.deleteChangedReaderObserver(Store.java:592)
> at org.apache.hadoop.hbase.regionserver.StoreScanner.close(StoreScanner.java:204)
> at org.apache.hadoop.hbase.regionserver.KeyValueHeap.close(KeyValueHeap.java:192)
> at org.apache.hadoop.hbase.regionserver.HRegion$RegionScanner.close(HRegion.java:2361)
> at org.apache.hadoop.hbase.regionserver.HRegion.get(HRegion.java:2945)
> at org.apache.hadoop.hbase.regionserver.HRegion.get(HRegion.java:2844)
> at org.apache.hadoop.hbase.regionserver.HRegionServer.get(HRegionServer.java:1566)
> at sun.reflect.GeneratedMethodAccessor5.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:570)
> at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1036)
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.