[HTRACE-330] Add to Tracer, TRACE-level logging of push and pop of contexts to aid debugging "Can't close TraceScope.."

• Type: Improvement
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Component/s: debugging, htraced
• Assignee: Colin McCabe
• Reporter: Michael Stack
• Created: 10/Dec/15 06:51
• Updated: 14/Dec/15 20:04

Description

Allow logging of push and pop of tracing scopes. Helps debug these kind of complaints:

74546 2015-12-09 22:41:35,588 FATAL [localhost:62928.activeMasterManager] master.HMaster: Failed to become active master
74547 java.lang.RuntimeException: Can't close TraceScope for {"a":"786592075da52dd193e82c3df8462a4a","b":1449729695240,"d":"get","r":"hconnection-0x7b764474","p":["786592075da52dd125a2fdf5331a5961"]} because it is not the current TraceScope, {"a":"786592075da52dd1b93b4c359c1f08f1","b":1449729695565,"d":"hbase:meta","r":"hconnection-0x7b764474","p":["786592075da5      2dd193e82c3df8462a4a"],"t":[{"t":1449729695584,"m":"Creating MemStoreScanner"}]}, in thread localhost:62928.activeMasterManager
74548   at org.apache.htrace.core.Tracer.throwClientError(Tracer.java:278)
74549   at org.apache.htrace.core.Tracer.closeScope(Tracer.java:588)
74550   at org.apache.htrace.core.TraceScope.close(TraceScope.java:111)
74551   at org.apache.hadoop.hbase.client.HTable.get(HTable.java:467)
74552   at org.apache.hadoop.hbase.client.HTable.get(HTable.java:414)
74553   at org.apache.hadoop.hbase.master.TableNamespaceManager.get(TableNamespaceManager.java:178)
74554   at org.apache.hadoop.hbase.master.TableNamespaceManager.isTableAvailableAndInitialized(TableNamespaceManager.java:295)
74555   at org.apache.hadoop.hbase.master.TableNamespaceManager.start(TableNamespaceManager.java:116)
74556   at org.apache.hadoop.hbase.master.HMaster.initNamespace(HMaster.java:971)
74557   at org.apache.hadoop.hbase.master.HMaster.finishActiveMasterInitialization(HMaster.java:786)
74558   at org.apache.hadoop.hbase.master.HMaster.access$500(HMaster.java:188)
74559   at org.apache.hadoop.hbase.master.HMaster$1.run(HMaster.java:1767)
74560   at org.apache.htrace.core.TraceRunnable.run(TraceRunnable.java:45)
74561   at java.lang.Thread.run(Thread.java:744)