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

Example 6 with TestLogging

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

the class IndexRecoveryIT method testDisconnectsDuringRecovery.

/**
     * Tests scenario where recovery target successfully sends recovery request to source but then the channel gets closed while
     * the source is working on the recovery process.
     */
@TestLogging("_root:DEBUG,org.elasticsearch.indices.recovery:TRACE")
public void testDisconnectsDuringRecovery() throws Exception {
    boolean primaryRelocation = randomBoolean();
    final String indexName = "test";
    final Settings nodeSettings = Settings.builder().put(RecoverySettings.INDICES_RECOVERY_RETRY_DELAY_NETWORK_SETTING.getKey(), TimeValue.timeValueMillis(randomIntBetween(0, 100))).build();
    TimeValue disconnectAfterDelay = TimeValue.timeValueMillis(randomIntBetween(0, 100));
    // start a master node
    String masterNodeName = internalCluster().startMasterOnlyNode(nodeSettings);
    final String blueNodeName = internalCluster().startNode(Settings.builder().put("node.attr.color", "blue").put(nodeSettings).build());
    final String redNodeName = internalCluster().startNode(Settings.builder().put("node.attr.color", "red").put(nodeSettings).build());
    client().admin().indices().prepareCreate(indexName).setSettings(Settings.builder().put(IndexMetaData.INDEX_ROUTING_INCLUDE_GROUP_SETTING.getKey() + "color", "blue").put(IndexMetaData.SETTING_NUMBER_OF_SHARDS, 1).put(IndexMetaData.SETTING_NUMBER_OF_REPLICAS, 0)).get();
    List<IndexRequestBuilder> requests = new ArrayList<>();
    int numDocs = scaledRandomIntBetween(25, 250);
    for (int i = 0; i < numDocs; i++) {
        requests.add(client().prepareIndex(indexName, "type").setSource("{}", XContentType.JSON));
    }
    indexRandom(true, requests);
    ensureSearchable(indexName);
    assertHitCount(client().prepareSearch(indexName).get(), numDocs);
    MockTransportService masterTransportService = (MockTransportService) internalCluster().getInstance(TransportService.class, masterNodeName);
    MockTransportService blueMockTransportService = (MockTransportService) internalCluster().getInstance(TransportService.class, blueNodeName);
    MockTransportService redMockTransportService = (MockTransportService) internalCluster().getInstance(TransportService.class, redNodeName);
    redMockTransportService.addDelegate(blueMockTransportService, new MockTransportService.DelegateTransport(redMockTransportService.original()) {

        private final AtomicInteger count = new AtomicInteger();

        @Override
        protected void sendRequest(Connection connection, long requestId, String action, TransportRequest request, TransportRequestOptions options) throws IOException {
            logger.info("--> sending request {} on {}", action, connection.getNode());
            if (PeerRecoverySourceService.Actions.START_RECOVERY.equals(action) && count.incrementAndGet() == 1) {
                // ensures that it's considered as valid recovery attempt by source
                try {
                    awaitBusy(() -> client(blueNodeName).admin().cluster().prepareState().setLocal(true).get().getState().getRoutingTable().index("test").shard(0).getAllInitializingShards().isEmpty() == false);
                } catch (InterruptedException e) {
                    throw new RuntimeException(e);
                }
                super.sendRequest(connection, requestId, action, request, options);
                try {
                    Thread.sleep(disconnectAfterDelay.millis());
                } catch (InterruptedException e) {
                    throw new RuntimeException(e);
                }
                throw new ConnectTransportException(connection.getNode(), "DISCONNECT: simulation disconnect after successfully sending " + action + " request");
            } else {
                super.sendRequest(connection, requestId, action, request, options);
            }
        }
    });
    final AtomicBoolean finalized = new AtomicBoolean();
    blueMockTransportService.addDelegate(redMockTransportService, new MockTransportService.DelegateTransport(blueMockTransportService.original()) {

        @Override
        protected void sendRequest(Connection connection, long requestId, String action, TransportRequest request, TransportRequestOptions options) throws IOException {
            logger.info("--> sending request {} on {}", action, connection.getNode());
            if (action.equals(PeerRecoveryTargetService.Actions.FINALIZE)) {
                finalized.set(true);
            }
            super.sendRequest(connection, requestId, action, request, options);
        }
    });
    for (MockTransportService mockTransportService : Arrays.asList(redMockTransportService, blueMockTransportService)) {
        mockTransportService.addDelegate(masterTransportService, new MockTransportService.DelegateTransport(mockTransportService.original()) {

            @Override
            protected void sendRequest(Connection connection, long requestId, String action, TransportRequest request, TransportRequestOptions options) throws IOException {
                logger.info("--> sending request {} on {}", action, connection.getNode());
                if ((primaryRelocation && finalized.get()) == false) {
                    assertNotEquals(action, ShardStateAction.SHARD_FAILED_ACTION_NAME);
                }
                super.sendRequest(connection, requestId, action, request, options);
            }
        });
    }
    if (primaryRelocation) {
        logger.info("--> starting primary relocation recovery from blue to red");
        client().admin().indices().prepareUpdateSettings(indexName).setSettings(Settings.builder().put(IndexMetaData.INDEX_ROUTING_INCLUDE_GROUP_SETTING.getKey() + "color", "red")).get();
        // also waits for relocation / recovery to complete
        ensureGreen();
        // if a primary relocation fails after the source shard has been marked as relocated, both source and target are failed. If the
        // source shard is moved back to started because the target fails first, it's possible that there is a cluster state where the
        // shard is marked as started again (and ensureGreen returns), but while applying the cluster state the primary is failed and
        // will be reallocated. The cluster will thus become green, then red, then green again. Triggering a refresh here before
        // searching helps, as in contrast to search actions, refresh waits for the closed shard to be reallocated.
        client().admin().indices().prepareRefresh(indexName).get();
    } else {
        logger.info("--> starting replica recovery from blue to red");
        client().admin().indices().prepareUpdateSettings(indexName).setSettings(Settings.builder().put(IndexMetaData.INDEX_ROUTING_INCLUDE_GROUP_SETTING.getKey() + "color", "red,blue").put(IndexMetaData.SETTING_NUMBER_OF_REPLICAS, 1)).get();
        ensureGreen();
    }
    for (int i = 0; i < 10; i++) {
        assertHitCount(client().prepareSearch(indexName).get(), numDocs);
    }
}

Example 7 with TestLogging

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

the class CircuitBreakerServiceIT method testParentChecking.

/**
     * Test that a breaker correctly redistributes to a different breaker, in
     * this case, the fielddata breaker borrows space from the request breaker
     */
@TestLogging("_root:DEBUG,org.elasticsearch.action.search:TRACE")
public void testParentChecking() throws Exception {
    if (noopBreakerUsed()) {
        logger.info("--> noop breakers used, skipping test");
        return;
    }
    assertAcked(prepareCreate("cb-test", 1, Settings.builder().put(SETTING_NUMBER_OF_REPLICAS, between(0, 1))).addMapping("type", "test", "type=text,fielddata=true"));
    Client client = client();
    // index some different terms so we have some field data for loading
    int docCount = scaledRandomIntBetween(300, 1000);
    List<IndexRequestBuilder> reqs = new ArrayList<>();
    for (long id = 0; id < docCount; id++) {
        reqs.add(client.prepareIndex("cb-test", "type", Long.toString(id)).setSource("test", "value" + id));
    }
    indexRandom(true, reqs);
    Settings resetSettings = Settings.builder().put(HierarchyCircuitBreakerService.FIELDDATA_CIRCUIT_BREAKER_LIMIT_SETTING.getKey(), "10b").put(HierarchyCircuitBreakerService.FIELDDATA_CIRCUIT_BREAKER_OVERHEAD_SETTING.getKey(), 1.0).build();
    assertAcked(client.admin().cluster().prepareUpdateSettings().setTransientSettings(resetSettings));
    // Perform a search to load field data for the "test" field
    try {
        client.prepareSearch("cb-test").setQuery(matchAllQuery()).addSort("test", SortOrder.DESC).get();
        fail("should have thrown an exception");
    } catch (Exception e) {
        String errMsg = "CircuitBreakingException[[fielddata] Data too large, data for [test] would be";
        assertThat("Exception: [" + e.toString() + "] should contain a CircuitBreakingException", e.toString(), containsString(errMsg));
        errMsg = "which is larger than the limit of [10/10b]]";
        assertThat("Exception: [" + e.toString() + "] should contain a CircuitBreakingException", e.toString(), containsString(errMsg));
    }
    // execute a search that loads field data (sorting on the "test" field)
    // again, this time it should trip the breaker
    SearchRequestBuilder searchRequest = client.prepareSearch("cb-test").setQuery(matchAllQuery()).addSort("test", SortOrder.DESC);
    String errMsg = "Data too large, data for [test] would be";
    assertFailures(searchRequest, RestStatus.INTERNAL_SERVER_ERROR, containsString(errMsg));
    errMsg = "which is larger than the limit of [10/10b]";
    assertFailures(searchRequest, RestStatus.INTERNAL_SERVER_ERROR, containsString(errMsg));
    reset();
    // Adjust settings so the parent breaker will fail, but neither the fielddata breaker nor the node request breaker will fail
    resetSettings = Settings.builder().put(HierarchyCircuitBreakerService.TOTAL_CIRCUIT_BREAKER_LIMIT_SETTING.getKey(), "500b").put(HierarchyCircuitBreakerService.FIELDDATA_CIRCUIT_BREAKER_LIMIT_SETTING.getKey(), "90%").put(HierarchyCircuitBreakerService.FIELDDATA_CIRCUIT_BREAKER_OVERHEAD_SETTING.getKey(), 1.0).build();
    client.admin().cluster().prepareUpdateSettings().setTransientSettings(resetSettings).execute().actionGet();
    // Perform a search to load field data for the "test" field
    try {
        SearchResponse searchResponse = client.prepareSearch("cb-test").setQuery(matchAllQuery()).addSort("test", SortOrder.DESC).get();
        if (searchResponse.getShardFailures().length > 0) {
            // each shard must have failed with CircuitBreakingException
            for (ShardSearchFailure shardSearchFailure : searchResponse.getShardFailures()) {
                Throwable cause = ExceptionsHelper.unwrap(shardSearchFailure.getCause(), CircuitBreakingException.class);
                assertThat(cause, instanceOf(CircuitBreakingException.class));
                assertEquals(((CircuitBreakingException) cause).getByteLimit(), 500L);
            }
        } else {
            fail("should have thrown a CircuitBreakingException");
        }
    } catch (Exception e) {
        Throwable cause = ExceptionsHelper.unwrap(e, CircuitBreakingException.class);
        assertThat(cause, instanceOf(CircuitBreakingException.class));
        assertEquals(((CircuitBreakingException) cause).getByteLimit(), 500L);
        assertThat("Exception: [" + cause.toString() + "] should be caused by the parent circuit breaker", cause.toString(), startsWith("CircuitBreakingException[[parent] Data too large"));
    }
    reset();
}

Example 8 with TestLogging

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

the class ClusterServiceIT method testPendingUpdateTask.

@TestLogging("_root:debug,org.elasticsearch.action.admin.cluster.tasks:trace")
public void testPendingUpdateTask() throws Exception {
    String node_0 = internalCluster().startNode();
    internalCluster().startCoordinatingOnlyNode(Settings.EMPTY);
    final ClusterService clusterService = internalCluster().getInstance(ClusterService.class, node_0);
    final CountDownLatch block1 = new CountDownLatch(1);
    final CountDownLatch invoked1 = new CountDownLatch(1);
    clusterService.submitStateUpdateTask("1", new ClusterStateUpdateTask() {

        @Override
        public ClusterState execute(ClusterState currentState) {
            invoked1.countDown();
            try {
                block1.await();
            } catch (InterruptedException e) {
                fail();
            }
            return currentState;
        }

        @Override
        public void onFailure(String source, Exception e) {
            invoked1.countDown();
            fail();
        }
    });
    invoked1.await();
    final CountDownLatch invoked2 = new CountDownLatch(9);
    for (int i = 2; i <= 10; i++) {
        clusterService.submitStateUpdateTask(Integer.toString(i), new ClusterStateUpdateTask() {

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

            @Override
            public void onFailure(String source, Exception e) {
                fail();
            }

            @Override
            public void clusterStateProcessed(String source, ClusterState oldState, ClusterState newState) {
                invoked2.countDown();
            }
        });
    }
    // there might be other tasks in this node, make sure to only take the ones we add into account in this test
    // The tasks can be re-ordered, so we need to check out-of-order
    Set<String> controlSources = new HashSet<>(Arrays.asList("1", "2", "3", "4", "5", "6", "7", "8", "9", "10"));
    List<PendingClusterTask> pendingClusterTasks = clusterService.pendingTasks();
    assertThat(pendingClusterTasks.size(), greaterThanOrEqualTo(10));
    assertThat(pendingClusterTasks.get(0).getSource().string(), equalTo("1"));
    assertThat(pendingClusterTasks.get(0).isExecuting(), equalTo(true));
    for (PendingClusterTask task : pendingClusterTasks) {
        controlSources.remove(task.getSource().string());
    }
    assertTrue(controlSources.isEmpty());
    controlSources = new HashSet<>(Arrays.asList("1", "2", "3", "4", "5", "6", "7", "8", "9", "10"));
    PendingClusterTasksResponse response = internalCluster().coordOnlyNodeClient().admin().cluster().preparePendingClusterTasks().get();
    assertThat(response.pendingTasks().size(), greaterThanOrEqualTo(10));
    assertThat(response.pendingTasks().get(0).getSource().string(), equalTo("1"));
    assertThat(response.pendingTasks().get(0).isExecuting(), equalTo(true));
    for (PendingClusterTask task : response) {
        controlSources.remove(task.getSource().string());
    }
    assertTrue(controlSources.isEmpty());
    block1.countDown();
    invoked2.await();
    // whenever we test for no tasks, we need to awaitBusy since this is a live node
    assertTrue(awaitBusy(() -> clusterService.pendingTasks().isEmpty()));
    waitNoPendingTasksOnAll();
    final CountDownLatch block2 = new CountDownLatch(1);
    final CountDownLatch invoked3 = new CountDownLatch(1);
    clusterService.submitStateUpdateTask("1", new ClusterStateUpdateTask() {

        @Override
        public ClusterState execute(ClusterState currentState) {
            invoked3.countDown();
            try {
                block2.await();
            } catch (InterruptedException e) {
                fail();
            }
            return currentState;
        }

        @Override
        public void onFailure(String source, Exception e) {
            invoked3.countDown();
            fail();
        }
    });
    invoked3.await();
    for (int i = 2; i <= 5; i++) {
        clusterService.submitStateUpdateTask(Integer.toString(i), new ClusterStateUpdateTask() {

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

            @Override
            public void onFailure(String source, Exception e) {
                fail();
            }
        });
    }
    Thread.sleep(100);
    pendingClusterTasks = clusterService.pendingTasks();
    assertThat(pendingClusterTasks.size(), greaterThanOrEqualTo(5));
    controlSources = new HashSet<>(Arrays.asList("1", "2", "3", "4", "5"));
    for (PendingClusterTask task : pendingClusterTasks) {
        controlSources.remove(task.getSource().string());
    }
    assertTrue(controlSources.isEmpty());
    response = internalCluster().coordOnlyNodeClient().admin().cluster().preparePendingClusterTasks().get();
    assertThat(response.pendingTasks().size(), greaterThanOrEqualTo(5));
    controlSources = new HashSet<>(Arrays.asList("1", "2", "3", "4", "5"));
    for (PendingClusterTask task : response) {
        if (controlSources.remove(task.getSource().string())) {
            assertThat(task.getTimeInQueueInMillis(), greaterThan(0L));
        }
    }
    assertTrue(controlSources.isEmpty());
    block2.countDown();
}

Example 9 with TestLogging

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

the class InternalEngineMergeIT method testMergesHappening.

@TestLogging("_root:DEBUG")
public void testMergesHappening() throws InterruptedException, IOException, ExecutionException {
    final int numOfShards = randomIntBetween(1, 5);
    // some settings to keep num segments low
    assertAcked(prepareCreate("test").setSettings(Settings.builder().put(IndexMetaData.SETTING_NUMBER_OF_SHARDS, numOfShards).put(IndexMetaData.SETTING_NUMBER_OF_REPLICAS, 0).build()));
    long id = 0;
    final int rounds = scaledRandomIntBetween(50, 300);
    logger.info("Starting rounds [{}] ", rounds);
    for (int i = 0; i < rounds; ++i) {
        final int numDocs = scaledRandomIntBetween(100, 1000);
        BulkRequestBuilder request = client().prepareBulk();
        for (int j = 0; j < numDocs; ++j) {
            request.add(Requests.indexRequest("test").type("type1").id(Long.toString(id++)).source(jsonBuilder().startObject().field("l", randomLong()).endObject()));
        }
        BulkResponse response = request.execute().actionGet();
        refresh();
        assertNoFailures(response);
        IndicesStatsResponse stats = client().admin().indices().prepareStats("test").setSegments(true).setMerge(true).get();
        logger.info("index round [{}] - segments {}, total merges {}, current merge {}", i, stats.getPrimaries().getSegments().getCount(), stats.getPrimaries().getMerge().getTotal(), stats.getPrimaries().getMerge().getCurrent());
    }
    final long upperNumberSegments = 2 * numOfShards * 10;
    awaitBusy(() -> {
        IndicesStatsResponse stats = client().admin().indices().prepareStats().setSegments(true).setMerge(true).get();
        logger.info("numshards {}, segments {}, total merges {}, current merge {}", numOfShards, stats.getPrimaries().getSegments().getCount(), stats.getPrimaries().getMerge().getTotal(), stats.getPrimaries().getMerge().getCurrent());
        long current = stats.getPrimaries().getMerge().getCurrent();
        long count = stats.getPrimaries().getSegments().getCount();
        return count < upperNumberSegments && current == 0;
    });
    IndicesStatsResponse stats = client().admin().indices().prepareStats().setSegments(true).setMerge(true).get();
    logger.info("numshards {}, segments {}, total merges {}, current merge {}", numOfShards, stats.getPrimaries().getSegments().getCount(), stats.getPrimaries().getMerge().getTotal(), stats.getPrimaries().getMerge().getCurrent());
    long count = stats.getPrimaries().getSegments().getCount();
    assertThat(count, Matchers.lessThanOrEqualTo(upperNumberSegments));
}

Example 10 with TestLogging

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

the class IndexWithShadowReplicasIT method testShadowReplicaNaturalRelocation.

/**
     * Tests that shadow replicas can be "naturally" rebalanced and relocated
     * around the cluster. By "naturally" I mean without using the reroute API
     */
// This test failed on CI when trying to assert that all the shard data has been deleted
// from the index path. It has not been reproduced locally. Despite the IndicesService
// deleting the index and hence, deleting all the shard data for the index, the test
// failure still showed some Lucene files in the data directory for that index. Not sure
// why that is, so turning on more logging here.
@TestLogging("org.elasticsearch.indices:TRACE,org.elasticsearch.env:TRACE,_root:DEBUG")
public void testShadowReplicaNaturalRelocation() throws Exception {
    Path dataPath = createTempDir();
    Settings nodeSettings = nodeSettings(dataPath);
    final List<String> nodes = internalCluster().startNodes(2, nodeSettings);
    String IDX = "test";
    Settings idxSettings = Settings.builder().put(IndexMetaData.SETTING_NUMBER_OF_SHARDS, 5).put(IndexMetaData.SETTING_NUMBER_OF_REPLICAS, 1).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);
    int docCount = randomIntBetween(10, 100);
    List<IndexRequestBuilder> builders = new ArrayList<>();
    for (int i = 0; i < docCount; i++) {
        builders.add(client().prepareIndex(IDX, "doc", i + "").setSource("foo", "bar"));
    }
    indexRandom(true, true, true, builders);
    flushAndRefresh(IDX);
    // start a third node, with 5 shards each on the other nodes, they
    // should relocate some to the third node
    final String node3 = internalCluster().startNode(nodeSettings);
    nodes.add(node3);
    assertBusy(new Runnable() {

        @Override
        public void run() {
            client().admin().cluster().prepareHealth().setWaitForNodes("3").get();
            ClusterStateResponse resp = client().admin().cluster().prepareState().get();
            RoutingNodes nodes = resp.getState().getRoutingNodes();
            for (RoutingNode node : nodes) {
                logger.info("--> node has {} shards (needs at least 2)", node.numberOfOwningShards());
                assertThat("at least 2 shards on node", node.numberOfOwningShards(), greaterThanOrEqualTo(2));
            }
        }
    });
    ensureYellow(IDX);
    logger.info("--> performing query");
    SearchResponse resp = client().prepareSearch(IDX).setQuery(matchAllQuery()).get();
    assertHitCount(resp, docCount);
    assertAcked(client().admin().indices().prepareDelete(IDX));
    assertAllIndicesRemovedAndDeletionCompleted(internalCluster().getInstances(IndicesService.class));
    assertPathHasBeenCleared(dataPath);
//TODO: uncomment the test below when https://github.com/elastic/elasticsearch/issues/17695 is resolved.
//assertIndicesDirsDeleted(nodes);
}