Actions
Bug #20470
closedrados/singleton/all/reg11184.yaml: assert proc.exitstatus == 0
Status:
Resolved
Priority:
Immediate
Assignee:
David Zafman
Category:
-
Target version:
-
% Done:
0%
Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(RADOS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
2017-06-30T07:47:16.974 INFO:teuthology.orchestra.run.smithi018.stderr:Read #2:f699a2a9:::existing_67:head# 2017-06-30T07:47:16.974 INFO:teuthology.orchestra.run.smithi018.stderr:Read #2:f9baac43:::existing_25:head# 2017-06-30T07:47:16.975 INFO:teuthology.orchestra.run.smithi018.stderr:Read #2:fb76688e:::existing_51:head# 2017-06-30T07:47:16.975 INFO:teuthology.orchestra.run.smithi018.stderr:Read #2:fbb92eec:::existing_69:head# 2017-06-30T07:47:16.975 INFO:teuthology.orchestra.run.smithi018.stderr:Export successful 2017-06-30T07:47:16.975 INFO:teuthology.orchestra.run.smithi018:Running: 'sudo adjust-ulimits ceph-objectstore-tool --data-path /var/lib/ceph/osd/ceph-2 --journal-path /var/lib/ceph/osd/ceph-2/journal --log-file=/var/log/ceph/objectstore_tool.$$.log --op remove --pgid 2.0' 2017-06-30T07:47:18.382 INFO:teuthology.orchestra.run.smithi018.stdout: marking collection for removal 2017-06-30T07:47:18.382 INFO:teuthology.orchestra.run.smithi018.stdout:setting '_remove' omap key 2017-06-30T07:47:18.382 INFO:teuthology.orchestra.run.smithi018.stdout:finish_remove_pgs 2.0_head removing 2.0 2017-06-30T07:47:18.383 INFO:teuthology.orchestra.run.smithi018.stdout:Remove successful 2017-06-30T07:47:18.383 INFO:tasks.reg11184:killing osd.0 2017-06-30T07:47:18.383 DEBUG:tasks.ceph.osd.0:waiting for process to exit 2017-06-30T07:47:18.383 INFO:teuthology.orchestra.run:waiting for 300 2017-06-30T07:47:18.418 INFO:tasks.ceph.osd.0:Stopped 2017-06-30T07:47:18.418 INFO:teuthology.orchestra.run.smithi018:Running: 'sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 120 ceph --cluster ceph osd down 0' 2017-06-30T07:47:19.750 INFO:teuthology.orchestra.run.smithi018.stderr:marked down osd.0. 2017-06-30T07:47:19.768 INFO:teuthology.orchestra.run.smithi018:Running: 'sudo adjust-ulimits ceph-objectstore-tool --data-path /var/lib/ceph/osd/ceph-0 --journal-path /var/lib/ceph/osd/ceph-0/journal --log-file=/var/log/ceph/objectstore_tool.$$.log --op import --file /home/ubuntu/cephtest/exp.70662.out' 2017-06-30T07:47:20.685 INFO:teuthology.orchestra.run.smithi018.stderr:pgid 2.0 already exists 2017-06-30T07:47:21.176 ERROR:teuthology.run_tasks:Saw exception from tasks. Traceback (most recent call last): File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/run_tasks.py", line 86, in run_tasks manager = run_one_task(taskname, ctx=ctx, config=config) File "/home/teuthworker/src/git.ceph.com_git_teuthology_master/teuthology/run_tasks.py", line 65, in run_one_task return task(**kwargs) File "/home/teuthworker/src/github.com_ceph_ceph-c_wip-sage-testing/qa/tasks/reg11184.py", line 193, in task assert proc.exitstatus == 0 AssertionError
pretty sure this is due to the rbd pool number 0 -> 1 change
/a/sage-2017-06-30_05:44:03-rados-wip-sage-testing-distro-basic-smithi/1345233
Updated by Sage Weil almost 7 years ago
This test confuses me. It seems like the PG is always going to exist on the target osd.. why was it passing before?
Updated by Sage Weil almost 7 years ago
- Assignee changed from Sage Weil to David Zafman
Updated by Kefu Chai almost 7 years ago
/a//sage-2017-07-09_19:14:46-rados-wip-sage-testing-distro-basic-smithi/1379319
Updated by David Zafman almost 7 years ago
For some reason pg 2.0 is created on osd.0 which never happened previously.
2017-07-11 15:45:03.386262 7f868273b700 5 osd.0 pg_epoch: 26 pg[2.0(unlocked)] enter Initial 2017-07-11 15:45:03.386405 7f868273b700 5 write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 4294967295'18446744073709551615, trimmed: , clear_divergent_priors: 0 2017-07-11 15:45:03.386468 7f868273b700 5 osd.0 pg_epoch: 26 pg[2.0( empty local-lis/les=0/0 n=0 ec=16/16 lis/c 16/16 les/c/f 17/17/0 26/26/26) [0] r=0 lpr=0 pi=[16,26)/1 crt=0'0 mlcod 0'0 unknown] exit Initial 0.000227 0 0.000000 2017-07-11 15:45:03.386519 7f868273b700 5 osd.0 pg_epoch: 26 pg[2.0( empty local-lis/les=0/0 n=0 ec=16/16 lis/c 16/16 les/c/f 17/17/0 26/26/26) [0] r=0 lpr=0 pi=[16,26)/1 crt=0'0 mlcod 0'0 unknown] enter Reset 2017-07-11 15:45:03.386574 7f868273b700 5 osd.0 pg_epoch: 26 pg[2.0( empty local-lis/les=0/0 n=0 ec=16/16 lis/c 16/16 les/c/f 17/17/0 26/26/26) [0] r=0 lpr=26 pi=[16,26)/1 crt=0'0 mlcod 0'0 unknown] exit Reset 0.000054 1 0.000098 2017-07-11 15:45:03.386609 7f868273b700 5 osd.0 pg_epoch: 26 pg[2.0( empty local-lis/les=0/0 n=0 ec=16/16 lis/c 16/16 les/c/f 17/17/0 26/26/26) [0] r=0 lpr=26 pi=[16,26)/1 crt=0'0 mlcod 0'0 unknown] enter Started 2017-07-11 15:45:03.386636 7f868273b700 5 osd.0 pg_epoch: 26 pg[2.0( empty local-lis/les=0/0 n=0 ec=16/16 lis/c 16/16 les/c/f 17/17/0 26/26/26) [0] r=0 lpr=26 pi=[16,26)/1 crt=0'0 mlcod 0'0 unknown] enter Start 2017-07-11 15:45:03.386665 7f868273b700 1 osd.0 pg_epoch: 26 pg[2.0( empty local-lis/les=0/0 n=0 ec=16/16 lis/c 16/16 les/c/f 17/17/0 26/26/26) [0] r=0 lpr=26 pi=[16,26)/1 crt=0'0 mlcod 0'0 unknown] state<Start>: transitioning to Primary 2017-07-11 15:45:03.386700 7f868273b700 5 osd.0 pg_epoch: 26 pg[2.0( empty local-lis/les=0/0 n=0 ec=16/16 lis/c 16/16 les/c/f 17/17/0 26/26/26) [0] r=0 lpr=26 pi=[16,26)/1 crt=0'0 mlcod 0'0 unknown] exit Start 0.000064 0 0.000000 2017-07-11 15:45:03.386737 7f868273b700 5 osd.0 pg_epoch: 26 pg[2.0( empty local-lis/les=0/0 n=0 ec=16/16 lis/c 16/16 les/c/f 17/17/0 26/26/26) [0] r=0 lpr=26 pi=[16,26)/1 crt=0'0 mlcod 0'0 unknown] enter Started/Primary 2017-07-11 15:45:03.386766 7f868273b700 5 osd.0 pg_epoch: 26 pg[2.0( empty local-lis/les=0/0 n=0 ec=16/16 lis/c 16/16 les/c/f 17/17/0 26/26/26) [0] r=0 lpr=26 pi=[16,26)/1 crt=0'0 mlcod 0'0 unknown] enter Started/Primary/Peering 2017-07-11 15:45:03.386803 7f868273b700 5 osd.0 pg_epoch: 26 pg[2.0( empty local-lis/les=0/0 n=0 ec=16/16 lis/c 16/16 les/c/f 17/17/0 26/26/26) [0] r=0 lpr=26 pi=[16,26)/1 crt=0'0 mlcod 0'0 peering] enter Started/Primary/Peering/GetInfo 2017-07-11 15:45:03.386910 7f868273b700 1 -- 172.21.6.124:6802/16958 --> 172.21.6.124:6807/17085 -- osd_map(26..26 src has 1..26) v3 -- 0x7f8699b45980 con 0 2017-07-11 15:45:03.386958 7f868273b700 1 -- 172.21.6.124:6802/16958 --> 172.21.6.124:6807/17085 -- pg_query(2.0 epoch 26) v4 -- 0x7f869a1f1b00 con 0 2017-07-11 15:45:03.386985 7f868273b700 10 bluestore(/var/lib/ceph/osd/ceph-0) queue_transactions new 0x7f869a20fd40 osr(2.0 0x7f869a1fc4e0) 2017-07-11 15:45:03.386997 7f868273b700 20 bluestore(/var/lib/ceph/osd/ceph-0) _txc_create osr 0x7f869a20fd40 = 0x7f8699c2b180 seq 1 2017-07-11 15:45:03.387012 7f868273b700 30 bluestore(/var/lib/ceph/osd/ceph-0) transaction dump: { "ops": [ { "op_num": 0, "op_name": "mkcoll", "collection": "2.0_head" }, { "op_num": 1, "op_name": "coll_hint", "collection": "2.0_head", "type": 1, "pg_num": 1, "expected_num_objects": 0 }, { "op_num": 2, "op_name": "touch", "collection": "2.0_head", "oid": "#2:00000000::::head#" }, { "op_num": 3, "op_name": "omap_setkeys", "collection": "2.0_head", "oid": "#2:00000000::::head#", "attr_lens": { "_infover": 1 } }, { "op_num": 4, "op_name": "touch", "collection": "2.0_head", "oid": "#2:00000000::::head#" }, { "op_num": 5, "op_name": "omap_setkeys", "collection": "2.0_head", "oid": "#2:00000000::::head#", "attr_lens": { "_biginfo": 95, "_epoch": 4, "_info": 871 } } ] } 2017-07-11 15:45:03.387164 7f868273b700 15 bluestore(/var/lib/ceph/osd/ceph-0) _create_collection 2.0_head bits 0 2017-07-11 15:45:03.387192 7f868273b700 10 bluestore(/var/lib/ceph/osd/ceph-0) _create_collection 2.0_head bits 0 = 0
Updated by David Zafman almost 7 years ago
Actions