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

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

        Activity

          People

            varun.velamuri Varun Velamuri
            mihir.kamdar Mihir Kamdar (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              PagerDuty