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