Uploaded image for project: 'Couchbase Server'
  1. Couchbase Server
  2. MB-53238

[6.6.5-15322] : RollbackAll to zero seen with need older than last used snapshot error in the indexer logs

    XMLWordPrintable

Details

    • Bug
    • Status: Closed
    • Major
    • Resolution: Duplicate
    • 6.6.5
    • None
    • secondary-index
    • None
    • 6.6.5-15322
    • Untriaged
    • 1
    • Unknown

    Description

      Steps to reproduce can be found here -> 

      https://issues.couchbase.com/browse/MB-53183

      Rollback seen in the indexer node 172.23.100.19

      Please use the timestamp 022-08-03T02:01:20.961-07:00  for analysis. There's a different ticket open with an older rollbackAlltoZero instance.

      022-08-03T02:01:20.961-07:00 [Info] test4/idx4/Mainstore#7627415350602477621:0 Plasma: Disable page eviction before reaching quota.
      2022-08-03T02:01:20.964-07:00 [Info] StorageMgr::handleRollback Rollback Index: 7627415350602477621 PartitionId: 0 SliceId: 0 To Zero 
      2022-08-03T02:01:20.964-07:00 [Info] StorageMgr::rollbackAllToZero MAINT_STREAM test4
      2022-08-03T02:01:21.023-07:00 [Info] Timekeeper::repairStream need rollback for MAINT_STREAM test2 8. Sending Init Prepare.
      2022-08-03T02:01:21.023-07:00 [Info] StreamState::adjustNonSnapAlignedVbs2022-08-03T02:01:20.585-07:00 [Info] StorageMgr::handleRollback 7627415350602477621 Discarding Snapshot SnapshotInfo: count:12009096 committed:false. Need older than last used snapshot bucket: test4, vbuckets: 1024 Crc64: 3946607195157190300 snapType FORCE_COMMIT -
      2022-08-03T02:01:20.587-07:00 [Info] StorageMgr::handleRollback 7627415350602477621 Discarding Snapshot SnapshotInfo: count:11999430 committed:false. Need older than last used snapshot bucket: test4, vbuckets: 1024 Crc64: 3946607195157190300 snapType FORCE_COMMIT -
      2022-08-03T02:01:21.575-07:00 [Info] StorageMgr::handleRollback 5088033563815624859 Discarding Snapshot SnapshotInfo: count:2358273 committed:false. Need older than last used snapshot bucket: test2, vbuckets: 1024 Crc64: 15555523098821266503 snapType FORCE_COMMIT -
      2022-08-03T02:01:21.577-07:00 [Info] StorageMgr::handleRollback 5088033563815624859 Discarding Snapshot SnapshotInfo: count:2357369 committed:false. Need older than last used snapshot bucket: test2, vbuckets: 1024 Crc64: 15555523098821266503 snapType FORCE_COMMIT -
      2022-08-03T02:01:28.367-07:00 [Info] StorageMgr::handleRollback 5919385808814089619 Discarding Snapshot SnapshotInfo: count:2372196 committed:false. Need older than last used snapshot bucket: test1, vbuckets: 1024 Crc64: 3186050440494187341 snapType FORCE_COMMIT -
      2022-08-03T02:01:28.373-07:00 [Info] StorageMgr::handleRollback 5919385808814089619 Discarding Snapshot SnapshotInfo: count:2371379 committed:false. Need older than last used snapshot bucket:

       

      Toy build -> Enterprise Edition 6.6.5 build 15322

       

      cbcollect logs

      https://cb-engineering.s3.amazonaws.com/MB-53221-2/collectinfo-2022-08-03T090330-ns_1%40172.23.100.15.zip
      https://cb-engineering.s3.amazonaws.com/MB-53221-2/collectinfo-2022-08-03T090330-ns_1%40172.23.100.16.zip
      https://cb-engineering.s3.amazonaws.com/MB-53221-2/collectinfo-2022-08-03T090330-ns_1%40172.23.100.17.zip
      https://cb-engineering.s3.amazonaws.com/MB-53221-2/collectinfo-2022-08-03T090330-ns_1%40172.23.100.19.zip
      https://cb-engineering.s3.amazonaws.com/MB-53221-2/collectinfo-2022-08-03T090330-ns_1%40172.23.100.22.zip
      https://cb-engineering.s3.amazonaws.com/MB-53221-2/collectinfo-2022-08-03T090330-ns_1%40172.23.121.215.zip

       

      cc Ritam Sharma Balakumaran Gopal 

      Attachments

        Issue Links

          No reviews matched the request. Check your Options in the drop-down menu of this sections header.

          Activity

            a. Taking rollback on test1 bucket for example

            2022-08-03T02:00:30.845-07:00 [Info] StorageMgr::handleRollback 5919385808814089619 latestSnapInfo SnapshotInfo: count:2372196 committed:false lastRollbackTs <nil>. Use latest snapshot.
            2022-08-03T02:00:30.845-07:00 [Info] StorageMgr::handleRollback 5919385808814089619 latestSnapInfo: SnapshotInfo: count:2372196 committed:false, timestamp: bucket: test1, vbuckets: 1024 Crc64: 3186050440494187341 snapType FORCE_COMMIT -
                {vbno, vbuuid, seqno, snapshot-start, snapshot-end}
                {  108     aac04fbbaea8       6638       6638       6638}
            
            

            b. Indexer got rollbacks for multiple vbuckets when tried with this disk snapshot

            2022-08-03T02:00:38.097-07:00 [Info] TK StreamBegin MAINT_STREAM test1 108 187742948142760 6637 7
            2022-08-03T02:00:38.097-07:00 [Warn] Timekeeper::handleStreamBegin StreamBegin rollback for StreamId MAINT_STREAM Bucket test1 vbucket 108. Rollback (6637,     aac04fbbaea8).
            
            

            c. Primarily because, indexer is asking a snapshot that does not exist with producer

            2022-08-03T02:00:37.432833-07:00 WARNING 61: (test1) DCP (Producer) eq_dcpq:secidx:proj-test1-MAINT_STREAM_TOPIC_731d948000d7ce90274a8909e1f131ea-18333194094929485496/0 - (vb:108) Stream request requires rollback to seqno:6637 because consumer ahead of producer - producer upper at 6637. Client requested seqnos:{6638,18446744073709551615} snapshot:{6638,6638} uuid:187742948142760

            d. Indexer discarded both snapshots - Due to the sequence of events mentioned in MB-53221

            2022-08-03T02:01:28.367-07:00 [Info] StorageMgr::handleRollback 5919385808814089619 Discarding Snapshot SnapshotInfo: count:2372196 committed:false. Need older than last used snapshot bucket: test1, vbuckets: 1024 Crc64: 3186050440494187341 snapType FORCE_COMMIT -
                {vbno, vbuuid, seqno, snapshot-start, snapshot-end}
                {    0     e0492fbc21e2       6156       6148       6156}
            
            

            ..

            2022-08-03T02:01:28.373-07:00 [Info] StorageMgr::handleRollback 5919385808814089619 Discarding Snapshot SnapshotInfo: count:2371379 committed:false. Need older than last used snapshot bucket: test1, vbuckets: 1024 Crc64: 3186050440494187341 snapType FORCE_COMMIT -
            {vbno, vbuuid, seqno, snapshot-start, snapshot-end}
                {    0     e0492fbc21e2       6156       6148       6156}
                {    1     a5c9cb8a8617       6564       6564       6564} 
            

            e. The lastRollbackTs and snapshot timestamp are not same for vb:150 & vb:275

            lastRollbackTs:

                {  150     d7c030702891       6888       6888       6888}
                {  275     ea0d7e7f9f82       3174       3174       3174}
            

            Snapshot timestamp:

                {  150     675f70d89019       6888       6888       6888}
                {  275      c4aac3ebf16       3174       3174       3174}
            

            f. This lead indexer to discard the second snapshot without trying, inspite of it having valid snapshot range

            . Snapshot timestamp: bucket: test1, vbuckets: 1024 Crc64: 8764197757749774136 snapType FORCE_COMMIT -
                {  108     aac04fbbaea8       6421       6421       6421}
            

            Closing this issue as a duplicate of MB-53221

             

            varun.velamuri Varun Velamuri added a comment - a. Taking rollback on test1 bucket for example 2022-08-03T02:00:30.845-07:00 [Info] StorageMgr::handleRollback 5919385808814089619 latestSnapInfo SnapshotInfo: count:2372196 committed:false lastRollbackTs <nil>. Use latest snapshot. 2022-08-03T02:00:30.845-07:00 [Info] StorageMgr::handleRollback 5919385808814089619 latestSnapInfo: SnapshotInfo: count:2372196 committed:false, timestamp: bucket: test1, vbuckets: 1024 Crc64: 3186050440494187341 snapType FORCE_COMMIT -     {vbno, vbuuid, seqno, snapshot-start, snapshot-end}   {  108     aac04fbbaea8       6638       6638       6638} b. Indexer got rollbacks for multiple vbuckets when tried with this disk snapshot 2022-08-03T02:00:38.097-07:00 [Info] TK StreamBegin MAINT_STREAM test1 108 187742948142760 6637 7 2022-08-03T02:00:38.097-07:00 [Warn] Timekeeper::handleStreamBegin StreamBegin rollback for StreamId MAINT_STREAM Bucket test1 vbucket 108. Rollback (6637,     aac04fbbaea8). c. Primarily because, indexer is asking a snapshot that does not exist with producer 2022-08-03T02:00:37.432833-07:00 WARNING 61: (test1) DCP (Producer) eq_dcpq:secidx:proj-test1-MAINT_STREAM_TOPIC_731d948000d7ce90274a8909e1f131ea-18333194094929485496/0 - (vb:108) Stream request requires rollback to seqno:6637 because consumer ahead of producer - producer upper at 6637. Client requested seqnos:{6638,18446744073709551615} snapshot:{6638,6638} uuid:187742948142760 d. Indexer discarded both snapshots - Due to the sequence of events mentioned in MB-53221 2022-08-03T02:01:28.367-07:00 [Info] StorageMgr::handleRollback 5919385808814089619 Discarding Snapshot SnapshotInfo: count:2372196 committed:false. Need older than last used snapshot bucket: test1, vbuckets: 1024 Crc64: 3186050440494187341 snapType FORCE_COMMIT -     {vbno, vbuuid, seqno, snapshot-start, snapshot-end}     {    0     e0492fbc21e2       6156       6148       6156} .. 2022-08-03T02:01:28.373-07:00 [Info] StorageMgr::handleRollback 5919385808814089619 Discarding Snapshot SnapshotInfo: count:2371379 committed:false. Need older than last used snapshot bucket: test1, vbuckets: 1024 Crc64: 3186050440494187341 snapType FORCE_COMMIT - {vbno, vbuuid, seqno, snapshot-start, snapshot-end}     {    0     e0492fbc21e2       6156       6148       6156}     {    1     a5c9cb8a8617       6564       6564       6564} e. The lastRollbackTs and snapshot timestamp are not same for vb:150 & vb:275 lastRollbackTs:     {  150     d7c030702891       6888       6888       6888}   {  275     ea0d7e7f9f82       3174       3174       3174} Snapshot timestamp:     {  150     675f70d89019       6888       6888       6888}   {  275      c4aac3ebf16       3174       3174       3174} f. This lead indexer to discard the second snapshot without trying, inspite of it having valid snapshot range . Snapshot timestamp: bucket: test1, vbuckets: 1024 Crc64: 8764197757749774136 snapType FORCE_COMMIT -   {  108     aac04fbbaea8       6421       6421       6421} Closing this issue as a duplicate of MB-53221 .   

            Duplicate of MB-53221

            varun.velamuri Varun Velamuri added a comment - Duplicate of MB-53221

            Varun Velamuri /Pavan PB - I see this is marked as resolved, pls update the fix version here when you get a chance, thanks! 

            prachi.sikchi Prachi Sikchi added a comment - Varun Velamuri / Pavan PB - I see this is marked as resolved, pls update the fix version here when you get a chance, thanks! 

            Closing the ticket as resolution is marked as Duplicate.

            chanabasappa.ghali Chanabasappa Ghali added a comment - Closing the ticket as resolution is marked as Duplicate.

            People

              pavan.pb Pavan PB
              pavan.pb Pavan PB
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Gerrit Reviews

                  There are no open Gerrit changes

                  PagerDuty