Project

General

Profile

Actions
Copy link

Bug #68833

closed

TEST_just_deep_scrubs fails from "key is query_last_duration: negation:1 # expected: 0 # in actual: 0"

Added by Naveen Naidu over 1 year ago. Updated 8 months ago.

Status:
Resolved
Priority:
Normal
Assignee:
Ronen Friedman
Category:
-
Target version:
-
% Done:

0%

Source:
Backport:
tentacle
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(RADOS):
Pull request ID:
62996
Tags (freeform):
backport_processed
Merge Commit:
f8383399dc0e30ade3a6a819bbf9015f3d6352e6
Fixed In:
v20.3.0-10-gf8383399dc
Released In:
Upkeep Timestamp:
2025-07-14T19:38:37+00:00

Description

/a/yuriw-2024-10-17_14:30:20-rados-wip-yuri-testing-2024-10-09-1524-squid-distro-default-smithi/7954332

2024-10-17T23:10:46.845 INFO:tasks.workunit.client.0.smithi082.stdout:waiting for any condition (WaitingAfterScrub ): pg:1.0 dt:2024-10-17T23:10:32.469384+0000 (10 retries)
2024-10-17T23:10:47.650 INFO:tasks.workunit.client.0.smithi082.stderr:dumped pgs
2024-10-17T23:10:47.834 INFO:tasks.workunit.client.0.smithi082.stdout:(
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[query_epoch]=19
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[query_seq]=45
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[query_active]=false
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[query_schedule]='scrub scheduled'
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[query_schedule_at]='2024-10-18T23:10:42.865 (2024-10-18T23:10:42.865)'
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[query_last_duration]=1
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[query_last_stamp]='2024-10-17T23:10:42.865730+0000'
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[query_last_scrub]='19x15'
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[query_is_future]=true
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[query_vs_date]=true
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[query_scrub_seq]=null
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[dmp_pg_state]='active+clean'
2024-10-17T23:10:47.835 INFO:tasks.workunit.client.0.smithi082.stdout:[dmp_state_has_scrubbing]=false
2024-10-17T23:10:47.836 INFO:tasks.workunit.client.0.smithi082.stdout:[dmp_last_duration]=1
2024-10-17T23:10:47.836 INFO:tasks.workunit.client.0.smithi082.stdout:[dmp_schedule]='periodic scrub scheduled'
2024-10-17T23:10:47.836 INFO:tasks.workunit.client.0.smithi082.stdout:[dmp_schedule_at]='2024-10-18T23:10:42.865730+0000'
2024-10-17T23:10:47.836 INFO:tasks.workunit.client.0.smithi082.stdout:[dmp_is_future]=true
2024-10-17T23:10:47.836 INFO:tasks.workunit.client.0.smithi082.stdout:[dmp_vs_date]=true
2024-10-17T23:10:47.836 INFO:tasks.workunit.client.0.smithi082.stdout:[dmp_reported_epoch]=19
2024-10-17T23:10:47.836 INFO:tasks.workunit.client.0.smithi082.stdout:[dmp_seq]=43
2024-10-17T23:10:47.836 INFO:tasks.workunit.client.0.smithi082.stdout:)
2024-10-17T23:10:47.870 INFO:tasks.workunit.client.0.smithi082.stdout:--> loop:  1 ~ false / 45 / 43  / true / 2024-10-17T23:10:42.865730+0000 / scrub scheduled %%% query_last_duration_neg query_last_duration
2024-10-17T23:10:47.870 INFO:tasks.workunit.client.0.smithi082.stdout:key is query_last_duration: negation:1 # expected: 0 # in actual: 1
2024-10-17T23:10:47.870 INFO:tasks.workunit.client.0.smithi082.stdout:WaitingAfterScrub  - 'query_last_duration' actual value (1) matches expected (0) (negation: 1)
2024-10-17T23:10:47.871 INFO:tasks.workunit.client.0.smithi082.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/scrub/scrub-helpers.sh:149: wait_any_cond:  return 0
2024-10-17T23:10:47.872 INFO:tasks.workunit.client.0.smithi082.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/scrub/osd-scrub-test.sh:596: TEST_dump_scrub_schedule:  sched_data=()
2024-10-17T23:10:47.872 INFO:tasks.workunit.client.0.smithi082.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/scrub/osd-scrub-test.sh:597: TEST_dump_scrub_schedule:  expct_dmp_duration=(['dmp_last_duration']='0' ['dmp_last_duration_neg']='not0')
2024-10-17T23:10:47.872 INFO:tasks.workunit.client.0.smithi082.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/scrub/osd-scrub-test.sh:597: TEST_dump_scrub_schedule:  declare -A expct_dmp_duration
2024-10-17T23:10:47.872 INFO:tasks.workunit.client.0.smithi082.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/scrub/osd-scrub-test.sh:598: TEST_dump_scrub_schedule:  wait_any_cond 1.0 10 2024-10-17T23:10:32.469384+0000 expct_dmp_duration 'WaitingAfterScrub_dmp ' sched_data

This looks similar to https://tracker.ceph.com/issues/64346

Related issues 3 (0 open — 3 closed)

Related to RADOS - Bug #64346: TEST_dump_scrub_schedule fails from "key is query_is_future: negation:0 # expected: false # in actual: true"ResolvedRonen Friedman

Actions
Copied to RADOS - Backport #71099: squid: TEST_just_deep_scrubs fails from "key is query_last_duration: negation:1 # expected: 0 # in actual: 0"ResolvedRonen FriedmanActions
Copied to RADOS - Backport #71104: tentacle: TEST_just_deep_scrubs fails from "key is query_last_duration: negation:1 # expected: 0 # in actual: 0"ResolvedRonen FriedmanActions
Actions
Copy link
 #1

Updated by Laura Flores over 1 year ago

  • Related to Bug #64346: TEST_dump_scrub_schedule fails from "key is query_is_future: negation:0 # expected: false # in actual: true" added
Actions
Copy link
 #2

Updated by Laura Flores over 1 year ago

  • Assignee set to Ronen Friedman

@Ronen Friedman can you take a look?

Actions
Copy link
 #3

Updated by Laura Flores over 1 year ago

Bump up

Actions
Copy link
 #4

Updated by Ronen Friedman over 1 year ago

  • Status changed from New to In Progress

Attempting to solve this with https://github.com/ceph/ceph/pull/61088 (which is marked as a fix to https://tracker.ceph.com/issues/68218,
i.e. to another test in this standalone script)

Actions
Copy link
 #5

Updated by Radoslaw Zarzynski over 1 year ago

  • Status changed from In Progress to Need More Info

I approved the squid PR. Let's observe whether the are any new occurrences with 61088 in.

Actions
Copy link
 #6

Updated by Laura Flores about 1 year ago

/a/yuriw-2024-12-24_16:11:09-rados-squid-release-distro-default-smithi/8051245

Actions
Copy link
 #7

Updated by Laura Flores about 1 year ago

@Ronen Friedman there was another occurrence since merging the prospective fix. Can you take another look?

Actions
Copy link
 #8

Updated by Naveen Naidu about 1 year ago

/a/skanta-2025-02-18_22:53:18-rados-wip-bharath2-testing-2025-02-18-1645-squid-distro-default-smithi/8138113

Actions
Copy link
 #10

Updated by Laura Flores about 1 year ago

Bump up

Actions
Copy link
 #11

Updated by Laura Flores 12 months ago

/a/yuriw-2025-03-27_15:03:25-rados-wip-yuri7-testing-2025-03-26-1605-distro-default-smithi/8213261

Actions
Copy link
 #12

Updated by Radoslaw Zarzynski 12 months ago

Pinging @Ronen Friedman on this.

Actions
Copy link
 #13

Updated by Laura Flores 12 months ago

/a/yuriw-2025-03-29_14:10:41-rados-wip-yuri11-testing-2025-03-28-1517-squid-distro-default-smithi/8215664

Actions
Copy link
 #14

Updated by Radoslaw Zarzynski 12 months ago

scrub note: bump up.

Actions
Copy link
 #15

Updated by Laura Flores 11 months ago

/a/skanta-2025-04-05_15:49:33-rados-wip-bharath8-testing-2025-04-05-1439-distro-default-smithi/8225290

Actions
Copy link
 #16

Updated by Radoslaw Zarzynski 11 months ago

scrub note: bump up.

Actions
Copy link
 #17

Updated by Laura Flores 11 months ago

bump up

Actions
Copy link
 #18

Updated by Ronen Friedman 11 months ago · Edited

The reappearance of this problem is probably due to https://github.com/ceph/ceph/pull/61935 and https://github.com/ceph/ceph/pull/61590
making Scrub faster:
the scrub requested in the failed test was performed as requested, but took less than 1s. The value was supposed to be "rounded up"
(actually - 'ceil'ed up), but the current code only performs the ceiling function in one of two report methods.

I will be verifying that this is the only issue with the timings in the test. verified in Teuthology run

Actions
Copy link
 #19

Updated by Ronen Friedman 11 months ago

  • Status changed from Need More Info to In Progress
Actions
Copy link
 #20

Updated by Ronen Friedman 11 months ago

  • Status changed from In Progress to Pending Backport
Actions
Copy link
 #21

Updated by Upkeep Bot 11 months ago

  • Copied to Backport #71099: squid: TEST_just_deep_scrubs fails from "key is query_last_duration: negation:1 # expected: 0 # in actual: 0" added
Actions
Copy link
 #22

Updated by Upkeep Bot 11 months ago

  • Tags (freeform) set to backport_processed
Actions
Copy link
 #23

Updated by Ronen Friedman 11 months ago · Edited

  • Status changed from Pending Backport to In Progress

Squid will have its own fix (not a backport)

Actions
Copy link
 #24

Updated by Ronen Friedman 11 months ago

  • Status changed from In Progress to Fix Under Review
  • Pull request ID set to 62996
Actions
Copy link
 #25

Updated by Ronen Friedman 11 months ago

  • Backport changed from squid to tentacle
Actions
Copy link
 #26

Updated by Ronen Friedman 11 months ago

  • Status changed from Fix Under Review to Pending Backport

Merged. Now for the Tentacle version...

Actions
Copy link
 #27

Updated by Ronen Friedman 11 months ago

  • Backport changed from tentacle to tentacles, Tentacle,tentacle
Actions
Copy link
 #28

Updated by Ronen Friedman 11 months ago

  • Backport changed from tentacles, Tentacle,tentacle to tentacle
Actions
Copy link
 #29

Updated by Patrick Donnelly 11 months ago

  • Tags (freeform) deleted (backport_processed)
Actions
Copy link
 #30

Updated by Upkeep Bot 11 months ago

  • Copied to Backport #71104: tentacle: TEST_just_deep_scrubs fails from "key is query_last_duration: negation:1 # expected: 0 # in actual: 0" added
Actions
Copy link
 #31

Updated by Upkeep Bot 11 months ago

  • Tags (freeform) set to backport_processed
Actions
Copy link
 #32

Updated by Ronen Friedman 11 months ago

  • Status changed from Pending Backport to Resolved
Actions
Copy link
 #33

Updated by Jaya Prakash 10 months ago

teuthology-2025-05-11_20:00:15-rados-main-distro-default-smithi/8280267

Actions
Copy link
 #34

Updated by Upkeep Bot 8 months ago

  • Merge Commit set to f8383399dc0e30ade3a6a819bbf9015f3d6352e6
  • Fixed In set to v20.3.0-10-gf8383399dc0
  • Upkeep Timestamp set to 2025-07-10T08:44:00+00:00
Actions
Copy link
 #35

Updated by Upkeep Bot 8 months ago

  • Fixed In changed from v20.3.0-10-gf8383399dc0 to v20.3.0-10-gf8383399dc
  • Upkeep Timestamp changed from 2025-07-10T08:44:00+00:00 to 2025-07-14T19:38:37+00:00
Actions
Copy link

Also available in: Atom PDF