From cc6395afedec1f951c4d191b379fdea4889f85ed Mon Sep 17 00:00:00 2001 From: Nick Dimiduk Date: Mon, 27 Mar 2023 15:19:27 +0200 Subject: [PATCH 1/4] HBASE-27762 Include EventType and ProcedureV2 pid in logging via MDC --- conf/log4j2.properties | 2 +- hbase-logging/src/test/resources/log4j2.properties | 2 +- .../java/org/apache/hadoop/hbase/executor/EventHandler.java | 5 +++++ .../hbase/regionserver/handler/RSProcedureHandler.java | 2 ++ 4 files changed, 9 insertions(+), 2 deletions(-) diff --git a/conf/log4j2.properties b/conf/log4j2.properties index 5ffcfda24176..90d52a2bea13 100644 --- a/conf/log4j2.properties +++ b/conf/log4j2.properties @@ -25,7 +25,7 @@ appender.console.type = Console appender.console.target = SYSTEM_ERR appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = %d{ISO8601} %-5p [%t] %c{2}: %.1000m%n +appender.console.layout.pattern = %d{ISO8601} %-5p [%t (%X)] %c{2}: %.1000m%n # Daily Rolling File Appender appender.DRFA.type = RollingFile diff --git a/hbase-logging/src/test/resources/log4j2.properties b/hbase-logging/src/test/resources/log4j2.properties index 56d67c85aa1b..4f29bb455624 100644 --- a/hbase-logging/src/test/resources/log4j2.properties +++ b/hbase-logging/src/test/resources/log4j2.properties @@ -26,7 +26,7 @@ appender.console.target = SYSTEM_ERR appender.console.name = Console appender.console.maxSize = 1G appender.console.layout.type = PatternLayout -appender.console.layout.pattern = %d{ISO8601} %-5p [%t] %C{2}(%L): %m%n +appender.console.layout.pattern = %d{ISO8601} %-5p [%t (%X)] %C{2}(%L): %m%n rootLogger = INFO,Console diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/executor/EventHandler.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/executor/EventHandler.java index ece244fda4fc..07c39ce7e444 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/executor/EventHandler.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/executor/EventHandler.java @@ -27,6 +27,7 @@ import org.apache.yetus.audience.InterfaceAudience; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import org.slf4j.MDC; /** * Abstract base class for all HBase event handlers. Subclasses should implement the @@ -96,6 +97,10 @@ public EventHandler prepare() throws Exception { public void run() { Span span = TraceUtil.getGlobalTracer().spanBuilder(getClass().getSimpleName()) .setParent(Context.current().with(parent)).startSpan(); + // assume that this is the top of an execution on a new or reused thread, that we're safe to + // blast any existing MDC state. + MDC.clear(); + MDC.put("event_type", eventType.toString()); try (Scope scope = span.makeCurrent()) { process(); } catch (Throwable t) { diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/RSProcedureHandler.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/RSProcedureHandler.java index d4ddebe727d7..d3ecc8a51e22 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/RSProcedureHandler.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/RSProcedureHandler.java @@ -23,6 +23,7 @@ import org.apache.yetus.audience.InterfaceAudience; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import org.slf4j.MDC; /** * A event handler for running procedure. @@ -46,6 +47,7 @@ public RSProcedureHandler(HRegionServer rs, long procId, RSProcedureCallable cal public void process() { Throwable error = null; try { + MDC.put("pid", Long.toString(procId)); callable.call(); } catch (Throwable t) { LOG.error("pid=" + this.procId, t); From 802faf0ec3713d78b564ce7634ef94c1499adc25 Mon Sep 17 00:00:00 2001 From: Nick Dimiduk Date: Wed, 29 Mar 2023 13:56:18 +0200 Subject: [PATCH 2/4] add the other two handlers that receive PIDs in their message --- .../hadoop/hbase/regionserver/handler/AssignRegionHandler.java | 2 ++ .../hbase/regionserver/handler/UnassignRegionHandler.java | 2 ++ 2 files changed, 4 insertions(+) diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/AssignRegionHandler.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/AssignRegionHandler.java index 16107d93f090..71fceef7e418 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/AssignRegionHandler.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/AssignRegionHandler.java @@ -37,6 +37,7 @@ import org.slf4j.LoggerFactory; import org.apache.hadoop.hbase.shaded.protobuf.generated.RegionServerStatusProtos.RegionStateTransition.TransitionCode; +import org.slf4j.MDC; /** * Handles opening of a region on a region server. @@ -90,6 +91,7 @@ private void cleanUpAndReportFailure(IOException error) throws IOException { @Override public void process() throws IOException { + MDC.put("pid", Long.toString(openProcId)); HRegionServer rs = getServer(); String encodedName = regionInfo.getEncodedName(); byte[] encodedNameBytes = regionInfo.getEncodedNameAsBytes(); diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/UnassignRegionHandler.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/UnassignRegionHandler.java index 9d218fa45c4b..03620086672f 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/UnassignRegionHandler.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/UnassignRegionHandler.java @@ -35,6 +35,7 @@ import org.slf4j.LoggerFactory; import org.apache.hadoop.hbase.shaded.protobuf.generated.RegionServerStatusProtos.RegionStateTransition.TransitionCode; +import org.slf4j.MDC; /** * Handles closing of a region on a region server. @@ -84,6 +85,7 @@ private HRegionServer getServer() { @Override public void process() throws IOException { + MDC.put("pid", Long.toString(closeProcId)); HRegionServer rs = getServer(); byte[] encodedNameBytes = Bytes.toBytes(encodedName); Boolean previous = rs.getRegionsInTransitionInRS().putIfAbsent(encodedNameBytes, Boolean.FALSE); From ce60ae83c044b435bf0803b47ee4805b932f7c51 Mon Sep 17 00:00:00 2001 From: Nick Dimiduk Date: Thu, 30 Mar 2023 13:23:29 +0200 Subject: [PATCH 3/4] clear at the end of `process()` --- .../java/org/apache/hadoop/hbase/executor/EventHandler.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/executor/EventHandler.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/executor/EventHandler.java index 07c39ce7e444..1244259fc176 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/executor/EventHandler.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/executor/EventHandler.java @@ -99,14 +99,14 @@ public void run() { .setParent(Context.current().with(parent)).startSpan(); // assume that this is the top of an execution on a new or reused thread, that we're safe to // blast any existing MDC state. - MDC.clear(); - MDC.put("event_type", eventType.toString()); try (Scope scope = span.makeCurrent()) { + MDC.put("event_type", eventType.toString()); process(); } catch (Throwable t) { handleException(t); } finally { span.end(); + MDC.clear(); } } From e0bbb6b92cbefa40c7c6e4b711953a7bb06cc413 Mon Sep 17 00:00:00 2001 From: Nick Dimiduk Date: Thu, 30 Mar 2023 13:25:38 +0200 Subject: [PATCH 4/4] fix spotless nits --- .../hadoop/hbase/regionserver/handler/AssignRegionHandler.java | 2 +- .../hbase/regionserver/handler/UnassignRegionHandler.java | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/AssignRegionHandler.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/AssignRegionHandler.java index 71fceef7e418..ee4d3144f72a 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/AssignRegionHandler.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/AssignRegionHandler.java @@ -35,9 +35,9 @@ import org.apache.yetus.audience.InterfaceAudience; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import org.slf4j.MDC; import org.apache.hadoop.hbase.shaded.protobuf.generated.RegionServerStatusProtos.RegionStateTransition.TransitionCode; -import org.slf4j.MDC; /** * Handles opening of a region on a region server. diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/UnassignRegionHandler.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/UnassignRegionHandler.java index 03620086672f..217f2ebbd45a 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/UnassignRegionHandler.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/handler/UnassignRegionHandler.java @@ -33,9 +33,9 @@ import org.apache.yetus.audience.InterfaceAudience; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import org.slf4j.MDC; import org.apache.hadoop.hbase.shaded.protobuf.generated.RegionServerStatusProtos.RegionStateTransition.TransitionCode; -import org.slf4j.MDC; /** * Handles closing of a region on a region server.