Hi All, I have a simple kafka streams app that seems to hang when restoring state for a GlobalKTable. We're running in a test environment at the moment and the topic it is loading from only has two messages in it, I don't know if the very low volume of messages would affect the restore?
I've attached a log, the topic in question is invoices-state. As you can see the GlobalStreamThread appears to load the two messages in the topic and then continues to send read requests to the topic despite having caught up. Any tips on debugging this would be very welcome. Thanks Alex
INFO 2017-11-07 14:12:22,531 0 org.apache.kafka.clients.producer.ProducerConfig [main] ProducerConfig values: acks = all batch.size = 16384 bootstrap.servers = [kafka-kafka.kafka.svc.cluster.local:9092] buffer.memory = 33554432 client.id = compression.type = none connections.max.idle.ms = 540000 enable.idempotence = false interceptor.classes = null key.serializer = class org.apache.kafka.common.serialization.ByteArraySerializer 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 = 1 retry.backoff.ms = 100 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.mechanism = GSSAPI security.protocol = PLAINTEXT send.buffer.bytes = 131072 ssl.cipher.suites = null ssl.enabled.protocols = [TLSv1.2, TLSv1.1, TLSv1] ssl.endpoint.identification.algorithm = null ssl.key.password = null ssl.keymanager.algorithm = SunX509 ssl.keystore.location = null ssl.keystore.password = null ssl.keystore.type = JKS ssl.protocol = TLS ssl.provider = null ssl.secure.random.implementation = null ssl.trustmanager.algorithm = PKIX ssl.truststore.location = null ssl.truststore.password = null ssl.truststore.type = JKS transaction.timeout.ms = 5000 transactional.id = invoices-transactions value.serializer = class io.confluent.kafka.serializers.KafkaAvroSerializer INFO 2017-11-07 14:12:23,124 593 io.confluent.kafka.serializers.KafkaAvroSerializerConfig [main] KafkaAvroSerializerConfig values: schema.registry.url = [http://sad-squid-schema-registry.schema-registry.svc.cluster.local:8000] max.schemas.per.subject = 1000 INFO 2017-11-07 14:12:24,126 1595 org.apache.kafka.clients.producer.KafkaProducer [main] Instantiated a transactional producer. INFO 2017-11-07 14:12:24,127 1596 org.apache.kafka.clients.producer.KafkaProducer [main] Overriding the default max.in.flight.requests.per.connection to 1 since idempontence is enabled. DEBUG 2017-11-07 14:12:24,134 1603 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bufferpool-wait-time DEBUG 2017-11-07 14:12:24,137 1606 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name buffer-exhausted-records DEBUG 2017-11-07 14:12:24,235 1704 org.apache.kafka.clients.Metadata [main] Updated cluster metadata version 1 to Cluster(id = null, nodes = [kafka-kafka.kafka.svc.cluster.local:9092 (id: -1 rack: null)], partitions = []) DEBUG 2017-11-07 14:12:24,243 1712 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name produce-throttle-time DEBUG 2017-11-07 14:12:24,260 1729 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name connections-closed: DEBUG 2017-11-07 14:12:24,260 1729 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name connections-created: DEBUG 2017-11-07 14:12:24,260 1729 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-sent-received: DEBUG 2017-11-07 14:12:24,260 1729 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-sent: DEBUG 2017-11-07 14:12:24,261 1730 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-received: DEBUG 2017-11-07 14:12:24,261 1730 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name select-time: DEBUG 2017-11-07 14:12:24,318 1787 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name io-time: DEBUG 2017-11-07 14:12:24,322 1791 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name batch-size DEBUG 2017-11-07 14:12:24,323 1792 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name compression-rate DEBUG 2017-11-07 14:12:24,323 1792 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name queue-time DEBUG 2017-11-07 14:12:24,323 1792 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name request-time DEBUG 2017-11-07 14:12:24,323 1792 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name records-per-request DEBUG 2017-11-07 14:12:24,324 1793 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name record-retries DEBUG 2017-11-07 14:12:24,324 1793 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name errors DEBUG 2017-11-07 14:12:24,324 1793 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name record-size-max DEBUG 2017-11-07 14:12:24,325 1794 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name batch-split-rate DEBUG 2017-11-07 14:12:24,326 1795 org.apache.kafka.clients.producer.internals.Sender [kafka-producer-network-thread | producer-1] Starting Kafka producer I/O thread. INFO 2017-11-07 14:12:24,329 1798 org.apache.kafka.common.utils.AppInfoParser [main] Kafka version : 0.11.0.1 INFO 2017-11-07 14:12:24,329 1798 org.apache.kafka.common.utils.AppInfoParser [main] Kafka commitId : c2a0d5f9b1f45bf5 DEBUG 2017-11-07 14:12:24,330 1799 org.apache.kafka.clients.producer.KafkaProducer [main] Kafka producer with client id producer-1 created DEBUG 2017-11-07 14:12:24,331 1800 org.apache.kafka.clients.producer.internals.TransactionManager [main] [TransactionalId invoices-transactions] Transition from state UNINITIALIZED to INITIALIZING INFO 2017-11-07 14:12:24,331 1800 org.apache.kafka.clients.producer.internals.TransactionManager [main] [TransactionalId invoices-transactions] ProducerId set to -1 with epoch -1 DEBUG 2017-11-07 14:12:24,421 1890 org.apache.kafka.clients.producer.internals.TransactionManager [main] [TransactionalId invoices-transactions] Enqueuing transactional request (type=InitProducerIdRequest, transactionalId=invoices-transactions, transactionTimeoutMs=5000) DEBUG 2017-11-07 14:12:24,429 1898 org.apache.kafka.clients.producer.internals.TransactionManager [kafka-producer-network-thread | producer-1] [TransactionalId invoices-transactions] Enqueuing transactional request (type=FindCoordinatorRequest, coordinatorKey=invoices-transactions, coordinatorType=TRANSACTION) DEBUG 2017-11-07 14:12:24,429 1898 org.apache.kafka.clients.producer.internals.TransactionManager [kafka-producer-network-thread | producer-1] [TransactionalId invoices-transactions] Enqueuing transactional request (type=InitProducerIdRequest, transactionalId=invoices-transactions, transactionTimeoutMs=5000) DEBUG 2017-11-07 14:12:24,531 2000 org.apache.kafka.clients.NetworkClient [kafka-producer-network-thread | producer-1] Initiating connection to node kafka-kafka.kafka.svc.cluster.local:9092 (id: -1 rack: null) DEBUG 2017-11-07 14:12:24,550 2019 org.apache.kafka.common.metrics.Metrics [kafka-producer-network-thread | producer-1] Added sensor with name node--1.bytes-sent DEBUG 2017-11-07 14:12:24,551 2020 org.apache.kafka.common.metrics.Metrics [kafka-producer-network-thread | producer-1] Added sensor with name node--1.bytes-received DEBUG 2017-11-07 14:12:24,551 2020 org.apache.kafka.common.metrics.Metrics [kafka-producer-network-thread | producer-1] Added sensor with name node--1.latency DEBUG 2017-11-07 14:12:24,552 2021 org.apache.kafka.common.network.Selector [kafka-producer-network-thread | producer-1] Created socket with SO_RCVBUF = 32768, SO_SNDBUF = 131072, SO_TIMEOUT = 0 to node -1 DEBUG 2017-11-07 14:12:24,552 2021 org.apache.kafka.clients.NetworkClient [kafka-producer-network-thread | producer-1] Completed connection to node -1. Fetching API versions. DEBUG 2017-11-07 14:12:24,552 2021 org.apache.kafka.clients.NetworkClient [kafka-producer-network-thread | producer-1] Initiating API versions fetch from node -1. DEBUG 2017-11-07 14:12:25,135 2604 org.apache.kafka.clients.NetworkClient [kafka-producer-network-thread | producer-1] Recorded API versions for node -1: (Produce(0): 0 to 3 [usable: 3], Fetch(1): 0 to 5 [usable: 5], Offsets(2): 0 to 2 [usable: 2], Metadata(3): 0 to 4 [usable: 4], LeaderAndIsr(4): 0 [usable: 0], StopReplica(5): 0 [usable: 0], UpdateMetadata(6): 0 to 3 [usable: 3], ControlledShutdown(7): 1 [usable: 1], OffsetCommit(8): 0 to 3 [usable: 3], OffsetFetch(9): 0 to 3 [usable: 3], FindCoordinator(10): 0 to 1 [usable: 1], JoinGroup(11): 0 to 2 [usable: 2], Heartbeat(12): 0 to 1 [usable: 1], LeaveGroup(13): 0 to 1 [usable: 1], SyncGroup(14): 0 to 1 [usable: 1], DescribeGroups(15): 0 to 1 [usable: 1], ListGroups(16): 0 to 1 [usable: 1], SaslHandshake(17): 0 [usable: 0], ApiVersions(18): 0 to 1 [usable: 1], CreateTopics(19): 0 to 2 [usable: 2], DeleteTopics(20): 0 to 1 [usable: 1], DeleteRecords(21): 0 [usable: 0], InitProducerId(22): 0 [usable: 0], OffsetForLeaderEpoch(23): 0 [usable: 0], AddPartitionsToTxn(24): 0 [usable: 0], AddOffsetsToTxn(25): 0 [usable: 0], EndTxn(26): 0 [usable: 0], WriteTxnMarkers(27): 0 [usable: 0], TxnOffsetCommit(28): 0 [usable: 0], DescribeAcls(29): 0 [usable: 0], CreateAcls(30): 0 [usable: 0], DeleteAcls(31): 0 [usable: 0], DescribeConfigs(32): 0 [usable: 0], AlterConfigs(33): 0 [usable: 0]) DEBUG 2017-11-07 14:12:25,135 2604 org.apache.kafka.clients.producer.internals.Sender [kafka-producer-network-thread | producer-1] [TransactionalId invoices-transactions] Sending transactional request (type=FindCoordinatorRequest, coordinatorKey=invoices-transactions, coordinatorType=TRANSACTION) to node kafka-kafka.kafka.svc.cluster.local:9092 (id: -1 rack: null) DEBUG 2017-11-07 14:12:25,220 2689 org.apache.kafka.clients.NetworkClient [kafka-producer-network-thread | producer-1] Initiating connection to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:25,222 2691 org.apache.kafka.common.metrics.Metrics [kafka-producer-network-thread | producer-1] Added sensor with name node-2.bytes-sent DEBUG 2017-11-07 14:12:25,223 2692 org.apache.kafka.common.metrics.Metrics [kafka-producer-network-thread | producer-1] Added sensor with name node-2.bytes-received DEBUG 2017-11-07 14:12:25,223 2692 org.apache.kafka.common.metrics.Metrics [kafka-producer-network-thread | producer-1] Added sensor with name node-2.latency DEBUG 2017-11-07 14:12:25,223 2692 org.apache.kafka.common.network.Selector [kafka-producer-network-thread | producer-1] Created socket with SO_RCVBUF = 32768, SO_SNDBUF = 131072, SO_TIMEOUT = 0 to node 2 DEBUG 2017-11-07 14:12:25,223 2692 org.apache.kafka.clients.NetworkClient [kafka-producer-network-thread | producer-1] Completed connection to node 2. Fetching API versions. DEBUG 2017-11-07 14:12:25,223 2692 org.apache.kafka.clients.NetworkClient [kafka-producer-network-thread | producer-1] Initiating API versions fetch from node 2. DEBUG 2017-11-07 14:12:25,225 2694 org.apache.kafka.clients.NetworkClient [kafka-producer-network-thread | producer-1] Recorded API versions for node 2: (Produce(0): 0 to 3 [usable: 3], Fetch(1): 0 to 5 [usable: 5], Offsets(2): 0 to 2 [usable: 2], Metadata(3): 0 to 4 [usable: 4], LeaderAndIsr(4): 0 [usable: 0], StopReplica(5): 0 [usable: 0], UpdateMetadata(6): 0 to 3 [usable: 3], ControlledShutdown(7): 1 [usable: 1], OffsetCommit(8): 0 to 3 [usable: 3], OffsetFetch(9): 0 to 3 [usable: 3], FindCoordinator(10): 0 to 1 [usable: 1], JoinGroup(11): 0 to 2 [usable: 2], Heartbeat(12): 0 to 1 [usable: 1], LeaveGroup(13): 0 to 1 [usable: 1], SyncGroup(14): 0 to 1 [usable: 1], DescribeGroups(15): 0 to 1 [usable: 1], ListGroups(16): 0 to 1 [usable: 1], SaslHandshake(17): 0 [usable: 0], ApiVersions(18): 0 to 1 [usable: 1], CreateTopics(19): 0 to 2 [usable: 2], DeleteTopics(20): 0 to 1 [usable: 1], DeleteRecords(21): 0 [usable: 0], InitProducerId(22): 0 [usable: 0], OffsetForLeaderEpoch(23): 0 [usable: 0], AddPartitionsToTxn(24): 0 [usable: 0], AddOffsetsToTxn(25): 0 [usable: 0], EndTxn(26): 0 [usable: 0], WriteTxnMarkers(27): 0 [usable: 0], TxnOffsetCommit(28): 0 [usable: 0], DescribeAcls(29): 0 [usable: 0], CreateAcls(30): 0 [usable: 0], DeleteAcls(31): 0 [usable: 0], DescribeConfigs(32): 0 [usable: 0], AlterConfigs(33): 0 [usable: 0]) DEBUG 2017-11-07 14:12:25,325 2794 org.apache.kafka.clients.producer.internals.Sender [kafka-producer-network-thread | producer-1] [TransactionalId invoices-transactions] Sending transactional request (type=InitProducerIdRequest, transactionalId=invoices-transactions, transactionTimeoutMs=5000) to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) INFO 2017-11-07 14:12:25,328 2797 org.apache.kafka.clients.producer.internals.TransactionManager [kafka-producer-network-thread | producer-1] [TransactionalId invoices-transactions] ProducerId set to 64000 with epoch 16 DEBUG 2017-11-07 14:12:25,328 2797 org.apache.kafka.clients.producer.internals.TransactionManager [kafka-producer-network-thread | producer-1] [TransactionalId invoices-transactions] Transition from state INITIALIZING to READY INFO 2017-11-07 14:12:25,428 2897 org.apache.kafka.streams.StreamsConfig [main] StreamsConfig values: application.id = invoices application.server = bootstrap.servers = [kafka-kafka.kafka.svc.cluster.local:9092] buffered.records.per.partition = 1000 cache.max.bytes.buffering = 10485760 client.id = commit.interval.ms = 30000 connections.max.idle.ms = 540000 default.key.serde = class org.apache.kafka.common.serialization.Serdes$ByteArraySerde default.timestamp.extractor = class org.apache.kafka.streams.processor.FailOnInvalidTimestamp default.value.serde = class io.confluent.kafka.streams.serdes.avro.SpecificAvroSerde key.serde = null metadata.max.age.ms = 300000 metric.reporters = [] metrics.num.samples = 2 metrics.recording.level = INFO metrics.sample.window.ms = 30000 num.standby.replicas = 0 num.stream.threads = 1 partition.grouper = class org.apache.kafka.streams.processor.DefaultPartitionGrouper poll.ms = 100 processing.guarantee = at_least_once receive.buffer.bytes = 32768 reconnect.backoff.max.ms = 1000 reconnect.backoff.ms = 50 replication.factor = 1 request.timeout.ms = 40000 retry.backoff.ms = 100 rocksdb.config.setter = null security.protocol = PLAINTEXT send.buffer.bytes = 131072 state.cleanup.delay.ms = 600000 state.dir = /tmp/kafka-streams timestamp.extractor = null value.serde = null windowstore.changelog.additional.retention.ms = 86400000 zookeeper.connect = INFO 2017-11-07 14:12:25,622 3091 org.apache.kafka.clients.consumer.ConsumerConfig [main] ConsumerConfig values: auto.commit.interval.ms = 5000 auto.offset.reset = earliest bootstrap.servers = [kafka-kafka.kafka.svc.cluster.local:9092] check.crcs = true client.id = invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-global-restore-consumer connections.max.idle.ms = 540000 enable.auto.commit = false exclude.internal.topics = true fetch.max.bytes = 52428800 fetch.max.wait.ms = 500 fetch.min.bytes = 1 group.id = heartbeat.interval.ms = 3000 interceptor.classes = null internal.leave.group.on.close = false isolation.level = read_uncommitted key.deserializer = class org.apache.kafka.common.serialization.ByteArrayDeserializer max.partition.fetch.bytes = 1048576 max.poll.interval.ms = 2147483647 max.poll.records = 1000 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 = 305000 retry.backoff.ms = 100 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.mechanism = GSSAPI security.protocol = PLAINTEXT send.buffer.bytes = 131072 session.timeout.ms = 10000 ssl.cipher.suites = null ssl.enabled.protocols = [TLSv1.2, TLSv1.1, TLSv1] ssl.endpoint.identification.algorithm = null ssl.key.password = null ssl.keymanager.algorithm = SunX509 ssl.keystore.location = null ssl.keystore.password = null ssl.keystore.type = JKS ssl.protocol = TLS ssl.provider = null ssl.secure.random.implementation = null ssl.trustmanager.algorithm = PKIX ssl.truststore.location = null ssl.truststore.password = null ssl.truststore.type = JKS value.deserializer = class org.apache.kafka.common.serialization.ByteArrayDeserializer DEBUG 2017-11-07 14:12:25,623 3092 org.apache.kafka.clients.consumer.KafkaConsumer [main] Starting the Kafka consumer DEBUG 2017-11-07 14:12:25,624 3093 org.apache.kafka.clients.Metadata [main] Updated cluster metadata version 1 to Cluster(id = null, nodes = [kafka-kafka.kafka.svc.cluster.local:9092 (id: -1 rack: null)], partitions = []) DEBUG 2017-11-07 14:12:25,630 3099 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name fetch-throttle-time DEBUG 2017-11-07 14:12:25,718 3187 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name connections-closed: DEBUG 2017-11-07 14:12:25,718 3187 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name connections-created: DEBUG 2017-11-07 14:12:25,719 3188 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-sent-received: DEBUG 2017-11-07 14:12:25,719 3188 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-sent: DEBUG 2017-11-07 14:12:25,719 3188 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-received: DEBUG 2017-11-07 14:12:25,720 3189 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name select-time: DEBUG 2017-11-07 14:12:25,720 3189 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name io-time: DEBUG 2017-11-07 14:12:25,736 3205 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name heartbeat-latency DEBUG 2017-11-07 14:12:25,736 3205 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name join-latency DEBUG 2017-11-07 14:12:25,736 3205 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name sync-latency DEBUG 2017-11-07 14:12:25,738 3207 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name commit-latency DEBUG 2017-11-07 14:12:25,821 3290 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-fetched DEBUG 2017-11-07 14:12:25,822 3291 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name records-fetched DEBUG 2017-11-07 14:12:25,822 3291 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name fetch-latency DEBUG 2017-11-07 14:12:25,823 3292 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name records-lag INFO 2017-11-07 14:12:25,823 3292 org.apache.kafka.common.utils.AppInfoParser [main] Kafka version : 0.11.0.1 INFO 2017-11-07 14:12:25,823 3292 org.apache.kafka.common.utils.AppInfoParser [main] Kafka commitId : c2a0d5f9b1f45bf5 DEBUG 2017-11-07 14:12:25,823 3292 org.apache.kafka.clients.consumer.KafkaConsumer [main] Kafka consumer with client id invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-global-restore-consumer created DEBUG 2017-11-07 14:12:25,839 3308 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name thread.invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1.commit-latency DEBUG 2017-11-07 14:12:25,839 3308 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name thread.invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1.poll-latency DEBUG 2017-11-07 14:12:25,839 3308 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name thread.invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1.process-latency DEBUG 2017-11-07 14:12:25,840 3309 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name thread.invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1.punctuate-latency DEBUG 2017-11-07 14:12:25,840 3309 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name thread.invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1.task-created DEBUG 2017-11-07 14:12:25,840 3309 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name thread.invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1.task-closed DEBUG 2017-11-07 14:12:25,840 3309 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name thread.invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1.skipped-records INFO 2017-11-07 14:12:25,840 3309 org.apache.kafka.streams.processor.internals.StreamThread [main] stream-thread [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1] Creating consumer client INFO 2017-11-07 14:12:25,918 3387 org.apache.kafka.clients.consumer.ConsumerConfig [main] ConsumerConfig values: auto.commit.interval.ms = 5000 auto.offset.reset = earliest bootstrap.servers = [kafka-kafka.kafka.svc.cluster.local:9092] check.crcs = true client.id = invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1-consumer connections.max.idle.ms = 540000 enable.auto.commit = false exclude.internal.topics = true fetch.max.bytes = 52428800 fetch.max.wait.ms = 500 fetch.min.bytes = 1 group.id = invoices heartbeat.interval.ms = 3000 interceptor.classes = null internal.leave.group.on.close = false isolation.level = read_uncommitted key.deserializer = class org.apache.kafka.common.serialization.ByteArrayDeserializer max.partition.fetch.bytes = 1048576 max.poll.interval.ms = 2147483647 max.poll.records = 1000 metadata.max.age.ms = 300000 metric.reporters = [] metrics.num.samples = 2 metrics.recording.level = INFO metrics.sample.window.ms = 30000 partition.assignment.strategy = [org.apache.kafka.streams.processor.internals.StreamPartitionAssignor] receive.buffer.bytes = 65536 reconnect.backoff.max.ms = 1000 reconnect.backoff.ms = 50 request.timeout.ms = 305000 retry.backoff.ms = 100 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.mechanism = GSSAPI security.protocol = PLAINTEXT send.buffer.bytes = 131072 session.timeout.ms = 10000 ssl.cipher.suites = null ssl.enabled.protocols = [TLSv1.2, TLSv1.1, TLSv1] ssl.endpoint.identification.algorithm = null ssl.key.password = null ssl.keymanager.algorithm = SunX509 ssl.keystore.location = null ssl.keystore.password = null ssl.keystore.type = JKS ssl.protocol = TLS ssl.provider = null ssl.secure.random.implementation = null ssl.trustmanager.algorithm = PKIX ssl.truststore.location = null ssl.truststore.password = null ssl.truststore.type = JKS value.deserializer = class org.apache.kafka.common.serialization.ByteArrayDeserializer DEBUG 2017-11-07 14:12:25,918 3387 org.apache.kafka.clients.consumer.KafkaConsumer [main] Starting the Kafka consumer DEBUG 2017-11-07 14:12:25,919 3388 org.apache.kafka.clients.Metadata [main] Updated cluster metadata version 1 to Cluster(id = null, nodes = [kafka-kafka.kafka.svc.cluster.local:9092 (id: -1 rack: null)], partitions = []) DEBUG 2017-11-07 14:12:25,919 3388 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name fetch-throttle-time DEBUG 2017-11-07 14:12:25,920 3389 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name connections-closed: DEBUG 2017-11-07 14:12:25,920 3389 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name connections-created: DEBUG 2017-11-07 14:12:25,920 3389 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-sent-received: DEBUG 2017-11-07 14:12:25,920 3389 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-sent: DEBUG 2017-11-07 14:12:25,920 3389 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-received: DEBUG 2017-11-07 14:12:25,920 3389 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name select-time: DEBUG 2017-11-07 14:12:25,921 3390 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name io-time: DEBUG 2017-11-07 14:12:25,926 3395 org.apache.kafka.clients.Metadata [main] Updated cluster metadata version 1 to Cluster(id = null, nodes = [kafka-kafka.kafka.svc.cluster.local:9092 (id: -1 rack: null)], partitions = []) DEBUG 2017-11-07 14:12:25,927 3396 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name connections-closed: DEBUG 2017-11-07 14:12:25,927 3396 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name connections-created: DEBUG 2017-11-07 14:12:25,927 3396 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-sent-received: DEBUG 2017-11-07 14:12:25,927 3396 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-sent: DEBUG 2017-11-07 14:12:25,928 3397 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-received: DEBUG 2017-11-07 14:12:25,928 3397 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name select-time: DEBUG 2017-11-07 14:12:25,928 3397 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name io-time: DEBUG 2017-11-07 14:12:25,929 3398 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name heartbeat-latency DEBUG 2017-11-07 14:12:25,929 3398 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name join-latency DEBUG 2017-11-07 14:12:25,929 3398 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name sync-latency DEBUG 2017-11-07 14:12:25,929 3398 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name commit-latency DEBUG 2017-11-07 14:12:26,018 3487 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-fetched DEBUG 2017-11-07 14:12:26,018 3487 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name records-fetched DEBUG 2017-11-07 14:12:26,019 3488 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name fetch-latency DEBUG 2017-11-07 14:12:26,019 3488 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name records-lag INFO 2017-11-07 14:12:26,019 3488 org.apache.kafka.common.utils.AppInfoParser [main] Kafka version : 0.11.0.1 INFO 2017-11-07 14:12:26,019 3488 org.apache.kafka.common.utils.AppInfoParser [main] Kafka commitId : c2a0d5f9b1f45bf5 DEBUG 2017-11-07 14:12:26,019 3488 org.apache.kafka.clients.consumer.KafkaConsumer [main] Kafka consumer with client id invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1-consumer created INFO 2017-11-07 14:12:26,019 3488 org.apache.kafka.streams.processor.internals.StreamThread [main] stream-thread [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1] Creating restore consumer client INFO 2017-11-07 14:12:26,020 3489 org.apache.kafka.clients.consumer.ConsumerConfig [main] ConsumerConfig values: auto.commit.interval.ms = 5000 auto.offset.reset = earliest bootstrap.servers = [kafka-kafka.kafka.svc.cluster.local:9092] check.crcs = true client.id = invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1-restore-consumer connections.max.idle.ms = 540000 enable.auto.commit = false exclude.internal.topics = true fetch.max.bytes = 52428800 fetch.max.wait.ms = 500 fetch.min.bytes = 1 group.id = heartbeat.interval.ms = 3000 interceptor.classes = null internal.leave.group.on.close = false isolation.level = read_uncommitted key.deserializer = class org.apache.kafka.common.serialization.ByteArrayDeserializer max.partition.fetch.bytes = 1048576 max.poll.interval.ms = 2147483647 max.poll.records = 1000 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 = 305000 retry.backoff.ms = 100 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.mechanism = GSSAPI security.protocol = PLAINTEXT send.buffer.bytes = 131072 session.timeout.ms = 10000 ssl.cipher.suites = null ssl.enabled.protocols = [TLSv1.2, TLSv1.1, TLSv1] ssl.endpoint.identification.algorithm = null ssl.key.password = null ssl.keymanager.algorithm = SunX509 ssl.keystore.location = null ssl.keystore.password = null ssl.keystore.type = JKS ssl.protocol = TLS ssl.provider = null ssl.secure.random.implementation = null ssl.trustmanager.algorithm = PKIX ssl.truststore.location = null ssl.truststore.password = null ssl.truststore.type = JKS value.deserializer = class org.apache.kafka.common.serialization.ByteArrayDeserializer DEBUG 2017-11-07 14:12:26,020 3489 org.apache.kafka.clients.consumer.KafkaConsumer [main] Starting the Kafka consumer DEBUG 2017-11-07 14:12:26,021 3490 org.apache.kafka.clients.Metadata [main] Updated cluster metadata version 1 to Cluster(id = null, nodes = [kafka-kafka.kafka.svc.cluster.local:9092 (id: -1 rack: null)], partitions = []) DEBUG 2017-11-07 14:12:26,021 3490 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name fetch-throttle-time DEBUG 2017-11-07 14:12:26,021 3490 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name connections-closed: DEBUG 2017-11-07 14:12:26,021 3490 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name connections-created: DEBUG 2017-11-07 14:12:26,022 3491 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-sent-received: DEBUG 2017-11-07 14:12:26,022 3491 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-sent: DEBUG 2017-11-07 14:12:26,022 3491 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-received: DEBUG 2017-11-07 14:12:26,022 3491 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name select-time: DEBUG 2017-11-07 14:12:26,023 3492 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name io-time: DEBUG 2017-11-07 14:12:26,023 3492 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name heartbeat-latency DEBUG 2017-11-07 14:12:26,023 3492 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name join-latency DEBUG 2017-11-07 14:12:26,024 3493 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name sync-latency DEBUG 2017-11-07 14:12:26,024 3493 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name commit-latency DEBUG 2017-11-07 14:12:26,025 3494 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name bytes-fetched DEBUG 2017-11-07 14:12:26,025 3494 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name records-fetched DEBUG 2017-11-07 14:12:26,025 3494 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name fetch-latency DEBUG 2017-11-07 14:12:26,026 3495 org.apache.kafka.common.metrics.Metrics [main] Added sensor with name records-lag INFO 2017-11-07 14:12:26,026 3495 org.apache.kafka.common.utils.AppInfoParser [main] Kafka version : 0.11.0.1 INFO 2017-11-07 14:12:26,026 3495 org.apache.kafka.common.utils.AppInfoParser [main] Kafka commitId : c2a0d5f9b1f45bf5 DEBUG 2017-11-07 14:12:26,026 3495 org.apache.kafka.clients.consumer.KafkaConsumer [main] Kafka consumer with client id invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-StreamThread-1-restore-consumer created DEBUG 2017-11-07 14:12:26,141 3610 org.apache.kafka.streams.KafkaStreams [Thread-1] stream-client [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f] Starting Kafka Stream process. DEBUG 2017-11-07 14:12:26,431 3900 org.apache.kafka.clients.Metadata [Thread-1] Updated cluster metadata version 1 to Cluster(id = null, nodes = [kafka-kafka.kafka.svc.cluster.local:9092 (id: -1 rack: null)], partitions = []) DEBUG 2017-11-07 14:12:26,432 3901 org.apache.kafka.common.metrics.Metrics [Thread-1] Added sensor with name connections-closed: DEBUG 2017-11-07 14:12:26,518 3987 org.apache.kafka.common.metrics.Metrics [Thread-1] Added sensor with name connections-created: DEBUG 2017-11-07 14:12:26,518 3987 org.apache.kafka.common.metrics.Metrics [Thread-1] Added sensor with name bytes-sent-received: DEBUG 2017-11-07 14:12:26,518 3987 org.apache.kafka.common.metrics.Metrics [Thread-1] Added sensor with name bytes-sent: DEBUG 2017-11-07 14:12:26,519 3988 org.apache.kafka.common.metrics.Metrics [Thread-1] Added sensor with name bytes-received: DEBUG 2017-11-07 14:12:26,519 3988 org.apache.kafka.common.metrics.Metrics [Thread-1] Added sensor with name select-time: DEBUG 2017-11-07 14:12:26,519 3988 org.apache.kafka.common.metrics.Metrics [Thread-1] Added sensor with name io-time: DEBUG 2017-11-07 14:12:26,520 3989 org.apache.kafka.clients.Metadata [Thread-1] Updated cluster metadata version 1 to Cluster(id = null, nodes = [kafka-kafka.kafka.svc.cluster.local:9092 (id: -1 rack: null)], partitions = []) DEBUG 2017-11-07 14:12:26,520 3989 org.apache.kafka.clients.NetworkClient [Thread-1] Initiating connection to node kafka-kafka.kafka.svc.cluster.local:9092 (id: -1 rack: null) DEBUG 2017-11-07 14:12:26,521 3990 org.apache.kafka.common.metrics.Metrics [Thread-1] Added sensor with name node--1.bytes-sent DEBUG 2017-11-07 14:12:26,521 3990 org.apache.kafka.common.metrics.Metrics [Thread-1] Added sensor with name node--1.bytes-received DEBUG 2017-11-07 14:12:26,521 3990 org.apache.kafka.common.metrics.Metrics [Thread-1] Added sensor with name node--1.latency DEBUG 2017-11-07 14:12:26,521 3990 org.apache.kafka.common.network.Selector [Thread-1] Created socket with SO_RCVBUF = 32768, SO_SNDBUF = 131072, SO_TIMEOUT = 0 to node -1 DEBUG 2017-11-07 14:12:26,522 3991 org.apache.kafka.clients.NetworkClient [Thread-1] Completed connection to node -1. Fetching API versions. DEBUG 2017-11-07 14:12:26,522 3991 org.apache.kafka.clients.NetworkClient [Thread-1] Initiating API versions fetch from node -1. DEBUG 2017-11-07 14:12:26,525 3994 org.apache.kafka.clients.NetworkClient [Thread-1] Recorded API versions for node -1: (Produce(0): 0 to 3 [usable: 3], Fetch(1): 0 to 5 [usable: 5], Offsets(2): 0 to 2 [usable: 2], Metadata(3): 0 to 4 [usable: 4], LeaderAndIsr(4): 0 [usable: 0], StopReplica(5): 0 [usable: 0], UpdateMetadata(6): 0 to 3 [usable: 3], ControlledShutdown(7): 1 [usable: 1], OffsetCommit(8): 0 to 3 [usable: 3], OffsetFetch(9): 0 to 3 [usable: 3], FindCoordinator(10): 0 to 1 [usable: 1], JoinGroup(11): 0 to 2 [usable: 2], Heartbeat(12): 0 to 1 [usable: 1], LeaveGroup(13): 0 to 1 [usable: 1], SyncGroup(14): 0 to 1 [usable: 1], DescribeGroups(15): 0 to 1 [usable: 1], ListGroups(16): 0 to 1 [usable: 1], SaslHandshake(17): 0 [usable: 0], ApiVersions(18): 0 to 1 [usable: 1], CreateTopics(19): 0 to 2 [usable: 2], DeleteTopics(20): 0 to 1 [usable: 1], DeleteRecords(21): 0 [usable: 0], InitProducerId(22): 0 [usable: 0], OffsetForLeaderEpoch(23): 0 [usable: 0], AddPartitionsToTxn(24): 0 [usable: 0], AddOffsetsToTxn(25): 0 [usable: 0], EndTxn(26): 0 [usable: 0], WriteTxnMarkers(27): 0 [usable: 0], TxnOffsetCommit(28): 0 [usable: 0], DescribeAcls(29): 0 [usable: 0], CreateAcls(30): 0 [usable: 0], DeleteAcls(31): 0 [usable: 0], DescribeConfigs(32): 0 [usable: 0], AlterConfigs(33): 0 [usable: 0]) DEBUG 2017-11-07 14:12:26,577 4046 org.apache.kafka.common.metrics.Metrics [Thread-1] Removed sensor with name connections-closed: DEBUG 2017-11-07 14:12:26,578 4047 org.apache.kafka.common.metrics.Metrics [Thread-1] Removed sensor with name connections-created: DEBUG 2017-11-07 14:12:26,578 4047 org.apache.kafka.common.metrics.Metrics [Thread-1] Removed sensor with name bytes-sent-received: DEBUG 2017-11-07 14:12:26,578 4047 org.apache.kafka.common.metrics.Metrics [Thread-1] Removed sensor with name bytes-sent: DEBUG 2017-11-07 14:12:26,578 4047 org.apache.kafka.common.metrics.Metrics [Thread-1] Removed sensor with name bytes-received: DEBUG 2017-11-07 14:12:26,579 4048 org.apache.kafka.common.metrics.Metrics [Thread-1] Removed sensor with name select-time: DEBUG 2017-11-07 14:12:26,579 4048 org.apache.kafka.common.metrics.Metrics [Thread-1] Removed sensor with name io-time: DEBUG 2017-11-07 14:12:26,579 4048 org.apache.kafka.common.metrics.Metrics [Thread-1] Removed sensor with name node--1.bytes-sent DEBUG 2017-11-07 14:12:26,579 4048 org.apache.kafka.common.metrics.Metrics [Thread-1] Removed sensor with name node--1.bytes-received DEBUG 2017-11-07 14:12:26,580 4049 org.apache.kafka.common.metrics.Metrics [Thread-1] Removed sensor with name node--1.latency INFO 2017-11-07 14:12:26,627 4096 io.confluent.kafka.serializers.KafkaAvroSerializerConfig [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] KafkaAvroSerializerConfig values: schema.registry.url = [http://sad-squid-schema-registry.schema-registry.svc.cluster.local:8000] max.schemas.per.subject = 1000 INFO 2017-11-07 14:12:26,632 4101 io.confluent.kafka.serializers.KafkaAvroDeserializerConfig [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] KafkaAvroDeserializerConfig values: schema.registry.url = [http://sad-squid-schema-registry.schema-registry.svc.cluster.local:8000] max.schemas.per.subject = 1000 specific.avro.reader = true DEBUG 2017-11-07 14:12:26,727 4196 org.apache.kafka.streams.processor.internals.StateDirectory [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] stream-thread [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Acquired global state dir lock DEBUG 2017-11-07 14:12:26,728 4197 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name put DEBUG 2017-11-07 14:12:26,728 4197 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name orders-put DEBUG 2017-11-07 14:12:26,729 4198 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name put-if-absent DEBUG 2017-11-07 14:12:26,729 4198 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name orders-put-if-absent DEBUG 2017-11-07 14:12:26,729 4198 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name get DEBUG 2017-11-07 14:12:26,730 4199 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name orders-get DEBUG 2017-11-07 14:12:26,730 4199 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name delete DEBUG 2017-11-07 14:12:26,730 4199 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name orders-delete DEBUG 2017-11-07 14:12:26,731 4200 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name put-all DEBUG 2017-11-07 14:12:26,731 4200 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name orders-put-all DEBUG 2017-11-07 14:12:26,731 4200 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name all DEBUG 2017-11-07 14:12:26,732 4201 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name orders-all DEBUG 2017-11-07 14:12:26,732 4201 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name range DEBUG 2017-11-07 14:12:26,732 4201 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name orders-range DEBUG 2017-11-07 14:12:26,732 4201 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name flush DEBUG 2017-11-07 14:12:26,733 4202 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name orders-flush DEBUG 2017-11-07 14:12:26,733 4202 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restore DEBUG 2017-11-07 14:12:26,733 4202 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name orders-restore INFO 2017-11-07 14:12:27,640 5109 org.apache.kafka.streams.processor.internals.GlobalStateManagerImpl [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] restoring state for global store orders DEBUG 2017-11-07 14:12:27,644 5113 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Initiating connection to node kafka-kafka.kafka.svc.cluster.local:9092 (id: -1 rack: null) DEBUG 2017-11-07 14:12:27,646 5115 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name node--1.bytes-sent DEBUG 2017-11-07 14:12:27,646 5115 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name node--1.bytes-received DEBUG 2017-11-07 14:12:27,646 5115 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name node--1.latency DEBUG 2017-11-07 14:12:27,646 5115 org.apache.kafka.common.network.Selector [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Created socket with SO_RCVBUF = 65536, SO_SNDBUF = 131072, SO_TIMEOUT = 0 to node -1 DEBUG 2017-11-07 14:12:27,647 5116 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Completed connection to node -1. Fetching API versions. DEBUG 2017-11-07 14:12:27,647 5116 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Initiating API versions fetch from node -1. DEBUG 2017-11-07 14:12:27,650 5119 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Recorded API versions for node -1: (Produce(0): 0 to 3 [usable: 3], Fetch(1): 0 to 5 [usable: 5], Offsets(2): 0 to 2 [usable: 2], Metadata(3): 0 to 4 [usable: 4], LeaderAndIsr(4): 0 [usable: 0], StopReplica(5): 0 [usable: 0], UpdateMetadata(6): 0 to 3 [usable: 3], ControlledShutdown(7): 1 [usable: 1], OffsetCommit(8): 0 to 3 [usable: 3], OffsetFetch(9): 0 to 3 [usable: 3], FindCoordinator(10): 0 to 1 [usable: 1], JoinGroup(11): 0 to 2 [usable: 2], Heartbeat(12): 0 to 1 [usable: 1], LeaveGroup(13): 0 to 1 [usable: 1], SyncGroup(14): 0 to 1 [usable: 1], DescribeGroups(15): 0 to 1 [usable: 1], ListGroups(16): 0 to 1 [usable: 1], SaslHandshake(17): 0 [usable: 0], ApiVersions(18): 0 to 1 [usable: 1], CreateTopics(19): 0 to 2 [usable: 2], DeleteTopics(20): 0 to 1 [usable: 1], DeleteRecords(21): 0 [usable: 0], InitProducerId(22): 0 [usable: 0], OffsetForLeaderEpoch(23): 0 [usable: 0], AddPartitionsToTxn(24): 0 [usable: 0], AddOffsetsToTxn(25): 0 [usable: 0], EndTxn(26): 0 [usable: 0], WriteTxnMarkers(27): 0 [usable: 0], TxnOffsetCommit(28): 0 [usable: 0], DescribeAcls(29): 0 [usable: 0], CreateAcls(30): 0 [usable: 0], DeleteAcls(31): 0 [usable: 0], DescribeConfigs(32): 0 [usable: 0], AlterConfigs(33): 0 [usable: 0]) DEBUG 2017-11-07 14:12:27,651 5120 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending metadata request (type=MetadataRequest, topics=) to node kafka-kafka.kafka.svc.cluster.local:9092 (id: -1 rack: null) DEBUG 2017-11-07 14:12:27,720 5189 org.apache.kafka.clients.Metadata [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Updated cluster metadata version 2 to Cluster(id = LLJLwedVTHOXROA2dbB0rQ, nodes = [kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null), kafka-kafka-0.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 0 rack: null), kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null)], partitions = []) DEBUG 2017-11-07 14:12:27,723 5192 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Partition orders-state-0 is unknown for fetching offset, wait for metadata refresh DEBUG 2017-11-07 14:12:27,723 5192 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Initialize connection to node kafka-kafka-0.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 0 rack: null) for sending metadata request DEBUG 2017-11-07 14:12:27,723 5192 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Initiating connection to node kafka-kafka-0.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 0 rack: null) DEBUG 2017-11-07 14:12:27,725 5194 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name node-0.bytes-sent DEBUG 2017-11-07 14:12:27,726 5195 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name node-0.bytes-received DEBUG 2017-11-07 14:12:27,726 5195 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name node-0.latency DEBUG 2017-11-07 14:12:27,726 5195 org.apache.kafka.common.network.Selector [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Created socket with SO_RCVBUF = 65536, SO_SNDBUF = 131072, SO_TIMEOUT = 0 to node 0 DEBUG 2017-11-07 14:12:27,726 5195 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Completed connection to node 0. Fetching API versions. DEBUG 2017-11-07 14:12:27,726 5195 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Initiating API versions fetch from node 0. DEBUG 2017-11-07 14:12:27,727 5196 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Initialize connection to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) for sending metadata request DEBUG 2017-11-07 14:12:27,727 5196 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Initiating connection to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:27,727 5196 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name node-2.bytes-sent DEBUG 2017-11-07 14:12:27,728 5197 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name node-2.bytes-received DEBUG 2017-11-07 14:12:27,728 5197 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name node-2.latency DEBUG 2017-11-07 14:12:27,729 5198 org.apache.kafka.common.network.Selector [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Created socket with SO_RCVBUF = 65536, SO_SNDBUF = 131072, SO_TIMEOUT = 0 to node 2 DEBUG 2017-11-07 14:12:27,729 5198 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Completed connection to node 2. Fetching API versions. DEBUG 2017-11-07 14:12:27,729 5198 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Initiating API versions fetch from node 2. DEBUG 2017-11-07 14:12:27,732 5201 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Initialize connection to node kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) for sending metadata request DEBUG 2017-11-07 14:12:27,732 5201 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Initiating connection to node kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:27,819 5288 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Recorded API versions for node 0: (Produce(0): 0 to 3 [usable: 3], Fetch(1): 0 to 5 [usable: 5], Offsets(2): 0 to 2 [usable: 2], Metadata(3): 0 to 4 [usable: 4], LeaderAndIsr(4): 0 [usable: 0], StopReplica(5): 0 [usable: 0], UpdateMetadata(6): 0 to 3 [usable: 3], ControlledShutdown(7): 1 [usable: 1], OffsetCommit(8): 0 to 3 [usable: 3], OffsetFetch(9): 0 to 3 [usable: 3], FindCoordinator(10): 0 to 1 [usable: 1], JoinGroup(11): 0 to 2 [usable: 2], Heartbeat(12): 0 to 1 [usable: 1], LeaveGroup(13): 0 to 1 [usable: 1], SyncGroup(14): 0 to 1 [usable: 1], DescribeGroups(15): 0 to 1 [usable: 1], ListGroups(16): 0 to 1 [usable: 1], SaslHandshake(17): 0 [usable: 0], ApiVersions(18): 0 to 1 [usable: 1], CreateTopics(19): 0 to 2 [usable: 2], DeleteTopics(20): 0 to 1 [usable: 1], DeleteRecords(21): 0 [usable: 0], InitProducerId(22): 0 [usable: 0], OffsetForLeaderEpoch(23): 0 [usable: 0], AddPartitionsToTxn(24): 0 [usable: 0], AddOffsetsToTxn(25): 0 [usable: 0], EndTxn(26): 0 [usable: 0], WriteTxnMarkers(27): 0 [usable: 0], TxnOffsetCommit(28): 0 [usable: 0], DescribeAcls(29): 0 [usable: 0], CreateAcls(30): 0 [usable: 0], DeleteAcls(31): 0 [usable: 0], DescribeConfigs(32): 0 [usable: 0], AlterConfigs(33): 0 [usable: 0]) DEBUG 2017-11-07 14:12:27,819 5288 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending metadata request (type=MetadataRequest, topics=orders-state) to node kafka-kafka-0.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 0 rack: null) DEBUG 2017-11-07 14:12:27,819 5288 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name node-1.bytes-sent DEBUG 2017-11-07 14:12:27,820 5289 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name node-1.bytes-received DEBUG 2017-11-07 14:12:27,820 5289 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name node-1.latency DEBUG 2017-11-07 14:12:27,820 5289 org.apache.kafka.common.network.Selector [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Created socket with SO_RCVBUF = 65536, SO_SNDBUF = 131072, SO_TIMEOUT = 0 to node 1 DEBUG 2017-11-07 14:12:27,820 5289 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Completed connection to node 1. Fetching API versions. DEBUG 2017-11-07 14:12:27,820 5289 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Initiating API versions fetch from node 1. DEBUG 2017-11-07 14:12:27,821 5290 org.apache.kafka.clients.Metadata [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Updated cluster metadata version 3 to Cluster(id = LLJLwedVTHOXROA2dbB0rQ, nodes = [kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null), kafka-kafka-0.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 0 rack: null), kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null)], partitions = [Partition(topic = orders-state, partition = 0, leader = 1, replicas = [1,2,0], isr = [1,2,0])]) DEBUG 2017-11-07 14:12:27,823 5292 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Recorded API versions for node 1: (Produce(0): 0 to 3 [usable: 3], Fetch(1): 0 to 5 [usable: 5], Offsets(2): 0 to 2 [usable: 2], Metadata(3): 0 to 4 [usable: 4], LeaderAndIsr(4): 0 [usable: 0], StopReplica(5): 0 [usable: 0], UpdateMetadata(6): 0 to 3 [usable: 3], ControlledShutdown(7): 1 [usable: 1], OffsetCommit(8): 0 to 3 [usable: 3], OffsetFetch(9): 0 to 3 [usable: 3], FindCoordinator(10): 0 to 1 [usable: 1], JoinGroup(11): 0 to 2 [usable: 2], Heartbeat(12): 0 to 1 [usable: 1], LeaveGroup(13): 0 to 1 [usable: 1], SyncGroup(14): 0 to 1 [usable: 1], DescribeGroups(15): 0 to 1 [usable: 1], ListGroups(16): 0 to 1 [usable: 1], SaslHandshake(17): 0 [usable: 0], ApiVersions(18): 0 to 1 [usable: 1], CreateTopics(19): 0 to 2 [usable: 2], DeleteTopics(20): 0 to 1 [usable: 1], DeleteRecords(21): 0 [usable: 0], InitProducerId(22): 0 [usable: 0], OffsetForLeaderEpoch(23): 0 [usable: 0], AddPartitionsToTxn(24): 0 [usable: 0], AddOffsetsToTxn(25): 0 [usable: 0], EndTxn(26): 0 [usable: 0], WriteTxnMarkers(27): 0 [usable: 0], TxnOffsetCommit(28): 0 [usable: 0], DescribeAcls(29): 0 [usable: 0], CreateAcls(30): 0 [usable: 0], DeleteAcls(31): 0 [usable: 0], DescribeConfigs(32): 0 [usable: 0], AlterConfigs(33): 0 [usable: 0]) DEBUG 2017-11-07 14:12:27,826 5295 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Handling ListOffsetResponse response for orders-state-0. Fetched offset 114, timestamp -1 DEBUG 2017-11-07 14:12:27,826 5295 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Subscribed to partition(s): orders-state-0 DEBUG 2017-11-07 14:12:27,827 5296 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Seeking to beginning of partition orders-state-0 DEBUG 2017-11-07 14:12:27,828 5297 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Handling ListOffsetResponse response for orders-state-0. Fetched offset 0, timestamp -1 DEBUG 2017-11-07 14:12:27,828 5297 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Resetting offset for partition orders-state-0 to offset 0. DEBUG 2017-11-07 14:12:27,829 5298 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition orders-state-0 at offset 0 to node kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:27,829 5298 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [orders-state-0] to broker kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:27,843 5312 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Recorded API versions for node 2: (Produce(0): 0 to 3 [usable: 3], Fetch(1): 0 to 5 [usable: 5], Offsets(2): 0 to 2 [usable: 2], Metadata(3): 0 to 4 [usable: 4], LeaderAndIsr(4): 0 [usable: 0], StopReplica(5): 0 [usable: 0], UpdateMetadata(6): 0 to 3 [usable: 3], ControlledShutdown(7): 1 [usable: 1], OffsetCommit(8): 0 to 3 [usable: 3], OffsetFetch(9): 0 to 3 [usable: 3], FindCoordinator(10): 0 to 1 [usable: 1], JoinGroup(11): 0 to 2 [usable: 2], Heartbeat(12): 0 to 1 [usable: 1], LeaveGroup(13): 0 to 1 [usable: 1], SyncGroup(14): 0 to 1 [usable: 1], DescribeGroups(15): 0 to 1 [usable: 1], ListGroups(16): 0 to 1 [usable: 1], SaslHandshake(17): 0 [usable: 0], ApiVersions(18): 0 to 1 [usable: 1], CreateTopics(19): 0 to 2 [usable: 2], DeleteTopics(20): 0 to 1 [usable: 1], DeleteRecords(21): 0 [usable: 0], InitProducerId(22): 0 [usable: 0], OffsetForLeaderEpoch(23): 0 [usable: 0], AddPartitionsToTxn(24): 0 [usable: 0], AddOffsetsToTxn(25): 0 [usable: 0], EndTxn(26): 0 [usable: 0], WriteTxnMarkers(27): 0 [usable: 0], TxnOffsetCommit(28): 0 [usable: 0], DescribeAcls(29): 0 [usable: 0], CreateAcls(30): 0 [usable: 0], DeleteAcls(31): 0 [usable: 0], DescribeConfigs(32): 0 [usable: 0], AlterConfigs(33): 0 [usable: 0]) DEBUG 2017-11-07 14:12:27,924 5393 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 0 for partition orders-state-0 returned fetch data (error=NONE, highWaterMark=114, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=117103) DEBUG 2017-11-07 14:12:28,026 5495 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name topic.orders-state.bytes-fetched DEBUG 2017-11-07 14:12:28,026 5495 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name topic.orders-state.records-fetched DEBUG 2017-11-07 14:12:28,027 5496 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name orders-state-0.records-lag DEBUG 2017-11-07 14:12:28,027 5496 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition orders-state-0 at offset 114 to node kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:28,028 5497 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [orders-state-0] to broker kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:28,030 5499 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Unsubscribed all topics or patterns and assigned partitions DEBUG 2017-11-07 14:12:28,030 5499 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Removed sensor with name orders-state-0.records-lag DEBUG 2017-11-07 14:12:28,032 5501 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name hitRatio DEBUG 2017-11-07 14:12:28,033 5502 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name users-put DEBUG 2017-11-07 14:12:28,033 5502 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name users-put-if-absent DEBUG 2017-11-07 14:12:28,033 5502 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name users-get DEBUG 2017-11-07 14:12:28,034 5503 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name users-delete DEBUG 2017-11-07 14:12:28,118 5587 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name users-put-all DEBUG 2017-11-07 14:12:28,118 5587 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name users-all DEBUG 2017-11-07 14:12:28,119 5588 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name users-range DEBUG 2017-11-07 14:12:28,120 5589 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name users-flush DEBUG 2017-11-07 14:12:28,122 5591 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name users-restore got orders INFO 2017-11-07 14:12:28,231 5700 org.apache.kafka.streams.processor.internals.GlobalStateManagerImpl [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] restoring state for global store users DEBUG 2017-11-07 14:12:28,240 5709 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Partition users-state-0 is unknown for fetching offset, wait for metadata refresh DEBUG 2017-11-07 14:12:28,241 5710 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending metadata request (type=MetadataRequest, topics=users-state,orders-state) to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,242 5711 org.apache.kafka.clients.Metadata [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Updated cluster metadata version 4 to Cluster(id = LLJLwedVTHOXROA2dbB0rQ, nodes = [kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null), kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null), kafka-kafka-0.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 0 rack: null)], partitions = [Partition(topic = users-state, partition = 0, leader = 2, replicas = [2,0,1], isr = [1,2,0]), Partition(topic = orders-state, partition = 0, leader = 1, replicas = [1,2,0], isr = [1,2,0])]) DEBUG 2017-11-07 14:12:28,244 5713 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Handling ListOffsetResponse response for users-state-0. Fetched offset 395, timestamp -1 DEBUG 2017-11-07 14:12:28,244 5713 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Subscribed to partition(s): users-state-0 DEBUG 2017-11-07 14:12:28,244 5713 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Seeking to beginning of partition users-state-0 DEBUG 2017-11-07 14:12:28,318 5787 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Handling ListOffsetResponse response for users-state-0. Fetched offset 0, timestamp -1 DEBUG 2017-11-07 14:12:28,318 5787 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Resetting offset for partition users-state-0 to offset 0. DEBUG 2017-11-07 14:12:28,318 5787 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition users-state-0 at offset 0 to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,318 5787 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [users-state-0] to broker kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,343 5812 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 0 for partition users-state-0 returned fetch data (error=NONE, highWaterMark=395, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=43289) DEBUG 2017-11-07 14:12:28,347 5816 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name topic.users-state.bytes-fetched DEBUG 2017-11-07 14:12:28,347 5816 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name topic.users-state.records-fetched DEBUG 2017-11-07 14:12:28,348 5817 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name users-state-0.records-lag DEBUG 2017-11-07 14:12:28,348 5817 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition users-state-0 at offset 393 to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,348 5817 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [users-state-0] to broker kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,350 5819 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 393 for partition users-state-0 returned fetch data (error=NONE, highWaterMark=395, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=335) DEBUG 2017-11-07 14:12:28,351 5820 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition users-state-0 at offset 395 to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,351 5820 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [users-state-0] to broker kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,351 5820 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Unsubscribed all topics or patterns and assigned partitions DEBUG 2017-11-07 14:12:28,351 5820 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Removed sensor with name users-state-0.records-lag DEBUG 2017-11-07 14:12:28,352 5821 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurants-put DEBUG 2017-11-07 14:12:28,352 5821 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurants-put-if-absent DEBUG 2017-11-07 14:12:28,352 5821 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurants-get DEBUG 2017-11-07 14:12:28,352 5821 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurants-delete DEBUG 2017-11-07 14:12:28,352 5821 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurants-put-all DEBUG 2017-11-07 14:12:28,352 5821 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurants-all DEBUG 2017-11-07 14:12:28,353 5822 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurants-range DEBUG 2017-11-07 14:12:28,353 5822 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurants-flush DEBUG 2017-11-07 14:12:28,353 5822 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurants-restore got users INFO 2017-11-07 14:12:28,432 5901 org.apache.kafka.streams.processor.internals.GlobalStateManagerImpl [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] restoring state for global store restaurants DEBUG 2017-11-07 14:12:28,433 5902 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Partition restaurants-state-0 is unknown for fetching offset, wait for metadata refresh DEBUG 2017-11-07 14:12:28,433 5902 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending metadata request (type=MetadataRequest, topics=users-state,restaurants-state) to node kafka-kafka-0.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 0 rack: null) DEBUG 2017-11-07 14:12:28,435 5904 org.apache.kafka.clients.Metadata [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Updated cluster metadata version 5 to Cluster(id = LLJLwedVTHOXROA2dbB0rQ, nodes = [kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null), kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null), kafka-kafka-0.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 0 rack: null)], partitions = [Partition(topic = users-state, partition = 0, leader = 2, replicas = [2,0,1], isr = [1,2,0]), Partition(topic = restaurants-state, partition = 0, leader = 2, replicas = [2,0,1], isr = [1,2,0])]) DEBUG 2017-11-07 14:12:28,530 5999 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 114 for partition orders-state-0 returned fetch data (error=NONE, highWaterMark=114, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=0) DEBUG 2017-11-07 14:12:28,853 6322 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 395 for partition users-state-0 returned fetch data (error=NONE, highWaterMark=395, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=0) DEBUG 2017-11-07 14:12:28,854 6323 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Handling ListOffsetResponse response for restaurants-state-0. Fetched offset 613, timestamp -1 DEBUG 2017-11-07 14:12:28,854 6323 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Subscribed to partition(s): restaurants-state-0 DEBUG 2017-11-07 14:12:28,854 6323 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Seeking to beginning of partition restaurants-state-0 DEBUG 2017-11-07 14:12:28,855 6324 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Handling ListOffsetResponse response for restaurants-state-0. Fetched offset 0, timestamp -1 DEBUG 2017-11-07 14:12:28,856 6325 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Resetting offset for partition restaurants-state-0 to offset 0. DEBUG 2017-11-07 14:12:28,856 6325 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Ignoring fetched records for partition orders-state-0 since it is no longer fetchable DEBUG 2017-11-07 14:12:28,856 6325 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Ignoring fetched records for partition users-state-0 since it is no longer fetchable DEBUG 2017-11-07 14:12:28,856 6325 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition restaurants-state-0 at offset 0 to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,856 6325 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [restaurants-state-0] to broker kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,859 6328 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 0 for partition restaurants-state-0 returned fetch data (error=NONE, highWaterMark=613, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=40459) DEBUG 2017-11-07 14:12:28,919 6388 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name topic.restaurants-state.bytes-fetched DEBUG 2017-11-07 14:12:28,922 6391 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name topic.restaurants-state.records-fetched DEBUG 2017-11-07 14:12:28,922 6391 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurants-state-0.records-lag DEBUG 2017-11-07 14:12:28,922 6391 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition restaurants-state-0 at offset 609 to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,922 6391 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [restaurants-state-0] to broker kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,940 6409 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 609 for partition restaurants-state-0 returned fetch data (error=NONE, highWaterMark=613, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=640) DEBUG 2017-11-07 14:12:28,941 6410 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition restaurants-state-0 at offset 613 to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,941 6410 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [restaurants-state-0] to broker kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:28,941 6410 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Unsubscribed all topics or patterns and assigned partitions DEBUG 2017-11-07 14:12:28,941 6410 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Removed sensor with name restaurants-state-0.records-lag DEBUG 2017-11-07 14:12:28,942 6411 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurant-groups-put DEBUG 2017-11-07 14:12:28,942 6411 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurant-groups-put-if-absent DEBUG 2017-11-07 14:12:28,942 6411 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurant-groups-get DEBUG 2017-11-07 14:12:28,942 6411 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurant-groups-delete DEBUG 2017-11-07 14:12:28,942 6411 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurant-groups-put-all DEBUG 2017-11-07 14:12:28,942 6411 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurant-groups-all DEBUG 2017-11-07 14:12:28,943 6412 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurant-groups-range DEBUG 2017-11-07 14:12:28,943 6412 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurant-groups-flush DEBUG 2017-11-07 14:12:28,943 6412 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurant-groups-restore got restaurants INFO 2017-11-07 14:12:29,040 6509 org.apache.kafka.streams.processor.internals.GlobalStateManagerImpl [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] restoring state for global store restaurant-groups DEBUG 2017-11-07 14:12:29,042 6511 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Partition restaurant-groups-state-0 is unknown for fetching offset, wait for metadata refresh DEBUG 2017-11-07 14:12:29,043 6512 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending metadata request (type=MetadataRequest, topics=restaurant-groups-state,restaurants-state) to node kafka-kafka-0.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 0 rack: null) DEBUG 2017-11-07 14:12:29,047 6516 org.apache.kafka.clients.Metadata [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Updated cluster metadata version 6 to Cluster(id = LLJLwedVTHOXROA2dbB0rQ, nodes = [kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null), kafka-kafka-0.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 0 rack: null), kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null)], partitions = [Partition(topic = restaurant-groups-state, partition = 0, leader = 2, replicas = [2,1,0], isr = [1,2,0]), Partition(topic = restaurants-state, partition = 0, leader = 2, replicas = [2,0,1], isr = [1,2,0])]) DEBUG 2017-11-07 14:12:29,446 6915 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 613 for partition restaurants-state-0 returned fetch data (error=NONE, highWaterMark=613, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=0) DEBUG 2017-11-07 14:12:29,447 6916 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Handling ListOffsetResponse response for restaurant-groups-state-0. Fetched offset 10, timestamp -1 DEBUG 2017-11-07 14:12:29,447 6916 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Subscribed to partition(s): restaurant-groups-state-0 DEBUG 2017-11-07 14:12:29,447 6916 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Seeking to beginning of partition restaurant-groups-state-0 DEBUG 2017-11-07 14:12:29,448 6917 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Handling ListOffsetResponse response for restaurant-groups-state-0. Fetched offset 0, timestamp -1 DEBUG 2017-11-07 14:12:29,448 6917 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Resetting offset for partition restaurant-groups-state-0 to offset 0. DEBUG 2017-11-07 14:12:29,448 6917 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Ignoring fetched records for partition restaurants-state-0 since it is no longer fetchable DEBUG 2017-11-07 14:12:29,448 6917 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition restaurant-groups-state-0 at offset 0 to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:29,448 6917 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [restaurant-groups-state-0] to broker kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:29,450 6919 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 0 for partition restaurant-groups-state-0 returned fetch data (error=NONE, highWaterMark=10, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=1433) DEBUG 2017-11-07 14:12:29,450 6919 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name topic.restaurant-groups-state.bytes-fetched DEBUG 2017-11-07 14:12:29,450 6919 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name topic.restaurant-groups-state.records-fetched DEBUG 2017-11-07 14:12:29,450 6919 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name restaurant-groups-state-0.records-lag DEBUG 2017-11-07 14:12:29,450 6919 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition restaurant-groups-state-0 at offset 10 to node kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:29,450 6919 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [restaurant-groups-state-0] to broker kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null) DEBUG 2017-11-07 14:12:29,451 6920 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Unsubscribed all topics or patterns and assigned partitions DEBUG 2017-11-07 14:12:29,451 6920 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Removed sensor with name restaurant-groups-state-0.records-lag DEBUG 2017-11-07 14:12:29,451 6920 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name invoices-put DEBUG 2017-11-07 14:12:29,451 6920 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name invoices-put-if-absent DEBUG 2017-11-07 14:12:29,451 6920 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name invoices-get DEBUG 2017-11-07 14:12:29,451 6920 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name invoices-delete DEBUG 2017-11-07 14:12:29,452 6921 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name invoices-put-all DEBUG 2017-11-07 14:12:29,452 6921 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name invoices-all DEBUG 2017-11-07 14:12:29,452 6921 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name invoices-range DEBUG 2017-11-07 14:12:29,452 6921 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name invoices-flush DEBUG 2017-11-07 14:12:29,452 6921 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name invoices-restore INFO 2017-11-07 14:12:29,522 6991 org.apache.kafka.streams.processor.internals.GlobalStateManagerImpl [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] restoring state for global store invoices DEBUG 2017-11-07 14:12:29,524 6993 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Partition invoices-state-0 is unknown for fetching offset, wait for metadata refresh DEBUG 2017-11-07 14:12:29,524 6993 org.apache.kafka.clients.NetworkClient [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending metadata request (type=MetadataRequest, topics=invoices-state,restaurant-groups-state) to node kafka-kafka-0.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 0 rack: null) DEBUG 2017-11-07 14:12:29,526 6995 org.apache.kafka.clients.Metadata [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Updated cluster metadata version 7 to Cluster(id = LLJLwedVTHOXROA2dbB0rQ, nodes = [kafka-kafka-0.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 0 rack: null), kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null), kafka-kafka-2.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 2 rack: null)], partitions = [Partition(topic = restaurant-groups-state, partition = 0, leader = 2, replicas = [2,1,0], isr = [1,2,0]), Partition(topic = invoices-state, partition = 0, leader = 1, replicas = [1,0,2], isr = [1,2,0])]) DEBUG 2017-11-07 14:12:29,527 6996 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Handling ListOffsetResponse response for invoices-state-0. Fetched offset 2, timestamp -1 DEBUG 2017-11-07 14:12:29,527 6996 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Subscribed to partition(s): invoices-state-0 DEBUG 2017-11-07 14:12:29,527 6996 org.apache.kafka.clients.consumer.KafkaConsumer [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Seeking to beginning of partition invoices-state-0 DEBUG 2017-11-07 14:12:29,528 6997 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Handling ListOffsetResponse response for invoices-state-0. Fetched offset 0, timestamp -1 DEBUG 2017-11-07 14:12:29,528 6997 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Resetting offset for partition invoices-state-0 to offset 0. DEBUG 2017-11-07 14:12:29,528 6997 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition invoices-state-0 at offset 0 to node kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:29,528 6997 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [invoices-state-0] to broker kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) got groups DEBUG 2017-11-07 14:12:29,530 6999 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 0 for partition invoices-state-0 returned fetch data (error=NONE, highWaterMark=2, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=308) DEBUG 2017-11-07 14:12:29,530 6999 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name topic.invoices-state.bytes-fetched DEBUG 2017-11-07 14:12:29,531 7000 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name topic.invoices-state.records-fetched DEBUG 2017-11-07 14:12:29,531 7000 org.apache.kafka.common.metrics.Metrics [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added sensor with name invoices-state-0.records-lag DEBUG 2017-11-07 14:12:29,531 7000 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition invoices-state-0 at offset 2 to node kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:29,531 7000 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [invoices-state-0] to broker kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:29,952 7421 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 10 for partition restaurant-groups-state-0 returned fetch data (error=NONE, highWaterMark=10, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=0) DEBUG 2017-11-07 14:12:29,952 7421 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Ignoring fetched records for partition restaurant-groups-state-0 since it is no longer fetchable DEBUG 2017-11-07 14:12:30,033 7502 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 2 for partition invoices-state-0 returned fetch data (error=NONE, highWaterMark=2, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=0) DEBUG 2017-11-07 14:12:30,033 7502 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition invoices-state-0 at offset 2 to node kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:30,033 7502 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [invoices-state-0] to broker kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:30,534 8003 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 2 for partition invoices-state-0 returned fetch data (error=NONE, highWaterMark=2, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=0) DEBUG 2017-11-07 14:12:30,535 8004 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition invoices-state-0 at offset 2 to node kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:30,535 8004 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [invoices-state-0] to broker kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:31,094 8563 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 2 for partition invoices-state-0 returned fetch data (error=NONE, highWaterMark=2, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=0) DEBUG 2017-11-07 14:12:31,094 8563 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition invoices-state-0 at offset 2 to node kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:31,094 8563 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [invoices-state-0] to broker kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:31,599 9068 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 2 for partition invoices-state-0 returned fetch data (error=NONE, highWaterMark=2, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=0) DEBUG 2017-11-07 14:12:31,599 9068 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition invoices-state-0 at offset 2 to node kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:31,599 9068 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [invoices-state-0] to broker kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:32,101 9570 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 2 for partition invoices-state-0 returned fetch data (error=NONE, highWaterMark=2, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=0) DEBUG 2017-11-07 14:12:32,101 9570 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition invoices-state-0 at offset 2 to node kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:32,101 9570 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [invoices-state-0] to broker kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:32,603 10072 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Fetch READ_UNCOMMITTED at offset 2 for partition invoices-state-0 returned fetch data (error=NONE, highWaterMark=2, lastStableOffset = -1, logStartOffset = 0, abortedTransactions = null, recordsSizeInBytes=0) DEBUG 2017-11-07 14:12:32,603 10072 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Added READ_UNCOMMITTED fetch request for partition invoices-state-0 at offset 2 to node kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null) DEBUG 2017-11-07 14:12:32,603 10072 org.apache.kafka.clients.consumer.internals.Fetcher [invoices-c146cbee-cb2b-452c-a900-1d12e87c422f-GlobalStreamThread] Sending READ_UNCOMMITTED fetch for partitions [invoices-state-0] to broker kafka-kafka-1.kafka-kafka-headless.kafka.svc.cluster.local:9092 (id: 1 rack: null)