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.trace.data.SpanData;
035import java.util.List;
036import java.util.function.Supplier;
037import java.util.stream.Collectors;
038import org.apache.hadoop.hbase.client.trace.StringTraceRenderer;
039import org.apache.hadoop.hbase.testclassification.MediumTests;
040import org.apache.hadoop.hbase.testclassification.RegionServerTests;
041import org.apache.hadoop.hbase.trace.OpenTelemetryClassRule;
042import org.hamcrest.Matcher;
043import org.junit.ClassRule;
044import org.junit.Test;
045import org.junit.experimental.categories.Category;
046import org.junit.rules.ExternalResource;
047import org.junit.rules.RuleChain;
048import org.junit.rules.TestRule;
049import org.junit.runners.model.Statement;
050import org.slf4j.Logger;
051import org.slf4j.LoggerFactory;
052
053/**
054 * Test that sundry operations internal to the region server are traced as expected.
055 */
056@Category({ MediumTests.class, RegionServerTests.class })
057public class TestServerInternalsTracing {
058  private static final Logger LOG = LoggerFactory.getLogger(TestServerInternalsTracing.class);
059
060  @ClassRule
061  public static final HBaseClassTestRule CLASS_RULE =
062    HBaseClassTestRule.forClass(TestServerInternalsTracing.class);
063
064  private static final String NO_PARENT_ID = "0000000000000000";
065  private static List<SpanData> spans;
066
067  /**
068   * Wait for the underlying cluster to come up -- defined by meta being available.
069   */
070  private static class Setup extends ExternalResource {
071    private final Supplier<HBaseTestingUtil> testingUtilSupplier;
072
073    public Setup(final Supplier<HBaseTestingUtil> testingUtilSupplier) {
074      this.testingUtilSupplier = testingUtilSupplier;
075    }
076
077    @Override
078    protected void before() throws Throwable {
079      final HBaseTestingUtil testingUtil = testingUtilSupplier.get();
080      testingUtil.waitTableAvailable(TableName.META_TABLE_NAME);
081    }
082  }
083
084  private static class Noop extends Statement {
085    @Override
086    public void evaluate() throws Throwable {
087    }
088  }
089
090  @ClassRule
091  public static TestRule classRule = (base, description) -> new Statement() {
092    @Override
093    public void evaluate() throws Throwable {
094      // setup and tear down the cluster, collecting all the spans produced in the process.
095      final OpenTelemetryClassRule otelClassRule = OpenTelemetryClassRule.create();
096      final MiniClusterRule miniClusterRule = MiniClusterRule.newBuilder().build();
097      final Setup setup = new Setup(miniClusterRule::getTestingUtility);
098      final TestRule clusterRule =
099        RuleChain.outerRule(otelClassRule).around(miniClusterRule).around(setup);
100      clusterRule.apply(new Noop(), description).evaluate();
101      spans = otelClassRule.getSpans();
102      if (LOG.isDebugEnabled()) {
103        StringTraceRenderer renderer = new StringTraceRenderer(spans);
104        renderer.render(LOG::debug);
105      }
106      base.evaluate();
107    }
108  };
109
110  @Test
111  public void testHBaseServerBaseConstructor() {
112    final Matcher<SpanData> hbaseServerBaseMatcher = allOf(hasName("HBaseServerBase.cxtor"),
113      hasParentSpanId(NO_PARENT_ID), hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
114    assertThat("there should be a span from the HBaseServerBase constructor.", spans,
115      hasItem(hbaseServerBaseMatcher));
116    final List<SpanData> hbaseServerBaseSpans =
117      spans.stream().filter(hbaseServerBaseMatcher::matches).collect(Collectors.toList());
118    assertThat("there should be two spans from the HBaseServerBase constructor, one for the master"
119      + " and one for the region server.", hbaseServerBaseSpans, hasSize(2));
120    assertThat("both should show zookeeper interaction.", spans,
121      hasItems(
122        allOf(hasParentSpanId(hbaseServerBaseSpans.get(0)),
123          hasName(containsString("RecoverableZookeeper."))),
124        allOf(hasParentSpanId(hbaseServerBaseSpans.get(1)),
125          hasName(containsString("RecoverableZookeeper.")))));
126  }
127
128  @Test
129  public void testHMasterConstructor() {
130    final Matcher<SpanData> masterConstructorMatcher = allOf(hasName("HMaster.cxtor"),
131      hasParentSpanId(NO_PARENT_ID), hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
132    assertThat("there should be a span from the HMaster constructor.", spans,
133      hasItem(masterConstructorMatcher));
134    final SpanData masterConstructorSpan = spans.stream().filter(masterConstructorMatcher::matches)
135      .findAny().orElseThrow(AssertionError::new);
136    assertThat("the HMaster constructor span should show zookeeper interaction.", spans, hasItem(
137      allOf(hasName(startsWith("RecoverableZookeeper.")), hasParentSpanId(masterConstructorSpan))));
138  }
139
140  @Test
141  public void testHMasterBecomeActiveMaster() {
142    final Matcher<SpanData> masterBecomeActiveMasterMatcher =
143      allOf(hasName("HMaster.becomeActiveMaster"), hasParentSpanId(NO_PARENT_ID),
144        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
145    assertThat("there should be a span from the HMaster.becomeActiveMaster.", spans,
146      hasItem(masterBecomeActiveMasterMatcher));
147    final SpanData masterBecomeActiveMasterSpan = spans.stream()
148      .filter(masterBecomeActiveMasterMatcher::matches).findAny().orElseThrow(AssertionError::new);
149    assertThat("the HMaster.becomeActiveMaster span should show zookeeper interaction.", spans,
150      hasItem(allOf(hasName(startsWith("RecoverableZookeeper.")),
151        hasParentSpanId(masterBecomeActiveMasterSpan))));
152    assertThat("the HMaster.becomeActiveMaster span should show Region interaction.", spans,
153      hasItem(
154        allOf(hasName(startsWith("Region.")), hasParentSpanId(masterBecomeActiveMasterSpan))));
155    assertThat("the HMaster.becomeActiveMaster span should show RegionScanner interaction.", spans,
156      hasItem(allOf(hasName(startsWith("RegionScanner.")),
157        hasParentSpanId(masterBecomeActiveMasterSpan))));
158    assertThat("the HMaster.becomeActiveMaster span should show hbase:meta interaction.", spans,
159      hasItem(allOf(hasName(containsString("hbase:meta")),
160        hasParentSpanId(masterBecomeActiveMasterSpan))));
161    assertThat("the HMaster.becomeActiveMaster span should show WAL interaction.", spans,
162      hasItem(allOf(hasName(startsWith("WAL.")), hasParentSpanId(masterBecomeActiveMasterSpan))));
163  }
164
165  @Test
166  public void testZKWatcherHMaster() {
167    final Matcher<SpanData> mZKWatcherMatcher = allOf(hasName(startsWith("ZKWatcher-master")),
168      hasParentSpanId(NO_PARENT_ID), hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
169    assertThat("there should be a span from the ZKWatcher running in the HMaster.", spans,
170      hasItem(mZKWatcherMatcher));
171    final SpanData mZKWatcherSpan =
172      spans.stream().filter(mZKWatcherMatcher::matches).findAny().orElseThrow(AssertionError::new);
173    assertThat("the ZKWatcher running in the HMaster span should invoke processEvent.", spans,
174      hasItem(allOf(hasName(containsString("processEvent")), hasParentSpanId(mZKWatcherSpan))));
175  }
176
177  @Test
178  public void testHMasterShutdown() {
179    final Matcher<SpanData> masterShutdownMatcher = allOf(hasName("HMaster.shutdown"),
180      hasParentSpanId(NO_PARENT_ID), hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
181    assertThat("there should be a span from the HMaster.shutdown.", spans,
182      hasItem(masterShutdownMatcher));
183    final SpanData masterShutdownSpan = spans.stream().filter(masterShutdownMatcher::matches)
184      .findAny().orElseThrow(AssertionError::new);
185    assertThat("the HMaster.shutdown span should show zookeeper interaction.", spans, hasItem(
186      allOf(hasName(startsWith("RecoverableZookeeper.")), hasParentSpanId(masterShutdownSpan))));
187    assertThat("the HMaster.shutdown span should show AsyncConnection interaction.", spans,
188      hasItem(allOf(hasName(startsWith("AsyncConnection.")), hasParentSpanId(masterShutdownSpan))));
189  }
190
191  @Test
192  public void testHMasterExitingMainLoop() {
193    final Matcher<SpanData> masterExitingMainLoopMatcher =
194      allOf(hasName("HMaster exiting main loop"), hasParentSpanId(NO_PARENT_ID),
195        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
196    assertThat("there should be a span from the HMaster exiting main loop.", spans,
197      hasItem(masterExitingMainLoopMatcher));
198    final SpanData masterExitingMainLoopSpan = spans.stream()
199      .filter(masterExitingMainLoopMatcher::matches).findAny().orElseThrow(AssertionError::new);
200    assertThat("the HMaster exiting main loop span should show zookeeper interaction.", spans,
201      hasItem(allOf(hasName(startsWith("RecoverableZookeeper.")),
202        hasParentSpanId(masterExitingMainLoopSpan))));
203    assertThat("the HMaster exiting main loop span should show WAL interaction.", spans,
204      hasItem(allOf(hasName(startsWith("WAL.")), hasParentSpanId(masterExitingMainLoopSpan))));
205    assertThat("the HMaster exiting main loop span should show AsyncConnection interaction.", spans,
206      hasItem(allOf(hasName(startsWith("AsyncConnection.")),
207        hasParentSpanId(masterExitingMainLoopSpan))));
208  }
209
210  @Test
211  public void testTryRegionServerReport() {
212    final Matcher<SpanData> tryRegionServerReportMatcher =
213      allOf(hasName("HRegionServer.tryRegionServerReport"), hasParentSpanId(NO_PARENT_ID),
214        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
215    assertThat("there should be a span for the region server sending a report.", spans,
216      hasItem(tryRegionServerReportMatcher));
217    final SpanData tryRegionServerReportSpan = spans.stream()
218      .filter(tryRegionServerReportMatcher::matches).findAny().orElseThrow(AssertionError::new);
219    assertThat(
220      "the region server report span should have an invocation of the RegionServerReport RPC.",
221      spans, hasItem(allOf(hasName(endsWith("RegionServerStatusService/RegionServerReport")),
222        hasParentSpanId(tryRegionServerReportSpan))));
223  }
224
225  @Test
226  public void testHRegionServerStartup() {
227    final Matcher<SpanData> regionServerStartupMatcher = allOf(hasName("HRegionServer.startup"),
228      hasParentSpanId(NO_PARENT_ID), hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
229    assertThat("there should be a span from the HRegionServer startup procedure.", spans,
230      hasItem(regionServerStartupMatcher));
231    final SpanData regionServerStartupSpan = spans.stream()
232      .filter(regionServerStartupMatcher::matches).findAny().orElseThrow(AssertionError::new);
233    assertThat("the HRegionServer startup procedure span should show zookeeper interaction.", spans,
234      hasItem(allOf(hasName(startsWith("RecoverableZookeeper.")),
235        hasParentSpanId(regionServerStartupSpan))));
236  }
237
238  @Test
239  public void testHRegionServerConstructor() {
240    final Matcher<SpanData> rsConstructorMatcher = allOf(hasName("HRegionServer.cxtor"),
241      hasParentSpanId(NO_PARENT_ID), hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
242    assertThat("there should be a span from the HRegionServer constructor.", spans,
243      hasItem(rsConstructorMatcher));
244    final SpanData rsConstructorSpan = spans.stream().filter(rsConstructorMatcher::matches)
245      .findAny().orElseThrow(AssertionError::new);
246    assertThat("the HRegionServer constructor span should show zookeeper interaction.", spans,
247      hasItem(
248        allOf(hasName(startsWith("RecoverableZookeeper.")), hasParentSpanId(rsConstructorSpan))));
249    assertThat("the HRegionServer constructor span should invoke the MasterAddressTracker.", spans,
250      hasItem(
251        allOf(hasName(startsWith("MasterAddressTracker.")), hasParentSpanId(rsConstructorSpan))));
252  }
253
254  @Test
255  public void testHRegionServerPreRegistrationInitialization() {
256    final Matcher<SpanData> rsPreRegistrationInitializationMatcher =
257      allOf(hasName("HRegionServer.preRegistrationInitialization"), hasParentSpanId(NO_PARENT_ID),
258        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
259    assertThat("there should be a span from the HRegionServer preRegistrationInitialization.",
260      spans, hasItem(rsPreRegistrationInitializationMatcher));
261    final SpanData rsPreRegistrationInitializationSpan =
262      spans.stream().filter(rsPreRegistrationInitializationMatcher::matches).findAny()
263        .orElseThrow(AssertionError::new);
264    assertThat(
265      "the HRegionServer preRegistrationInitialization span should show zookeeper interaction.",
266      spans, hasItem(allOf(hasName(startsWith("RecoverableZookeeper.")),
267        hasParentSpanId(rsPreRegistrationInitializationSpan))));
268  }
269
270  @Test
271  public void testHRegionServerRegisterWithMaster() {
272    final Matcher<SpanData> rsRegisterWithMasterMatcher =
273      allOf(hasName("HRegionServer.registerWithMaster"), hasParentSpanId(NO_PARENT_ID),
274        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
275    assertThat("there should be a span from the HRegionServer registerWithMaster.", spans,
276      hasItem(rsRegisterWithMasterMatcher));
277    final SpanData rsRegisterWithMasterSpan = spans.stream()
278      .filter(rsRegisterWithMasterMatcher::matches).findAny().orElseThrow(AssertionError::new);
279    assertThat("the HRegionServer registerWithMaster span should show zookeeper interaction.",
280      spans, hasItem(allOf(hasName(startsWith("RecoverableZookeeper.")),
281        hasParentSpanId(rsRegisterWithMasterSpan))));
282    assertThat(
283      "the HRegionServer registerWithMaster span should have an invocation of the"
284        + " RegionServerStartup RPC.",
285      spans, hasItem(allOf(hasName(endsWith("RegionServerStatusService/RegionServerStartup")),
286        hasParentSpanId(rsRegisterWithMasterSpan))));
287  }
288
289  @Test
290  public void testZKWatcherRegionServer() {
291    final Matcher<SpanData> rsZKWatcherMatcher =
292      allOf(hasName(startsWith("ZKWatcher-regionserver")), hasParentSpanId(NO_PARENT_ID),
293        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
294    assertThat("there should be a span from the ZKWatcher running in the HRegionServer.", spans,
295      hasItem(rsZKWatcherMatcher));
296    final SpanData rsZKWatcherSpan =
297      spans.stream().filter(rsZKWatcherMatcher::matches).findAny().orElseThrow(AssertionError::new);
298    assertThat("the ZKWatcher running in the HRegionServer span should invoke processEvent.", spans,
299      hasItem(allOf(hasName(containsString("processEvent")), hasParentSpanId(rsZKWatcherSpan))));
300  }
301
302  @Test
303  public void testHRegionServerExitingMainLoop() {
304    final Matcher<SpanData> rsExitingMainLoopMatcher =
305      allOf(hasName("HRegionServer exiting main loop"), hasParentSpanId(NO_PARENT_ID),
306        hasStatusWithCode(isOneOf(StatusCode.OK, StatusCode.ERROR)));
307    assertThat("there should be a span from the HRegionServer exiting main loop.", spans,
308      hasItem(rsExitingMainLoopMatcher));
309    final SpanData rsExitingMainLoopSpan = spans.stream().filter(rsExitingMainLoopMatcher::matches)
310      .findAny().orElseThrow(AssertionError::new);
311    assertThat("the HRegionServer exiting main loop span should show zookeeper interaction.", spans,
312      hasItem(allOf(hasName(startsWith("RecoverableZookeeper.")),
313        hasParentSpanId(rsExitingMainLoopSpan))));
314    assertThat("the HRegionServer exiting main loop span should show AsyncConnection interaction.",
315      spans, hasItem(
316        allOf(hasName(startsWith("AsyncConnection.")), hasParentSpanId(rsExitingMainLoopSpan))));
317    assertThat("the HRegionServer exiting main loop span should invoke CloseMetaHandler.", spans,
318      hasItem(allOf(hasName("CloseMetaHandler"), hasParentSpanId(rsExitingMainLoopSpan))));
319  }
320}