Skip to:

  1. Skip to Jira Navigation
  2. Skip to Side Navigation
  3. Skip to Main Content

[BP MB-50770 to 7.0.x] Query log has flood with messages

Description

Repro : Same as https://couchbasecloud.atlassian.net/browse/MB-50766#icft=MB-50766 + following steps
after travel-sample failed
create default bucket (no data)
create primary index it takes 17s+
then drop the default bucket

query.log keep flood with

127.0.0.1:8091/pools/default/b/default": Requested resource not found.^M ) .. Retrying(122) 2022-02-02T20:03:55.221-08:00 [Warn] cluster_info: Out of sync for bucket default. Retrying to getTerseBucket. retry count 1 2022-02-02T20:03:55.227-08:00 [Warn] cluster_info: Out of sync for bucket default. Retrying to getTerseBucket. retry count 2 2022-02-02T20:03:55.233-08:00 [Warn] cluster_info: Out of sync for bucket default. Retrying to getTerseBucket. retry count 3 2022-02-02T20:03:55.239-08:00 [Warn] cluster_info: Out of sync for bucket default. Retrying to getTerseBucket. retry count 4 2022-02-02T20:03:55.245-08:00 [Warn] cluster_info: Out of sync for bucket default. Retrying to getTerseBucket. retry count 5 2022-02-02T20:03:57.252-08:00 [Info] Error occurred during cluster info update (HTTP error 404 Object Not Found getting "http://127.0.0.1:8091/pools/default/b/default": Requested resource not found.^M ) .. Retrying(123) 2022-02-02T20:03:57.254-08:00 [Warn] cluster_info: Out of sync for bucket default. Retrying to getTerseBucket. retry count 1 2022-02-02T20:03:57.260-08:00 [Warn] cluster_info: Out of sync for bucket default. Retrying to getTerseBucket. retry count 2 2022-02-02T20:03:57.266-08:00 [Warn] cluster_info: Out of sync for bucket default. Retrying to getTerseBucket. retry count 3 2022-02-02T20:03:57.271-08:00 [Warn] cluster_info: Out of sync for bucket default. Retrying to getTerseBucket. retry count 4 2022-02-02T20:03:57.277-08:00 [Warn] cluster_info: Out of sync for bucket default. Retrying to getTerseBucket. retry count 5 2022-02-02T20:03:59.284-08:00 [Info] Error occurred during cluster info update (HTTP error 404 Object Not Found getting "http://127.0.0.1:8091/pools/default/b/default": Requested resource not found.^M ) .. Retrying(124) 2022-02-02T20:03:59.288-08:00 [Warn] cluster_info: Out of sync for bucket default. Retrying to getTerseBucket. retry count 1 2022-02-02T20:03:59.294-08:00 [Warn] cluster_info: Out of sync for bucket default. Retrying to getTerseBucket. retry count 2 2022-02-02T20:03:59.300-08:00 [Warn] cluster......

The bucket already dropped.

Components

Affects versions

Fix versions

Labels

Environment

None

Link to Log File, atop/blg, CBCollectInfo, Core dump

None

Release Notes Description

None

Attachments

2
  • 18 Apr 2022, 08:16 AM
  • 18 Apr 2022, 08:16 AM

is a backport of

Activity

Hemant Rajput April 29, 2022 at 6:47 AM

Validated on 7.0.4-7261. Closing as per Sai's comment.

Sai Kommaraju April 29, 2022 at 6:37 AM

this looks fine. Every Scheduled index will validate the bucket independently once every 30 secs while while waiting for the scheduled index and try to do so 5 times to account for any failures so this should not flood the logs now. 

Hemant Rajput April 18, 2022 at 8:18 AM

, I followed the below steps, however, I still see high no. of msgs for "out of sync". Let me know if this no. is expected

 

Steps to verify

  1. Create a cluster with n0:kv+n1ql,n1:Index

  2. Set indexer.debug.enableBackgroundIndexCreation to false to disable the scheduled index creation

  3. Create 10 indexes in parallel, 3 indexes went to schedule state and rest of the indexes were built one by one.

  4. Delete the bucket on which the indexes are created

  5. indexer.debug.enableBackgroundIndexCreation to true. Check for the "out of sync" msgs in query.log

Logs attached

CB robot April 7, 2022 at 3:12 PM

Build couchbase-server-7.0.4-7245 contains indexing commit 61aa8d0 with commit message:
https://couchbasecloud.atlassian.net/browse/MB-50861#icft=MB-50861 [BP MB 50770 to 7.0.x] Reduce retries under waitForScheduledIndex()

Sai Kommaraju April 7, 2022 at 2:50 PM

Steps to verify

  1. Create a cluster with n0:kv+n1ql,n1:Index

  2. Set indexer.debug.enableBackgroundIndexCreation to false to disable the scheduled index creation

  3. Create an index and while that index is being created create few more indexes to make it scheduled index.

  4. Delete the bucket on which the indexes are created

  5. indexer.debug.enableBackgroundIndexCreation to true

We should not see any log flooding on the query side. Query client check for keyspace once every 30 seconds. 

After 30 seconds we should see errors like below but to max of 5 times per index in scheduled state

2022-04-07T20:07:35.662+05:30 [Warn] Pool::RefreshBucket: Retried 6 times due to out of sync for bucket default. Final err: HTTP error 404 Object Not Found getting "http://127.0.0.1:9000/pools/default/b/default": Requested resource not found. 2022-04-07T20:07:37.663+05:30 [Info] Error occurred during cluster info update (HTTP error 404 Object Not Found getting "http://127.0.0.1:9000/pools/default/b/default": Requested resource not found. ) .. Retrying(1)
Fixed
Pinned fields
Click on the next to a field label to start pinning.

Details

Assignee

Reporter

Is this a Regression?

Yes

Triage

Untriaged

Story Points

Priority

Instabug

Open Instabug

PagerDuty

Sentry

Zendesk Support

Created February 7, 2022 at 11:33 PM
Updated April 29, 2022 at 6:47 AM
Resolved April 7, 2022 at 2:51 PM
Instabug