001/*
002 * Licensed to the Apache Software Foundation (ASF) under one
003 * or more contributor license agreements.  See the NOTICE file
004 * distributed with this work for additional information
005 * regarding copyright ownership.  The ASF licenses this file
006 * to you under the Apache License, Version 2.0 (the
007 * "License"); you may not use this file except in compliance
008 * with the License.  You may obtain a copy of the License at
009 *
010 *     http://www.apache.org/licenses/LICENSE-2.0
011 *
012 * Unless required by applicable law or agreed to in writing, software
013 * distributed under the License is distributed on an "AS IS" BASIS,
014 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
015 * See the License for the specific language governing permissions and
016 * limitations under the License.
017 */
018package org.apache.hadoop.hbase;
019
020import static org.apache.hadoop.hbase.client.trace.hamcrest.SpanDataMatchers.hasName;
021import static org.apache.hadoop.hbase.client.trace.hamcrest.SpanDataMatchers.hasParentSpanId;
022import static org.apache.hadoop.hbase.client.trace.hamcrest.SpanDataMatchers.hasStatusWithCode;
023import static org.hamcrest.MatcherAssert.assertThat;
024import static org.hamcrest.Matchers.allOf;
025import static org.hamcrest.Matchers.containsString;
026import static org.hamcrest.Matchers.endsWith;
027import static org.hamcrest.Matchers.hasItem;
028import static org.hamcrest.Matchers.hasItems;
029import static org.hamcrest.Matchers.hasSize;
030import static org.hamcrest.Matchers.isOneOf;
031import static org.hamcrest.Matchers.startsWith;
032
033import io.opentelemetry.api.trace.StatusCode;
034import io.opentelemetry.sdk.testing.junit5.OpenTelemetryExtension;
035import io.opentelemetry.sdk.trace.data.SpanData;
036import java.util.ArrayList;
037import java.util.List;
038import java.util.stream.Collectors;
039import org.apache.hadoop.hbase.client.trace.StringTraceRenderer;
040import org.apache.hadoop.hbase.testclassification.MediumTests;
041import org.apache.hadoop.hbase.testclassification.RegionServerTests;
042import org.hamcrest.Matcher;
043import org.junit.jupiter.api.BeforeAll;
044import org.junit.jupiter.api.Tag;
045import org.junit.jupiter.api.Test;
046import org.junit.jupiter.api.extension.RegisterExtension;
047import org.slf4j.Logger;
048import org.slf4j.LoggerFactory;
049
050/**
051 * Test that sundry operations internal to the region server are traced as expected.
052 */
053@Tag(RegionServerTests.TAG)
054@Tag(MediumTests.TAG)
055public class TestServerInternalsTracing {
056  private static final Logger LOG = LoggerFactory.getLogger(TestServerInternalsTracing.class);
057
058  @RegisterExtension
059  private static final OpenTelemetryExtension OTEL_EXT = OpenTelemetryExtension.create();
060
061  private static final String NO_PARENT_ID = "0000000000000000";
062
063  private static List<SpanData> spans;
064
065  @BeforeAll
066  public static void setUp() throws Exception {
067    HBaseTestingUtil util = new HBaseTestingUtil();
068    util.startMiniCluster();
069    // Wait for the underlying cluster to come up -- defined by meta being available.
070    util.waitTableAvailable(TableName.META_TABLE_NAME);
071    // shutdown the cluster
072    util.shutdownMiniCluster();
073    // copy the span data since it will be cleared after each test run
074    spans = new ArrayList<>(OTEL_EXT.getSpans());
075    if (LOG.isDebugEnabled()) {
076      StringTraceRenderer renderer = new StringTraceRenderer(spans);
077      renderer.render(LOG::debug);
078    }
079  }
080
081  @Test
082  public void testHBaseServerBaseConstructor() {
083    final Matcher<SpanData> hbaseServerBaseMatcher = allOf(hasName("HBaseServerBase.cxtor"),
084      hasParentSpanId(NO_PARENT_ID), hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
085
086    assertThat("there should be a span from the HBaseServerBase constructor.", spans,
087      hasItem(hbaseServerBaseMatcher));
088    final List<SpanData> hbaseServerBaseSpans =
089      spans.stream().filter(hbaseServerBaseMatcher::matches).collect(Collectors.toList());
090    assertThat("there should be two spans from the HBaseServerBase constructor, one for the master"
091      + " and one for the region server.", hbaseServerBaseSpans, hasSize(2));
092    assertThat("both should show zookeeper interaction.", spans,
093      hasItems(
094        allOf(hasParentSpanId(hbaseServerBaseSpans.get(0)),
095          hasName(containsString("RecoverableZookeeper."))),
096        allOf(hasParentSpanId(hbaseServerBaseSpans.get(1)),
097          hasName(containsString("RecoverableZookeeper.")))));
098  }
099
100  @Test
101  public void testHMasterConstructor() {
102    final Matcher<SpanData> masterConstructorMatcher = allOf(hasName("HMaster.cxtor"),
103      hasParentSpanId(NO_PARENT_ID), hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
104
105    assertThat("there should be a span from the HMaster constructor.", spans,
106      hasItem(masterConstructorMatcher));
107    final SpanData masterConstructorSpan = spans.stream().filter(masterConstructorMatcher::matches)
108      .findAny().orElseThrow(AssertionError::new);
109    assertThat("the HMaster constructor span should show zookeeper interaction.", spans, hasItem(
110      allOf(hasName(startsWith("RecoverableZookeeper.")), hasParentSpanId(masterConstructorSpan))));
111  }
112
113  @Test
114  public void testHMasterBecomeActiveMaster() {
115    final Matcher<SpanData> masterBecomeActiveMasterMatcher =
116      allOf(hasName("HMaster.becomeActiveMaster"), hasParentSpanId(NO_PARENT_ID),
117        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
118
119    assertThat("there should be a span from the HMaster.becomeActiveMaster.", spans,
120      hasItem(masterBecomeActiveMasterMatcher));
121    final SpanData masterBecomeActiveMasterSpan = spans.stream()
122      .filter(masterBecomeActiveMasterMatcher::matches).findAny().orElseThrow(AssertionError::new);
123    assertThat("the HMaster.becomeActiveMaster span should show zookeeper interaction.", spans,
124      hasItem(allOf(hasName(startsWith("RecoverableZookeeper.")),
125        hasParentSpanId(masterBecomeActiveMasterSpan))));
126    assertThat("the HMaster.becomeActiveMaster span should show Region interaction.", spans,
127      hasItem(
128        allOf(hasName(startsWith("Region.")), hasParentSpanId(masterBecomeActiveMasterSpan))));
129    assertThat("the HMaster.becomeActiveMaster span should show RegionScanner interaction.", spans,
130      hasItem(allOf(hasName(startsWith("RegionScanner.")),
131        hasParentSpanId(masterBecomeActiveMasterSpan))));
132    assertThat("the HMaster.becomeActiveMaster span should show hbase:meta interaction.", spans,
133      hasItem(allOf(hasName(containsString("hbase:meta")),
134        hasParentSpanId(masterBecomeActiveMasterSpan))));
135    assertThat("the HMaster.becomeActiveMaster span should show WAL interaction.", spans,
136      hasItem(allOf(hasName(startsWith("WAL.")), hasParentSpanId(masterBecomeActiveMasterSpan))));
137  }
138
139  @Test
140  public void testZKWatcherHMaster() {
141    final Matcher<SpanData> mZKWatcherMatcher = allOf(hasName(startsWith("ZKWatcher-master")),
142      hasParentSpanId(NO_PARENT_ID), hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
143
144    assertThat("there should be a span from the ZKWatcher running in the HMaster.", spans,
145      hasItem(mZKWatcherMatcher));
146    final SpanData mZKWatcherSpan =
147      spans.stream().filter(mZKWatcherMatcher::matches).findAny().orElseThrow(AssertionError::new);
148    assertThat("the ZKWatcher running in the HMaster span should invoke processEvent.", spans,
149      hasItem(allOf(hasName(containsString("processEvent")), hasParentSpanId(mZKWatcherSpan))));
150  }
151
152  @Test
153  public void testHMasterShutdown() {
154    final Matcher<SpanData> masterShutdownMatcher = allOf(hasName("HMaster.shutdown"),
155      hasParentSpanId(NO_PARENT_ID), hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
156
157    assertThat("there should be a span from the HMaster.shutdown.", spans,
158      hasItem(masterShutdownMatcher));
159    final SpanData masterShutdownSpan = spans.stream().filter(masterShutdownMatcher::matches)
160      .findAny().orElseThrow(AssertionError::new);
161    assertThat("the HMaster.shutdown span should show zookeeper interaction.", spans, hasItem(
162      allOf(hasName(startsWith("RecoverableZookeeper.")), hasParentSpanId(masterShutdownSpan))));
163    assertThat("the HMaster.shutdown span should show AsyncConnection interaction.", spans,
164      hasItem(allOf(hasName(startsWith("AsyncConnection.")), hasParentSpanId(masterShutdownSpan))));
165  }
166
167  @Test
168  public void testHMasterExitingMainLoop() {
169    final Matcher<SpanData> masterExitingMainLoopMatcher =
170      allOf(hasName("HMaster exiting main loop"), hasParentSpanId(NO_PARENT_ID),
171        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
172
173    assertThat("there should be a span from the HMaster exiting main loop.", spans,
174      hasItem(masterExitingMainLoopMatcher));
175    final SpanData masterExitingMainLoopSpan = spans.stream()
176      .filter(masterExitingMainLoopMatcher::matches).findAny().orElseThrow(AssertionError::new);
177    assertThat("the HMaster exiting main loop span should show zookeeper interaction.", spans,
178      hasItem(allOf(hasName(startsWith("RecoverableZookeeper.")),
179        hasParentSpanId(masterExitingMainLoopSpan))));
180    assertThat("the HMaster exiting main loop span should show WAL interaction.", spans,
181      hasItem(allOf(hasName(startsWith("WAL.")), hasParentSpanId(masterExitingMainLoopSpan))));
182    assertThat("the HMaster exiting main loop span should show AsyncConnection interaction.", spans,
183      hasItem(allOf(hasName(startsWith("AsyncConnection.")),
184        hasParentSpanId(masterExitingMainLoopSpan))));
185  }
186
187  @Test
188  public void testTryRegionServerReport() {
189    final Matcher<SpanData> tryRegionServerReportMatcher =
190      allOf(hasName("HRegionServer.tryRegionServerReport"), hasParentSpanId(NO_PARENT_ID),
191        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
192
193    assertThat("there should be a span for the region server sending a report.", spans,
194      hasItem(tryRegionServerReportMatcher));
195    final SpanData tryRegionServerReportSpan = spans.stream()
196      .filter(tryRegionServerReportMatcher::matches).findAny().orElseThrow(AssertionError::new);
197    assertThat(
198      "the region server report span should have an invocation of the RegionServerReport RPC.",
199      spans, hasItem(allOf(hasName(endsWith("RegionServerStatusService/RegionServerReport")),
200        hasParentSpanId(tryRegionServerReportSpan))));
201  }
202
203  @Test
204  public void testHRegionServerStartup() {
205    final Matcher<SpanData> regionServerStartupMatcher = allOf(hasName("HRegionServer.startup"),
206      hasParentSpanId(NO_PARENT_ID), hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
207
208    assertThat("there should be a span from the HRegionServer startup procedure.", spans,
209      hasItem(regionServerStartupMatcher));
210    final SpanData regionServerStartupSpan = spans.stream()
211      .filter(regionServerStartupMatcher::matches).findAny().orElseThrow(AssertionError::new);
212    assertThat("the HRegionServer startup procedure span should show zookeeper interaction.", spans,
213      hasItem(allOf(hasName(startsWith("RecoverableZookeeper.")),
214        hasParentSpanId(regionServerStartupSpan))));
215  }
216
217  @Test
218  public void testHRegionServerConstructor() {
219    final Matcher<SpanData> rsConstructorMatcher = allOf(hasName("HRegionServer.cxtor"),
220      hasParentSpanId(NO_PARENT_ID), hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
221
222    assertThat("there should be a span from the HRegionServer constructor.", spans,
223      hasItem(rsConstructorMatcher));
224    final SpanData rsConstructorSpan = spans.stream().filter(rsConstructorMatcher::matches)
225      .findAny().orElseThrow(AssertionError::new);
226    assertThat("the HRegionServer constructor span should show zookeeper interaction.", spans,
227      hasItem(
228        allOf(hasName(startsWith("RecoverableZookeeper.")), hasParentSpanId(rsConstructorSpan))));
229    assertThat("the HRegionServer constructor span should invoke the MasterAddressTracker.", spans,
230      hasItem(
231        allOf(hasName(startsWith("MasterAddressTracker.")), hasParentSpanId(rsConstructorSpan))));
232  }
233
234  @Test
235  public void testHRegionServerPreRegistrationInitialization() {
236    final Matcher<SpanData> rsPreRegistrationInitializationMatcher =
237      allOf(hasName("HRegionServer.preRegistrationInitialization"), hasParentSpanId(NO_PARENT_ID),
238        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
239
240    assertThat("there should be a span from the HRegionServer preRegistrationInitialization.",
241      spans, hasItem(rsPreRegistrationInitializationMatcher));
242    final SpanData rsPreRegistrationInitializationSpan =
243      spans.stream().filter(rsPreRegistrationInitializationMatcher::matches).findAny()
244        .orElseThrow(AssertionError::new);
245    assertThat(
246      "the HRegionServer preRegistrationInitialization span should show zookeeper interaction.",
247      spans, hasItem(allOf(hasName(startsWith("RecoverableZookeeper.")),
248        hasParentSpanId(rsPreRegistrationInitializationSpan))));
249  }
250
251  @Test
252  public void testHRegionServerRegisterWithMaster() {
253    final Matcher<SpanData> rsRegisterWithMasterMatcher =
254      allOf(hasName("HRegionServer.registerWithMaster"), hasParentSpanId(NO_PARENT_ID),
255        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
256
257    assertThat("there should be a span from the HRegionServer registerWithMaster.", spans,
258      hasItem(rsRegisterWithMasterMatcher));
259    final SpanData rsRegisterWithMasterSpan = spans.stream()
260      .filter(rsRegisterWithMasterMatcher::matches).findAny().orElseThrow(AssertionError::new);
261    assertThat("the HRegionServer registerWithMaster span should show zookeeper interaction.",
262      spans, hasItem(allOf(hasName(startsWith("RecoverableZookeeper.")),
263        hasParentSpanId(rsRegisterWithMasterSpan))));
264    assertThat(
265      "the HRegionServer registerWithMaster span should have an invocation of the"
266        + " RegionServerStartup RPC.",
267      spans, hasItem(allOf(hasName(endsWith("RegionServerStatusService/RegionServerStartup")),
268        hasParentSpanId(rsRegisterWithMasterSpan))));
269  }
270
271  @Test
272  public void testZKWatcherRegionServer() {
273    final Matcher<SpanData> rsZKWatcherMatcher =
274      allOf(hasName(startsWith("ZKWatcher-regionserver")), hasParentSpanId(NO_PARENT_ID),
275        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
276
277    assertThat("there should be a span from the ZKWatcher running in the HRegionServer.", spans,
278      hasItem(rsZKWatcherMatcher));
279    final SpanData rsZKWatcherSpan =
280      spans.stream().filter(rsZKWatcherMatcher::matches).findAny().orElseThrow(AssertionError::new);
281    assertThat("the ZKWatcher running in the HRegionServer span should invoke processEvent.", spans,
282      hasItem(allOf(hasName(containsString("processEvent")), hasParentSpanId(rsZKWatcherSpan))));
283  }
284
285  @Test
286  public void testHRegionServerExitingMainLoop() {
287    final Matcher<SpanData> rsExitingMainLoopMatcher =
288      allOf(hasName("HRegionServer exiting main loop"), hasParentSpanId(NO_PARENT_ID),
289        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
290
291    assertThat("there should be a span from the HRegionServer exiting main loop.", spans,
292      hasItem(rsExitingMainLoopMatcher));
293    final SpanData rsExitingMainLoopSpan = spans.stream().filter(rsExitingMainLoopMatcher::matches)
294      .findAny().orElseThrow(AssertionError::new);
295    assertThat("the HRegionServer exiting main loop span should show zookeeper interaction.", spans,
296      hasItem(allOf(hasName(startsWith("RecoverableZookeeper.")),
297        hasParentSpanId(rsExitingMainLoopSpan))));
298    assertThat("the HRegionServer exiting main loop span should show AsyncConnection interaction.",
299      spans, hasItem(
300        allOf(hasName(startsWith("AsyncConnection.")), hasParentSpanId(rsExitingMainLoopSpan))));
301    assertThat("the HRegionServer exiting main loop span should invoke CloseMetaHandler.", spans,
302      hasItem(allOf(hasName("CloseMetaHandler"), hasParentSpanId(rsExitingMainLoopSpan))));
303  }
304}