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

[System Test] : index building an index is stuck at 0% while the collection has been dropped

    XMLWordPrintable

    Details

      Description

      Test Details
      Build : 7.0.0-3938
      Test : -test tests/integration/cheshirecat/test_cheshirecat_kv_gsi_coll.yml -scope tests/integration/cheshirecat/scope_cheshirecat.yml
      Scale : 3
      Iteration : 1st

      In the Cheshire Cat Longevity test, there are steps to create and drop scopes and collections continuously on bucket8 & bucket9. There is one more step that would create indexes in a loop on these scopes and collections. When the scope/collection is dropped, the corresponding indexes would also be cascade dropped

      There is one index that is stuck in building state at 0% progress. The collection on which this index was created does not exist now, so this is an orphan index.

      index name : idx2_8BT0B4N3Z5
      Keyspace : `bucket9`.`_default`.`Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ`
      Node : 172.23.96.254
      Instance Id : 10472948336169034061
      Defn Id : 4755105098552588744

      The last messages for this index seen in the indexer logs on 172.23.96.254 are

      indexer.log.2.gz:2020-12-04T18:19:41.286-08:00 [Info] Timekeeper::handleFlushStateChange Received Flush State Change for KeyspaceId: bucket9:_default:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ StreamId: INIT_STREAM Type: TK_ENABLE_FLUSH
      indexer.log.2.gz:2020-12-04T18:19:41.287-08:00 [Info] Timekeeper::addIndextoStream IndexCount map[MAINT_STREAM:map[bucket4:45 bucket5:37 bucket6:31 bucket7:38 bucket9:2 default:4] INIT_STREAM:map[bucket9:_default:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ:1]]
      indexer.log.2.gz:	Defn: DefnId: 4755105098552588744 Name: idx2_8BT0B4N3Z5 Using: plasma Bucket: bucket9 Scope/Id: _default/0 Collection/Id: Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ/1d2 IsPrimary: false NumReplica: 4 InstVersion: 0
      indexer.log.2.gz:Instances [indexInstance:<instId:10472948336169034061 state:IndexLoading  definition:<defnID:4755105098552588744 bucket:bucket9 scope:_default collection:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ isPrimary:false name:idx2_8BT0B4N3Z5 using:0 exprType:N1QL secExpressions:<ud>([`free_breakfast` `type` `free_parking` array_count(`public_likes`) `price` `country`])</ud> partitionScheme:SINGLE whereExpression:<ud>()</ud> > singlePartn:endpoints:"172.23.96.254:9105" > ]
      indexer.log.2.gz:Instances [indexInstance:<instId:10472948336169034061 state:IndexLoading  definition:<defnID:4755105098552588744 bucket:bucket9 scope:_default collection:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ isPrimary:false name:idx2_8BT0B4N3Z5 using:0 exprType:N1QL secExpressions:<ud>([`free_breakfast` `type` `free_parking` array_count(`public_likes`) `price` `country`])</ud> partitionScheme:SINGLE whereExpression:<ud>()</ud> > singlePartn:endpoints:"172.23.96.254:9105" > ]
      indexer.log.2.gz:Instances [indexInstance:<instId:10472948336169034061 state:IndexLoading  definition:<defnID:4755105098552588744 bucket:bucket9 scope:_default collection:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ isPrimary:false name:idx2_8BT0B4N3Z5 using:0 exprType:N1QL secExpressions:<ud>([`free_breakfast` `type` `free_parking` array_count(`public_likes`) `price` `country`])</ud> partitionScheme:SINGLE whereExpression:<ud>()</ud> > singlePartn:endpoints:"172.23.96.254:9105" > ]
      indexer.log.2.gz:Instances [indexInstance:<instId:10472948336169034061 state:IndexLoading  definition:<defnID:4755105098552588744 bucket:bucket9 scope:_default collection:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ isPrimary:false name:idx2_8BT0B4N3Z5 using:0 exprType:N1QL secExpressions:<ud>([`free_breakfast` `type` `free_parking` array_count(`public_likes`) `price` `country`])</ud> partitionScheme:SINGLE whereExpression:<ud>()</ud> > singlePartn:endpoints:"172.23.96.254:9105" > ]
      indexer.log.2.gz:Instances [indexInstance:<instId:10472948336169034061 state:IndexLoading  definition:<defnID:4755105098552588744 bucket:bucket9 scope:_default collection:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ isPrimary:false name:idx2_8BT0B4N3Z5 using:0 exprType:N1QL secExpressions:<ud>([`free_breakfast` `type` `free_parking` array_count(`public_likes`) `price` `country`])</ud> partitionScheme:SINGLE whereExpression:<ud>()</ud> > singlePartn:endpoints:"172.23.96.254:9105" > ]
      indexer.log.2.gz:Instances [indexInstance:<instId:10472948336169034061 state:IndexLoading  definition:<defnID:4755105098552588744 bucket:bucket9 scope:_default collection:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ isPrimary:false name:idx2_8BT0B4N3Z5 using:0 exprType:N1QL secExpressions:<ud>([`free_breakfast` `type` `free_parking` array_count(`public_likes`) `price` `country`])</ud> partitionScheme:SINGLE whereExpression:<ud>()</ud> > singlePartn:endpoints:"172.23.96.254:9105" > ]
      indexer.log.2.gz:Instances [indexInstance:<instId:10472948336169034061 state:IndexLoading  definition:<defnID:4755105098552588744 bucket:bucket9 scope:_default collection:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ isPrimary:false name:idx2_8BT0B4N3Z5 using:0 exprType:N1QL secExpressions:<ud>([`free_breakfast` `type` `free_parking` array_count(`public_likes`) `price` `country`])</ud> partitionScheme:SINGLE whereExpression:<ud>()</ud> > singlePartn:endpoints:"172.23.96.254:9105" > ]
      indexer.log.2.gz:Instances [indexInstance:<instId:10472948336169034061 state:IndexLoading  definition:<defnID:4755105098552588744 bucket:bucket9 scope:_default collection:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ isPrimary:false name:idx2_8BT0B4N3Z5 using:0 exprType:N1QL secExpressions:<ud>([`free_breakfast` `type` `free_parking` array_count(`public_likes`) `price` `country`])</ud> partitionScheme:SINGLE whereExpression:<ud>()</ud> > singlePartn:endpoints:"172.23.96.254:9105" > ]
      indexer.log.2.gz:Instances [indexInstance:<instId:10472948336169034061 state:IndexLoading  definition:<defnID:4755105098552588744 bucket:bucket9 scope:_default collection:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ isPrimary:false name:idx2_8BT0B4N3Z5 using:0 exprType:N1QL secExpressions:<ud>([`free_breakfast` `type` `free_parking` array_count(`public_likes`) `price` `country`])</ud> partitionScheme:SINGLE whereExpression:<ud>()</ud> > singlePartn:endpoints:"172.23.96.254:9105" > ]
      indexer.log.2.gz:Instances [indexInstance:<instId:10472948336169034061 state:IndexLoading  definition:<defnID:4755105098552588744 bucket:bucket9 scope:_default collection:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ isPrimary:false name:idx2_8BT0B4N3Z5 using:0 exprType:N1QL secExpressions:<ud>([`free_breakfast` `type` `free_parking` array_count(`public_likes`) `price` `country`])</ud> partitionScheme:SINGLE whereExpression:<ud>()</ud> > singlePartn:endpoints:"172.23.96.254:9105" > ]
      indexer.log.2.gz:Instances [indexInstance:<instId:10472948336169034061 state:IndexLoading  definition:<defnID:4755105098552588744 bucket:bucket9 scope:_default collection:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ isPrimary:false name:idx2_8BT0B4N3Z5 using:0 exprType:N1QL secExpressions:<ud>([`free_breakfast` `type` `free_parking` array_count(`public_likes`) `price` `country`])</ud> partitionScheme:SINGLE whereExpression:<ud>()</ud> > singlePartn:endpoints:"172.23.96.254:9105" > ]
      indexer.log.2.gz:Instances [indexInstance:<instId:10472948336169034061 state:IndexLoading  definition:<defnID:4755105098552588744 bucket:bucket9 scope:_default collection:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ isPrimary:false name:idx2_8BT0B4N3Z5 using:0 exprType:N1QL secExpressions:<ud>([`free_breakfast` `type` `free_parking` array_count(`public_likes`) `price` `country`])</ud> partitionScheme:SINGLE whereExpression:<ud>()</ud> > singlePartn:endpoints:"172.23.96.254:9105" > ]
      indexer.log.2.gz:2020-12-04T18:19:41.608-08:00 [Info] Indexer::processBuildDoneCatchup Success Stream INIT_STREAM KeyspaceId bucket9:_default:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ SessionId 1
      indexer.log.2.gz:2020-12-04T18:19:41.608-08:00 [Info] Indexer::handleInitBuildDoneAck StreamId INIT_STREAM KeyspaceId bucket9:_default:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ SessionId 1
      indexer.log.2.gz:2020-12-04T18:19:41.608-08:00 [Info] Timekeeper::handleInitBuildDoneAck StreamId INIT_STREAM KeyspaceId bucket9:_default:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ
      indexer.log.2.gz:2020-12-04T18:19:41.608-08:00 [Info] Timekeeper::checkInitStreamReadyToMerge INIT_STREAM In Repair.INIT_STREAM cannot be merged. Continue both streams for keyspaceId bucket9:_default:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ.
      indexer.log.2.gz:	KeyspaceId bucket9:_default:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ StreamId INIT_STREAM Vbuckets [].
      indexer.log.2.gz:2020-12-04T18:19:42.027-08:00 [Info] Timekeeper::repairStream Nothing to repair for Stream INIT_STREAM and KeyspaceId bucket9:_default:Dpgl7Y4QREwDWaCedPC8hPn6WZuOQ
      

      Also seeing errors like these throughout the log. Maybe these are related :

      [root@s00503 logs]# zgrep -i "feed.DcpGetSeqnos(): MCResponse status=UNKNOWN_COLLECTION" indexer.log.2.gz | grep T18:16
      2020-12-04T18:16:04.988-08:00 [Error] feed.DcpGetSeqnos(): MCResponse status=UNKNOWN_COLLECTION, opcode=DCP_GET_SEQNO, opaque=0, msg: {"error":{"context":"Unknown scope or collection in operation"},"manifest_uid":"46d"}
      2020-12-04T18:16:10.933-08:00 [Error] feed.DcpGetSeqnos(): MCResponse status=UNKNOWN_COLLECTION, opcode=DCP_GET_SEQNO, opaque=0, msg: {"error":{"context":"Unknown scope or collection in operation"},"manifest_uid":"46e"}
      2020-12-04T18:16:18.448-08:00 [Error] feed.DcpGetSeqnos(): MCResponse status=UNKNOWN_COLLECTION, opcode=DCP_GET_SEQNO, opaque=0, msg: {"error":{"context":"Unknown scope or collection in operation"},"manifest_uid":"46e"}
      2020-12-04T18:16:31.766-08:00 [Error] feed.DcpGetSeqnos(): MCResponse status=UNKNOWN_COLLECTION, opcode=DCP_GET_SEQNO, opaque=0, msg: {"error":{"context":"Unknown scope or collection in operation"},"manifest_uid":"46f"}
      2020-12-04T18:16:40.558-08:00 [Error] feed.DcpGetSeqnos(): MCResponse status=UNKNOWN_COLLECTION, opcode=DCP_GET_SEQNO, opaque=0, msg: {"error":{"context":"Unknown scope or collection in operation"},"manifest_uid":"46f"}
      2020-12-04T18:16:49.442-08:00 [Error] feed.DcpGetSeqnos(): MCResponse status=UNKNOWN_COLLECTION, opcode=DCP_GET_SEQNO, opaque=0, msg: {"error":{"context":"Unknown scope or collection in operation"},"manifest_uid":"470"}
      2020-12-04T18:16:57.824-08:00 [Error] feed.DcpGetSeqnos(): MCResponse status=UNKNOWN_COLLECTION, opcode=DCP_GET_SEQNO, opaque=0, msg: {"error":{"context":"Unknown scope or collection in operation"},"manifest_uid":"471"}
      

      All indexer nodes = 172.23.123.32, 172.23.96.243, 172.23.96.254, 172.23.97.105, 172.23.97.110, 172.23.97.112
      All Query nodes = 172.23.97.148, 172.23.97.149

        Attachments

        For Gerrit Dashboard: MB-43117
        # Subject Branch Project Status CR V

          Activity

          Hide
          build-team Couchbase Build Team added a comment -

          Build couchbase-server-7.0.0-4114 contains indexing commit ba7ddf8 with commit message:
          MB-43117 Log more information when there are errors fetching seqnos

          Show
          build-team Couchbase Build Team added a comment - Build couchbase-server-7.0.0-4114 contains indexing commit ba7ddf8 with commit message: MB-43117 Log more information when there are errors fetching seqnos
          Hide
          build-team Couchbase Build Team added a comment -

          Build couchbase-server-7.0.0-4114 contains indexing commit 2056d46 with commit message:
          MB-43117 Add timeouts when opening memcached connections

          Show
          build-team Couchbase Build Team added a comment - Build couchbase-server-7.0.0-4114 contains indexing commit 2056d46 with commit message: MB-43117 Add timeouts when opening memcached connections
          Hide
          build-team Couchbase Build Team added a comment -

          Build couchbase-server-7.0.0-4114 contains indexing commit 9de5101 with commit message:
          MB-43117 Respond back to outstanding requets in worker channels on close

          Show
          build-team Couchbase Build Team added a comment - Build couchbase-server-7.0.0-4114 contains indexing commit 9de5101 with commit message: MB-43117 Respond back to outstanding requets in worker channels on close
          Hide
          build-team Couchbase Build Team added a comment -

          Build couchbase-server-7.0.0-4131 contains indexing commit 3c5fe91 with commit message:
          MB-43117 Use pointer based reference for requests/responses in dcp_seqno

          Show
          build-team Couchbase Build Team added a comment - Build couchbase-server-7.0.0-4131 contains indexing commit 3c5fe91 with commit message: MB-43117 Use pointer based reference for requests/responses in dcp_seqno
          Hide
          mihir.kamdar Mihir Kamdar added a comment -

          Verified on 7.0.0-4226. Not seeing this issue any more.

          Show
          mihir.kamdar Mihir Kamdar added a comment - Verified on 7.0.0-4226. Not seeing this issue any more.

            People

            Assignee:
            varun.velamuri Varun Velamuri
            Reporter:
            mihir.kamdar Mihir Kamdar
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved:

                PagerDuty