ctubbsii
commented
3 years ago @dlmarion Do you think this might be related to #1896 or #1866?
Closed ctubbsii closed 3 years ago
ctubbsii
commented
3 years ago @dlmarion Do you think this might be related to #1896 or #1866?
dlmarion
commented
3 years ago I don't think it's related. I have run this test many times without those issues. Is it continually happening?
On Thu, Feb 4, 2021 at 11:29 AM Christopher Tubbs notifications@github.com wrote:
@dlmarion https://github.com/dlmarion Do you think this might be related to #1896 https://github.com/apache/accumulo/pull/1896 or #1866 https://github.com/apache/accumulo/pull/1866?
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/apache/accumulo/issues/1909#issuecomment-773436953, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAEKUZ2PYA6ZRKGLSIOL2HDS5LDPLANCNFSM4XDEBD7A .
ctubbsii
commented
3 years ago I don't think it's related.
It has to be related. The code that failed is brand new in #1866. I just checked.
I have run this test many times without those issues. Is it continually happening?
I don't know how often it happens, only that it's a new failure that didn't happen before (it couldn't have, since this test code is new). ConnectionLoss is usually a transient issue, so I suspect the test can be made to handle it. Since ConnectionLoss can happen frequently, it makes me wonder if the code change in #1896 to use ZK directly (instead of ZooReaderWriter, which handles ConnectionLoss) may also be affected by transient issues like this one that affects this test.
milleruntime
commented
3 years ago FYI You can drag and drop text files (with .txt extentions) to attach files to an issue. It is useful for logs so it won't show up in notification messages.
ctubbsii
commented
3 years ago @dlmarion In answer to your previous question about how frequent the failure is: it has failed in 4 out of 4 Jenkins builds since #1896. The ConnectionLoss was the first I saw, but the other 3 were:
java.lang.AssertionError
at org.junit.Assert.fail(Assert.java:87)
at org.junit.Assert.assertTrue(Assert.java:42)
at org.junit.Assert.assertTrue(Assert.java:53)
at org.apache.accumulo.test.fate.zookeeper.ZooLockIT.testLockSerial(ZooLockIT.java:436)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)One had an repeated message in STDOUT that looked like:
2021-02-05T04:34:20,692 [zookeeper.ZooLock] DEBUG: [zlock#f1fde7ea-8561-4744-a1e0-85fad77cb5f7#] Renewing watch on prior node /zltestDeleteWaiting-1685185170-l1/zlock#64cdee91-3fc3-4957-b57c-d6bf315bb550#0000000000Two others had:
2021-02-04T23:37:51,181 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 created
2021-02-04T23:37:51,182 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial
2021-02-04T23:37:51,182 [zookeeper.ZooLock] DEBUG: Children nodes: 1
2021-02-04T23:37:51,183 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000
2021-02-04T23:37:51,183 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000
2021-02-04T23:37:51,184 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial
2021-02-04T23:37:51,184 [zookeeper.ZooLock] DEBUG: Children nodes: 1
2021-02-04T23:37:51,184 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000
2021-02-04T23:37:51,184 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] First candidate is my lock, acquiring...
2021-02-04T23:37:51,186 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 created
2021-02-04T23:37:51,187 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial
2021-02-04T23:37:51,187 [zookeeper.ZooLock] DEBUG: Children nodes: 2
2021-02-04T23:37:51,187 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000
2021-02-04T23:37:51,187 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001
2021-02-04T23:37:51,187 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001
2021-02-04T23:37:51,188 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial
2021-02-04T23:37:51,188 [zookeeper.ZooLock] DEBUG: Children nodes: 2
2021-02-04T23:37:51,189 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000
2021-02-04T23:37:51,189 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001
2021-02-04T23:37:51,189 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Lock held by another process with ephemeral node: zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000
2021-02-04T23:37:51,189 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Establishing watch on prior node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000So, it passes when building locally and in the GitHub CI build. What's different about the Jenkins server? Using the native client was something suggest in this comment thread: https://github.com/apache/accumulo/pull/1677#discussion_r469470006. I'm not sure what the solution should be here, since we were specifically getting rid of the retries...
On Fri, Feb 5, 2021 at 8:57 AM Christopher Tubbs notifications@github.com wrote:
@dlmarion https://github.com/dlmarion In answer to your previous question about how frequent the failure is: it has failed in 4 out of 4 Jenkins builds since #1896 https://github.com/apache/accumulo/pull/1896. The ConnectionLoss was the first I saw, but the other 3 were:
java.lang.AssertionError at org.junit.Assert.fail(Assert.java:87) at org.junit.Assert.assertTrue(Assert.java:42) at org.junit.Assert.assertTrue(Assert.java:53) at org.apache.accumulo.test.fate.zookeeper.ZooLockIT.testLockSerial(ZooLockIT.java:436) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
One had an repeated message in STDOUT that looked like:
2021-02-05T04:34:20,692 [zookeeper.ZooLock] DEBUG: [zlock#f1fde7ea-8561-4744-a1e0-85fad77cb5f7#] Renewing watch on prior node /zltestDeleteWaiting-1685185170-l1/zlock#64cdee91-3fc3-4957-b57c-d6bf315bb550#0000000000
Two others had:
2021-02-04T23:37:51,181 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 created 2021-02-04T23:37:51,182 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T23:37:51,182 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T23:37:51,183 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T23:37:51,183 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T23:37:51,184 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T23:37:51,184 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T23:37:51,184 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T23:37:51,184 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] First candidate is my lock, acquiring... 2021-02-04T23:37:51,186 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 created 2021-02-04T23:37:51,187 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T23:37:51,187 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T23:37:51,187 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T23:37:51,187 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T23:37:51,187 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T23:37:51,188 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T23:37:51,188 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T23:37:51,189 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T23:37:51,189 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T23:37:51,189 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Lock held by another process with ephemeral node: zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T23:37:51,189 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Establishing watch on prior node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/apache/accumulo/issues/1909#issuecomment-774047768, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAEKUZYVGRXDLAMHSCF7VPLS5P2KVANCNFSM4XDEBD7A .
ctubbsii
commented
3 years ago It doesn't pass locally for me. It fails on the assertion on line 436, as in the above. It seems the missing handling of the transient ConnectionLoss issue is only one problem. The assertion failure is a separate problem. When it failed locally for me, there were no errors or warnings in any logs other than the normal warnings about swappiness or deprecated config properties, and typical warnings from ZK client threads when the ZK session is closed at the end of the test.
So, it seems this assertion is catching actual incorrect code logic somewhere.
dlmarion
commented
3 years ago Interesting. Ok, I will look at it on Monday.
On Fri, Feb 5, 2021 at 9:17 AM Christopher Tubbs notifications@github.com wrote:
It doesn't pass locally for me. It fails on the assertion on line 436, as in the above. It seems the missing handling of the transient ConnectionLoss issue is only one problem. The assertion failure is a separate problem. When it failed locally for me, there were no errors or warnings in any logs other than the normal warnings about swappiness or deprecated config properties, and typical warnings from ZK client threads when the ZK session is closed at the end of the test.
So, it seems this assertion is catching actual incorrect code logic somewhere.
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/apache/accumulo/issues/1909#issuecomment-774059314, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAEKUZ5QSTHF5DH72BEHDLDS5P4Y7ANCNFSM4XDEBD7A .
dlmarion
commented
3 years ago @ctubbsii - I was able to replicate this. The issue stemmed from the changes in removing the constructor in ZooLock that was only called by the ZooLockIT.
Test name(s)
Describe the failure observed
Testing Environment:
Additional context
STDOUT (DEBUG logs) - click to expand
``` 2021-02-04T07:36:29,569 [miniclusterImpl.MiniAccumuloClusterImpl] INFO : Starting MAC against instance miniInstance and zookeeper(s) localhost:33061. 2021-02-04T07:36:33,300 [zookeeper.ZooSession] DEBUG: Connecting to localhost:33061 with timeout 30000 with auth 2021-02-04T07:36:33,324 [common.X509Util] INFO : Setting -D jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated TLS renegotiation 2021-02-04T07:36:33,480 [zookeeper.ZooSession] DEBUG: Connecting to localhost:33061 with timeout 30000000 with auth 2021-02-04T07:36:33,608 [zookeeper.ZooLock] DEBUG: [zlock#96057b7a-d384-44b5-a463-bfb62364be2b#] Ephemeral node /zltestDeleteWaiting-1316037646-l1/zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 created 2021-02-04T07:36:33,611 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteWaiting-1316037646-l1 2021-02-04T07:36:33,612 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:33,613 [zookeeper.ZooLock] DEBUG: - zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,614 [zookeeper.ZooLock] DEBUG: [zlock#96057b7a-d384-44b5-a463-bfb62364be2b#] Setting watcher on /zltestDeleteWaiting-1316037646-l1/zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,616 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteWaiting-1316037646-l1 2021-02-04T07:36:33,616 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:33,616 [zookeeper.ZooLock] DEBUG: - zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,617 [zookeeper.ZooLock] DEBUG: [zlock#96057b7a-d384-44b5-a463-bfb62364be2b#] First candidate is my lock, acquiring... 2021-02-04T07:36:33,625 [zookeeper.ZooLock] DEBUG: [zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#] Ephemeral node /zltestDeleteWaiting-1316037646-l1/zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#0000000001 created 2021-02-04T07:36:33,634 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteWaiting-1316037646-l1 2021-02-04T07:36:33,634 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:36:33,635 [zookeeper.ZooLock] DEBUG: - zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,635 [zookeeper.ZooLock] DEBUG: - zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#0000000001 2021-02-04T07:36:33,635 [zookeeper.ZooLock] DEBUG: [zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#] Setting watcher on /zltestDeleteWaiting-1316037646-l1/zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#0000000001 2021-02-04T07:36:33,642 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteWaiting-1316037646-l1 2021-02-04T07:36:33,643 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:36:33,643 [zookeeper.ZooLock] DEBUG: - zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,643 [zookeeper.ZooLock] DEBUG: - zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#0000000001 2021-02-04T07:36:33,643 [zookeeper.ZooLock] DEBUG: [zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#] Lock held by another process with ephemeral node: zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,644 [zookeeper.ZooLock] DEBUG: [zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#] Establishing watch on prior node /zltestDeleteWaiting-1316037646-l1/zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,650 [zookeeper.ZooLock] DEBUG: [zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#] Ephemeral node /zltestDeleteWaiting-1316037646-l1/zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#0000000002 created 2021-02-04T07:36:33,651 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteWaiting-1316037646-l1 2021-02-04T07:36:33,651 [zookeeper.ZooLock] DEBUG: Children nodes: 3 2021-02-04T07:36:33,651 [zookeeper.ZooLock] DEBUG: - zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,652 [zookeeper.ZooLock] DEBUG: - zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#0000000001 2021-02-04T07:36:33,652 [zookeeper.ZooLock] DEBUG: - zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#0000000002 2021-02-04T07:36:33,652 [zookeeper.ZooLock] DEBUG: [zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#] Setting watcher on /zltestDeleteWaiting-1316037646-l1/zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#0000000002 2021-02-04T07:36:33,655 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteWaiting-1316037646-l1 2021-02-04T07:36:33,655 [zookeeper.ZooLock] DEBUG: Children nodes: 3 2021-02-04T07:36:33,655 [zookeeper.ZooLock] DEBUG: - zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,655 [zookeeper.ZooLock] DEBUG: - zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#0000000001 2021-02-04T07:36:33,655 [zookeeper.ZooLock] DEBUG: - zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#0000000002 2021-02-04T07:36:33,656 [zookeeper.ZooLock] DEBUG: [zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#] Lock held by another process with ephemeral node: zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,656 [zookeeper.ZooLock] DEBUG: [zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#] Establishing watch on prior node /zltestDeleteWaiting-1316037646-l1/zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#0000000001 2021-02-04T07:36:33,658 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteWaiting-1316037646-l1 2021-02-04T07:36:33,659 [zookeeper.ZooLock] DEBUG: Children nodes: 3 2021-02-04T07:36:33,659 [zookeeper.ZooLock] DEBUG: - zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,659 [zookeeper.ZooLock] DEBUG: - zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#0000000001 2021-02-04T07:36:33,659 [zookeeper.ZooLock] DEBUG: - zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#0000000002 2021-02-04T07:36:33,679 [zookeeper.ZooLock] DEBUG: [zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#] zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#0000000001 was deleted 2021-02-04T07:36:33,679 [zookeeper.ZooLock] DEBUG: [zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#] Lock deleted before acquired, setting createdNodeName zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#0000000001 to null 2021-02-04T07:36:33,680 [zookeeper.ZooLock] DEBUG: [zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#] Detected deletion of prior node /zltestDeleteWaiting-1316037646-l1/zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#0000000001, attempting to acquire lock 2021-02-04T07:36:33,688 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteWaiting-1316037646-l1 2021-02-04T07:36:33,689 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:36:33,689 [zookeeper.ZooLock] DEBUG: - zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,689 [zookeeper.ZooLock] DEBUG: - zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#0000000002 2021-02-04T07:36:33,689 [zookeeper.ZooLock] DEBUG: [zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#] Lock held by another process with ephemeral node: zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,689 [zookeeper.ZooLock] DEBUG: [zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#] Establishing watch on prior node /zltestDeleteWaiting-1316037646-l1/zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 2021-02-04T07:36:33,697 [zookeeper.ZooLock] DEBUG: [zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#] Detected deletion of prior node /zltestDeleteWaiting-1316037646-l1/zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000, attempting to acquire lock 2021-02-04T07:36:33,697 [zookeeper.ZooLock] DEBUG: [zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#] While waiting for another lock /zltestDeleteWaiting-1316037646-l1/zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000, zlock#bcb1cf22-a7ed-4da0-aeab-bbc879e48c32#0000000001 was deleted 2021-02-04T07:36:33,698 [zookeeper.ZooLock] DEBUG: [zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#] Detected deletion of prior node /zltestDeleteWaiting-1316037646-l1/zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000, attempting to acquire lock 2021-02-04T07:36:33,699 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteWaiting-1316037646-l1 2021-02-04T07:36:33,699 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:33,699 [zookeeper.ZooLock] DEBUG: - zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#0000000002 2021-02-04T07:36:33,699 [zookeeper.ZooLock] DEBUG: [zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#] First candidate is my lock, acquiring... 2021-02-04T07:36:33,700 [zookeeper.ZooLock] DEBUG: [zlock#96057b7a-d384-44b5-a463-bfb62364be2b#] zlock#96057b7a-d384-44b5-a463-bfb62364be2b#0000000000 was deleted 2021-02-04T07:36:33,702 [zookeeper.ZooLock] DEBUG: [zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#] Deleting all at path /zltestDeleteWaiting-1316037646-l1/zlock#0ae39df1-c9cf-45b3-9d2d-2e978ddd516f#0000000002 due to unlock 2021-02-04T07:36:33,978 [zookeeper.ZooLock] DEBUG: event /zltestTryLock-1210442320-l2 NodeCreated SyncConnected 2021-02-04T07:36:33,990 [zookeeper.ZooLock] DEBUG: event /zltestTryLock-1210442320-l2 NodeDeleted SyncConnected 2021-02-04T07:36:33,998 [zookeeper.ZooLock] DEBUG: event /zltestTryLock-1210442320-l2 NodeDeleted SyncConnected 2021-02-04T07:36:34,011 [zookeeper.ZooLock] DEBUG: event /zltestTryLock-1210442320-l2 NodeDeleted SyncConnected 2021-02-04T07:36:34,019 [zookeeper.ZooLock] DEBUG: event /zltestTryLock-1210442320-l2 NodeCreated SyncConnected 2021-02-04T07:36:34,037 [zookeeper.ZooLock] DEBUG: event /zltestTryLock-1210442320-l2 NodeCreated SyncConnected 2021-02-04T07:36:34,057 [zookeeper.ZooLock] DEBUG: event /zltestTryLock-1210442320-l2 NodeCreated SyncConnected 2021-02-04T07:36:34,065 [zookeeper.ZooLock] DEBUG: event /zltestTryLock-1210442320-l2 NodeDeleted SyncConnected 2021-02-04T07:36:34,092 [zookeeper.ZooLock] DEBUG: event /zltestTryLock-1210442320-l2 NodeDeleted SyncConnected 2021-02-04T07:36:34,115 [zookeeper.ZooLock] DEBUG: event /zltestTryLock-1210442320-l2 NodeDeleted SyncConnected 2021-02-04T07:36:34,130 [zookeeper.ZooLock] DEBUG: event /zltestTryLock-1210442320-l2 NodeDeleted SyncConnected 2021-02-04T07:36:34,139 [zookeeper.ZooLock] DEBUG: [zlock#f00cd5b0-23b1-44a1-846b-b98e537d9db2#] Ephemeral node /zltestTryLock-1210442320-l2/zlock#f00cd5b0-23b1-44a1-846b-b98e537d9db2#0000000000 created 2021-02-04T07:36:34,141 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestTryLock-1210442320-l2 2021-02-04T07:36:34,142 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:34,142 [zookeeper.ZooLock] DEBUG: - zlock#f00cd5b0-23b1-44a1-846b-b98e537d9db2#0000000000 2021-02-04T07:36:34,142 [zookeeper.ZooLock] DEBUG: [zlock#f00cd5b0-23b1-44a1-846b-b98e537d9db2#] Setting watcher on /zltestTryLock-1210442320-l2/zlock#f00cd5b0-23b1-44a1-846b-b98e537d9db2#0000000000 2021-02-04T07:36:34,151 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestTryLock-1210442320-l2 2021-02-04T07:36:34,151 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:34,151 [zookeeper.ZooLock] DEBUG: - zlock#f00cd5b0-23b1-44a1-846b-b98e537d9db2#0000000000 2021-02-04T07:36:34,151 [zookeeper.ZooLock] DEBUG: [zlock#f00cd5b0-23b1-44a1-846b-b98e537d9db2#] First candidate is my lock, acquiring... 2021-02-04T07:36:34,152 [zookeeper.ZooLock] DEBUG: [zlock#f00cd5b0-23b1-44a1-846b-b98e537d9db2#] Deleting all at path /zltestTryLock-1210442320-l2/zlock#f00cd5b0-23b1-44a1-846b-b98e537d9db2#0000000000 due to unlock 2021-02-04T07:36:34,157 [zookeeper.ZooLock] DEBUG: event /zltestTryLock-1210442320-l2 NodeCreated SyncConnected 2021-02-04T07:36:38,751 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-000000000000#] Ephemeral node /zlParallel/zlock#00000000-0000-0000-0000-000000000000#0000000000 created 2021-02-04T07:36:38,753 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:38,753 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:38,753 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,753 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-000000000000#] Setting watcher on /zlParallel/zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,762 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-333333333333#] Ephemeral node /zlParallel/zlock#00000000-0000-0000-0000-333333333333#0000000001 created 2021-02-04T07:36:38,762 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-111111111111#] Ephemeral node /zlParallel/zlock#00000000-0000-0000-0000-111111111111#0000000002 created 2021-02-04T07:36:38,763 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-222222222222#] Ephemeral node /zlParallel/zlock#00000000-0000-0000-0000-222222222222#0000000003 created 2021-02-04T07:36:38,764 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:38,764 [zookeeper.ZooLock] DEBUG: Children nodes: 4 2021-02-04T07:36:38,764 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,764 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-333333333333#0000000001 2021-02-04T07:36:38,764 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,765 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:38,765 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-111111111111#] Setting watcher on /zlParallel/zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,765 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:38,765 [zookeeper.ZooLock] DEBUG: Children nodes: 4 2021-02-04T07:36:38,765 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,765 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-333333333333#0000000001 2021-02-04T07:36:38,766 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,766 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:38,766 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-333333333333#] Setting watcher on /zlParallel/zlock#00000000-0000-0000-0000-333333333333#0000000001 2021-02-04T07:36:38,766 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:38,766 [zookeeper.ZooLock] DEBUG: Children nodes: 4 2021-02-04T07:36:38,766 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,767 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-333333333333#0000000001 2021-02-04T07:36:38,767 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,767 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:38,767 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-000000000000#] First candidate is my lock, acquiring... 2021-02-04T07:36:38,768 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:38,768 [zookeeper.ZooLock] DEBUG: Children nodes: 4 2021-02-04T07:36:38,768 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,768 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-333333333333#0000000001 2021-02-04T07:36:38,768 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,769 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:38,769 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-222222222222#] Setting watcher on /zlParallel/zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:38,769 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:38,769 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: Children nodes: 4 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: Children nodes: 4 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-333333333333#0000000001 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-333333333333#0000000001 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-333333333333#] Lock held by another process with ephemeral node: zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-111111111111#] Lock held by another process with ephemeral node: zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-111111111111#] Establishing watch on prior node /zlParallel/zlock#00000000-0000-0000-0000-333333333333#0000000001 2021-02-04T07:36:38,770 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-333333333333#] Establishing watch on prior node /zlParallel/zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,783 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:38,784 [zookeeper.ZooLock] DEBUG: Children nodes: 4 2021-02-04T07:36:38,784 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,784 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-333333333333#0000000001 2021-02-04T07:36:38,784 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,784 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:38,784 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-222222222222#] Lock held by another process with ephemeral node: zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,784 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-222222222222#] Establishing watch on prior node /zlParallel/zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,791 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:38,791 [zookeeper.ZooLock] DEBUG: Children nodes: 4 2021-02-04T07:36:38,792 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-000000000000#0000000000 2021-02-04T07:36:38,792 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-333333333333#0000000001 2021-02-04T07:36:38,792 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,792 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:38,793 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-000000000000#] Deleting all at path /zlParallel/zlock#00000000-0000-0000-0000-000000000000#0000000000 due to unlock 2021-02-04T07:36:38,796 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-333333333333#] Detected deletion of prior node /zlParallel/zlock#00000000-0000-0000-0000-000000000000#0000000000, attempting to acquire lock 2021-02-04T07:36:38,807 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:38,807 [zookeeper.ZooLock] DEBUG: Children nodes: 3 2021-02-04T07:36:38,807 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-333333333333#0000000001 2021-02-04T07:36:38,807 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,807 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:38,807 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-333333333333#] First candidate is my lock, acquiring... 2021-02-04T07:36:38,911 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:38,912 [zookeeper.ZooLock] DEBUG: Children nodes: 3 2021-02-04T07:36:38,912 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-333333333333#0000000001 2021-02-04T07:36:38,912 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,912 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:38,912 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-333333333333#] Deleting all at path /zlParallel/zlock#00000000-0000-0000-0000-333333333333#0000000001 due to unlock 2021-02-04T07:36:38,915 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-111111111111#] Detected deletion of prior node /zlParallel/zlock#00000000-0000-0000-0000-333333333333#0000000001, attempting to acquire lock 2021-02-04T07:36:38,919 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:38,919 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:36:38,919 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:38,919 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:38,919 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-111111111111#] First candidate is my lock, acquiring... 2021-02-04T07:36:39,013 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:39,014 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:36:39,014 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-111111111111#0000000002 2021-02-04T07:36:39,014 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:39,014 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-111111111111#] Deleting all at path /zlParallel/zlock#00000000-0000-0000-0000-111111111111#0000000002 due to unlock 2021-02-04T07:36:39,018 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-222222222222#] Detected deletion of prior node /zlParallel/zlock#00000000-0000-0000-0000-111111111111#0000000002, attempting to acquire lock 2021-02-04T07:36:39,021 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:39,021 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:39,021 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:39,022 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-222222222222#] First candidate is my lock, acquiring... 2021-02-04T07:36:39,124 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlParallel 2021-02-04T07:36:39,125 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:39,125 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-222222222222#0000000003 2021-02-04T07:36:39,128 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-222222222222#] Deleting all at path /zlParallel/zlock#00000000-0000-0000-0000-222222222222#0000000003 due to unlock 2021-02-04T07:36:42,767 [zookeeper.ZooLock] DEBUG: event /zltestDeleteParent-118295874-l3 NodeCreated SyncConnected 2021-02-04T07:36:42,771 [zookeeper.ZooLock] DEBUG: event /zltestDeleteParent-118295874-l3 NodeCreated SyncConnected 2021-02-04T07:36:42,773 [zookeeper.ZooLock] DEBUG: [zlock#529ef1ac-e381-4d87-880a-1951bbd716db#] Ephemeral node /zltestDeleteParent-118295874-l3/zlock#529ef1ac-e381-4d87-880a-1951bbd716db#0000000000 created 2021-02-04T07:36:42,774 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteParent-118295874-l3 2021-02-04T07:36:42,774 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:42,774 [zookeeper.ZooLock] DEBUG: - zlock#529ef1ac-e381-4d87-880a-1951bbd716db#0000000000 2021-02-04T07:36:42,774 [zookeeper.ZooLock] DEBUG: [zlock#529ef1ac-e381-4d87-880a-1951bbd716db#] Setting watcher on /zltestDeleteParent-118295874-l3/zlock#529ef1ac-e381-4d87-880a-1951bbd716db#0000000000 2021-02-04T07:36:42,775 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteParent-118295874-l3 2021-02-04T07:36:42,775 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:42,775 [zookeeper.ZooLock] DEBUG: - zlock#529ef1ac-e381-4d87-880a-1951bbd716db#0000000000 2021-02-04T07:36:42,775 [zookeeper.ZooLock] DEBUG: [zlock#529ef1ac-e381-4d87-880a-1951bbd716db#] First candidate is my lock, acquiring... 2021-02-04T07:36:42,775 [zookeeper.ZooLock] DEBUG: [zlock#529ef1ac-e381-4d87-880a-1951bbd716db#] Deleting all at path /zltestDeleteParent-118295874-l3/zlock#529ef1ac-e381-4d87-880a-1951bbd716db#0000000000 due to unlock 2021-02-04T07:36:42,783 [zookeeper.ZooLock] DEBUG: [zlock#5fbeaeeb-8677-4392-8dd6-9c85f47d0851#] Ephemeral node /zltestDeleteLock-216606314-l4/zlock#5fbeaeeb-8677-4392-8dd6-9c85f47d0851#0000000000 created 2021-02-04T07:36:42,784 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteLock-216606314-l4 2021-02-04T07:36:42,784 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:42,784 [zookeeper.ZooLock] DEBUG: - zlock#5fbeaeeb-8677-4392-8dd6-9c85f47d0851#0000000000 2021-02-04T07:36:42,784 [zookeeper.ZooLock] DEBUG: [zlock#5fbeaeeb-8677-4392-8dd6-9c85f47d0851#] Setting watcher on /zltestDeleteLock-216606314-l4/zlock#5fbeaeeb-8677-4392-8dd6-9c85f47d0851#0000000000 2021-02-04T07:36:42,785 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestDeleteLock-216606314-l4 2021-02-04T07:36:42,785 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:42,785 [zookeeper.ZooLock] DEBUG: - zlock#5fbeaeeb-8677-4392-8dd6-9c85f47d0851#0000000000 2021-02-04T07:36:42,785 [zookeeper.ZooLock] DEBUG: [zlock#5fbeaeeb-8677-4392-8dd6-9c85f47d0851#] First candidate is my lock, acquiring... 2021-02-04T07:36:42,787 [zookeeper.ZooLock] DEBUG: [zlock#5fbeaeeb-8677-4392-8dd6-9c85f47d0851#] zlock#5fbeaeeb-8677-4392-8dd6-9c85f47d0851#0000000000 was deleted 2021-02-04T07:36:47,399 [zookeeper.ZooLock] DEBUG: [zlock#68c05c29-3950-4ad4-ab17-2eb8361b3e08#] Ephemeral node /zltestUnexpectedEvent-500065530-l5/zlock#68c05c29-3950-4ad4-ab17-2eb8361b3e08#0000000000 created 2021-02-04T07:36:47,400 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestUnexpectedEvent-500065530-l5 2021-02-04T07:36:47,400 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:47,400 [zookeeper.ZooLock] DEBUG: - zlock#68c05c29-3950-4ad4-ab17-2eb8361b3e08#0000000000 2021-02-04T07:36:47,400 [zookeeper.ZooLock] DEBUG: [zlock#68c05c29-3950-4ad4-ab17-2eb8361b3e08#] Setting watcher on /zltestUnexpectedEvent-500065530-l5/zlock#68c05c29-3950-4ad4-ab17-2eb8361b3e08#0000000000 2021-02-04T07:36:47,401 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestUnexpectedEvent-500065530-l5 2021-02-04T07:36:47,402 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:47,402 [zookeeper.ZooLock] DEBUG: - zlock#68c05c29-3950-4ad4-ab17-2eb8361b3e08#0000000000 2021-02-04T07:36:47,402 [zookeeper.ZooLock] DEBUG: [zlock#68c05c29-3950-4ad4-ab17-2eb8361b3e08#] First candidate is my lock, acquiring... 2021-02-04T07:36:47,402 [zookeeper.ZooLock] DEBUG: event /zltestUnexpectedEvent-500065530-l5 NodeDataChanged SyncConnected 2021-02-04T07:36:47,403 [zookeeper.ZooLock] DEBUG: Unexpected event watching lock node WatchedEvent state:SyncConnected type:NodeDataChanged path:/zltestUnexpectedEvent-500065530-l5/zlock#68c05c29-3950-4ad4-ab17-2eb8361b3e08#0000000000 /zltestUnexpectedEvent-500065530-l5/zlock#68c05c29-3950-4ad4-ab17-2eb8361b3e08#0000000000 2021-02-04T07:36:49,923 [zookeeper.ZooLock] DEBUG: [zlock#3c202b40-dde8-4b9b-9c79-ef7661affc66#] Ephemeral node /zltestChangeData-1536761882-l7/zlock#3c202b40-dde8-4b9b-9c79-ef7661affc66#0000000000 created 2021-02-04T07:36:49,924 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestChangeData-1536761882-l7 2021-02-04T07:36:49,924 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:49,924 [zookeeper.ZooLock] DEBUG: - zlock#3c202b40-dde8-4b9b-9c79-ef7661affc66#0000000000 2021-02-04T07:36:49,924 [zookeeper.ZooLock] DEBUG: [zlock#3c202b40-dde8-4b9b-9c79-ef7661affc66#] Setting watcher on /zltestChangeData-1536761882-l7/zlock#3c202b40-dde8-4b9b-9c79-ef7661affc66#0000000000 2021-02-04T07:36:49,925 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zltestChangeData-1536761882-l7 2021-02-04T07:36:49,925 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:36:49,925 [zookeeper.ZooLock] DEBUG: - zlock#3c202b40-dde8-4b9b-9c79-ef7661affc66#0000000000 2021-02-04T07:36:49,926 [zookeeper.ZooLock] DEBUG: [zlock#3c202b40-dde8-4b9b-9c79-ef7661affc66#] First candidate is my lock, acquiring... 2021-02-04T07:36:49,929 [zookeeper.ZooLock] DEBUG: Unexpected event watching lock node WatchedEvent state:SyncConnected type:NodeDataChanged path:/zltestChangeData-1536761882-l7/zlock#3c202b40-dde8-4b9b-9c79-ef7661affc66#0000000000 /zltestChangeData-1536761882-l7/zlock#3c202b40-dde8-4b9b-9c79-ef7661affc66#0000000000 2021-02-04T07:36:51,915 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:36:53,214 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zlParallel at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:36:53,226 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:36:54,636 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zltestDeleteParent-118295874-l3 at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:36:54,637 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:36:56,333 [miniclusterImpl.MiniAccumuloClusterImpl] INFO : Starting MAC against instance miniInstance and zookeeper(s) localhost:46547. 2021-02-04T07:36:56,440 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zlParallel at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:36:56,440 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:36:57,704 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zltestNoParent-1385271392-l6 at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:36:57,704 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:36:58,931 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zltestUnexpectedEvent-500065530-l5 at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:36:58,931 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:00,160 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zlParallel at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:00,161 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:01,110 [zookeeper.ZooSession] DEBUG: Connecting to localhost:46547 with timeout 30000000 with auth 2021-02-04T07:37:01,223 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 created 2021-02-04T07:37:01,225 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:01,225 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:37:01,225 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:01,225 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:01,232 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:01,232 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:37:01,232 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:01,232 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] First candidate is my lock, acquiring... 2021-02-04T07:37:01,243 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 created 2021-02-04T07:37:01,251 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:01,252 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:37:01,252 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:01,252 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:01,252 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:01,261 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:01,261 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:37:01,262 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:01,262 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:01,262 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Lock held by another process with ephemeral node: zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:01,262 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Establishing watch on prior node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:02,201 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zltestDeleteWaiting-1316037646-l1 at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:02,201 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:02,705 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:03,461 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zltestDeleteLock-216606314-l4 at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:03,462 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:04,309 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zlretryLockSerial at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:04,310 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:04,845 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zlParallel at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:04,846 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:06,062 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zltestDeleteWaiting-1316037646-l1 at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:06,062 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:06,093 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zlretryLockSerial at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:06,094 [zookeeper.ZooLock] INFO : Zookeeper Session expired / disconnected 2021-02-04T07:37:07,297 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zltestTryLock-1210442320-l2 at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:07,297 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:07,441 [miniclusterImpl.MiniAccumuloClusterImpl] INFO : Starting MAC against instance miniInstance and zookeeper(s) localhost:42113. 2021-02-04T07:37:08,518 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zltestChangeData-1536761882-l7 at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:08,519 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:09,642 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zltestDeleteWaiting-1316037646-l1 at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:11,379 [zookeeper.ZooSession] DEBUG: Connecting to localhost:42113 with timeout 30000000 with auth 2021-02-04T07:37:11,493 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 created 2021-02-04T07:37:11,496 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:11,496 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:37:11,496 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:11,496 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:11,501 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:11,501 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:37:11,501 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:11,501 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] First candidate is my lock, acquiring... 2021-02-04T07:37:11,537 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 created 2021-02-04T07:37:11,543 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:11,543 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:37:11,544 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:11,544 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:11,544 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:11,560 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:11,560 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:37:11,560 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:11,560 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:11,560 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Lock held by another process with ephemeral node: zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:11,560 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Establishing watch on prior node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:13,723 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:15,594 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zlretryLockSerial at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:15,594 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:17,205 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zlretryLockSerial at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:17,205 [zookeeper.ZooLock] INFO : Zookeeper Session expired / disconnected 2021-02-04T07:37:18,190 [miniclusterImpl.MiniAccumuloClusterImpl] INFO : Starting MAC against instance miniInstance and zookeeper(s) localhost:35157. 2021-02-04T07:37:22,927 [zookeeper.ZooSession] DEBUG: Connecting to localhost:35157 with timeout 30000000 with auth 2021-02-04T07:37:23,060 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 created 2021-02-04T07:37:23,064 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:23,064 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:37:23,064 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:23,064 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:23,067 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:23,068 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:37:23,068 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:23,068 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] First candidate is my lock, acquiring... 2021-02-04T07:37:23,086 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 created 2021-02-04T07:37:23,087 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:23,088 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:37:23,088 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:23,088 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:23,088 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:23,092 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:23,092 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:37:23,092 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:23,092 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:23,092 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Lock held by another process with ephemeral node: zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:23,092 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Establishing watch on prior node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:25,457 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:27,067 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zlretryLockSerial at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:27,068 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:28,173 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zlretryLockSerial at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:28,173 [zookeeper.ZooLock] INFO : Zookeeper Session expired / disconnected 2021-02-04T07:37:29,912 [miniclusterImpl.MiniAccumuloClusterImpl] INFO : Starting MAC against instance miniInstance and zookeeper(s) localhost:46415. 2021-02-04T07:37:33,819 [zookeeper.ZooSession] DEBUG: Connecting to localhost:46415 with timeout 30000000 with auth 2021-02-04T07:37:34,966 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 created 2021-02-04T07:37:34,967 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:34,967 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:37:34,967 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:34,967 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:34,982 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:34,983 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:37:34,983 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:34,983 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] First candidate is my lock, acquiring... 2021-02-04T07:37:34,994 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 created 2021-02-04T07:37:34,994 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:34,995 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:37:34,995 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:34,995 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:34,995 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:34,998 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:34,998 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:37:34,998 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:34,999 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:34,999 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Lock held by another process with ephemeral node: zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:34,999 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Establishing watch on prior node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:36,465 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:37,729 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zlretryLockSerial at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:37,729 [zookeeper.ZooLock] INFO : Zookeeper Session expired / disconnected 2021-02-04T07:37:37,729 [zookeeper.ZooLock] DEBUG: event null None Disconnected 2021-02-04T07:37:38,906 [zookeeper.ZooLock] WARN : lost connection to zookeeper org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /zlretryLockSerial at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:2021) ~[zookeeper-3.5.9.jar:3.5.9] at org.apache.accumulo.fate.zookeeper.ZooLock.process(ZooLock.java:609) [accumulo-core-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT] at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) [zookeeper-3.5.9.jar:3.5.9] at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) [zookeeper-3.5.9.jar:3.5.9] 2021-02-04T07:37:40,894 [miniclusterImpl.MiniAccumuloClusterImpl] INFO : Starting MAC against instance miniInstance and zookeeper(s) localhost:44605. 2021-02-04T07:37:44,806 [zookeeper.ZooSession] DEBUG: Connecting to localhost:44605 with timeout 30000000 with auth 2021-02-04T07:37:47,037 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 created 2021-02-04T07:37:47,039 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:47,039 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:37:47,039 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:47,040 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:47,045 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:47,045 [zookeeper.ZooLock] DEBUG: Children nodes: 1 2021-02-04T07:37:47,046 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:47,046 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#] First candidate is my lock, acquiring... 2021-02-04T07:37:47,051 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Ephemeral node /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 created 2021-02-04T07:37:47,061 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:47,061 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:37:47,061 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:47,061 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:47,062 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Setting watcher on /zlretryLockSerial/zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:47,090 [zookeeper.ZooLock] DEBUG: validating and sorting children at path /zlretryLockSerial 2021-02-04T07:37:47,090 [zookeeper.ZooLock] DEBUG: Children nodes: 2 2021-02-04T07:37:47,090 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:47,090 [zookeeper.ZooLock] DEBUG: - zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#0000000001 2021-02-04T07:37:47,090 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Lock held by another process with ephemeral node: zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 2021-02-04T07:37:47,090 [zookeeper.ZooLock] DEBUG: [zlock#00000000-0000-0000-0000-bbbbbbbbbbbb#] Establishing watch on prior node /zlretryLockSerial/zlock#00000000-0000-0000-0000-aaaaaaaaaaaa#0000000000 ```