Hi,
This is a bug in 0.11. You can work around it by setting
StreamsConfig.STATE_DIR_CLEANUP_DELAY_MS_CONFIG to Long.MAX_VALUE
Also, if you have logs it would be easier to either attach them or put them
in a gist. It is a bit hard to read in an email.
Thanks,
Damian
On Wed, 9 Aug 2017 at 10:10 Sameer Kumar <sam.kum.w...@gmail.com> wrote:
> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> 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 <(214)%20748-3556> rack: null) for
> group LICSp-7-a20.
> 2017-08-08 21:17:22 INFO AbstractCoordinator:432 - (Re-)joining group
> LICSp-7-a20
>
