[HBase-dev] [jira] Created: (HBASE-2029) Reduce shell exception dump on console

[ https://issues.apache.org/jira/browse/HBASE-2029?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Lars George updated HBASE-2029:
-------------------------------

Component/s: scripts
Description:
As discussed on IRC and seen over and over, the shell is too verbose when it prints Java related exceptions. The huge stack trace on the console is often causing more harm then actually helping.


{noformat}
...
[11:31pm] larsgeorge:
the only concern is to keep it in sync with new changes and also reduce its stacktrace
[11:31pm] larsgeorge:
that can be quite nasty
[11:31pm] _dodger_:
I've seen a prime example of that on the mailing list today
[11:32pm] larsgeorge:
yeah, those do repeat themselves
[11:32pm] larsgeorge:
also that DEBUG is on by default
[11:33pm] larsgeorge:
mind you, that is a good idea for the daemons
[11:33pm] larsgeorge:
but prolly not the shell
[11:33pm] jdcryans:
I was thinking
[11:33pm] larsgeorge:
maybe we can set ERROR logging level just for the shell when it is started?
[11:34pm] jdcryans:
we should stop printing the stack trace for NSRE
[11:34pm] larsgeorge:
there are a few others of that sort
[11:34pm] larsgeorge:
be it ZK reconnects etc.
[11:35pm] jdcryans:
yeah there's a lot of hbase-generated zk-related noise
{noformat}

was:
As discussed on IRC and seen over and over, the shell is too verbose when it prints Java related exceptions. The huge stack trace on the console is often causing more harm then actually helping.

{noformat}
...
[11:31pm] larsgeorge:
the only concern is to keep it in sync with new changes and also reduce its stacktrace
[11:31pm] larsgeorge:
that can be quite nasty
[11:31pm] _dodger_:
I've seen a prime example of that on the mailing list today
[11:32pm] larsgeorge:
yeah, those do repeat themselves
[11:32pm] larsgeorge:
also that DEBUG is on by default
[11:33pm] larsgeorge:
mind you, that is a good idea for the daemons
[11:33pm] larsgeorge:
but prolly not the shell
[11:33pm] jdcryans:
I was thinking
[11:33pm] larsgeorge:
maybe we can set ERROR logging level just for the shell when it is started?
[11:34pm] jdcryans:
we should stop printing the stack trace for NSRE
[11:34pm] larsgeorge:
there are a few others of that sort
[11:34pm] larsgeorge:
be it ZK reconnects etc.
[11:35pm] jdcryans:
yeah there's a lot of hbase-generated zk-related noise
{noformat}

[ https://issues.apache.org/jira/browse/HBASE-2029?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jean-Daniel Cryans reassigned HBASE-2029:
-----------------------------------------

Assignee: Jean-Daniel Cryans

I will try something.

[ https://issues.apache.org/jira/browse/HBASE-2029?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jean-Daniel Cryans updated HBASE-2029:
--------------------------------------

Attachment: HBASE-2029.patch

First cut.

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

stack commented on HBASE-2029:
------------------------------

Close hbase-1612. It dupes this. Patch looks good. There is also an irb env variable related to size of stack shown. I was going to look into this for jirb.

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

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

I think it's something like

irb --back-trace-limit 100

But I'm not sure how to set it in our shell.

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

stack commented on HBASE-2029:
------------------------------

According to http://ruby-doc.org/docs/ProgrammingRuby/html/irb.html, should be able to do something like this in our subclass of Irb:

{code}
Index: bin/hirb.rb
===================================================================
--- bin/hirb.rb (revision 887084)
+++ bin/hirb.rb (working copy)
@@ -478,6 +478,7 @@
IRB.setup(ap_path)
@CONF[:IRB_NAME] = 'hbase'
@CONF[:AP_NAME] = 'hbase'
+ @CONF[:BACK_TRACE_LIMIT] = 1

if @CONF[:SCRIPT]
hirb = HIRB.new(nil, @CONF[:SCRIPT])
{code}

I'll play w/ it and get back to you.

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

Lars George commented on HBASE-2029:
------------------------------------

Looks like that is it, haven't tried it but I grep'ed the JRuby sources and that config option has been used quite a few times. So we now have to see if it has the desired effect.

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

Lars George commented on HBASE-2029:
------------------------------------

OK, tried it and I suggest we use

{code}
@CONF[:BACK_TRACE_LIMIT] = 0
{code}

Reason is that 1 gives

{noformat}
hbase(main):001:0> scan 'e'
NativeException: org.apache.hadoop.hbase.TableNotFoundException: e
from org/apache/hadoop/hbase/client/HConnectionManager.java:650:in `locateRegionInMeta'
... 166 levels...
from (hbase):2hbase(main):002:0>
{noformat}

Using 0 gives

{noformat}
hbase(main):001:0> scan 'e'
NativeException: org.apache.hadoop.hbase.TableNotFoundException: e

hbase(main):002:0>
{noformat}

+1 for the latter.

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

Lars George commented on HBASE-2029:
------------------------------------

I also suggest we change the logging levels for ZK to ERROR and do the same for HBase. The reason is that having DEBUG now on for 0.20.2 and onwards which is good for the daemons doing it in the shell can easily deter users from the various details printed out.

I have changed added this to hirb.rb

{code}
# Hack to turn down zk logging so it don't spew over the shell
# log4j.logger.org.apache.zookeeper=INFO
logger = org.apache.log4j.Logger.getLogger("org.apache.zookeeper")
logger.setLevel(org.apache.log4j.Level::ERROR);

# Hack to turn down HBase logging so it don't spew over the shell
logger = org.apache.log4j.Logger.getLogger("org.apache.hadoop.hbase")
logger.setLevel(org.apache.log4j.Level::ERROR);
{code}

That now yields no spurious warnings etc.

What I could think of though is having a debug option at shell start up to set HBase debug level for the developers and advanced user. Saves from editing the hirb.rb - but which is still not the worst for an advanced user. Not sure if we could have something like this

{code}
$ hbase shell -debug
{code}

Should be easy I would think to detect the flag and hand it into the org.jruy.Main call (or simply pass it on as is and let the hirb.rb handle it.

Just suggesting.

[ https://issues.apache.org/jira/browse/HBASE-2029?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Lars George updated HBASE-2029:
-------------------------------

Attachment: HBASE-2029-hirb.patch

Add -d and --debug support. Help:

{noformat}
LarsMacBookPro:hbase-trunk-ro larsgeorge$ bin/hbase shell -h
HBase Shell command-line options:
format Formatter for outputting results: console | html. Default: console
format-width Width of table outputs. Default: 110 characters.
-d | --debug Set DEBUG log levels.
{noformat}

Without DEBUG switch, nice and clean:

{noformat}
LarsMacBookPro:hbase-trunk-ro larsgeorge$ bin/hbase shell
HBase Shell; enter 'help<RETURN>' for list of supported commands.
Version: 0.21.0-dev, r886052, Thu Dec 3 17:05:20 CET 2009
hbase(main):001:0> scan 'e'
NativeException: org.apache.hadoop.hbase.TableNotFoundException: e

hbase(main):002:0> exit
{noformat}

And with DEBUG switch, verbose as requested:

{noformat}
LarsMacBookPro:hbase-trunk-ro larsgeorge$ bin/hbase shell -d
Setting DEBUG log level...
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:zookeeper.version=3.2.1-808558, built on 08/27/2009 18:48 GMT
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:host.name=192.168.2.107
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:java.version=1.6.0_15
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:java.vendor=Apple Inc.
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:java.home=/System/Library/Frameworks/JavaVM.framework/Versions/1.6.0/Home
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:java.class.path=/Development/eclipse/workspace/hbase-trunk-ro/bin/../conf:/System/Library/Frameworks/JavaVM.framework/Versions/1.6/Home//lib/tools.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../build/classes:/Development/eclipse/workspace/hbase-trunk-ro/bin/../build/test:/Development/eclipse/workspace/hbase-trunk-ro/bin/../build:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/avro-1.2.0.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/commons-cli-2.0-SNAPSHOT.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/commons-el-from-jetty-5.1.4.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/commons-httpclient-3.0.1.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/commons-logging-1.0.4.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/commons-logging-api-1.0.4.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/commons-math-1.1.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/hadoop-core-0.21.0-SNAPSHOT-r832250.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/hadoop-core-test-0.21.0-SNAPSHOT-r832250.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/hadoop-hdfs-0.21.0-dev-r836012.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/hadoop-hdfs-test-0.21.0-dev-r836012.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/hadoop-mapred-0.21.0-dev-r833993.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/hadoop-mapred-test-0.21.0-dev-r833993.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/jasper-compiler-5.5.12.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/jasper-runtime-5.5.12.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/jetty-6.1.14.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/jetty-util-6.1.14.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/jruby-complete-1.3.1.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/json.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/junit-4.7.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/libthrift-r771587.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/log4j-1.2.15.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/lucene-core-2.2.0.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/servlet-api-2.5-6.1.14.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/zookeeper-3.2.1.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/jsp-2.1/jsp-2.1.jar:/Development/eclipse/workspace/hbase-trunk-ro/bin/../lib/jsp-2.1/jsp-api-2.1.jar
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:java.library.path=.:/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:java.io.tmpdir=/var/folders/Ok/Ok45YK4DF8S5jZMXZptEek+++TI/-Tmp-/
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:java.compiler=<NA>
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:os.name=Mac OS X
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:os.arch=x86_64
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:os.version=10.6.2
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:user.name=larsgeorge
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:user.home=/Users/larsgeorge
09/12/04 12:20:36 INFO zookeeper.ZooKeeper: Client environment:user.dir=/Development/eclipse/workspace/hbase-trunk-ro
HBase Shell; enter 'help<RETURN>' for list of supported commands.
Version: 0.21.0-dev, r886052, Thu Dec 3 17:05:20 CET 2009
hbase(main):001:0> scan 'e'
09/12/04 12:20:40 INFO zookeeper.ZooKeeper: Initiating client connection, connectString=localhost:2181 sessionTimeout=60000 watcher=org.apache.hadoop.hbase.client.HConnectionManager$ClientZKWatcher@58f41393
09/12/04 12:20:40 INFO zookeeper.ClientCnxn: zookeeper.disableAutoWatchReset is false
09/12/04 12:20:40 INFO zookeeper.ClientCnxn: Attempting connection to server localhost/0:0:0:0:0:0:0:1:2181
09/12/04 12:20:40 INFO zookeeper.ClientCnxn: Priming connection to java.nio.channels.SocketChannel[connected local=/0:0:0:0:0:0:0:1%0:57219 remote=localhost/0:0:0:0:0:0:0:1:2181]
09/12/04 12:20:40 INFO zookeeper.ClientCnxn: Server connection successful
09/12/04 12:20:40 DEBUG client.HConnectionManager$ClientZKWatcher: Got ZooKeeper event, state: SyncConnected, type: None, path: null
09/12/04 12:20:40 DEBUG zookeeper.ClientCnxn: Reading reply sessionid:0x125554a4a9f000c, packet:: clientPath:null serverPath:null finished:false header:: -8,101 replyHeader:: -8,229,0 request:: 0,v{},v{},v{} response:: null
09/12/04 12:20:40 DEBUG zookeeper.ClientCnxn: Reading reply sessionid:0x125554a4a9f000c, packet:: clientPath:null serverPath:null finished:false header:: 1,4 replyHeader:: 1,229,0 request:: '/hbase/root-region-server,F response:: #3139322e3136382e322e3130373a3532303437,s{11,209,1259840355831,1259856415401,9,0,0,0,19,0,11}
09/12/04 12:20:40 DEBUG zookeeper.ZooKeeperWrapper: Read ZNode /hbase/root-region-server got 192.168.2.107:52047
09/12/04 12:20:41 DEBUG client.HConnectionManager$TableServers: Found ROOT at 192.168.2.107:52047
09/12/04 12:20:41 DEBUG client.HConnectionManager$TableServers: Cached location address: 192.168.2.107:52047, regioninfo: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_META => 'true', FAMILIES => [{NAME => 'historian', VERSIONS => '2147483647', COMPRESSION => 'NONE', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}, {NAME => 'info', VERSIONS => '10', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
NativeException: org.apache.hadoop.hbase.TableNotFoundException: e

hbase(main):002:0> exit
09/12/04 12:20:48 INFO zookeeper.ZooKeeper: Closing session: 0x125554a4a9f000c
09/12/04 12:20:48 INFO zookeeper.ClientCnxn: Closing ClientCnxn for session: 0x125554a4a9f000c
09/12/04 12:20:48 INFO zookeeper.ClientCnxn: Exception while closing send thread for session 0x125554a4a9f000c : Read error rc = -1 java.nio.DirectByteBuffer[pos=0 lim=4 cap=4]
09/12/04 12:20:48 WARN zookeeper.ClientCnxn: Ignoring exception during shutdown input
java.net.SocketException: Socket is not connected
at sun.nio.ch.SocketChannelImpl.shutdown(Native Method)
at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:640)
at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:360)
at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:999)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:984)
09/12/04 12:20:48 INFO zookeeper.ClientCnxn: Disconnecting ClientCnxn for session: 0x125554a4a9f000c
09/12/04 12:20:48 INFO zookeeper.ZooKeeper: Session: 0x125554a4a9f000c closed
09/12/04 12:20:48 INFO zookeeper.ClientCnxn: EventThread shut down
09/12/04 12:20:48 DEBUG zookeeper.ZooKeeperWrapper: Closed connection with ZooKeeper
{noformat}

One last thing I could think of is to set the @CONF[:BACK_TRACE_LIMIT] = 0 according to that switch as well. So that with DEBUG enabled it also logs the full details from the ruby scripts.

[ https://issues.apache.org/jira/browse/HBASE-2029?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Lars George updated HBASE-2029:
-------------------------------

Attachment: HBASE-2029-hirb-v2.patch

HBASE-2029-hirb-v2.patch adds the discussed back trace limit configuration. If DEBUG is off the back trace is set to 0 as discussed above and if DEBUG is on it does the default (which it seems is set to 16, which should suffice but could easily changed to print all).

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

stack commented on HBASE-2029:
------------------------------

I like the -d addtion.

I tried the patch. It makes big difference.

When no cluster running instead of spewing zk stuff, it just does nothing printing out a master not running on end.

Good (could be better) but way better than what was there before.

When I do a create table for an already created table, it does:

{code}
hbase(main):001:0> create 'y', 'y'
0 row(s) in 6.2210 seconds
hbase(main):002:0> create 'y', 'y'
NativeException: org.apache.hadoop.hbase.TableExistsException: org.apache.hadoop.hbase.TableExistsException: y
at org.apache.hadoop.hbase.master.HMaster.createTable(HMaster.java:790)
at org.apache.hadoop.hbase.master.HMaster.createTable(HMaster.java:755)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
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:648)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
{code}

Which is better than the big page of exceptions before.

Enabling non-existent table does this:

{code}
hbase(main):007:0> enable 'xyz'
NativeException: org.apache.hadoop.hbase.TableNotFoundException: org.apache.hadoop.hbase.TableNotFoundException: xyz
at org.apache.hadoop.hbase.master.TableOperation$ProcessTableOperation.call(TableOperation.java:144)
at org.apache.hadoop.hbase.master.TableOperation$ProcessTableOperation.call(TableOperation.java:73)
at org.apache.hadoop.hbase.master.RetryableMetaOperation.doWithRetries(RetryableMetaOperation.java:67)
at org.apache.hadoop.hbase.master.TableOperation.process(TableOperation.java:157)
at org.apache.hadoop.hbase.master.HMaster.enableTable(HMaster.java:827)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
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:648)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
{code}

With -d, its really profuse logging but its good in that its more than just DEBUG from before printing out environment.

Will commit in a little while unless objection.

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

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

Did you try both patches at the same time? (mine and Lars')

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

Lars George commented on HBASE-2029:
------------------------------------

Weird, without the -d option you get back trace? See my example with the non-existent table, same NativeException stanza but I only get a single line as expected. Hmmm.

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

stack commented on HBASE-2029:
------------------------------

I have both patches in place.

If i try to scan a non-existent table I get:

{code}

hbase(main):009:0> scan 'xyz'
NativeException: org.apache.hadoop.hbase.TableNotFoundException: xyz

{code}

.. which is same as you Lars.

What happens if you try to enable a non-existent table? Do you see same ten lines of stack trace (10 lines is fine IMO... but will wait till get OK from you Lars before applying).

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

Lars George commented on HBASE-2029:
------------------------------------

Yeah, I get those extra lines on creating an existing table too. Odd that they respond differently. Let me check into once more.

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

Lars George commented on HBASE-2029:
------------------------------------

Oh sweet, while looking into this issue I found that a

{code}
@CONF[:SAVE_HISTORY] = 10
{code}

enables command history saving. We should definitely add that!

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

Lars George commented on HBASE-2029:
------------------------------------

Apart from that I found the reason for the different output. The TableExistsException wraps a RemoteException. This is done so:

{code}
public static IOException decodeRemoteException(final RemoteException re)
throws IOException {
IOException i = re;
...
Object[] arguments = { re.getMessage() };
Throwable t = (Throwable) ctor.newInstance(arguments);
...
{code}

The issue here is that re.getMessage() for a remote message is the stack trace! So in the case of my "scan 'e'" test the exception message is "e" as in the table that does not exists. But for the "create 'y', 'y'" it fails on the master and that is wrapped into a local exception and then the message is

{code}
y
at org.apache.hadoop.hbase.master.HMaster.createTable(HMaster.java:793)
at org.apache.hadoop.hbase.master.HMaster.createTable(HMaster.java:758)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
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:648)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
{code}

So we can either live with this or change how the RemoteException is decoded.

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

stack commented on HBASE-2029:
------------------------------

Making a stacktrace into an exception message is broken. Change how RemoteException is done I'd say. Should be putting the exception that provoked the problem into initCause: http://java.sun.com/j2se/1.4.2/docs/api/java/lang/Throwable.html#initCause%28java.lang.Throwable%29

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

stack commented on HBASE-2029:
------------------------------

I took a look. Issue is in the rpc client:

{code}
boolean isError = in.readBoolean(); // read if error
if (isError) {
call.setException(new RemoteException( WritableUtils.readString(in),
WritableUtils.readString(in)));
{code}

The second argument is the 'message'.

Here is server-side:

{code}
try {
value = call(call.param, call.timestamp); // make the call
} catch (Throwable e) {
LOG.info(getName()+", call "+call+": error: " + e, e);
errorClass = e.getClass().getName();
error = StringUtils.stringifyException(e);
}
{code}

So, changing above so we passed exception class name then message and then cause would change the ipc. Since we'd like to get this fix back into 0.20, I'd say lets apply what you fellas have done up to now -- its way better than what was there -- and then open new issue to make passing of exceptions cleaner.

On command history, yeah... you can just add config to your .irbrc -- IIRC -- to enable history. Should we turn it on as default? How we tell the case where user doesn't want it? Or case where they want more history than ten commands; i.e. we don't want case where they have made a setting in their irbrc but can't figure why it ain't working. Maybe can do a if not defined, set it to history of 100 commands?

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

Lars George commented on HBASE-2029:
------------------------------------

I made the change that avoids sending the stacktrace over the wire as part of the message. Please verify in the new patch that this is indeed OK to do.

Here is how it looks like:

{code}
hbase(main):002:0> scan 'e'
NativeException: org.apache.hadoop.hbase.TableNotFoundException: e

hbase(main):003:0> create 'y', 'y'
NativeException: org.apache.hadoop.hbase.TableExistsException: y

hbase(main):004:0>
{code}

[ https://issues.apache.org/jira/browse/HBASE-2029?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Lars George updated HBASE-2029:
-------------------------------

Attachment: HBASE-2029-hirb-v3.patch

HBASE-2029-hirb-v3.patch adds the change to HBaseServer.java to avoid sending the stack trace as part of the message and also adds history saving for the last 50 commands. Otherwise it has the same content as the v2 patch.

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

Lars George commented on HBASE-2029:
------------------------------------

Oh sorry Michael, did not see your updates until after I upped the patch. I agree that adding it to the .irbrc is good enough to enable it, could be documented somewhere :) I will remove it and up another path. What do you think of the small HBaseServer change I did? Does not break the IPC but the question is if anyone relied on the stack trace being in the message? I doubt it though.

[ https://issues.apache.org/jira/browse/HBASE-2029?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Lars George updated HBASE-2029:
-------------------------------

Attachment: HBASE-2029-hirb-v4.patch

HBASE-2029-hirb-v4.patch same as before but without the saving of commands option.

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

stack commented on HBASE-2029:
------------------------------

On doc'ing shell stuff, I did it a while ago: http://wiki.apache.org/hadoop/Hbase/Shell (See Useful tricks on the end). No one reads doc though so need to get it in closer to the shell help some how. Perhaps when we refactor help so its help by command instead of a single-page dump. On removing the stack-trace, I'd say leave it. All kinds of exception cross the ipc bridge. For most cases, it'll be fine if no stack trace just the raw message but for the odd one that is just an IOE with a cryptic message, context would be important. Yours and J-D's improvements have brought us a long way already. Its good enough I'd say to commit leaving the patch in? Do you have to make v5 or can I commit v2 and j-d's change?

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

Lars George commented on HBASE-2029:
------------------------------------

Ah see, I did not see that page either. Wiki is often too chaotic and unstructured. Hmm.

Yes, use my v2 patch and JD's initial patch. Thanks!

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

Lars George commented on HBASE-2029:
------------------------------------

One final note, the error handling should have its own JIRA so that it is addressed one day?

Oh, and that wiki page for the shell is slightly formatted wrong by the looks, it changes to cursive/italics and stays until the end. And the .irbrc sample output has no line breaks and makes it difficult to read it.

[ https://issues.apache.org/jira/browse/HBASE-2029?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

stack resolved HBASE-2029.
--------------------------

Resolution: Fixed
Fix Version/s: 0.20.3
Release Note: Added a -d and --debug to shell options
Hadoop Flags: [Reviewed]

Applied branch and trunk. Thanks for patch J-D and Lars.

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

stack commented on HBASE-2029:
------------------------------

I added hbase-2030 at Lars's suggestion to cover fixing rpc exception stack trace handling.