refinements to improve how pod logs are saved (#22093)

also adding more information into the main log

Closes #10128
This commit is contained in:
Steven Hawkins 2023-07-31 11:05:30 -04:00 committed by GitHub
parent 07129329c3
commit b2e11735ed
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
6 changed files with 525 additions and 589 deletions

View file

@ -428,9 +428,13 @@ public class KeycloakDeployment extends OperatorManagedResource<StatefulSet> imp
return new ArrayList<>(ret);
}
public static String getName(Keycloak keycloak) {
return keycloak.getMetadata().getName();
}
@Override
public String getName() {
return keycloakCR.getMetadata().getName();
return getName(keycloakCR);
}
public void migrateDeployment(StatefulSet previousDeployment, StatefulSet reconciledDeployment) {

View file

@ -0,0 +1 @@
org.keycloak.operator.testsuite.integration.BaseOperatorTest

View file

@ -19,21 +19,25 @@ package org.keycloak.operator.testsuite.integration;
import io.fabric8.kubernetes.api.model.HasMetadata;
import io.fabric8.kubernetes.api.model.NamespaceBuilder;
import io.fabric8.kubernetes.api.model.Secret;
import io.fabric8.kubernetes.api.model.PodSpecFluent.ContainersNested;
import io.fabric8.kubernetes.api.model.PodTemplateSpecFluent.SpecNested;
import io.fabric8.kubernetes.api.model.Secret;
import io.fabric8.kubernetes.api.model.apps.StatefulSet;
import io.fabric8.kubernetes.client.Config;
import io.fabric8.kubernetes.client.ConfigBuilder;
import io.fabric8.kubernetes.client.KubernetesClient;
import io.fabric8.kubernetes.client.KubernetesClientBuilder;
import io.fabric8.kubernetes.client.KubernetesClientException;
import io.fabric8.kubernetes.client.NamespacedKubernetesClient;
import io.fabric8.kubernetes.client.readiness.Readiness;
import io.fabric8.kubernetes.client.utils.Serialization;
import io.javaoperatorsdk.operator.Operator;
import io.javaoperatorsdk.operator.api.reconciler.Reconciler;
import io.quarkiverse.operatorsdk.runtime.QuarkusConfigurationService;
import io.quarkus.logging.Log;
import jakarta.enterprise.inject.Instance;
import jakarta.enterprise.inject.spi.CDI;
import jakarta.enterprise.util.TypeLiteral;
import io.quarkus.test.junit.callback.QuarkusTestAfterEachCallback;
import io.quarkus.test.junit.callback.QuarkusTestMethodContext;
import org.awaitility.Awaitility;
import org.eclipse.microprofile.config.ConfigProvider;
import org.junit.jupiter.api.AfterAll;
@ -42,9 +46,11 @@ import org.junit.jupiter.api.BeforeAll;
import org.junit.jupiter.api.BeforeEach;
import org.junit.jupiter.api.TestInfo;
import org.keycloak.operator.Constants;
import org.keycloak.operator.controllers.KeycloakDeployment;
import org.keycloak.operator.crds.v2alpha1.deployment.Keycloak;
import org.keycloak.operator.crds.v2alpha1.deployment.KeycloakSpecBuilder;
import org.keycloak.operator.crds.v2alpha1.deployment.KeycloakSpecFluent.UnsupportedNested;
import org.keycloak.operator.crds.v2alpha1.deployment.KeycloakStatusCondition;
import org.keycloak.operator.crds.v2alpha1.deployment.spec.UnsupportedSpecFluent.PodTemplateNested;
import org.keycloak.operator.testsuite.utils.K8sUtils;
@ -55,13 +61,18 @@ import java.io.FileWriter;
import java.net.MalformedURLException;
import java.net.URL;
import java.time.Duration;
import java.util.Optional;
import java.util.UUID;
import jakarta.enterprise.inject.Instance;
import jakarta.enterprise.inject.spi.CDI;
import jakarta.enterprise.util.TypeLiteral;
import static org.assertj.core.api.Assertions.assertThat;
import static org.keycloak.operator.Utils.isOpenShift;
import static org.keycloak.operator.testsuite.utils.K8sUtils.getResourceFromFile;
public abstract class BaseOperatorTest {
public class BaseOperatorTest implements QuarkusTestAfterEachCallback {
public static final String QUARKUS_KUBERNETES_DEPLOYMENT_TARGET = "quarkus.kubernetes.deployment-target";
public static final String OPERATOR_DEPLOYMENT_PROP = "test.operator.deployment";
@ -218,7 +229,7 @@ public abstract class BaseOperatorTest {
fw.write(podLog);
}
} catch (Exception e) {
Log.error(e.getStackTrace());
Log.errorf("Error saving pod logs: %s", e.getMessage());
}
}
}
@ -228,7 +239,6 @@ public abstract class BaseOperatorTest {
Awaitility.setDefaultTimeout(Duration.ofSeconds(360));
}
@AfterEach
public void cleanup() {
Log.info("Deleting Keycloak CR");
k8sclient.resources(Keycloak.class).delete();
@ -245,6 +255,45 @@ public abstract class BaseOperatorTest {
});
}
@Override
public void afterEach(QuarkusTestMethodContext context) {
if (!(context.getTestInstance() instanceof BaseOperatorTest)) {
return;
}
try {
if (!context.getTestStatus().isTestFailed()) {
return;
}
savePodLogs();
// provide some helpful entries in the main log as well
k8sclient.resources(Keycloak.class).list().getItems().stream()
.filter(kc -> !Boolean.TRUE.equals(Optional.ofNullable(kc.getStatus())
.flatMap(keycloak -> keycloak.findCondition(KeycloakStatusCondition.READY))
.map(KeycloakStatusCondition::getStatus).orElse(null)))
.forEach(kc -> {
Log.warnf("Keycloak failed to become ready \"%s\" %s", kc.getMetadata().getName(), Serialization.asYaml(kc.getStatus()));
var statefulSet = k8sclient.resources(StatefulSet.class).withName(KeycloakDeployment.getName(kc)).get();
if (statefulSet != null) {
Log.warnf("Keycloak \"%s\" StatefulSet status %s", kc.getMetadata().getName(), Serialization.asYaml(statefulSet.getStatus()));
k8sclient.pods().withLabels(statefulSet.getSpec().getSelector().getMatchLabels()).list()
.getItems().stream().filter(pod -> !Readiness.isPodReady(pod)).forEach(pod -> {
try {
String log = k8sclient.pods().resource(pod).getLog();
if (log.length() > 5000) {
log = log.substring(log.length() - 5000, log.length());
}
Log.warnf("Not ready pod log \"%s\": %s", pod.getMetadata().getName(), log);
} catch (KubernetesClientException e) {
Log.warnf("No pod log for \"%s\": %s", pod.getMetadata().getName(), e.getMessage());
}
});
}
});
} finally {
cleanup();
}
}
@AfterAll
public static void after() throws FileNotFoundException {

View file

@ -257,9 +257,6 @@ public class KeycloakIngressTest extends BaseOperatorTest {
assertThat(k8sclient.network().v1().ingresses().inNamespace(namespace).list().getItems().size()).isEqualTo(1);
});
} catch (Exception e) {
savePodLogs();
throw e;
} finally {
Log.info("Destroying the Custom Ingress created manually to avoid errors in others Tests methods");
if (customIngressDeployedManuallySelector != null && customIngressDeployedManuallySelector.isReady()) {

View file

@ -55,67 +55,57 @@ import static org.keycloak.operator.testsuite.utils.K8sUtils.deployKeycloak;
public class WatchedSecretsTest extends BaseOperatorTest {
@Test
public void testSecretsAreWatched() {
try {
var kc = getTestKeycloakDeployment(true);
deployKeycloak(k8sclient, kc, true);
var kc = getTestKeycloakDeployment(true);
deployKeycloak(k8sclient, kc, true);
Secret dbSecret = getDbSecret();
Secret tlsSecret = getTlsSecret();
Secret dbSecret = getDbSecret();
Secret tlsSecret = getTlsSecret();
assertThat(dbSecret.getMetadata().getLabels()).containsEntry(Constants.KEYCLOAK_COMPONENT_LABEL, WatchedSecrets.WATCHED_SECRETS_LABEL_VALUE);
assertThat(tlsSecret.getMetadata().getLabels()).containsEntry(Constants.KEYCLOAK_COMPONENT_LABEL, WatchedSecrets.WATCHED_SECRETS_LABEL_VALUE);
assertThat(dbSecret.getMetadata().getLabels()).containsEntry(Constants.KEYCLOAK_COMPONENT_LABEL, WatchedSecrets.WATCHED_SECRETS_LABEL_VALUE);
assertThat(tlsSecret.getMetadata().getLabels()).containsEntry(Constants.KEYCLOAK_COMPONENT_LABEL, WatchedSecrets.WATCHED_SECRETS_LABEL_VALUE);
Log.info("Updating DB Secret, expecting restart");
testDeploymentRestarted(Set.of(kc), Set.of(), () -> {
dbSecret.getData().put(UUID.randomUUID().toString(), "YmxhaGJsYWg=");
k8sclient.resource(dbSecret).update();
});
Log.info("Updating DB Secret, expecting restart");
testDeploymentRestarted(Set.of(kc), Set.of(), () -> {
dbSecret.getData().put(UUID.randomUUID().toString(), "YmxhaGJsYWg=");
k8sclient.resource(dbSecret).update();
});
Log.info("Updating TLS Secret, expecting restart");
testDeploymentRestarted(Set.of(kc), Set.of(), () -> {
tlsSecret.getData().put(UUID.randomUUID().toString(), "YmxhaGJsYWg=");
k8sclient.resource(tlsSecret).update();
});
Log.info("Updating TLS Secret, expecting restart");
testDeploymentRestarted(Set.of(kc), Set.of(), () -> {
tlsSecret.getData().put(UUID.randomUUID().toString(), "YmxhaGJsYWg=");
k8sclient.resource(tlsSecret).update();
});
Log.info("Updating DB Secret metadata, NOT expecting restart");
testDeploymentRestarted(Set.of(), Set.of(kc), () -> {
dbSecret.getMetadata().getLabels().put(UUID.randomUUID().toString(), "YmxhaGJsYWg");
k8sclient.resource(dbSecret).update();
});
} catch (Exception e) {
savePodLogs();
throw e;
}
Log.info("Updating DB Secret metadata, NOT expecting restart");
testDeploymentRestarted(Set.of(), Set.of(kc), () -> {
dbSecret.getMetadata().getLabels().put(UUID.randomUUID().toString(), "YmxhaGJsYWg");
k8sclient.resource(dbSecret).update();
});
}
@Test
public void testSecretChangesArePropagated() {
try {
final String username = "HomerSimpson";
final String username = "HomerSimpson";
var kc = getTestKeycloakDeployment(false);
deployKeycloak(k8sclient, kc, true);
var kc = getTestKeycloakDeployment(false);
deployKeycloak(k8sclient, kc, true);
var prevRevision = getStatefulSet(kc).getStatus().getUpdateRevision();
var prevRevision = getStatefulSet(kc).getStatus().getUpdateRevision();
var dbSecret = getDbSecret();
var dbSecret = getDbSecret();
dbSecret.getData().put("username",
Base64.getEncoder().encodeToString(username.getBytes()));
k8sclient.resource(dbSecret).update();
dbSecret.getData().put("username",
Base64.getEncoder().encodeToString(username.getBytes()));
k8sclient.resource(dbSecret).update();
Pod pod = k8sclient.pods().withName(kc.getMetadata().getName() + "-0").waitUntilCondition(
p -> p != null && !prevRevision.equals(p.getMetadata().getLabels().get("controller-revision-hash")),
30, TimeUnit.SECONDS);
Pod pod = k8sclient.pods().withName(kc.getMetadata().getName() + "-0").waitUntilCondition(
p -> p != null && !prevRevision.equals(p.getMetadata().getLabels().get("controller-revision-hash")),
30, TimeUnit.SECONDS);
ByteArrayOutputStream logBytes = new ByteArrayOutputStream();
try (var ignored = k8sclient.pods().resource(pod).watchLog(logBytes)) {
Awaitility.await().atMost(1, TimeUnit.MINUTES).until(() -> logBytes.toString(StandardCharsets.UTF_8)
.contains("password authentication failed for user \"" + username + "\""));
}
} catch (Exception e) {
savePodLogs();
throw e;
ByteArrayOutputStream logBytes = new ByteArrayOutputStream();
try (var ignored = k8sclient.pods().resource(pod).watchLog(logBytes)) {
Awaitility.await().atMost(1, TimeUnit.MINUTES).until(() -> logBytes.toString(StandardCharsets.UTF_8)
.contains("password authentication failed for user \"" + username + "\""));
}
}
@ -125,73 +115,62 @@ public class WatchedSecretsTest extends BaseOperatorTest {
@Test
public void testSecretsCanBeUnWatched() {
try {
var kc = getTestKeycloakDeployment(true);
deployKeycloak(k8sclient, kc, true);
var kc = getTestKeycloakDeployment(true);
deployKeycloak(k8sclient, kc, true);
Log.info("Updating KC to not to rely on DB Secret");
hardcodeDBCredsInCR(kc);
testDeploymentRestarted(Set.of(kc), Set.of(), () -> {
deployKeycloak(k8sclient, kc, false, false);
});
Log.info("Updating KC to not to rely on DB Secret");
hardcodeDBCredsInCR(kc);
testDeploymentRestarted(Set.of(kc), Set.of(), () -> {
deployKeycloak(k8sclient, kc, false, false);
});
Log.info("Updating DB Secret to trigger clean-up process");
testDeploymentRestarted(Set.of(), Set.of(kc), () -> {
var dbSecret = getDbSecret();
dbSecret.getMetadata().getLabels().put(UUID.randomUUID().toString(), "YmxhaGJsYWg");
k8sclient.resource(dbSecret).update();
});
Log.info("Updating DB Secret to trigger clean-up process");
testDeploymentRestarted(Set.of(), Set.of(kc), () -> {
var dbSecret = getDbSecret();
dbSecret.getMetadata().getLabels().put(UUID.randomUUID().toString(), "YmxhaGJsYWg");
k8sclient.resource(dbSecret).update();
});
Awaitility.await().untilAsserted(() -> {
Log.info("Checking labels on DB Secret");
assertThat(getDbSecret().getMetadata().getLabels()).doesNotContainKey(Constants.KEYCLOAK_COMPONENT_LABEL);
});
} catch (Exception e) {
savePodLogs();
throw e;
}
Awaitility.await().untilAsserted(() -> {
Log.info("Checking labels on DB Secret");
assertThat(getDbSecret().getMetadata().getLabels()).doesNotContainKey(Constants.KEYCLOAK_COMPONENT_LABEL);
});
}
@Test
public void testSingleSecretMultipleKeycloaks() {
try {
var kc1 = getTestKeycloakDeployment(true);
var kc1Hostname = new HostnameSpecBuilder().withHostname("kc1.local").build();
kc1.getMetadata().setName(kc1.getMetadata().getName() + "-1");
kc1.getSpec().setHostnameSpec(kc1Hostname);
var kc1 = getTestKeycloakDeployment(true);
var kc1Hostname = new HostnameSpecBuilder().withHostname("kc1.local").build();
kc1.getMetadata().setName(kc1.getMetadata().getName() + "-1");
kc1.getSpec().setHostnameSpec(kc1Hostname);
var kc2 = getTestKeycloakDeployment(true);
var kc2Hostname = new HostnameSpecBuilder().withHostname("kc2.local").build();
kc2.getMetadata().setName(kc2.getMetadata().getName() + "-2");
kc2.getSpec().setHostnameSpec(kc2Hostname); // to prevent Ingress conflicts
var kc2 = getTestKeycloakDeployment(true);
var kc2Hostname = new HostnameSpecBuilder().withHostname("kc2.local").build();
kc2.getMetadata().setName(kc2.getMetadata().getName() + "-2");
kc2.getSpec().setHostnameSpec(kc2Hostname); // to prevent Ingress conflicts
deployKeycloak(k8sclient, kc1, true);
deployKeycloak(k8sclient, kc2, true);
deployKeycloak(k8sclient, kc1, true);
deployKeycloak(k8sclient, kc2, true);
var dbSecret = getDbSecret();
var dbSecret = getDbSecret();
Log.info("Updating DB Secret, expecting restart of both KCs");
testDeploymentRestarted(Set.of(kc1, kc2), Set.of(), () -> {
dbSecret.getData().put(UUID.randomUUID().toString(), "YmxhaGJsYWg=");
k8sclient.resource(dbSecret).update();
});
Log.info("Updating DB Secret, expecting restart of both KCs");
testDeploymentRestarted(Set.of(kc1, kc2), Set.of(), () -> {
dbSecret.getData().put(UUID.randomUUID().toString(), "YmxhaGJsYWg=");
k8sclient.resource(dbSecret).update();
});
Log.info("Updating KC1 to not to rely on DB Secret");
hardcodeDBCredsInCR(kc1);
testDeploymentRestarted(Set.of(kc1), Set.of(kc2), () -> {
deployKeycloak(k8sclient, kc1, false, false);
});
Log.info("Updating KC1 to not to rely on DB Secret");
hardcodeDBCredsInCR(kc1);
testDeploymentRestarted(Set.of(kc1), Set.of(kc2), () -> {
deployKeycloak(k8sclient, kc1, false, false);
});
Log.info("Updating DB Secret, expecting restart of just KC2");
testDeploymentRestarted(Set.of(kc2), Set.of(kc1), () -> {
dbSecret.getData().put(UUID.randomUUID().toString(), "YmxhaGJsYWg=");
k8sclient.resource(dbSecret).update();
});
}
catch (Exception e) {
savePodLogs();
throw e;
}
Log.info("Updating DB Secret, expecting restart of just KC2");
testDeploymentRestarted(Set.of(kc2), Set.of(kc1), () -> {
dbSecret.getData().put(UUID.randomUUID().toString(), "YmxhaGJsYWg=");
k8sclient.resource(dbSecret).update();
});
}
private void testDeploymentRestarted(Set<Keycloak> crsToBeRestarted, Set<Keycloak> crsNotToBeRestarted, Runnable action) {