Examples with TestLogging org.elasticsearch.test.junit.annotations.TestLogging used on opensource projects

Example 1 with TestLogging

use of org.elasticsearch.test.junit.annotations.TestLogging in project elasticsearch by elastic.

the class SharedClusterSnapshotRestoreIT method testReadonlyRepository.

// this fails every now and then: https://github.com/elastic/elasticsearch/issues/18121 but without
@TestLogging("_root:DEBUG")
public // more logs we cannot find out why
void testReadonlyRepository() throws Exception {
    Client client = client();
    logger.info("-->  creating repository");
    Path repositoryLocation = randomRepoPath();
    assertAcked(client.admin().cluster().preparePutRepository("test-repo").setType("fs").setSettings(Settings.builder().put("location", repositoryLocation).put("compress", randomBoolean()).put("chunk_size", randomIntBetween(100, 1000), ByteSizeUnit.BYTES)));
    createIndex("test-idx");
    ensureGreen();
    logger.info("--> indexing some data");
    for (int i = 0; i < 100; i++) {
        index("test-idx", "doc", Integer.toString(i), "foo", "bar" + i);
    }
    refresh();
    logger.info("--> snapshot");
    CreateSnapshotResponse createSnapshotResponse = client.admin().cluster().prepareCreateSnapshot("test-repo", "test-snap").setWaitForCompletion(true).setIndices("test-idx").get();
    assertThat(createSnapshotResponse.getSnapshotInfo().successfulShards(), greaterThan(0));
    assertThat(createSnapshotResponse.getSnapshotInfo().successfulShards(), equalTo(createSnapshotResponse.getSnapshotInfo().totalShards()));
    assertThat(client.admin().cluster().prepareGetSnapshots("test-repo").setSnapshots("test-snap").get().getSnapshots().get(0).state(), equalTo(SnapshotState.SUCCESS));
    logger.info("--> delete index");
    cluster().wipeIndices("test-idx");
    logger.info("--> create read-only URL repository");
    assertAcked(client.admin().cluster().preparePutRepository("readonly-repo").setType("fs").setSettings(Settings.builder().put("location", repositoryLocation).put("compress", randomBoolean()).put("readonly", true).put("chunk_size", randomIntBetween(100, 1000), ByteSizeUnit.BYTES)));
    logger.info("--> restore index after deletion");
    RestoreSnapshotResponse restoreSnapshotResponse = client.admin().cluster().prepareRestoreSnapshot("readonly-repo", "test-snap").setWaitForCompletion(true).setIndices("test-idx").execute().actionGet();
    assertThat(restoreSnapshotResponse.getRestoreInfo().totalShards(), greaterThan(0));
    assertThat(client.prepareSearch("test-idx").setSize(0).get().getHits().getTotalHits(), equalTo(100L));
    logger.info("--> list available shapshots");
    GetSnapshotsResponse getSnapshotsResponse = client.admin().cluster().prepareGetSnapshots("readonly-repo").get();
    assertThat(getSnapshotsResponse.getSnapshots(), notNullValue());
    assertThat(getSnapshotsResponse.getSnapshots().size(), equalTo(1));
    logger.info("--> try deleting snapshot");
    assertThrows(client.admin().cluster().prepareDeleteSnapshot("readonly-repo", "test-snap"), RepositoryException.class, "cannot delete snapshot from a readonly repository");
    logger.info("--> try making another snapshot");
    assertThrows(client.admin().cluster().prepareCreateSnapshot("readonly-repo", "test-snap-2").setWaitForCompletion(true).setIndices("test-idx"), RepositoryException.class, "cannot create snapshot in a readonly repository");
}

Example 2 with TestLogging

use of org.elasticsearch.test.junit.annotations.TestLogging in project elasticsearch by elastic.

the class LoggingListenerTests method testInvalidMethodTestLoggingAnnotation.

public void testInvalidMethodTestLoggingAnnotation() throws Exception {
    final LoggingListener loggingListener = new LoggingListener();
    final Description suiteDescription = Description.createSuiteDescription(InvalidMethod.class);
    loggingListener.testRunStarted(suiteDescription);
    final Method method = InvalidMethod.class.getMethod("invalidMethod");
    final TestLogging annotation = method.getAnnotation(TestLogging.class);
    Description testDescription = Description.createTestDescription(InvalidMethod.class, "invalidMethod", annotation);
    final IllegalArgumentException e = expectThrows(IllegalArgumentException.class, () -> loggingListener.testStarted(testDescription));
    assertThat(e.getMessage(), equalTo("invalid test logging annotation [abc:INFO:WARN]"));
}

Example 3 with TestLogging

use of org.elasticsearch.test.junit.annotations.TestLogging in project elasticsearch by elastic.

the class ClusterServiceTests method testClusterStateUpdateLogging.

// To ensure that we log cluster state events on TRACE level
@TestLogging("org.elasticsearch.cluster.service:TRACE")
public void testClusterStateUpdateLogging() throws Exception {
    MockLogAppender mockAppender = new MockLogAppender();
    mockAppender.start();
    mockAppender.addExpectation(new MockLogAppender.SeenEventExpectation("test1", "org.elasticsearch.cluster.service.ClusterServiceTests$TimedClusterService", Level.DEBUG, "*processing [test1]: took [1s] no change in cluster_state"));
    mockAppender.addExpectation(new MockLogAppender.SeenEventExpectation("test2", "org.elasticsearch.cluster.service.ClusterServiceTests$TimedClusterService", Level.TRACE, "*failed to execute cluster state update in [2s]*"));
    mockAppender.addExpectation(new MockLogAppender.SeenEventExpectation("test3", "org.elasticsearch.cluster.service.ClusterServiceTests$TimedClusterService", Level.DEBUG, "*processing [test3]: took [3s] done applying updated cluster_state (version: *, uuid: *)"));
    Logger clusterLogger = Loggers.getLogger("org.elasticsearch.cluster.service");
    Loggers.addAppender(clusterLogger, mockAppender);
    try {
        final CountDownLatch latch = new CountDownLatch(4);
        clusterService.currentTimeOverride = System.nanoTime();
        clusterService.submitStateUpdateTask("test1", new ClusterStateUpdateTask() {

            @Override
            public ClusterState execute(ClusterState currentState) throws Exception {
                clusterService.currentTimeOverride += TimeValue.timeValueSeconds(1).nanos();
                return currentState;
            }

            @Override
            public void clusterStateProcessed(String source, ClusterState oldState, ClusterState newState) {
                latch.countDown();
            }

            @Override
            public void onFailure(String source, Exception e) {
                fail();
            }
        });
        clusterService.submitStateUpdateTask("test2", new ClusterStateUpdateTask() {

            @Override
            public ClusterState execute(ClusterState currentState) {
                clusterService.currentTimeOverride += TimeValue.timeValueSeconds(2).nanos();
                throw new IllegalArgumentException("Testing handling of exceptions in the cluster state task");
            }

            @Override
            public void clusterStateProcessed(String source, ClusterState oldState, ClusterState newState) {
                fail();
            }

            @Override
            public void onFailure(String source, Exception e) {
                latch.countDown();
            }
        });
        clusterService.submitStateUpdateTask("test3", new ClusterStateUpdateTask() {

            @Override
            public ClusterState execute(ClusterState currentState) {
                clusterService.currentTimeOverride += TimeValue.timeValueSeconds(3).nanos();
                return ClusterState.builder(currentState).incrementVersion().build();
            }

            @Override
            public void clusterStateProcessed(String source, ClusterState oldState, ClusterState newState) {
                latch.countDown();
            }

            @Override
            public void onFailure(String source, Exception e) {
                fail();
            }
        });
        // Additional update task to make sure all previous logging made it to the loggerName
        // We don't check logging for this on since there is no guarantee that it will occur before our check
        clusterService.submitStateUpdateTask("test4", new ClusterStateUpdateTask() {

            @Override
            public ClusterState execute(ClusterState currentState) {
                return currentState;
            }

            @Override
            public void clusterStateProcessed(String source, ClusterState oldState, ClusterState newState) {
                latch.countDown();
            }

            @Override
            public void onFailure(String source, Exception e) {
                fail();
            }
        });
        latch.await();
    } finally {
        Loggers.removeAppender(clusterLogger, mockAppender);
        mockAppender.stop();
    }
    mockAppender.assertAllExpectationsMatched();
}

Example 4 with TestLogging

use of org.elasticsearch.test.junit.annotations.TestLogging in project elasticsearch by elastic.

the class IndexWithShadowReplicasIT method testIndexWithFewDocuments.

@TestLogging("org.elasticsearch.gateway:TRACE")
public void testIndexWithFewDocuments() throws Exception {
    final Path dataPath = createTempDir();
    Settings nodeSettings = nodeSettings(dataPath);
    internalCluster().startNodes(3, nodeSettings);
    final String IDX = "test";
    Settings idxSettings = Settings.builder().put(IndexMetaData.SETTING_NUMBER_OF_SHARDS, 1).put(IndexMetaData.SETTING_NUMBER_OF_REPLICAS, 2).put(IndexSettings.INDEX_TRANSLOG_FLUSH_THRESHOLD_SIZE_SETTING.getKey(), new ByteSizeValue(1, ByteSizeUnit.PB)).put(IndexMetaData.SETTING_DATA_PATH, dataPath.toAbsolutePath().toString()).put(IndexMetaData.SETTING_SHADOW_REPLICAS, true).put(IndexMetaData.SETTING_SHARED_FILESYSTEM, true).build();
    prepareCreate(IDX).setSettings(idxSettings).addMapping("doc", "foo", "type=text").get();
    ensureGreen(IDX);
    // So basically, the primary should fail and the replica will need to
    // replay the translog, this is what this tests
    client().prepareIndex(IDX, "doc", "1").setSource("foo", "bar").get();
    client().prepareIndex(IDX, "doc", "2").setSource("foo", "bar").get();
    IndicesStatsResponse indicesStatsResponse = client().admin().indices().prepareStats(IDX).clear().setTranslog(true).get();
    assertEquals(2, indicesStatsResponse.getIndex(IDX).getPrimaries().getTranslog().estimatedNumberOfOperations());
    assertEquals(2, indicesStatsResponse.getIndex(IDX).getTotal().getTranslog().estimatedNumberOfOperations());
    Index index = resolveIndex(IDX);
    for (IndicesService service : internalCluster().getInstances(IndicesService.class)) {
        IndexService indexService = service.indexService(index);
        if (indexService != null) {
            IndexShard shard = indexService.getShard(0);
            TranslogStats translogStats = shard.translogStats();
            assertTrue(translogStats != null || shard instanceof ShadowIndexShard);
            if (translogStats != null) {
                assertEquals(2, translogStats.estimatedNumberOfOperations());
            }
        }
    }
    // Check that we can get doc 1 and 2, because we are doing realtime
    // gets and getting from the primary
    GetResponse gResp1 = client().prepareGet(IDX, "doc", "1").get();
    GetResponse gResp2 = client().prepareGet(IDX, "doc", "2").get();
    assertThat(gResp1.getSource().get("foo"), equalTo("bar"));
    assertThat(gResp2.getSource().get("foo"), equalTo("bar"));
    flushAndRefresh(IDX);
    client().prepareIndex(IDX, "doc", "3").setSource("foo", "bar").get();
    client().prepareIndex(IDX, "doc", "4").setSource("foo", "bar").get();
    refresh();
    // Check that we can get doc 1 and 2 without realtime
    gResp1 = client().prepareGet(IDX, "doc", "1").setRealtime(false).get();
    gResp2 = client().prepareGet(IDX, "doc", "2").setRealtime(false).get();
    assertThat(gResp1.getSource().get("foo"), equalTo("bar"));
    assertThat(gResp2.getSource().get("foo"), equalTo("bar"));
    logger.info("--> restarting all nodes");
    if (randomBoolean()) {
        logger.info("--> rolling restart");
        internalCluster().rollingRestart();
    } else {
        logger.info("--> full restart");
        internalCluster().fullRestart();
    }
    client().admin().cluster().prepareHealth().setWaitForNodes("3").get();
    ensureGreen(IDX);
    flushAndRefresh(IDX);
    logger.info("--> performing query");
    SearchResponse resp = client().prepareSearch(IDX).setQuery(matchAllQuery()).get();
    assertHitCount(resp, 4);
    logger.info("--> deleting index");
    assertAcked(client().admin().indices().prepareDelete(IDX));
}

Example 5 with TestLogging

use of org.elasticsearch.test.junit.annotations.TestLogging in project elasticsearch by elastic.

the class RecoveryDuringReplicationTests method testRecoveryAfterPrimaryPromotion.

@TestLogging("org.elasticsearch.index.shard:TRACE,org.elasticsearch.indices.recovery:TRACE")
public void testRecoveryAfterPrimaryPromotion() throws Exception {
    try (ReplicationGroup shards = createGroup(2)) {
        shards.startAll();
        int totalDocs = shards.indexDocs(randomInt(10));
        int committedDocs = 0;
        if (randomBoolean()) {
            shards.flush();
            committedDocs = totalDocs;
        }
        // we need some indexing to happen to transfer local checkpoint information to the primary
        // so it can update the global checkpoint and communicate to replicas
        boolean expectSeqNoRecovery = totalDocs > 0;
        final IndexShard oldPrimary = shards.getPrimary();
        final IndexShard newPrimary = shards.getReplicas().get(0);
        final IndexShard replica = shards.getReplicas().get(1);
        if (randomBoolean()) {
            // simulate docs that were inflight when primary failed, these will be rolled back
            final int rollbackDocs = randomIntBetween(1, 5);
            logger.info("--> indexing {} rollback docs", rollbackDocs);
            for (int i = 0; i < rollbackDocs; i++) {
                final IndexRequest indexRequest = new IndexRequest(index.getName(), "type", "rollback_" + i).source("{}", XContentType.JSON);
                final IndexResponse primaryResponse = indexOnPrimary(indexRequest, oldPrimary);
                indexOnReplica(primaryResponse, indexRequest, replica);
            }
            if (randomBoolean()) {
                oldPrimary.flush(new FlushRequest(index.getName()));
                expectSeqNoRecovery = false;
            }
        }
        shards.promoteReplicaToPrimary(newPrimary);
        // index some more
        totalDocs += shards.indexDocs(randomIntBetween(0, 5));
        oldPrimary.close("demoted", false);
        oldPrimary.store().close();
        IndexShard newReplica = shards.addReplicaWithExistingPath(oldPrimary.shardPath(), oldPrimary.routingEntry().currentNodeId());
        shards.recoverReplica(newReplica);
        if (expectSeqNoRecovery) {
            assertThat(newReplica.recoveryState().getIndex().fileDetails(), empty());
            assertThat(newReplica.recoveryState().getTranslog().recoveredOperations(), equalTo(totalDocs - committedDocs));
        } else {
            assertThat(newReplica.recoveryState().getIndex().fileDetails(), not(empty()));
            assertThat(newReplica.recoveryState().getTranslog().recoveredOperations(), equalTo(totalDocs - committedDocs));
        }
        shards.removeReplica(replica);
        replica.close("resync", false);
        replica.store().close();
        newReplica = shards.addReplicaWithExistingPath(replica.shardPath(), replica.routingEntry().currentNodeId());
        shards.recoverReplica(newReplica);
        shards.assertAllEqual(totalDocs);
    }
}