Hi All,
I wrote a Kafka Streams job that went running for 3-4 hrs, after which it
started throwing these errors.Not sure why we got these errors.
I am using Kafka 11.0 both on broker side as well as on consumer side.
*Machine1*
2017-08-08 17:25:35 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-7] partition
assignment took 1003 ms.
current active tasks: [0_24, 0_9]
current standby tasks: []
2017-08-08 17:25:35 INFO StoreChangelogReader:121 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-6] Starting
restoring state stores from changelog topics []
2017-08-08 17:25:35 INFO StreamThread:1345 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-6] Adding
assigned standby tasks {}
2017-08-08 17:25:35 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-6] State
transition from ASSIGNING_PARTITIONS to RUNNING.
2017-08-08 17:25:35 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-6] partition
assignment took 1011 ms.
current active tasks: [0_22, 0_7]
current standby tasks: []
2017-08-08 17:25:35 INFO StoreChangelogReader:121 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-4] Starting
restoring state stores from changelog topics []
2017-08-08 17:25:35 INFO StreamThread:1345 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-4] Adding
assigned standby tasks {}
2017-08-08 17:25:35 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-4] State
transition from ASSIGNING_PARTITIONS to RUNNING.
2017-08-08 17:25:35 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-4] partition
assignment took 1015 ms.
current active tasks: [0_19, 0_4]
current standby tasks: []
2017-08-08 17:25:35 INFO StoreChangelogReader:121 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-11] Starting
restoring state stores from changelog topics []
2017-08-08 17:25:35 INFO StreamThread:1345 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-11] Adding
assigned standby tasks {}
2017-08-08 17:25:35 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-11] State
transition from ASSIGNING_PARTITIONS to RUNNING.
2017-08-08 17:25:35 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-11]
partition assignment took 1043 ms.
current active tasks: [0_20, 0_5]
current standby tasks: []
2017-08-08 17:25:35 INFO StoreChangelogReader:121 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-10] Starting
restoring state stores from changelog topics []
2017-08-08 17:25:35 INFO StreamThread:1345 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-10] Adding
assigned standby tasks {}
2017-08-08 17:25:35 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-10] State
transition from ASSIGNING_PARTITIONS to RUNNING.
2017-08-08 17:25:35 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-10]
partition assignment took 1044 ms.
current active tasks: [0_26, 0_11]
current standby tasks: []
2017-08-08 17:25:35 INFO StoreChangelogReader:121 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-13] Starting
restoring state stores from changelog topics []
2017-08-08 17:25:35 INFO StreamThread:1345 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-13] Adding
assigned standby tasks {}
2017-08-08 17:25:35 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-13] State
transition from ASSIGNING_PARTITIONS to RUNNING.
2017-08-08 17:25:35 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-13]
partition assignment took 1053 ms.
current active tasks: [0_25, 0_10]
current standby tasks: []
2017-08-08 17:25:35 INFO StoreChangelogReader:121 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-12] Starting
restoring state stores from changelog topics []
2017-08-08 17:25:35 INFO StreamThread:1345 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-12] Adding
assigned standby tasks {}
2017-08-08 17:25:35 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-12] State
transition from ASSIGNING_PARTITIONS to RUNNING.
2017-08-08 17:25:35 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-12]
partition assignment took 1057 ms.
current active tasks: [0_23, 0_8]
current standby tasks: []
2017-08-08 17:25:35 INFO StoreChangelogReader:121 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Starting
restoring state stores from changelog topics []
2017-08-08 17:25:35 INFO StreamThread:1345 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Adding
assigned standby tasks {}
2017-08-08 17:25:35 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] State
transition from ASSIGNING_PARTITIONS to RUNNING.
2017-08-08 17:25:35 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14]
partition assignment took 1068 ms.
current active tasks: [0_18, 0_3]
current standby tasks: []
2017-08-08 17:25:35 INFO StoreChangelogReader:121 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-3] Starting
restoring state stores from changelog topics []
2017-08-08 17:25:35 INFO StreamThread:1345 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-3] Adding
assigned standby tasks {}
2017-08-08 17:25:35 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-3] State
transition from ASSIGNING_PARTITIONS to RUNNING.
2017-08-08 17:25:35 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-3] partition
assignment took 1068 ms.
current active tasks: [0_0, 0_15]
current standby tasks: []
2017-08-08 17:25:35 INFO StoreChangelogReader:121 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-8] Starting
restoring state stores from changelog topics []
2017-08-08 17:25:35 INFO StreamThread:1345 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-8] Adding
assigned standby tasks {}
2017-08-08 17:25:35 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-8] State
transition from ASSIGNING_PARTITIONS to RUNNING.
2017-08-08 17:25:35 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-8] partition
assignment took 1074 ms.
current active tasks: [0_17, 0_2]
current standby tasks: []
2017-08-08 17:25:35 INFO StreamThread:1280 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-15] Adding
assigned tasks as active
{0_27=[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-27,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-27, AdServe-27],
0_12=[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-12,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-12, AdServe-12]}
2017-08-08 17:25:35 INFO StreamThread:1229 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-15] Creating
active task 0_27 with assigned partitions
[[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-27,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-27, AdServe-27]]
2017-08-08 17:25:35 INFO ProcessorStateManager:122 - task [0_27] Created
state store manager for task 0_27 with the acquired state dir lock
2017-08-08 17:25:35 INFO StreamThread:1280 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-5] Adding
assigned tasks as active
{0_28=[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-28,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-28, AdServe-28],
0_13=[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-13,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-13, AdServe-13]}
2017-08-08 17:25:35 INFO StreamThread:1229 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-5] Creating
active task 0_28 with assigned partitions
[[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-28,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-28, AdServe-28]]
2017-08-08 17:25:35 INFO ProcessorStateManager:122 - task [0_28] Created
state store manager for task 0_28 with the acquired state dir lock
2017-08-08 17:25:36 INFO ProcessorStateManager:352 - task [0_27] Register
global stores []
2017-08-08 17:25:36 INFO StreamThread:1248 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-15] Created
active task 0_27 with assigned partitions
[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-27,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-27, AdServe-27]
2017-08-08 17:25:36 INFO StreamThread:1229 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-15] Creating
active task 0_12 with assigned partitions
[[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-12,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-12, AdServe-12]]
2017-08-08 17:25:36 INFO ProcessorStateManager:122 - task [0_12] Created
state store manager for task 0_12 with the acquired state dir lock
2017-08-08 17:25:36 INFO ProcessorStateManager:352 - task [0_28] Register
global stores []
2017-08-08 17:25:36 INFO StreamThread:1248 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-5] Created
active task 0_28 with assigned partitions
[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-28,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-28, AdServe-28]
2017-08-08 17:25:36 INFO StreamThread:1229 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-5] Creating
active task 0_13 with assigned partitions
[[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-13,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-13, AdServe-13]]
2017-08-08 17:25:36 INFO ProcessorStateManager:122 - task [0_13] Created
state store manager for task 0_13 with the acquired state dir lock
2017-08-08 17:25:36 INFO ProcessorStateManager:352 - task [0_13] Register
global stores []
2017-08-08 17:25:36 INFO ProcessorStateManager:352 - task [0_12] Register
global stores []
2017-08-08 17:25:36 INFO StreamThread:1248 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-5] Created
active task 0_13 with assigned partitions
[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-13,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-13, AdServe-13]
2017-08-08 17:25:36 INFO StoreChangelogReader:121 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-5] Starting
restoring state stores from changelog topics []
2017-08-08 17:25:36 INFO StreamThread:1345 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-5] Adding
assigned standby tasks {}
2017-08-08 17:25:36 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-5] State
transition from ASSIGNING_PARTITIONS to RUNNING.
2017-08-08 17:25:36 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-5] partition
assignment took 2243 ms.
current active tasks: [0_28, 0_13]
current standby tasks: []
2017-08-08 17:25:36 INFO StreamThread:1248 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-15] Created
active task 0_12 with assigned partitions
[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-12,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-12, AdServe-12]
2017-08-08 17:25:36 INFO StoreChangelogReader:121 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-15] Starting
restoring state stores from changelog topics []
2017-08-08 17:25:36 INFO StreamThread:1345 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-15] Adding
assigned standby tasks {}
2017-08-08 17:25:36 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-15] State
transition from ASSIGNING_PARTITIONS to RUNNING.
2017-08-08 17:25:36 INFO KafkaStreams:229 - stream-client
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce] State transition from
REBALANCING to RUNNING.
2017-08-08 17:25:36 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-15]
partition assignment took 2248 ms.
current active tasks: [0_27, 0_12]
current standby tasks: []
2017-08-08 17:35:35 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-4] Deleting
obsolete state directory 0_51 for task 0_51 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:35 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-6] Deleting
obsolete state directory 0_56 for task 0_56 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-10] Deleting
obsolete state directory 0_53 for task 0_53 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Deleting
obsolete state directory 0_48 for task 0_48 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-10] Deleting
obsolete state directory 0_57 for task 0_57 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-6] Deleting
obsolete state directory 0_32 for task 0_32 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Deleting
obsolete state directory 0_49 for task 0_49 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-4] Deleting
obsolete state directory 0_52 for task 0_52 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-6] Deleting
obsolete state directory 0_55 for task 0_55 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-10] Deleting
obsolete state directory 0_58 for task 0_58 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 ERROR StateDirectory:227 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Failed
to lock the state directory due to an unexpected exception
java.nio.file.DirectoryNotEmptyException: /data/streampoc/LICSp-7-a20/0_49
at
sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:242)
at
sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
at java.nio.file.Files.delete(Files.java:1126)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:597)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:580)
at java.nio.file.Files.walkFileTree(Files.java:2688)
at java.nio.file.Files.walkFileTree(Files.java:2742)
at org.apache.kafka.common.utils.Utils.delete(Utils.java:580)
at
org.apache.kafka.streams.processor.internals.StateDirectory.cleanRemovedTasks(StateDirectory.java:221)
at
org.apache.kafka.streams.processor.internals.StreamThread.maybeClean(StreamThread.java:878)
at
org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:569)
at
org.apache.kafka.streams.processor.internals.StreamThread.run(StreamThread.java:527)
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-10] Deleting
obsolete state directory 0_50 for task 0_50 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-6] Deleting
obsolete state directory 0_54 for task 0_54 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Deleting
obsolete state directory 0_59 for task 0_59 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 ERROR StateDirectory:227 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-4] Failed to
lock the state directory due to an unexpected exception
java.nio.file.DirectoryNotEmptyException: /data/streampoc/LICSp-7-a20/0_52
at
sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:242)
at
sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
at java.nio.file.Files.delete(Files.java:1126)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:597)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:580)
at java.nio.file.Files.walkFileTree(Files.java:2688)
at java.nio.file.Files.walkFileTree(Files.java:2742)
at org.apache.kafka.common.utils.Utils.delete(Utils.java:580)
at
org.apache.kafka.streams.processor.internals.StateDirectory.cleanRemovedTasks(StateDirectory.java:221)
at
org.apache.kafka.streams.processor.internals.StreamThread.maybeClean(StreamThread.java:878)
at
org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:569)
at
org.apache.kafka.streams.processor.internals.StreamThread.run(StreamThread.java:527)
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-4] Deleting
obsolete state directory 0_42 for task 0_42 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-8] Deleting
obsolete state directory 0_33 for task 0_33 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Deleting
obsolete state directory 0_41 for task 0_41 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-6] Deleting
obsolete state directory 0_39 for task 0_39 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-10] Deleting
obsolete state directory 0_43 for task 0_43 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 ERROR StateDirectory:227 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-8] Failed to
lock the state directory due to an unexpected exception
java.nio.file.DirectoryNotEmptyException: /data/streampoc/LICSp-7-a20/0_33
at
sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:242)
at
sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
at java.nio.file.Files.delete(Files.java:1126)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:597)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:580)
at java.nio.file.Files.walkFileTree(Files.java:2688)
at java.nio.file.Files.walkFileTree(Files.java:2742)
at org.apache.kafka.common.utils.Utils.delete(Utils.java:580)
at
org.apache.kafka.streams.processor.internals.StateDirectory.cleanRemovedTasks(StateDirectory.java:221)
at
org.apache.kafka.streams.processor.internals.StreamThread.maybeClean(StreamThread.java:878)
at
org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:569)
at
org.apache.kafka.streams.processor.internals.StreamThread.run(StreamThread.java:527)
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-8] Deleting
obsolete state directory 0_35 for task 0_35 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-4] Deleting
obsolete state directory 0_38 for task 0_38 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-8] Deleting
obsolete state directory 0_37 for task 0_37 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 ERROR StateDirectory:227 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Failed
to lock the state directory due to an unexpected exception
java.nio.file.DirectoryNotEmptyException: /data/streampoc/LICSp-7-a20/0_41
at
sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:242)
at
sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
at java.nio.file.Files.delete(Files.java:1126)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:597)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:580)
at java.nio.file.Files.walkFileTree(Files.java:2688)
at java.nio.file.Files.walkFileTree(Files.java:2742)
at org.apache.kafka.common.utils.Utils.delete(Utils.java:580)
at
org.apache.kafka.streams.processor.internals.StateDirectory.cleanRemovedTasks(StateDirectory.java:221)
at
org.apache.kafka.streams.processor.internals.StreamThread.maybeClean(StreamThread.java:878)
at
org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:569)
at
org.apache.kafka.streams.processor.internals.StreamThread.run(StreamThread.java:527)
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Deleting
obsolete state directory 0_44 for task 0_44 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-6] Deleting
obsolete state directory 0_34 for task 0_34 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-4] Deleting
obsolete state directory 0_36 for task 0_36 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 ERROR StateDirectory:227 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-8] Failed to
lock the state directory due to an unexpected exception
java.nio.file.DirectoryNotEmptyException: /data/streampoc/LICSp-7-a20/0_37
at
sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:242)
at
sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
at java.nio.file.Files.delete(Files.java:1126)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:597)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:580)
at java.nio.file.Files.walkFileTree(Files.java:2688)
at java.nio.file.Files.walkFileTree(Files.java:2742)
at org.apache.kafka.common.utils.Utils.delete(Utils.java:580)
at
org.apache.kafka.streams.processor.internals.StateDirectory.cleanRemovedTasks(StateDirectory.java:221)
at
org.apache.kafka.streams.processor.internals.StreamThread.maybeClean(StreamThread.java:878)
at
org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:569)
at
org.apache.kafka.streams.processor.internals.StreamThread.run(StreamThread.java:527)
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-8] Deleting
obsolete state directory 0_45 for task 0_45 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-10] Deleting
obsolete state directory 0_40 for task 0_40 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Deleting
obsolete state directory 0_46 for task 0_46 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-2] Deleting
obsolete state directory 0_30 for task 0_30 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-10] Deleting
obsolete state directory 0_31 for task 0_31 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-4] Deleting
obsolete state directory 0_47 for task 0_47 as cleanup delay of 600000 ms
has passed
2017-08-08 17:35:36 ERROR StateDirectory:227 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-6] Failed to
lock the state directory due to an unexpected exception
java.nio.file.DirectoryNotEmptyException: /data/streampoc/LICSp-7-a20/0_34
at
sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:242)
at
sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
at java.nio.file.Files.delete(Files.java:1126)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:597)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:580)
at java.nio.file.Files.walkFileTree(Files.java:2688)
at java.nio.file.Files.walkFileTree(Files.java:2742)
at org.apache.kafka.common.utils.Utils.delete(Utils.java:580)
at
org.apache.kafka.streams.processor.internals.StateDirectory.cleanRemovedTasks(StateDirectory.java:221)
at
org.apache.kafka.streams.processor.internals.StreamThread.maybeClean(StreamThread.java:878)
at
org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:569)
at
org.apache.kafka.streams.processor.internals.StreamThread.run(StreamThread.java:527)
2017-08-08 17:35:36 ERROR StateDirectory:227 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-4] Failed to
lock the state directory due to an unexpected exception
java.nio.file.DirectoryNotEmptyException: /data/streampoc/LICSp-7-a20/0_47
at
sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:242)
at
sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
at java.nio.file.Files.delete(Files.java:1126)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:597)
at org.apache.kafka.common.utils.Utils$2.postVisitDirectory(Utils.java:580)
at java.nio.file.Files.walkFileTree(Files.java:2688)
at java.nio.file.Files.walkFileTree(Files.java:2742)
at org.apache.kafka.common.utils.Utils.delete(Utils.java:580)
at
org.apache.kafka.streams.processor.internals.StateDirectory.cleanRemovedTasks(StateDirectory.java:221)
at
org.apache.kafka.streams.processor.internals.StreamThread.maybeClean(StreamThread.java:878)
at
org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:569)
at
org.apache.kafka.streams.processor.internals.StreamThread.run(StreamThread.java:527)
2017-08-08 17:45:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Deleting
obsolete state directory 0_49 for task 0_49 as cleanup delay of 600000 ms
has passed
2017-08-08 17:45:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Deleting
obsolete state directory 0_52 for task 0_52 as cleanup delay of 600000 ms
has passed
2017-08-08 17:45:36 INFO StateDirectory:220 - stream-thread
[LICSp-7-a20-f9405688-4aba-4971-9f5e-b029756dcdce-StreamThread-14] Deleting
obsolete state directory 0_33 for task 0_33 as cleanup delay of 600000 ms
has passed
*Machine2*
2017-08-08 21:14:34 INFO StreamThread:227 - stream-thread
[LICSp-7-a20-912f35f4-5584-4102-900b-eccf1787859a-StreamThread-14]
partition revocation took 2314 ms.
suspended active tasks: [0_59, 0_28, 0_44, 0_6]
suspended standby tasks: []
previous active tasks: [0_6, 0_59, 0_28, 0_44]
2017-08-08 21:14:34 INFO AbstractCoordinator:432 - (Re-)joining group
LICSp-7-a20
2017-08-08 21:14:40 INFO StreamThread:1345 - stream-thread
[LICSp-7-a20-912f35f4-5584-4102-900b-eccf1787859a-StreamThread-12] Adding
assigned standby tasks {}
2017-08-08 21:14:40 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-912f35f4-5584-4102-900b-eccf1787859a-StreamThread-12] State
transition from ASSIGNING_PARTITIONS to RUNNING.
2017-08-08 21:14:40 INFO StreamThread:193 - stream-thread
[LICSp-7-a20-912f35f4-5584-4102-900b-eccf1787859a-StreamThread-12]
partition assignment took 437816 ms.
current active tasks: [0_5, 0_25, 0_58, 0_43]
current standby tasks: []
2017-08-08 21:14:40 INFO ConsumerCoordinator:419 - Revoking previously
assigned partitions
[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-43,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-43, AdServe-58,
AdServe-25, LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-58,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-25, AdServe-5,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-58,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-25, AdServe-43,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-5,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-5] for group
LICSp-7-a20
2017-08-08 21:14:40 INFO StreamThread:205 - stream-thread
[LICSp-7-a20-912f35f4-5584-4102-900b-eccf1787859a-StreamThread-12] at state
RUNNING: partitions
[LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-43,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-43, AdServe-58,
AdServe-25, LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-58,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-25, AdServe-5,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-58,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-25, AdServe-43,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000007-repartition-5,
LICSp-7-a20-KSTREAM-BRANCHCHILD-0000000008-repartition-5] revoked at the
beginning of consumer rebalance.
current assigned active tasks: [0_5, 0_25, 0_58, 0_43]
current assigned standby tasks: []
2017-08-08 21:14:40 INFO StreamThread:980 - stream-thread
[LICSp-7-a20-912f35f4-5584-4102-900b-eccf1787859a-StreamThread-12] State
transition from RUNNING to PARTITIONS_REVOKED.
2017-08-08 21:14:40 INFO KafkaStreams:229 - stream-client
[LICSp-7-a20-912f35f4-5584-4102-900b-eccf1787859a] State transition from
REBALANCING to REBALANCING.
2017-08-08 21:14:41 INFO StreamThread:1400 - stream-thread
[LICSp-7-a20-912f35f4-5584-4102-900b-eccf1787859a-StreamThread-12] Updating
suspended tasks to contain active tasks [0_5, 0_25, 0_58, 0_43]
2017-08-08 21:14:41 INFO StreamThread:1407 - stream-thread
[LICSp-7-a20-912f35f4-5584-4102-900b-eccf1787859a-StreamThread-12] Removing
all active tasks [0_5, 0_25, 0_58, 0_43]
2017-08-08 21:14:41 INFO StreamThread:1421 - stream-thread
[LICSp-7-a20-912f35f4-5584-4102-900b-eccf1787859a-StreamThread-12] Removing
all standby tasks []
2017-08-08 21:14:41 INFO StreamThread:227 - stream-thread
[LICSp-7-a20-912f35f4-5584-4102-900b-eccf1787859a-StreamThread-12]
partition revocation took 1135 ms.
suspended active tasks: [0_25, 0_58, 0_43, 0_5]
suspended standby tasks: []
previous active tasks: [0_5, 0_25, 0_58, 0_43]
2017-08-08 21:14:41 INFO AbstractCoordinator:432 - (Re-)joining group
LICSp-7-a20
2017-08-08 21:17:04 INFO AbstractCoordinator:642 - Marking the coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) dead for group LICSp-7-a20
2017-08-08 21:17:04 INFO AbstractCoordinator:597 - Discovered coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) for group LICSp-7-a20.
2017-08-08 21:17:04 INFO AbstractCoordinator:432 - (Re-)joining group
LICSp-7-a20
2017-08-08 21:17:15 INFO AbstractCoordinator:642 - Marking the coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) dead for group LICSp-7-a20
2017-08-08 21:17:15 INFO AbstractCoordinator:597 - Discovered coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) for group LICSp-7-a20.
2017-08-08 21:17:15 INFO AbstractCoordinator:432 - (Re-)joining group
LICSp-7-a20
2017-08-08 21:17:16 INFO AbstractCoordinator:642 - Marking the coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) dead for group LICSp-7-a20
2017-08-08 21:17:16 INFO AbstractCoordinator:597 - Discovered coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) for group LICSp-7-a20.
2017-08-08 21:17:16 INFO AbstractCoordinator:432 - (Re-)joining group
LICSp-7-a20
2017-08-08 21:17:19 INFO AbstractCoordinator:642 - Marking the coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) dead for group LICSp-7-a20
2017-08-08 21:17:19 INFO AbstractCoordinator:597 - Discovered coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) for group LICSp-7-a20.
2017-08-08 21:17:19 INFO AbstractCoordinator:432 - (Re-)joining group
LICSp-7-a20
2017-08-08 21:17:20 INFO AbstractCoordinator:642 - Marking the coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) dead for group LICSp-7-a20
2017-08-08 21:17:20 INFO AbstractCoordinator:597 - Discovered coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) for group LICSp-7-a20.
2017-08-08 21:17:20 INFO AbstractCoordinator:432 - (Re-)joining group
LICSp-7-a20
2017-08-08 21:17:21 INFO AbstractCoordinator:642 - Marking the coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) dead for group LICSp-7-a20
2017-08-08 21:17:21 INFO AbstractCoordinator:597 - Discovered coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) for group LICSp-7-a20.
2017-08-08 21:17:21 INFO AbstractCoordinator:432 - (Re-)joining group
LICSp-7-a20
2017-08-08 21:17:22 INFO AbstractCoordinator:642 - Marking the coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) dead for group LICSp-7-a20
2017-08-08 21:17:22 INFO AbstractCoordinator:597 - Discovered coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) for group LICSp-7-a20.
2017-08-08 21:17:22 INFO AbstractCoordinator:432 - (Re-)joining group
LICSp-7-a20
2017-08-08 21:17:22 INFO AbstractCoordinator:642 - Marking the coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) dead for group LICSp-7-a20
2017-08-08 21:17:22 INFO AbstractCoordinator:642 - Marking the coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) dead for group LICSp-7-a20
2017-08-08 21:17:22 INFO AbstractCoordinator:597 - Discovered coordinator
172.29.65.91:9092 (id: 2147483556 rack: null) for group LICSp-7-a20.
2017-08-08 21:17:22 INFO AbstractCoordinator:432 - (Re-)joining group
LICSp-7-a20
