Major Back link to Report Portal:
Test Item comments:
Issues like this should be filtered out, because it's nto cause by Strimzi, but by admin client.
Test execution log:
Test execution log
Time: 04/13/2020 02:02:54, Level: INFO, Log: 2020-04-12 21:22:35 [32mINFO [m [TimeMeasuringSystem:94] Start time of operation TEST_EXECUTION is correctly stored 2020-04-12 21:22:35 [32mINFO [m [TestSeparator:27] ############################################################################ 2020-04-12 21:22:35 [32mINFO [m [TestSeparator:28] io.strimzi.systemtest.KafkaST.testLoadBalancerTls-STARTED 2020-04-12 21:22:35 [32mINFO [m [ResourceManager:89] Setting pointer to method resources 2020-04-12 21:22:35 [32mINFO [m [ResourceManager:106] Scheduled deletion of Kafka my-cluster in namespace kafka-cluster-test 2020-04-12 21:22:35 [32mINFO [m [KafkaResource:213] Waiting for Kafka my-cluster in namespace kafka-cluster-test 2020-04-12 21:22:35 [32mINFO [m [KafkaResource:215] Waiting for Zookeeper pods 2020-04-12 21:27:28 [32mINFO [m [KafkaResource:217] Zookeeper pods are ready 2020-04-12 21:27:28 [32mINFO [m [KafkaResource:219] Waiting for Kafka pods 2020-04-12 21:27:57 [32mINFO [m [KafkaResource:221] Kafka pods are ready 2020-04-12 21:27:57 [32mINFO [m [KafkaResource:225] Waiting for Entity Operator pods 2020-04-12 21:28:07 [32mINFO [m [KafkaResource:227] Entity Operator pods are ready 2020-04-12 21:28:07 [32mINFO [m [KafkaUserResource:64] Created KafkaUser alice 2020-04-12 21:28:07 [32mINFO [m [ResourceManager:106] Scheduled deletion of KafkaUser alice in namespace kafka-cluster-test 2020-04-12 21:28:07 [32mINFO [m [KafkaUserResource:81] Waiting for Kafka User alice 2020-04-12 21:28:07 [32mINFO [m [KafkaUserUtils:24] Waiting for Kafka user creation alice 2020-04-12 21:28:07 [32mINFO [m [SecretUtils:40] Waiting for Kafka user secret alice 2020-04-12 21:28:08 [32mINFO [m [SecretUtils:44] Kafka user secret alice created 2020-04-12 21:28:08 [32mINFO [m [KafkaUserUtils:35] Kafka user alice created 2020-04-12 21:28:08 [32mINFO [m [KafkaUserResource:83] Kafka User alice is ready 2020-04-12 21:28:08 [32mINFO [m [ServiceUtils:90] Waiting till address null is reachable 2020-04-12 21:28:08 [32mINFO [m [ServiceUtils:100] Address null is reachable 2020-04-12 21:28:08 [32mINFO [m [BasicExternalKafkaClient:101] Going to use the following CA certificate: my-cluster-cluster-ca-cert 2020-04-12 21:28:08 [32mINFO [m [Producer:36] Creating instance of Vert.x for the client io.strimzi.systemtest.kafkaclients.externalClients.Producer 2020-04-12 21:28:08 [32mINFO [m [Producer:38] Producer is starting with following properties: {ssl.keystore.location=/tmp/io.strimzi.systemtest.kafkaclients.KafkaClientProperties6849305172572043506.keystore, bootstrap.servers=172.29.80.156:9094, key.serializer=org.apache.kafka.common.serialization.StringSerializer, ssl.truststore.type=PKCS12, security.protocol=SSL, ssl.keystore.type=PKCS12, value.serializer=org.apache.kafka.common.serialization.StringSerializer, ssl.truststore.location=/tmp/io.strimzi.systemtest.kafkaclients.KafkaClientProperties13213314450239032017.truststore, ssl.keystore.password=foo, sasl.mechanism=, ssl.truststore.password=M7ioA0FL9RDE, client.id=alice-producer, ssl.endpoint.identification.algorithm=} 2020-04-12 21:28:08 [32mINFO [m [ProducerConfig:347] ProducerConfig values: acks = 1 batch.size = 16384 bootstrap.servers = [172.29.80.156:9094] buffer.memory = 33554432 client.dns.lookup = default client.id = alice-producer compression.type = none connections.max.idle.ms = 540000 delivery.timeout.ms = 120000 enable.idempotence = false interceptor.classes = [] key.serializer = class org.apache.kafka.common.serialization.StringSerializer linger.ms = 0 max.block.ms = 60000 max.in.flight.requests.per.connection = 5 max.request.size = 1048576 metadata.max.age.ms = 300000 metric.reporters = [] metrics.num.samples = 2 metrics.recording.level = INFO metrics.sample.window.ms = 30000 partitioner.class = class org.apache.kafka.clients.producer.internals.DefaultPartitioner receive.buffer.bytes = 32768 reconnect.backoff.max.ms = 1000 reconnect.backoff.ms = 50 request.timeout.ms = 30000 retries = 2147483647 retry.backoff.ms = 100 sasl.client.callback.handler.class = null sasl.jaas.config = null sasl.kerberos.kinit.cmd = /usr/bin/kinit sasl.kerberos.min.time.before.relogin = 60000 sasl.kerberos.service.name = null sasl.kerberos.ticket.renew.jitter = 0.05 sasl.kerberos.ticket.renew.window.factor = 0.8 sasl.login.callback.handler.class = null sasl.login.class = null sasl.login.refresh.buffer.seconds = 300 sasl.login.refresh.min.period.seconds = 60 sasl.login.refresh.window.factor = 0.8 sasl.login.refresh.window.jitter = 0.05 sasl.mechanism = security.protocol = SSL security.providers = null send.buffer.bytes = 131072 ssl.cipher.suites = null ssl.enabled.protocols = [TLSv1.2, TLSv1.1, TLSv1] ssl.endpoint.identification.algorithm = ssl.key.password = null ssl.keymanager.algorithm = SunX509 ssl.keystore.location = /tmp/io.strimzi.systemtest.kafkaclients.KafkaClientProperties6849305172572043506.keystore ssl.keystore.password = [hidden] ssl.keystore.type = PKCS12 ssl.protocol = TLS ssl.provider = null ssl.secure.random.implementation = null ssl.trustmanager.algorithm = PKIX ssl.truststore.location = /tmp/io.strimzi.systemtest.kafkaclients.KafkaClientProperties13213314450239032017.truststore ssl.truststore.password = [hidden] ssl.truststore.type = PKCS12 transaction.timeout.ms = 60000 transactional.id = null value.serializer = class org.apache.kafka.common.serialization.StringSerializer 2020-04-12 21:28:08 [32mINFO [m [AppInfoParser:117] Kafka version: 2.4.0 2020-04-12 21:28:08 [32mINFO [m [AppInfoParser:118] Kafka commitId: 77a89fcf8d7fa018 2020-04-12 21:28:08 [32mINFO [m [AppInfoParser:119] Kafka startTimeMs: 1586726888306 2020-04-12 21:28:08 [33mWARN [m [NetworkClient:1063] [Producer clientId=alice-producer] Error while fetching metadata with correlation id 1 : {test-topic=LEADER_NOT_AVAILABLE} 2020-04-12 21:28:08 [32mINFO [m [Metadata:261] [Producer clientId=alice-producer] Cluster ID: KhLtNlkoSj-aikr-Eex_iA 2020-04-12 21:28:08 [33mWARN [m [NetworkClient:1063] [Producer clientId=alice-producer] Error while fetching metadata with correlation id 3 : {test-topic=LEADER_NOT_AVAILABLE} 2020-04-12 21:28:08 [33mWARN [m [NetworkClient:1063] [Producer clientId=alice-producer] Error while fetching metadata with correlation id 4 : {test-topic=LEADER_NOT_AVAILABLE} 2020-04-12 21:28:08 [33mWARN [m [NetworkClient:1063] [Producer clientId=alice-producer] Error while fetching metadata with correlation id 5 : {test-topic=LEADER_NOT_AVAILABLE} 2020-04-12 21:28:09 [33mWARN [m [NetworkClient:1063] [Producer clientId=alice-producer] Error while fetching metadata with correlation id 6 : {test-topic=LEADER_NOT_AVAILABLE} 2020-04-12 21:28:10 [32mINFO [m [Producer:79] Producer produced 100 messages 2020-04-12 21:28:10 [32mINFO [m [Producer:57] Closing Vert.x instance for the client io.strimzi.systemtest.kafkaclients.externalClients.Producer 2020-04-12 21:28:10 [32mINFO [m [KafkaProducer:1183] [Producer clientId=alice-producer] Closing the Kafka producer with timeoutMillis = 9223372036854775807 ms. 2020-04-12 21:28:10 [32mINFO [m [BasicExternalKafkaClient:182] Going to use the following CA certificate: my-cluster-cluster-ca-cert 2020-04-12 21:28:10 [32mINFO [m [Consumer:34] Consumer is starting with following properties: {key.deserializer=org.apache.kafka.common.serialization.StringDeserializer, value.deserializer=org.apache.kafka.common.serialization.StringDeserializer, group.id=my-consumer-group-1563524823, ssl.keystore.location=/tmp/io.strimzi.systemtest.kafkaclients.KafkaClientProperties11122369265433048783.keystore, bootstrap.servers=172.29.80.156:9094, ssl.truststore.type=PKCS12, security.protocol=SSL, ssl.keystore.type=PKCS12, ssl.truststore.location=/tmp/io.strimzi.systemtest.kafkaclients.KafkaClientProperties3810683017402744648.truststore, ssl.keystore.password=foo, sasl.mechanism=, ssl.truststore.password=M7ioA0FL9RDE, auto.offset.reset=earliest, client.id=alice-consumer, ssl.endpoint.identification.algorithm=} 2020-04-12 21:28:10 [32mINFO [m [ConsumerConfig:347] ConsumerConfig values: allow.auto.create.topics = true auto.commit.interval.ms = 5000 auto.offset.reset = earliest bootstrap.servers = [172.29.80.156:9094] check.crcs = true client.dns.lookup = default client.id = alice-consumer client.rack = connections.max.idle.ms = 540000 default.api.timeout.ms = 60000 enable.auto.commit = true exclude.internal.topics = true fetch.max.bytes = 52428800 fetch.max.wait.ms = 500 fetch.min.bytes = 1 group.id = my-consumer-group-1563524823 group.instance.id = null heartbeat.interval.ms = 3000 interceptor.classes = [] internal.leave.group.on.close = true isolation.level = read_uncommitted key.deserializer = class org.apache.kafka.common.serialization.StringDeserializer max.partition.fetch.bytes = 1048576 max.poll.interval.ms = 300000 max.poll.records = 500 metadata.max.age.ms = 300000 metric.reporters = [] metrics.num.samples = 2 metrics.recording.level = INFO metrics.sample.window.ms = 30000 partition.assignment.strategy = [class org.apache.kafka.clients.consumer.RangeAssignor] receive.buffer.bytes = 65536 reconnect.backoff.max.ms = 1000 reconnect.backoff.ms = 50 request.timeout.ms = 30000 retry.backoff.ms = 100 sasl.client.callback.handler.class = null sasl.jaas.config = null sasl.kerberos.kinit.cmd = /usr/bin/kinit sasl.kerberos.min.time.before.relogin = 60000 sasl.kerberos.service.name = null sasl.kerberos.ticket.renew.jitter = 0.05 sasl.kerberos.ticket.renew.window.factor = 0.8 sasl.login.callback.handler.class = null sasl.login.class = null sasl.login.refresh.buffer.seconds = 300 sasl.login.refresh.min.period.seconds = 60 sasl.login.refresh.window.factor = 0.8 sasl.login.refresh.window.jitter = 0.05 sasl.mechanism = security.protocol = SSL security.providers = null send.buffer.bytes = 131072 session.timeout.ms = 10000 ssl.cipher.suites = null ssl.enabled.protocols = [TLSv1.2, TLSv1.1, TLSv1] ssl.endpoint.identification.algorithm = ssl.key.password = null ssl.keymanager.algorithm = SunX509 ssl.keystore.location = /tmp/io.strimzi.systemtest.kafkaclients.KafkaClientProperties11122369265433048783.keystore ssl.keystore.password = [hidden] ssl.keystore.type = PKCS12 ssl.protocol = TLS ssl.provider = null ssl.secure.random.implementation = null ssl.trustmanager.algorithm = PKIX ssl.truststore.location = /tmp/io.strimzi.systemtest.kafkaclients.KafkaClientProperties3810683017402744648.truststore ssl.truststore.password = [hidden] ssl.truststore.type = PKCS12 value.deserializer = class org.apache.kafka.common.serialization.StringDeserializer 2020-04-12 21:28:10 [32mINFO [m [AppInfoParser:117] Kafka version: 2.4.0 2020-04-12 21:28:10 [32mINFO [m [AppInfoParser:118] Kafka commitId: 77a89fcf8d7fa018 2020-04-12 21:28:10 [32mINFO [m [AppInfoParser:119] Kafka startTimeMs: 1586726890220 2020-04-12 21:28:10 [32mINFO [m [KafkaConsumer:969] [Consumer clientId=alice-consumer, groupId=my-consumer-group-1563524823] Subscribed to topic(s): test-topic 2020-04-12 21:28:10 [32mINFO [m [Metadata:261] [Consumer clientId=alice-consumer, groupId=my-consumer-group-1563524823] Cluster ID: KhLtNlkoSj-aikr-Eex_iA 2020-04-12 21:28:11 [32mINFO [m [AbstractCoordinator:756] [Consumer clientId=alice-consumer, groupId=my-consumer-group-1563524823] Discovered group coordinator 172.29.171.200:9094 (id: 2147483645 rack: null) 2020-04-12 21:28:11 [32mINFO [m [AbstractCoordinator:533] [Consumer clientId=alice-consumer, groupId=my-consumer-group-1563524823] (Re-)joining group 2020-04-12 21:28:11 [32mINFO [m [AbstractCoordinator:533] [Consumer clientId=alice-consumer, groupId=my-consumer-group-1563524823] (Re-)joining group 2020-04-12 21:28:14 [32mINFO [m [ConsumerCoordinator:585] [Consumer clientId=alice-consumer, groupId=my-consumer-group-1563524823] Finished assignment for group at generation 1: {alice-consumer-1bf03a9b-db64-4a54-b0ac-9a41b504fb99=org.apache.kafka.clients.consumer.ConsumerPartitionAssignor$Assignment@4d2e45c5} 2020-04-12 21:28:14 [32mINFO [m [AbstractCoordinator:484] [Consumer clientId=alice-consumer, groupId=my-consumer-group-1563524823] Successfully joined group with generation 1 2020-04-12 21:28:14 [32mINFO [m [ConsumerCoordinator:267] [Consumer clientId=alice-consumer, groupId=my-consumer-group-1563524823] Adding newly assigned partitions: test-topic-0 2020-04-12 21:28:14 [32mINFO [m [ConsumerCoordinator:1241] [Consumer clientId=alice-consumer, groupId=my-consumer-group-1563524823] Found no committed offset for partition test-topic-0 2020-04-12 21:28:15 [32mINFO [m [SubscriptionState:385] [Consumer clientId=alice-consumer, groupId=my-consumer-group-1563524823] Resetting offset for partition test-topic-0 to offset 0. 2020-04-12 21:28:15 [32mINFO [m [Consumer:55] Consumer consumed 100 messages 2020-04-12 21:28:15 [32mINFO [m [Consumer:68] Closing Vert.x instance for the client io.strimzi.systemtest.kafkaclients.externalClients.Consumer 2020-04-12 21:28:15 [32mINFO [m [BaseST:666] Search in strimzi-cluster-operator log for errors in last 0 seconds 2020-04-12 21:28:15 [32mINFO [m [ConsumerCoordinator:286] [Consumer clientId=alice-consumer, groupId=my-consumer-group-1563524823] Revoke previously assigned partitions test-topic-0 2020-04-12 21:28:15 [32mINFO [m [AbstractCoordinator:916] [Consumer clientId=alice-consumer, groupId=my-consumer-group-1563524823] Member alice-consumer-1bf03a9b-db64-4a54-b0ac-9a41b504fb99 sending LeaveGroup request to coordinator 172.29.171.200:9094 (id: 2147483645 rack: null) due to the consumer is being closed 2020-04-12 21:28:16 [1;31mERROR[m [BaseST:744] Cluster Operator contains unexpected errors! 2020-04-12 21:28:16 [32mINFO [m [BaseST:750] Test execution contains exception, going to recreate test environment 2020-04-12 21:28:16 [32mINFO [m [ResourceManager:341] Going to clear all method resources 2020-04-12 21:28:16 [32mINFO [m [ResourceManager:216] Deleting KafkaUser alice in namespace kafka-cluster-test 2020-04-12 21:28:16 [32mINFO [m [ResourceManager:111] Deleting Kafka my-cluster in namespace kafka-cluster-test 2020-04-12 21:28:16 [32mINFO [m [ResourceManager:229] Waiting when all the pods are terminated for Kafka my-cluster 2020-04-12 21:28:16 [33mWARN [m [StatefulSetUtils:159] StatefulSet my-cluster-zookeeper is not deleted yet! Triggering force delete by cmd client! 2020-04-12 21:28:21 [32mINFO [m [PodUtils:138] Waiting when Pod my-cluster-zookeeper-0 will be deleted 2020-04-12 21:28:28 [32mINFO [m [PodUtils:152] Pod my-cluster-zookeeper-0 deleted 2020-04-12 21:28:28 [32mINFO [m [PodUtils:138] Waiting when Pod my-cluster-zookeeper-1 will be deleted 2020-04-12 21:28:28 [32mINFO [m [PodUtils:152] Pod my-cluster-zookeeper-1 deleted 2020-04-12 21:28:28 [32mINFO [m [PodUtils:138] Waiting when Pod my-cluster-zookeeper-2 will be deleted 2020-04-12 21:28:28 [32mINFO [m [PodUtils:152] Pod my-cluster-zookeeper-2 deleted 2020-04-12 21:28:28 [32mINFO [m [PodUtils:138] Waiting when Pod my-cluster-kafka-0 will be deleted 2020-04-12 21:28:56 [32mINFO [m [PodUtils:152] Pod my-cluster-kafka-0 deleted 2020-04-12 21:28:56 [32mINFO [m [PodUtils:138] Waiting when Pod my-cluster-kafka-1 will be deleted 2020-04-12 21:29:03 [32mINFO [m [PodUtils:152] Pod my-cluster-kafka-1 deleted 2020-04-12 21:29:03 [32mINFO [m [PodUtils:138] Waiting when Pod my-cluster-kafka-2 will be deleted 2020-04-12 21:29:03 [32mINFO [m [PodUtils:152] Pod my-cluster-kafka-2 deleted 2020-04-12 21:29:03 [32mINFO [m [SecretUtils:95] Waiting for Kafka cluster my-cluster secrets deletion 2020-04-12 21:29:03 [32mINFO [m [SecretUtils:109] Kafka cluster my-cluster secrets deleted 2020-04-12 21:29:03 [32mINFO [m [PersistentVolumeClaimUtils:58] Waiting till PVC deletion for cluster my-cluster 2020-04-12 21:29:03 [32mINFO [m [PersistentVolumeClaimUtils:72] PVC for cluster my-cluster was deleted 2020-04-12 21:29:03 [32mINFO [m [ConfigMapUtils:66] Waiting till ConfigMaps deletion for cluster my-cluster-kafka-config 2020-04-12 21:29:03 [32mINFO [m [ConfigMapUtils:80] ConfigMaps for cluster my-cluster-kafka-config were deleted 2020-04-12 21:29:03 [32mINFO [m [ConfigMapUtils:66] Waiting till ConfigMaps deletion for cluster my-cluster-zookeeper-config 2020-04-12 21:29:03 [32mINFO [m [ConfigMapUtils:80] ConfigMaps for cluster my-cluster-zookeeper-config were deleted 2020-04-12 21:29:03 [32mINFO [m [ResourceManager:333] Going to clear all class resources 2020-04-12 21:29:03 [32mINFO [m [ResourceManager:216] Deleting NetworkPolicy global-network-policy in namespace kafka-cluster-test 2020-04-12 21:29:03 [32mINFO [m [ResourceManager:177] Deleting Deployment strimzi-cluster-operator 2020-04-12 21:29:03 [32mINFO [m [ResourceManager:323] Waiting when all the pods are terminated for Deployment strimzi-cluster-operator 2020-04-12 21:29:03 [33mWARN [m [DeploymentUtils:187] Deployment strimzi-cluster-operator is not deleted yet! Triggering force delete by cmd client! 2020-04-12 21:29:08 [32mINFO [m [ResourceManager:191] Deleting RoleBinding strimzi-cluster-operator-topic-operator-delegation 2020-04-12 21:29:08 [32mINFO [m [ResourceManager:191] Deleting RoleBinding strimzi-cluster-operator-entity-operator-delegation 2020-04-12 21:29:08 [32mINFO [m [ResourceManager:184] Deleting ClusterRoleBinding strimzi-cluster-operator-kafka-broker-delegation 2020-04-12 21:29:08 [32mINFO [m [ResourceManager:184] Deleting ClusterRoleBinding strimzi-cluster-operator 2020-04-12 21:29:08 [32mINFO [m [ResourceManager:191] Deleting RoleBinding strimzi-cluster-operator 2020-04-12 21:29:08 [32mINFO [m [TimeMeasuringSystem:94] Start time of operation CO_DELETION is correctly stored 2020-04-12 21:29:08 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/048-Crd-kafkamirrormaker2.yaml 2020-04-12 21:29:09 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/047-Crd-kafkaconnector.yaml 2020-04-12 21:29:09 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/046-Crd-kafkabridge.yaml 2020-04-12 21:29:09 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/045-Crd-kafkamirrormaker.yaml 2020-04-12 21:29:10 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/044-Crd-kafkauser.yaml 2020-04-12 21:29:10 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/043-Crd-kafkatopic.yaml 2020-04-12 21:29:10 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/042-Crd-kafkaconnects2i.yaml 2020-04-12 21:29:10 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/041-Crd-kafkaconnect.yaml 2020-04-12 21:29:11 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/040-Crd-kafka.yaml 2020-04-12 21:29:11 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/032-ClusterRole-strimzi-topic-operator.yaml 2020-04-12 21:29:11 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/031-ClusterRole-strimzi-entity-operator.yaml 2020-04-12 21:29:12 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/030-ClusterRole-strimzi-kafka-broker.yaml 2020-04-12 21:29:12 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/021-ClusterRole-strimzi-cluster-operator-role.yaml 2020-04-12 21:29:12 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/020-ClusterRole-strimzi-cluster-operator-role.yaml 2020-04-12 21:29:12 [32mINFO [m [KubeClusterResource:185] Deleting configuration file: ../install/cluster-operator/010-ServiceAccount-strimzi-cluster-operator.yaml 2020-04-12 21:29:12 [32mINFO [m [TimeMeasuringSystem:113] End time of operation CO_DELETION is correctly stored 2020-04-12 21:29:12 [32mINFO [m [KubeClusterResource:231] Deleting namespace: kafka-cluster-test 2020-04-12 21:29:20 [32mINFO [m [KubeClusterResource:237] Using namespace kafka-cluster-test 2020-04-12 21:29:20 [32mINFO [m [KubeClusterResource:125] Changing to kafka-cluster-test namespace 2020-04-12 21:29:20 [32mINFO [m [KubeClusterResource:206] Creating namespace: kafka-cluster-test 2020-04-12 21:29:20 [32mINFO [m [KubeClusterResource:212] Using namespace kafka-cluster-test 2020-04-12 21:29:20 [32mINFO [m [KubeClusterResource:125] Changing to kafka-cluster-test namespace 2020-04-12 21:29:20 [32mINFO [m [TimeMeasuringSystem:94] Start time of operation CO_CREATION is correctly stored 2020-04-12 21:29:20 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/010-ServiceAccount-strimzi-cluster-operator.yaml 2020-04-12 21:29:21 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/020-ClusterRole-strimzi-cluster-operator-role.yaml 2020-04-12 21:29:21 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/021-ClusterRole-strimzi-cluster-operator-role.yaml 2020-04-12 21:29:21 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/030-ClusterRole-strimzi-kafka-broker.yaml 2020-04-12 21:29:22 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/031-ClusterRole-strimzi-entity-operator.yaml 2020-04-12 21:29:22 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/032-ClusterRole-strimzi-topic-operator.yaml 2020-04-12 21:29:22 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/040-Crd-kafka.yaml 2020-04-12 21:29:23 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/041-Crd-kafkaconnect.yaml 2020-04-12 21:29:23 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/042-Crd-kafkaconnects2i.yaml 2020-04-12 21:29:23 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/043-Crd-kafkatopic.yaml 2020-04-12 21:29:24 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/044-Crd-kafkauser.yaml 2020-04-12 21:29:24 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/045-Crd-kafkamirrormaker.yaml 2020-04-12 21:29:24 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/046-Crd-kafkabridge.yaml 2020-04-12 21:29:25 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/047-Crd-kafkaconnector.yaml 2020-04-12 21:29:25 [32mINFO [m [KubeClusterResource:103] Applying configuration file: ../install/cluster-operator/048-Crd-kafkamirrormaker2.yaml 2020-04-12 21:29:25 [32mINFO [m [TimeMeasuringSystem:113] End time of operation CO_CREATION is correctly stored 2020-04-12 21:29:25 [32mINFO [m [ResourceManager:94] Setting pointer to class resources 2020-04-12 21:29:25 [32mINFO [m [KubernetesResource:142] Creating RoleBinding from ../install/cluster-operator/020-RoleBinding-strimzi-cluster-operator.yaml in namespace kafka-cluster-test 2020-04-12 21:29:25 [32mINFO [m [KubernetesResource:151] Apply RoleBinding in namespace kafka-cluster-test 2020-04-12 21:29:25 [32mINFO [m [ResourceManager:106] Scheduled deletion of RoleBinding strimzi-cluster-operator in namespace (not set) 2020-04-12 21:29:25 [32mINFO [m [KubernetesResource:158] Creating ClusterRoleBinding from ../install/cluster-operator/021-ClusterRoleBinding-strimzi-cluster-operator.yaml in namespace kafka-cluster-test 2020-04-12 21:29:25 [32mINFO [m [KubernetesResource:167] Apply ClusterRoleBinding in namespace kafka-cluster-test 2020-04-12 21:29:25 [32mINFO [m [ResourceManager:106] Scheduled deletion of ClusterRoleBinding strimzi-cluster-operator in namespace (not set) 2020-04-12 21:29:25 [32mINFO [m [KubernetesResource:158] Creating ClusterRoleBinding from ../install/cluster-operator/030-ClusterRoleBinding-strimzi-cluster-operator-kafka-broker-delegation.yaml in namespace kafka-cluster-test 2020-04-12 21:29:25 [32mINFO [m [KubernetesResource:167] Apply ClusterRoleBinding in namespace kafka-cluster-test 2020-04-12 21:29:25 [32mINFO [m [ResourceManager:106] Scheduled deletion of ClusterRoleBinding strimzi-cluster-operator-kafka-broker-delegation in namespace (not set) 2020-04-12 21:29:25 [32mINFO [m [KubernetesResource:142] Creating RoleBinding from ../install/cluster-operator/031-RoleBinding-strimzi-cluster-operator-entity-operator-delegation.yaml in namespace kafka-cluster-test 2020-04-12 21:29:25 [32mINFO [m [KubernetesResource:151] Apply RoleBinding in namespace kafka-cluster-test 2020-04-12 21:29:25 [32mINFO [m [ResourceManager:106] Scheduled deletion of RoleBinding strimzi-cluster-operator-entity-operator-delegation in namespace (not set) 2020-04-12 21:29:25 [32mINFO [m [KubernetesResource:142] Creating RoleBinding from ../install/cluster-operator/032-RoleBinding-strimzi-cluster-operator-topic-operator-delegation.yaml in namespace kafka-cluster-test 2020-04-12 21:29:25 [32mINFO [m [KubernetesResource:151] Apply RoleBinding in namespace kafka-cluster-test 2020-04-12 21:29:25 [32mINFO [m [ResourceManager:106] Scheduled deletion of RoleBinding strimzi-cluster-operator-topic-operator-delegation in namespace (not set) 2020-04-12 21:29:25 [32mINFO [m [ResourceManager:106] Scheduled deletion of Deployment strimzi-cluster-operator in namespace (not set) 2020-04-12 21:29:25 [32mINFO [m [KubernetesResource:422] Waiting for deployment strimzi-cluster-operator 2020-04-12 21:30:17 [32mINFO [m [KubernetesResource:424] Deployment strimzi-cluster-operator is ready 2020-04-12 21:30:17 [32mINFO [m [ResourceManager:106] Scheduled deletion of NetworkPolicy global-network-policy in namespace kafka-cluster-test 2020-04-12 21:30:17 [32mINFO [m [KubernetesResource:402] Network policy successfully set to: DEFAULT_TO_DENY 2020-04-12 21:30:17 [32mINFO [m [KubernetesResource:324] NetworkPolicy successfully set to: true for namespace: kafka-cluster-test 2020-04-12 21:30:17 [32mINFO [m [BaseST:753] Env recreated. 2020-04-12 21:30:17 [32mINFO [m [ResourceManager:341] Going to clear all method resources 2020-04-12 21:30:17 [33mWARN [m [TimeMeasuringSystem:115] End time of operation TEST_EXECUTION is not set due to exception: java.lang.NullPointerException 2020-04-12 21:30:17 [32mINFO [m [TestSeparator:34] io.strimzi.systemtest.KafkaST.testLoadBalancerTls-FINISHED 2020-04-12 21:30:17 [32mINFO [m [TestSeparator:35] ############################################################################
Time: 04/13/2020 02:02:54, Level: ERROR, Log: java.lang.AssertionError:
Expected: The log should not contain unexpected errors.
but: was "2020-04-12 21:00:52 DEBUG NativeLibraryLoader:344 - Unable to load the library 'netty_transport_native_epoll_x86_64', trying other loading mechanism.\njava.lang.UnsatisfiedLinkError: no netty_transport_native_epoll_x86_64 in java.library.path\n--\n2020-04-12 21:12:06 DEBUG DnsQueryContext:117 - [id: 0xdbda75b9] WRITE: UDP, [28873: /172.30.0.2:53], DefaultDnsQuestion(my-cluster-zookeeper-0.my-cluster-zookeeper-nodes.kafka-cluster-test.svc.cluster.local. IN AAAA)\n2020-04-12 21:12:06 DEBUG DnsNameResolver:1205 - [id: 0xdbda75b9] RECEIVED: UDP [31748: /172.30.0.2:53], DatagramDnsResponse(from: /172.30.0.2:53, to: /0:0:0:0:0:0:0:0:55566, 31748, QUERY(0), NoError(0), RD AA RA)\n--\n\tDefaultDnsRawRecord(my-cluster-zookeeper-0.my-cluster-zookeeper-nodes.kafka-cluster-test.svc.cluster.local. 30 IN A 4B)\n2020-04-12 21:12:06 DEBUG DnsNameResolver:1205 - [id: 0xdbda75b9] RECEIVED: UDP [28873: /172.30.0.2:53], DatagramDnsResponse(from: /172.30.0.2:53, to: /0:0:0:0:0:0:0:0:55566, 28873, QUERY(0), NoError(0), RD AA RA)\n--\n2020-04-12 21:12:06 DEBUG DnsQueryContext:117 - [id: 0xdbda75b9] WRITE: UDP, [43515: /172.30.0.2:53], DefaultDnsQuestion(my-cluster-zookeeper-1.my-cluster-zookeeper-nodes.kafka-cluster-test.svc.cluster.local. IN AAAA)\n2020-04-12 21:12:06 DEBUG DnsNameResolver:1205 - [id: 0xdbda75b9] RECEIVED: UDP [43515: /172.30.0.2:53], DatagramDnsResponse(from: /172.30.0.2:53, to: /0:0:0:0:0:0:0:0:55566, 43515, QUERY(0), NoError(0), RD AA RA)\n--\n\tDefaultDnsRawRecord(cluster.local. 60 IN SOA 42B)\n2020-04-12 21:12:06 DEBUG DnsNameResolver:1205 - [id: 0xdbda75b9] RECEIVED: UDP [26133: /172.30.0.2:53], DatagramDnsResponse(from: /172.30.0.2:53, to: /0:0:0:0:0:0:0:0:55566, 26133, QUERY(0), NoError(0), RD AA RA)\n--\n2020-04-12 21:26:50 DEBUG ZookeeperScaler:243 - Failed to close the ZooKeeperAdmin\njava.lang.NullPointerException: null\n--\n2020-04-12 21:26:50 WARN KafkaAssemblyOperator:1551 - {}: Failed to verify Zookeeper configuration\nio.strimzi.operator.cluster.operator.resource.ZookeeperScalingException: Failed to connect to Zookeeper my-cluster-zookeeper-0.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-1.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181. Connection was not ready in 300000 ms.\n--\n\tat java.lang.Thread.run(Thread.java:748) [?:1.8.0_242]\nCaused by: io.strimzi.operator.common.operator.resource.TimeoutException: Exceeded timeout of 300000ms while waiting for ZooKeeperAdmin connection to my-cluster-zookeeper-0.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-1.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181 to be ready\n\t... 11 more\n2020-04-12 21:26:50 DEBUG StatusDiff:42 - Status differs: {\"op\":\"replace\",\"path\":\"/\",\"value\":{\"conditions\":[{\"type\":\"NotReady\",\"status\":\"True\",\"lastTransitionTime\":\"2020-04-12T21:26:50+0000\",\"reason\":\"ZookeeperScalingException\",\"message\":\"Failed to connect to Zookeeper my-cluster-zookeeper-0.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-1.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181. Connection was not ready in 300000 ms.\"}],\"observedGeneration\":1}}\n--\n2020-04-12 21:26:50 ERROR AbstractOperator:175 - Reconciliation #60(watch) Kafka(kafka-cluster-test/my-cluster): createOrUpdate failed\nio.strimzi.operator.cluster.operator.resource.ZookeeperScalingException: Failed to connect to Zookeeper my-cluster-zookeeper-0.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-1.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181. Connection was not ready in 300000 ms.\n--\n\tat java.lang.Thread.run(Thread.java:748) [?:1.8.0_242]\nCaused by: io.strimzi.operator.common.operator.resource.TimeoutException: Exceeded timeout of 300000ms while waiting for ZooKeeperAdmin connection to my-cluster-zookeeper-0.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-1.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181 to be ready\n--\n2020-04-12 21:26:50 WARN AbstractOperator:329 - Reconciliation #60(watch) Kafka(kafka-cluster-test/my-cluster): Failed to reconcile\nio.strimzi.operator.cluster.operator.resource.ZookeeperScalingException: Failed to connect to Zookeeper my-cluster-zookeeper-0.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-1.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181. Connection was not ready in 300000 ms.\n--\n\tat java.lang.Thread.run(Thread.java:748) [?:1.8.0_242]\nCaused by: io.strimzi.operator.common.operator.resource.TimeoutException: Exceeded timeout of 300000ms while waiting for ZooKeeperAdmin connection to my-cluster-zookeeper-0.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-1.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181,my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.kafka-cluster-test.svc:2181 to be ready\n"