Skip to content

Instantly share code, notes, and snippets.

@programmatix

programmatix/gist:88f8ca7c130ae6e1bce3794073f12338 Secret

Created August 8, 2022 13:04
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save programmatix/88f8ca7c130ae6e1bce3794073f12338 to your computer and use it in GitHub Desktop.
Save programmatix/88f8ca7c130ae6e1bce3794073f12338 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
gistfile1.txt
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.591 8981/java-performer-1948/9c46a SDK version: - config: atrs=1024, metadataCollection=Optional.empty, expiry=15000ms durability=MAJORITY per-txn config= durability=Optional.empty, supported=Supported {extensions=[EXT_TRANSACTION_ID, EXT_DEFERRED_COMMIT, EXT_TIME_OPT_UNSTAGING, EXT_BINARY_METADATA, EXT_CUSTOM_METADATA_COLLECTION, EXT_QUERY, EXT_STORE_DURABILITY, BF_CBD_3838, BF_CBD_3787, BF_CBD_3705, BF_CBD_3794, EXT_REMOVE_COMPLETED, EXT_ALL_KV_COMBINATIONS, EXT_UNKNOWN_ATR_STATES, BF_CBD_3791, EXT_SINGLE_QUERY, EXT_THREAD_SAFE, EXT_SERIALIZATION, EXT_SDK_INTEGRATION, EXT_MOBILE_INTEROP], protocol=2.1}
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.591 8907/cb-txn-1909/9c46a/1074b starting attempt 1/9c46ad61-b3f1-4ec0-b444-bd6577d66507/1074bde4-85f9-4f3a-9af0-8d547cbab978
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 8907/cb-txn-1909/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id5</ud> - ebdee] is locking, 0 waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 8907/cb-txn-1909/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id5</ud> - ebdee], 1 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 8907/cb-txn-1909/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id5</ud>, resolvingMissingATREntry=<empty>
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 4459/cb-txn-717/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id4</ud> - 51948] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id5</ud> - ebdee], 0 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 1967/cb-txn-253/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id7</ud> - 10a11] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id5</ud> - ebdee], 1 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 8907/cb-txn-1909/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id5</ud> - ebdee: standard] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id4</ud> - 51948] now has lock, 1 left waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 8826/cb-txn-1879/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id0</ud> - 86216] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id4</ud> - 51948], 1 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 8908/cb-txn-1910/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id4</ud> - 51948], 2 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 8908/cb-txn-1910/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id4</ud>, resolvingMissingATREntry=<empty>
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 8907/cb-txn-1909/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id3</ud> - d6ea8] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id4</ud> - 51948], 2 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 8908/cb-txn-1910/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id4</ud> - 51948: standard] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id7</ud> - 10a11] now has lock, 2 left waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 8906/cb-txn-1908/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id7</ud> - 10a11], 3 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 8906/cb-txn-1908/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id7</ud>, resolvingMissingATREntry=<empty>
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.592 8906/cb-txn-1908/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id7</ud> - 10a11: standard] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id0</ud> - 86216] now has lock, 1 left waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8903/cb-txn-1905/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id0</ud> - 86216], 4 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8908/cb-txn-1910/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id1</ud> - 5436d] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id0</ud> - 86216], 1 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8903/cb-txn-1905/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id0</ud>, resolvingMissingATREntry=<empty>
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8903/cb-txn-1905/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id0</ud> - 86216: standard] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id3</ud> - d6ea8] now has lock, 1 left waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 4459/cb-txn-717/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id6</ud> - 4575f] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id3</ud> - d6ea8], 1 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8903/cb-txn-1905/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id8</ud> - 7954d] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id3</ud> - d6ea8], 2 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8826/cb-txn-1879/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id3</ud> - d6ea8], 5 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8826/cb-txn-1879/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id3</ud>, resolvingMissingATREntry=<empty>
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8826/cb-txn-1879/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id3</ud> - d6ea8: standard] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id1</ud> - 5436d] now has lock, 2 left waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8906/cb-txn-1908/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id2</ud> - eae07] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id1</ud> - 5436d], 2 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8826/cb-txn-1879/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id9</ud> - c39dd] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id1</ud> - 5436d], 3 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id1</ud> - 5436d], 6 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id1</ud>, resolvingMissingATREntry=<empty>
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id1</ud> - 5436d: standard] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id6</ud> - 4575f] now has lock, 3 left waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id6</ud> - 4575f], 7 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id6</ud>, resolvingMissingATREntry=<empty>
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id6</ud> - 4575f: standard] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id8</ud> - 7954d] now has lock, 2 left waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id8</ud> - 7954d], 8 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id8</ud>, resolvingMissingATREntry=<empty>
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id8</ud> - 7954d: standard] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id2</ud> - eae07] now has lock, 1 left waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id2</ud> - eae07], 9 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id2</ud>, resolvingMissingATREntry=<empty>
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id2</ud> - eae07: standard] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id9</ud> - c39dd] now has lock, 0 left waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id9</ud> - c39dd], 10 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id9</ud>, resolvingMissingATREntry=<empty>
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.593 8907/cb-txn-1909/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id9</ud> - c39dd: standard] is unlocking, nothing waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8907/cb-txn-1909/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id5</ud>,cas=1659908097547239424,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 1850us
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8826/cb-txn-1879/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id7</ud>,cas=1659908097553203200,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 1858us
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8907/cb-txn-1909/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id5</ud> - ebdee] is done, 9 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8826/cb-txn-1879/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id7</ud> - 10a11] is done, 8 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8906/cb-txn-1908/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id7</ud> - 78b7d] is locking, 0 waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8906/cb-txn-1908/9c46a/1074b WG: adding [replace <ud>default.Optional[_default].Optional[_default].id7</ud> - 78b7d], 9 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8906/cb-txn-1908/9c46a/1074b replace doc TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id7</ud>,cas=1659908097553203200,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty}, operationId = 78b7d114-bf73-46e2-9566-6506d55be0d9
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8826/cb-txn-1879/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id4</ud>,cas=1659908097544224768,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 1979us
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8826/cb-txn-1879/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id4</ud> - 51948] is done, 8 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8826/cb-txn-1879/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id3</ud>,cas=1659908097539964928,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 1914us
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 1967/cb-txn-253/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id5</ud> - 909a2] will wait for lock currently held by [replace <ud>default.Optional[_default].Optional[_default].id7</ud> - 78b7d], 0 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8906/cb-txn-1908/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id7</ud> - 78b7d: standard] is unlocking, [replace <ud>default.Optional[_default].Optional[_default].id5</ud> - 909a2] now has lock, 0 left waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8826/cb-txn-1879/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id3</ud> - d6ea8] is done, 7 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8906/cb-txn-1908/9c46a/1074b LOCK: [before ATR <ud>default.Optional[_default].Optional[_default].id7</ud>] will wait for lock currently held by [replace <ud>default.Optional[_default].Optional[_default].id5</ud> - 909a2], 0 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8903/cb-txn-1905/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id3</ud> - dc82a] will wait for lock currently held by [replace <ud>default.Optional[_default].Optional[_default].id5</ud> - 909a2], 1 other waiters
21:35:12.596 [grpc-default-executor-90] INFO  com.couchbase.PerformerService - ================ Test file : Start ================ 
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 4459/cb-txn-717/9c46a/1074b WG: adding [replace <ud>default.Optional[_default].Optional[_default].id5</ud> - 909a2], 8 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 4459/cb-txn-717/9c46a/1074b replace doc TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id5</ud>,cas=1659908097547239424,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty}, operationId = 909a2b5d-ac5a-4222-8c63-449654856afa
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8907/cb-txn-1909/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id4</ud> - 4978d] will wait for lock currently held by [replace <ud>default.Optional[_default].Optional[_default].id5</ud> - 909a2], 2 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 4459/cb-txn-717/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id5</ud> - 909a2: standard] is unlocking, [before ATR <ud>default.Optional[_default].Optional[_default].id7</ud>] now has lock, 2 left waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 4459/cb-txn-717/9c46a/1074b LOCK: [before ATR <ud>default.Optional[_default].Optional[_default].id5</ud>] will wait for lock currently held by [before ATR <ud>default.Optional[_default].Optional[_default].id7</ud>], 2 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 4299/cb-txn-662/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id1</ud>,cas=1659908097533411328,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 1989us
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8908/cb-txn-1910/9c46a/1074b First mutated doc in txn is '<ud>default.Optional[_default].Optional[_default].id7</ud>' on vbucket 363, so using atr _txn:atr-363-#cf8
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.594 8908/cb-txn-1910/9c46a/1074b about to set ATR <ud>default:_default._default._txn:atr-363-#cf8</ud> to Pending
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.595 4299/cb-txn-662/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id1</ud> - 5436d] is done, 7 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.595 4459/cb-txn-717/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id1</ud> - f9ad7] will wait for lock currently held by [before ATR <ud>default.Optional[_default].Optional[_default].id7</ud>], 3 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.595 8826/cb-txn-1879/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id0</ud>,cas=1659908097530331136,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 2402us
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.595 8826/cb-txn-1879/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id0</ud> - 86216] is done, 6 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.595 8908/cb-txn-1910/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id0</ud> - c5475] will wait for lock currently held by [before ATR <ud>default.Optional[_default].Optional[_default].id7</ud>], 4 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.595 4299/cb-txn-662/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id6</ud>,cas=1659908097550188544,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 2151us
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.595 4299/cb-txn-662/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id6</ud> - 4575f] is done, 5 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.595 8826/cb-txn-1879/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id6</ud> - aa3a6] will wait for lock currently held by [before ATR <ud>default.Optional[_default].Optional[_default].id7</ud>], 5 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.595 4299/cb-txn-662/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id9</ud>,cas=1659908097559756800,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 2242us
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.595 4299/cb-txn-662/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id9</ud> - c39dd] is done, 4 now in waiting
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.595 1967/cb-txn-253/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id9</ud> - e429a] will wait for lock currently held by [before ATR <ud>default.Optional[_default].Optional[_default].id7</ud>], 6 other waiters
21:35:12.596 [cb-txn-1913] INFO   -     21:34:57.596 8906/cb-txn-1908/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id2</ud>,cas=1659908097536360448,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 3664us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.596 4299/cb-txn-662/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id8</ud>,cas=1659908097555890176,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 3750us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.596 8906/cb-txn-1908/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id2</ud> - eae07] is done, 3 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.596 8904/cb-txn-1906/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id2</ud> - 6b757] will wait for lock currently held by [before ATR <ud>default.Optional[_default].Optional[_default].id7</ud>], 7 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.596 4299/cb-txn-662/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id8</ud> - 7954d] is done, 2 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.596 8906/cb-txn-1908/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id8</ud> - 70890] will wait for lock currently held by [before ATR <ud>default.Optional[_default].Optional[_default].id7</ud>], 8 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.598 4299/cb-txn-662/9c46a/1074b set ATR <ud>default:_default._default._txn:atr-363-#cf8</ud> to Pending in 3663us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.598 4299/cb-txn-662/9c46a/1074b changed state to PENDING
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.598 4299/cb-txn-662/9c46a/1074b about to replace doc <ud>default.Optional[_default].Optional[_default].id7</ud> with cas 1659908097553203200, accessDeleted=false
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.598 4299/cb-txn-662/9c46a/1074b LOCK: [before ATR <ud>default.Optional[_default].Optional[_default].id7</ud>: doUnderLock on signal onComplete] is unlocking, [replace <ud>default.Optional[_default].Optional[_default].id3</ud> - dc82a] now has lock, 8 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.598 4299/cb-txn-662/9c46a/1074b WG: adding [replace <ud>default.Optional[_default].Optional[_default].id3</ud> - dc82a], 3 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.598 4299/cb-txn-662/9c46a/1074b replace doc TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id3</ud>,cas=1659908097539964928,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty}, operationId = dc82a7c5-b642-4201-978c-da768c8b8fe2
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.598 4299/cb-txn-662/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id3</ud> - dc82a: standard] is unlocking, [replace <ud>default.Optional[_default].Optional[_default].id4</ud> - 4978d] now has lock, 7 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.598 4299/cb-txn-662/9c46a/1074b about to replace doc <ud>default.Optional[_default].Optional[_default].id3</ud> with cas 1659908097539964928, accessDeleted=false
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.598 8905/cb-txn-1907/9c46a/1074b WG: adding [replace <ud>default.Optional[_default].Optional[_default].id4</ud> - 4978d], 4 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.598 8905/cb-txn-1907/9c46a/1074b replace doc TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id4</ud>,cas=1659908097544224768,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty}, operationId = 4978dc92-929d-4a7f-b3b6-9b02ff5acacc
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.598 8905/cb-txn-1907/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id4</ud> - 4978d: standard] is unlocking, [before ATR <ud>default.Optional[_default].Optional[_default].id5</ud>] now has lock, 6 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 8905/cb-txn-1907/9c46a/1074b about to replace doc <ud>default.Optional[_default].Optional[_default].id4</ud> with cas 1659908097544224768, accessDeleted=false
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 8905/cb-txn-1907/9c46a/1074b about to replace doc <ud>default.Optional[_default].Optional[_default].id5</ud> with cas 1659908097547239424, accessDeleted=false
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 8905/cb-txn-1907/9c46a/1074b LOCK: [before ATR <ud>default.Optional[_default].Optional[_default].id5</ud>: doUnderLock on signal onComplete] is unlocking, [replace <ud>default.Optional[_default].Optional[_default].id1</ud> - f9ad7] now has lock, 5 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 8905/cb-txn-1907/9c46a/1074b WG: adding [replace <ud>default.Optional[_default].Optional[_default].id1</ud> - f9ad7], 5 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 8905/cb-txn-1907/9c46a/1074b replace doc TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id1</ud>,cas=1659908097533411328,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty}, operationId = f9ad7aa3-f74e-49d2-bd8c-8363eb260a97
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 8905/cb-txn-1907/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id1</ud> - f9ad7: standard] is unlocking, [replace <ud>default.Optional[_default].Optional[_default].id0</ud> - c5475] now has lock, 4 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 8905/cb-txn-1907/9c46a/1074b about to replace doc <ud>default.Optional[_default].Optional[_default].id1</ud> with cas 1659908097533411328, accessDeleted=false
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 8907/cb-txn-1909/9c46a/1074b WG: adding [replace <ud>default.Optional[_default].Optional[_default].id0</ud> - c5475], 6 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 8907/cb-txn-1909/9c46a/1074b replace doc TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id0</ud>,cas=1659908097530331136,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty}, operationId = c5475bf4-963a-4aa3-bb18-7737534ec8fc
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 8907/cb-txn-1909/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id0</ud> - c5475: standard] is unlocking, [replace <ud>default.Optional[_default].Optional[_default].id6</ud> - aa3a6] now has lock, 3 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 8907/cb-txn-1909/9c46a/1074b about to replace doc <ud>default.Optional[_default].Optional[_default].id0</ud> with cas 1659908097530331136, accessDeleted=false
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b WG: adding [replace <ud>default.Optional[_default].Optional[_default].id6</ud> - aa3a6], 7 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b replace doc TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id6</ud>,cas=1659908097550188544,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty}, operationId = aa3a6bbf-6f1a-438f-a866-e74c9daa4d94
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id6</ud> - aa3a6: standard] is unlocking, [replace <ud>default.Optional[_default].Optional[_default].id9</ud> - e429a] now has lock, 2 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b about to replace doc <ud>default.Optional[_default].Optional[_default].id6</ud> with cas 1659908097550188544, accessDeleted=false
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b WG: adding [replace <ud>default.Optional[_default].Optional[_default].id9</ud> - e429a], 8 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b replace doc TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id9</ud>,cas=1659908097559756800,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty}, operationId = e429aa6d-0bf3-44ec-9410-b5ff93fe4818
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id9</ud> - e429a: standard] is unlocking, [replace <ud>default.Optional[_default].Optional[_default].id2</ud> - 6b757] now has lock, 1 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b about to replace doc <ud>default.Optional[_default].Optional[_default].id9</ud> with cas 1659908097559756800, accessDeleted=false
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b WG: adding [replace <ud>default.Optional[_default].Optional[_default].id2</ud> - 6b757], 9 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b replace doc TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id2</ud>,cas=1659908097536360448,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty}, operationId = 6b757209-0414-41e3-9a47-b377720babd4
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id2</ud> - 6b757: standard] is unlocking, [replace <ud>default.Optional[_default].Optional[_default].id8</ud> - 70890] now has lock, 0 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b about to replace doc <ud>default.Optional[_default].Optional[_default].id2</ud> with cas 1659908097536360448, accessDeleted=false
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b WG: adding [replace <ud>default.Optional[_default].Optional[_default].id8</ud> - 70890], 10 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b replace doc TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id8</ud>,cas=1659908097555890176,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty}, operationId = 708909a4-e18f-4235-bfa4-376b2870eb2e
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id8</ud> - 70890: standard] is unlocking, nothing waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.599 4459/cb-txn-717/9c46a/1074b about to replace doc <ud>default.Optional[_default].Optional[_default].id8</ud> with cas 1659908097555890176, accessDeleted=false
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.602 4459/cb-txn-717/9c46a/1074b replaced doc <ud>default.Optional[_default].Optional[_default].id5</ud> got cas 1659908097599799296, in 2877us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.602 4459/cb-txn-717/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id5</ud>] is locking, 0 waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.602 4459/cb-txn-717/9c46a/1074b WG: [replace <ud>default.Optional[_default].Optional[_default].id5</ud> - 909a2] is done, 9 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.602 8906/cb-txn-1908/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id15</ud> - 9ac87] will wait for lock currently held by [addStagedMutation <ud>default.Optional[_default].Optional[_default].id5</ud>], 0 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.602 4459/cb-txn-717/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id5</ud>: doUnderLock on signal onComplete] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id15</ud> - 9ac87] now has lock, 0 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.602 8905/cb-txn-1907/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id15</ud> - 9ac87], 10 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.602 8905/cb-txn-1907/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id15</ud>, resolvingMissingATREntry=<empty>
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.602 8905/cb-txn-1907/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id15</ud> - 9ac87: standard] is unlocking, nothing waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.603 8905/cb-txn-1907/9c46a/1074b replaced doc <ud>default.Optional[_default].Optional[_default].id7</ud> got cas 1659908097599078400, in 5316us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.603 8905/cb-txn-1907/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id7</ud>] is locking, 0 waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8906/cb-txn-1908/9c46a/1074b replaced doc <ud>default.Optional[_default].Optional[_default].id2</ud> got cas 1659908097600192512, in 4270us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8906/cb-txn-1908/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id2</ud>] will wait for lock currently held by [addStagedMutation <ud>default.Optional[_default].Optional[_default].id7</ud>], 0 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8906/cb-txn-1908/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id17</ud> - 5901f] will wait for lock currently held by [addStagedMutation <ud>default.Optional[_default].Optional[_default].id7</ud>], 1 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8905/cb-txn-1907/9c46a/1074b WG: [replace <ud>default.Optional[_default].Optional[_default].id7</ud> - 78b7d] is done, 9 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8905/cb-txn-1907/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id7</ud>: doUnderLock on signal onComplete] is unlocking, [addStagedMutation <ud>default.Optional[_default].Optional[_default].id2</ud>] now has lock, 1 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8904/cb-txn-1906/9c46a/1074b replaced doc <ud>default.Optional[_default].Optional[_default].id8</ud> got cas 1659908097602420736, in 4370us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8904/cb-txn-1906/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id8</ud>] will wait for lock currently held by [addStagedMutation <ud>default.Optional[_default].Optional[_default].id2</ud>], 1 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8905/cb-txn-1907/9c46a/1074b WG: [replace <ud>default.Optional[_default].Optional[_default].id2</ud> - 6b757] is done, 8 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8905/cb-txn-1907/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id2</ud>: doUnderLock on signal onComplete] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id17</ud> - 5901f] now has lock, 1 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 4459/cb-txn-717/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id12</ud> - 563a0] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id17</ud> - 5901f], 1 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8905/cb-txn-1907/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id17</ud> - 5901f], 9 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8905/cb-txn-1907/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id17</ud>, resolvingMissingATREntry=<empty>
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8905/cb-txn-1907/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id17</ud> - 5901f: standard] is unlocking, [addStagedMutation <ud>default.Optional[_default].Optional[_default].id8</ud>] now has lock, 1 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 1967/cb-txn-253/9c46a/1074b WG: [replace <ud>default.Optional[_default].Optional[_default].id8</ud> - 70890] is done, 8 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 1967/cb-txn-253/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id8</ud>: doUnderLock on signal onComplete] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id12</ud> - 563a0] now has lock, 0 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8905/cb-txn-1907/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id18</ud> - e6d7f] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id12</ud> - 563a0], 0 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 1967/cb-txn-253/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id12</ud> - 563a0], 9 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 1967/cb-txn-253/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id12</ud>, resolvingMissingATREntry=<empty>
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 1967/cb-txn-253/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id12</ud> - 563a0: standard] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id18</ud> - e6d7f] now has lock, 0 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8904/cb-txn-1906/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id18</ud> - e6d7f], 10 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8904/cb-txn-1906/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id18</ud>, resolvingMissingATREntry=<empty>
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8904/cb-txn-1906/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id18</ud> - e6d7f: standard] is unlocking, nothing waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8904/cb-txn-1906/9c46a/1074b replaced doc <ud>default.Optional[_default].Optional[_default].id0</ud> got cas 1659908097601896448, in 5561us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.604 8904/cb-txn-1906/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id0</ud>] is locking, 0 waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.605 8905/cb-txn-1907/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id10</ud> - 8633b] will wait for lock currently held by [addStagedMutation <ud>default.Optional[_default].Optional[_default].id0</ud>], 0 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.605 8904/cb-txn-1906/9c46a/1074b WG: [replace <ud>default.Optional[_default].Optional[_default].id0</ud> - c5475] is done, 9 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.605 8904/cb-txn-1906/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id0</ud>: doUnderLock on signal onComplete] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id10</ud> - 8633b] now has lock, 0 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.605 8906/cb-txn-1908/9c46a/1074b WG: adding [get <ud>default.Optional[_default].Optional[_default].id10</ud> - 8633b], 10 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.605 8906/cb-txn-1908/9c46a/1074b getting doc <ud>default.Optional[_default].Optional[_default].id10</ud>, resolvingMissingATREntry=<empty>
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.605 8906/cb-txn-1908/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id10</ud> - 8633b: standard] is unlocking, nothing waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 8906/cb-txn-1908/9c46a/1074b replaced doc <ud>default.Optional[_default].Optional[_default].id4</ud> got cas 1659908097602224128, in 8216us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 8906/cb-txn-1908/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id4</ud>] is locking, 0 waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 8905/cb-txn-1907/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id15</ud>,cas=1659908097577189376,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 5060us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 8904/cb-txn-1906/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id10</ud>,cas=1659908097562443776,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 2210us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 8905/cb-txn-1907/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id15</ud> - 9ac87] is done, 9 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 8906/cb-txn-1908/9c46a/1074b WG: [replace <ud>default.Optional[_default].Optional[_default].id4</ud> - 4978d] is done, 8 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 8904/cb-txn-1906/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id10</ud> - 8633b] is done, 7 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 4459/cb-txn-717/9c46a/1074b LOCK: [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716] will wait for lock currently held by [addStagedMutation <ud>default.Optional[_default].Optional[_default].id4</ud>], 0 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 1967/cb-txn-253/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id15</ud> - fadd4] will wait for lock currently held by [addStagedMutation <ud>default.Optional[_default].Optional[_default].id4</ud>], 1 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 8906/cb-txn-1908/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id4</ud>: doUnderLock on signal onComplete] is unlocking, [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716] now has lock, 1 left waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 8826/cb-txn-1879/9c46a/1074b replaced doc <ud>default.Optional[_default].Optional[_default].id1</ud> got cas 1659908097604911104, in 8108us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 8826/cb-txn-1879/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id1</ud>] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 1 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.607 8905/cb-txn-1907/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id10</ud> - cb918] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 2 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 8906/cb-txn-1908/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id17</ud>,cas=1659908097584594944,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 9096us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 8906/cb-txn-1908/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id17</ud> - 5901f] is done, 6 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 8826/cb-txn-1879/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id17</ud> - 524e1] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 3 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 4459/cb-txn-717/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id12</ud>,cas=1659908097568145408,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 9013us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 8906/cb-txn-1908/9c46a/1074b completed get of TransactionGetResultInternal{id=<ud>default.Optional[_default].Optional[_default].id18</ud>,cas=1659908097586823168,bucket=default,scope=Optional[_default],coll=Optional[_default],links=TransactionLinks{atr=none.none.none.none.,txnId=none,attemptId=none,crc32Staging=none,isDeleted=false,op=none,fc=none,opId=none,restore={none,none,-1}},txnMeta=Optional.empty} in 8717us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 4459/cb-txn-717/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id12</ud> - 563a0] is done, 5 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 8904/cb-txn-1906/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id12</ud> - ece47] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 4 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 8906/cb-txn-1908/9c46a/1074b WG: [get <ud>default.Optional[_default].Optional[_default].id18</ud> - e6d7f] is done, 4 now in waiting
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 8907/cb-txn-1909/9c46a/1074b LOCK: [replace <ud>default.Optional[_default].Optional[_default].id18</ud> - 3f20c] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 5 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 8908/cb-txn-1910/9c46a/1074b replaced doc <ud>default.Optional[_default].Optional[_default].id6</ud> got cas 1659908097608646656, in 13869us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 8908/cb-txn-1910/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id6</ud>] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 6 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 4459/cb-txn-717/9c46a/1074b replaced doc <ud>default.Optional[_default].Optional[_default].id3</ud> got cas 1659908097599537152, in 14543us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.613 4459/cb-txn-717/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id3</ud>] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 7 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.614 4459/cb-txn-717/9c46a/1074b replaced doc <ud>default.Optional[_default].Optional[_default].id9</ud> got cas 1659908097609564160, in 15021us
21:35:12.597 [cb-txn-1913] INFO   -     21:34:57.614 4459/cb-txn-717/9c46a/1074b LOCK: [addStagedMutation <ud>default.Optional[_default].Optional[_default].id9</ud>] will wait for lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 8 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.592 8906/cb-txn-1908/9c46a/1074b Attempt expired while [replace <ud>default.Optional[_default].Optional[_default].id12</ud> - ece47] waiting for lock on timeout of 14979ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.592 4459/cb-txn-717/9c46a/1074b Attempt expired while [addStagedMutation <ud>default.Optional[_default].Optional[_default].id6</ud>] waiting for lock on timeout of 14979ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.592 8908/cb-txn-1910/9c46a/1074b Attempt expired while [replace <ud>default.Optional[_default].Optional[_default].id17</ud> - 524e1] waiting for lock on timeout of 14979ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.592 4299/cb-txn-662/9c46a/1074b Attempt expired while [replace <ud>default.Optional[_default].Optional[_default].id18</ud> - 3f20c] waiting for lock on timeout of 14979ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.592 8915/cb-txn-1915/9c46a/1074b Attempt expired while [addStagedMutation <ud>default.Optional[_default].Optional[_default].id1</ud>] waiting for lock on timeout of 14985ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.592 8914/cb-txn-1914/9c46a/1074b Attempt expired while [addStagedMutation <ud>default.Optional[_default].Optional[_default].id3</ud>] waiting for lock on timeout of 14979ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.592 8913/cb-txn-1913/9c46a/1074b Attempt expired while [replace <ud>default.Optional[_default].Optional[_default].id10</ud> - cb918] waiting for lock on timeout of 14985ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.592 8903/cb-txn-1905/9c46a/1074b Attempt expired while [replace <ud>default.Optional[_default].Optional[_default].id15</ud> - fadd4] waiting for lock on timeout of 14985ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.593 8906/cb-txn-1908/9c46a/1074b changed state bits in operationFailed, changed
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.593 8913/cb-txn-1913/9c46a/1074b changed state bits in operationFailed, changed shouldNotRollback to true shouldNotRetry to true shouldNotCommit to true toRaise from TRANSACTION_SUCCESS to TRANSACTION_EXPIRED
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.593 8903/cb-txn-1905/9c46a/1074b changed state bits in operationFailed, changed
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.593 8914/cb-txn-1914/9c46a/1074b changed state bits in operationFailed, changed
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.593 8914/cb-txn-1914/9c46a/1074b error while replacing doc <ud>default.Optional[_default].Optional[_default].id3</ud> in 14994206355000us: <ud>TransactionOperationFailedException {cause:<ud>com.couchbase.client.core.error.transaction.AttemptExpiredException</ud>, retry:false, autoRollback:false, raise:TRANSACTION_EXPIRED}</ud> cause: <ud>com.couchbase.client.core.error.transaction.AttemptExpiredException: Attempt expired while [addStagedMutation <ud>default.Optional[_default].Optional[_default].id3</ud>] waiting for lock on timeout of 14979ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters</ud> stacktrace:
21:35:12.597 [cb-txn-1913] INFO   -     21:35:12.593 8914/cb-txn-1914/9c46a/1074b changed state bits in operationFailed, changed
21:35:12.598 [cb-txn-1913] INFO   -     21:35:12.593 8983/cb-txn-1949/9c46a/1074b Attempt expired while [addStagedMutation <ud>default.Optional[_default].Optional[_default].id9</ud>] waiting for lock on timeout of 14978ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters
21:35:12.598 [cb-txn-1913] INFO   -     21:35:12.593 8983/cb-txn-1949/9c46a/1074b changed state bits in operationFailed, changed
21:35:12.598 [cb-txn-1913] INFO   -     21:35:12.593 8983/cb-txn-1949/9c46a/1074b error while replacing doc <ud>default.Optional[_default].Optional[_default].id9</ud> in 14993770804000us: <ud>TransactionOperationFailedException {cause:<ud>com.couchbase.client.core.error.transaction.AttemptExpiredException</ud>, retry:false, autoRollback:false, raise:TRANSACTION_EXPIRED}</ud> cause: <ud>com.couchbase.client.core.error.transaction.AttemptExpiredException: Attempt expired while [addStagedMutation <ud>default.Optional[_default].Optional[_default].id9</ud>] waiting for lock on timeout of 14978ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters</ud> stacktrace:
21:35:12.598 [cb-txn-1913] INFO   -     21:35:12.593 8983/cb-txn-1949/9c46a/1074b changed state bits in operationFailed, changed
21:35:12.598 [cb-txn-1913] INFO   -     21:35:12.593 4459/cb-txn-717/9c46a/1074b changed state bits in operationFailed, changed
21:35:12.598 [cb-txn-1913] INFO   -     21:35:12.593 4459/cb-txn-717/9c46a/1074b error while replacing doc <ud>default.Optional[_default].Optional[_default].id6</ud> in 14993943521000us: <ud>TransactionOperationFailedException {cause:<ud>com.couchbase.client.core.error.transaction.AttemptExpiredException</ud>, retry:false, autoRollback:false, raise:TRANSACTION_EXPIRED}</ud> cause: <ud>com.couchbase.client.core.error.transaction.AttemptExpiredException: Attempt expired while [addStagedMutation <ud>default.Optional[_default].Optional[_default].id6</ud>] waiting for lock on timeout of 14979ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters</ud> stacktrace:
21:35:12.598 [cb-txn-1913] INFO   -     21:35:12.593 4459/cb-txn-717/9c46a/1074b changed state bits in operationFailed, changed
21:35:12.598 [cb-txn-1913] INFO   -     21:35:12.593 8915/cb-txn-1915/9c46a/1074b changed state bits in operationFailed, changed
21:35:12.598 [cb-txn-1913] INFO   -     21:35:12.593 8915/cb-txn-1915/9c46a/1074b error while replacing doc <ud>default.Optional[_default].Optional[_default].id1</ud> in 14994176225000us: <ud>TransactionOperationFailedException {cause:<ud>com.couchbase.client.core.error.transaction.AttemptExpiredException</ud>, retry:false, autoRollback:false, raise:TRANSACTION_EXPIRED}</ud> cause: <ud>com.couchbase.client.core.error.transaction.AttemptExpiredException: Attempt expired while [addStagedMutation <ud>default.Optional[_default].Optional[_default].id1</ud>] waiting for lock on timeout of 14985ms, lock currently held by [get <ud>default.Optional[_default].Optional[_default].id14</ud> - 32716], 9 other waiters</ud> stacktrace:
21:35:12.598 [cb-txn-1913] INFO   -     21:35:12.593 4299/cb-txn-662/9c46a/1074b changed state bits in operationFailed, changed
21:35:12.598 [cb-txn-1913] INFO   -     21:35:12.593 8915/cb-txn-1915/9c46a/1074b changed state bits in operationFailed, changed
21:35:12.598 [cb-txn-1913] INFO   -     21:35:12.593 8908/cb-txn-1910/9c46a/1074b changed state bits in operationFailed, changed
21:35:12.598 [cb-txn-1913] INFO   - A parallel op REPLACE has errored with {}
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment