Project

General

Profile

Actions

Bug #62401

open

ObjectStore/StoreTestSpecificAUSize.SpilloverFixedTest/2 fails from l_bluefs_slow_used_bytes not matching the expected value

Added by Laura Flores 9 months ago. Updated 4 months ago.

Status:
Pending Backport
Priority:
Normal
Assignee:
Target version:
% Done:

0%

Source:
Community (dev)
Tags:
backport_processed
Backport:
quincy, reef, pacific
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

/a/yuriw-2023-07-25_21:35:32-rados-wip-yuri8-testing-2023-07-24-0819-quincy-distro-default-smithi/7352449

2023-07-26T21:14:11.542 INFO:teuthology.orchestra.run.smithi006.stdout:[ RUN      ] ObjectStore/StoreTestSpecificAUSize.SpilloverFixedTest/2
2023-07-26T21:14:15.964 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 0
2023-07-26T21:14:15.966 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 10
2023-07-26T21:14:16.037 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 20
2023-07-26T21:14:16.038 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 30
2023-07-26T21:14:16.040 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 40
2023-07-26T21:14:16.041 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 50
2023-07-26T21:14:16.042 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 60
2023-07-26T21:14:16.043 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 70
2023-07-26T21:14:16.044 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 80
2023-07-26T21:14:16.045 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 90
2023-07-26T21:14:16.046 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 100
2023-07-26T21:14:16.085 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 110
2023-07-26T21:14:16.086 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 120
2023-07-26T21:14:16.088 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 130
2023-07-26T21:14:16.089 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 140
2023-07-26T21:14:16.090 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 150
2023-07-26T21:14:16.092 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 160
2023-07-26T21:14:16.093 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 170
2023-07-26T21:14:16.094 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 180
2023-07-26T21:14:16.095 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 190
2023-07-26T21:14:16.097 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 200
2023-07-26T21:14:16.145 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 210
2023-07-26T21:14:16.146 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 220
2023-07-26T21:14:16.148 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 230
2023-07-26T21:14:16.149 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 240
2023-07-26T21:14:16.151 INFO:teuthology.orchestra.run.smithi006.stderr:seeding object 250
2023-07-26T21:14:16.152 INFO:teuthology.orchestra.run.smithi006.stderr:Op 0
2023-07-26T21:14:16.152 INFO:teuthology.orchestra.run.smithi006.stderr:available_objects: 252 in_flight_objects: 4 total objects: 256 in_flight 4
2023-07-26T21:14:23.941 INFO:teuthology.orchestra.run.smithi006.stderr:Op 100
2023-07-26T21:14:23.941 INFO:teuthology.orchestra.run.smithi006.stderr:available_objects: 241 in_flight_objects: 15 total objects: 256 in_flight 15
2023-07-26T21:14:31.945 INFO:teuthology.orchestra.run.smithi006.stderr:Op 200
2023-07-26T21:14:31.945 INFO:teuthology.orchestra.run.smithi006.stderr:available_objects: 251 in_flight_objects: 5 total objects: 256 in_flight 5
2023-07-26T21:14:36.664 INFO:teuthology.orchestra.run.smithi006.stdout:done
2023-07-26T21:14:54.253 INFO:teuthology.orchestra.run.smithi006.stdout:/build/ceph-17.2.6-823-gf97a6ef3/src/test/objectstore/store_test.cc:10447: Failure
2023-07-26T21:14:54.254 INFO:teuthology.orchestra.run.smithi006.stdout:Expected equality of these values:
2023-07-26T21:14:54.254 INFO:teuthology.orchestra.run.smithi006.stdout:  0
2023-07-26T21:14:54.254 INFO:teuthology.orchestra.run.smithi006.stdout:  logger->get(l_bluefs_slow_used_bytes)
2023-07-26T21:14:54.254 INFO:teuthology.orchestra.run.smithi006.stdout:    Which is: 221577216
2023-07-26T21:14:54.254 INFO:teuthology.orchestra.run.smithi006.stdout:1 : device size 0xbfffe000 : using 0x3a900000(937 MiB)
2023-07-26T21:14:54.254 INFO:teuthology.orchestra.run.smithi006.stdout:2 : device size 0x2625a0000 : using 0xd360000(211 MiB)
2023-07-26T21:14:54.255 INFO:teuthology.orchestra.run.smithi006.stdout:RocksDBBlueFSVolumeSelector Usage Matrix:
2023-07-26T21:14:54.255 INFO:teuthology.orchestra.run.smithi006.stdout:DEV/LEV     WAL         DB          SLOW        *           *           REAL        FILES
2023-07-26T21:14:54.255 INFO:teuthology.orchestra.run.smithi006.stdout:LOG         0 B         4 MiB       0 B         0 B         0 B         992 KiB     1
2023-07-26T21:14:54.255 INFO:teuthology.orchestra.run.smithi006.stdout:WAL         0 B         0 B         0 B         0 B         0 B         0 B         1
2023-07-26T21:14:54.255 INFO:teuthology.orchestra.run.smithi006.stdout:DB          0 B         933 MiB     0 B         0 B         0 B         834 MiB     21
2023-07-26T21:14:54.255 INFO:teuthology.orchestra.run.smithi006.stdout:SLOW        0 B         0 B         211 MiB     0 B         0 B         208 MiB     3
2023-07-26T21:14:54.255 INFO:teuthology.orchestra.run.smithi006.stdout:TOTAL       0 B         937 MiB     211 MiB     0 B         0 B         0 B         26
2023-07-26T21:14:54.255 INFO:teuthology.orchestra.run.smithi006.stdout:MAXIMUMS:
2023-07-26T21:14:54.256 INFO:teuthology.orchestra.run.smithi006.stdout:LOG         0 B         4 MiB       0 B         0 B         0 B         992 KiB
2023-07-26T21:14:54.256 INFO:teuthology.orchestra.run.smithi006.stdout:WAL         0 B         2.2 GiB     282 MiB     0 B         0 B         1.0 GiB
2023-07-26T21:14:54.256 INFO:teuthology.orchestra.run.smithi006.stdout:DB          0 B         1.3 GiB     0 B         0 B         0 B         1.3 GiB
2023-07-26T21:14:54.256 INFO:teuthology.orchestra.run.smithi006.stdout:SLOW        0 B         0 B         211 MiB     0 B         0 B         208 MiB
2023-07-26T21:14:54.256 INFO:teuthology.orchestra.run.smithi006.stdout:TOTAL       0 B         2.9 GiB     493 MiB     0 B         0 B         0 B
2023-07-26T21:14:54.256 INFO:teuthology.orchestra.run.smithi006.stdout:>> SIZE <<  0 B         2.8 GiB     9.1 GiB
2023-07-26T21:14:54.256 INFO:teuthology.orchestra.run.smithi006.stdout:
2023-07-26T21:14:58.258 INFO:teuthology.orchestra.run.smithi006.stdout:==> rm -r bluestore.test_temp_dir
2023-07-26T21:14:58.521 INFO:teuthology.orchestra.run.smithi006.stdout:[  FAILED  ] ObjectStore/StoreTestSpecificAUSize.SpilloverFixedTest/2, where GetParam() = "bluestore" (46980 ms)


Related issues 3 (2 open1 closed)

Copied to bluestore - Backport #63812: reef: ObjectStore/StoreTestSpecificAUSize.SpilloverFixedTest/2 fails from l_bluefs_slow_used_bytes not matching the expected valueIn ProgressIgor FedotovActions
Copied to bluestore - Backport #63813: quincy: ObjectStore/StoreTestSpecificAUSize.SpilloverFixedTest/2 fails from l_bluefs_slow_used_bytes not matching the expected valueIn ProgressIgor FedotovActions
Copied to bluestore - Backport #64123: pacific: ObjectStore/StoreTestSpecificAUSize.SpilloverFixedTest/2 fails from l_bluefs_slow_used_bytes not matching the expected valueRejectedIgor FedotovActions
Actions #1

Updated by Laura Flores 9 months ago

/a/yuriw-2023-07-26_15:58:31-rados-wip-yuri8-testing-2023-07-24-0819-quincy-distro-default-smithi/7354021

Actions #2

Updated by Laura Flores 7 months ago

  • Status changed from New to Closed

This was caught in an unmerged test batch, caused by PR https://github.com/ceph/ceph/pull/51774. The bug was fixed before the PR was merged.

Actions #3

Updated by Laura Flores 7 months ago

  • Status changed from Closed to New
  • Assignee set to Igor Fedotov

/a/yuriw-2023-10-06_20:29:18-rados-wip-yuri6-testing-2023-10-06-0904-quincy-distro-default-smithi/7415596

2023-10-07T05:31:02.252 INFO:teuthology.orchestra.run.smithi124.stdout:/build/ceph-17.2.6-1287-gfedcea84/src/test/objectstore/store_test.cc:10449: Failure
2023-10-07T05:31:02.252 INFO:teuthology.orchestra.run.smithi124.stdout:Expected equality of these values:
2023-10-07T05:31:02.252 INFO:teuthology.orchestra.run.smithi124.stdout:  0
2023-10-07T05:31:02.252 INFO:teuthology.orchestra.run.smithi124.stdout:  logger->get(l_bluefs_slow_used_bytes)
2023-10-07T05:31:02.252 INFO:teuthology.orchestra.run.smithi124.stdout:    Which is: 73859072
2023-10-07T05:31:02.252 INFO:teuthology.orchestra.run.smithi124.stdout:0 : device size 0x577ff000 : using 0x400000(4 MiB)
2023-10-07T05:31:02.252 INFO:teuthology.orchestra.run.smithi124.stdout:1 : device size 0xbfffe000 : using 0x43300000(1.0 GiB)
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:2 : device size 0x2625a0000 : using 0x4680000(70 MiB)
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:RocksDBBlueFSVolumeSelector Usage Matrix:
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:DEV/LEV     WAL         DB          SLOW        *           *           REAL        FILES
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:LOG         4 MiB       0 B         0 B         0 B         0 B         980 KiB     1
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:WAL         0 B         0 B         0 B         0 B         0 B         0 B         1
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:DB          0 B         933 MiB     0 B         0 B         0 B         834 MiB     21
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:SLOW        0 B         142 MiB     70 MiB      0 B         0 B         208 MiB     3
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:TOTAL       4 MiB       1.0 GiB     70 MiB      0 B         0 B         0 B         26
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:MAXIMUMS:
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:LOG         4 MiB       0 B         0 B         0 B         0 B         980 KiB
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:WAL         1.1 GiB     1.4 GiB     0 B         0 B         0 B         1.0 GiB
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:DB          0 B         1.3 GiB     0 B         0 B         0 B         1.3 GiB
2023-10-07T05:31:02.253 INFO:teuthology.orchestra.run.smithi124.stdout:SLOW        0 B         142 MiB     70 MiB      0 B         0 B         208 MiB
2023-10-07T05:31:02.254 INFO:teuthology.orchestra.run.smithi124.stdout:TOTAL       1.1 GiB     2.7 GiB     70 MiB      0 B         0 B         0 B
2023-10-07T05:31:02.254 INFO:teuthology.orchestra.run.smithi124.stdout:>> SIZE <<  1.3 GiB     2.8 GiB     9.1 GiB
2023-10-07T05:31:02.254 INFO:teuthology.orchestra.run.smithi124.stdout:
2023-10-07T05:31:06.335 INFO:teuthology.orchestra.run.smithi124.stdout:==> rm -r bluestore.test_temp_dir
2023-10-07T05:31:06.609 INFO:teuthology.orchestra.run.smithi124.stdout:[  FAILED  ] ObjectStore/StoreTestSpecificAUSize.SpilloverFixedTest/2, where GetParam() = "bluestore" (48483 ms)

Hey Igor, can you take a look? I thought we caught this before we merged your bluestore PR, but it just came up in another run. It didn't reproduce a second time, so the failure is nondeterministic.

Actions #4

Updated by Laura Flores 7 months ago

  • Backport set to quincy
Actions #5

Updated by Igor Fedotov 7 months ago

Laura Flores wrote:

Hey Igor, can you take a look? I thought we caught this before we merged your bluestore PR, but it just came up in another run. It didn't reproduce a second time, so the failure is nondeterministic.

Looking...

Actions #6

Updated by Laura Flores 7 months ago

Adam said it looked like a test problem.

Actions #7

Updated by Igor Fedotov 7 months ago

  • Status changed from New to Fix Under Review
  • Backport changed from quincy to quincy, reef
  • Pull request ID set to 54102

Tests reworked as a part of
https://github.com/ceph/ceph/pull/54102

Actions #8

Updated by Konstantin Shalygin 5 months ago

  • Status changed from Fix Under Review to Pending Backport
  • Target version set to v19.0.0
  • Source set to Community (dev)
Actions #9

Updated by Backport Bot 5 months ago

  • Copied to Backport #63812: reef: ObjectStore/StoreTestSpecificAUSize.SpilloverFixedTest/2 fails from l_bluefs_slow_used_bytes not matching the expected value added
Actions #10

Updated by Backport Bot 5 months ago

  • Copied to Backport #63813: quincy: ObjectStore/StoreTestSpecificAUSize.SpilloverFixedTest/2 fails from l_bluefs_slow_used_bytes not matching the expected value added
Actions #11

Updated by Backport Bot 5 months ago

  • Tags set to backport_processed
Actions #12

Updated by Laura Flores 4 months ago

/a/yuriw-2024-01-09_20:55:51-rados-quincy-distro-default-smithi/7509971

Actions #13

Updated by Laura Flores 4 months ago

  • Backport changed from quincy, reef to quincy, reef, pacific
Actions #14

Updated by Laura Flores 4 months ago

/a/yuriw-2024-01-21_16:34:39-rados-wip-yuri4-testing-2024-01-18-1257-pacific-distro-default-smithi/7525000

Actions #15

Updated by Konstantin Shalygin 4 months ago

  • Tags deleted (backport_processed)
Actions #16

Updated by Backport Bot 4 months ago

  • Copied to Backport #64123: pacific: ObjectStore/StoreTestSpecificAUSize.SpilloverFixedTest/2 fails from l_bluefs_slow_used_bytes not matching the expected value added
Actions #17

Updated by Backport Bot 4 months ago

  • Tags set to backport_processed
Actions

Also available in: Atom PDF