Bug #19398: incorrectly "ignoring pg on deleted pool 167.7" (on newly-created pool) - Ceph - Ceph

Actions

Copy link

Bug #19398

closed

incorrectly "ignoring pg on deleted pool 167.7" (on newly-created pool)

Added by Sage Weil about 7 years ago. Updated about 7 years ago.

Status:

Resolved

Priority:

Immediate

Assignee:

Kefu Chai

Category:

Target version:

% Done:

Source:

Tags:

Backport:

kraken,jewel

Regression:

Severity:

3 - minor

Reviewed:

Affected Versions:

ceph-qa-suite:

Pull request ID:

Crash signature (v1):

Crash signature (v2):

Description

2017-03-28 03:45:29.252251 1fbe5700  1 -- 172.21.15.26:6800/27436 <== mon.0 172.21.15.26:6789/0 76 ==== osd_pg_create(e480 166.0:481 167.3:481 167.5:481 167.7:481) v3 ==== 308+0+0 (3557027298 0 0) 0x35267c70 con 0xe013000
2017-03-28 03:45:29.252540 1fbe5700 20 osd.0 480 OSD::ms_dispatch: osd_pg_create(e480 166.0:481 167.3:481 167.5:481 167.7:481) v3
2017-03-28 03:45:29.252752 1fbe5700 20 osd.0 480 _dispatch 0x35267c70 osd_pg_create(e480 166.0:481 167.3:481 167.5:481 167.7:481) v3
2017-03-28 03:45:29.252905 1fbe5700 10 osd.0 480 handle_pg_create osd_pg_create(e480 166.0:481 167.3:481 167.5:481 167.7:481) v3
2017-03-28 03:45:29.255118 1fbe5700 20 osd.0 480 ignoring pg on deleted pool 167.7

/a/sage-2017-03-28_02:00:55-rados-wip-sage-testing---basic-smithi/952718

The pg create message could arrive at the OSD before the osd has the map. It needs to wait in that case.

Actions

Copy link

Updated by Greg Farnum about 7 years ago

Subject changed from ignoring pg on deleted pool 167.7 to incorrectly "ignoring pg on deleted pool 167.7" (on newly-created pool)

Actions

Copy link

Updated by Kefu Chai about 7 years ago

Assignee set to Kefu Chai

2017-03-28 03:45:29.252752 1fbe5700 20 osd.0 480 _dispatch 0x35267c70 osd_pg_create(e480 166.0:481 167.3:481 167.5:481 167.7:481) v3

the epoch of this message is 480, while the create epoch of "166.0" is 481. so the message epoch is wrong. and it should be 481, i believe.

2017-03-28 03:29:31.496021 10ed5700  7 mon.a@0(leader).log v3 update_from_paxos applying incremental log 3 2017-03-28 03:29:28.586312 mon.0 172.21.15.26:6789/0 11 : cluster [INF] mon.a@0 won leader election with quorum 0,1,2

2017-03-28 03:45:29.017284 10ed5700 15 mon.a@0(leader).osd e480 update_from_paxos paxos e 481, my e 480
2017-03-28 03:45:29.017904 10ed5700  7 mon.a@0(leader).osd e480 update_from_paxos  applying incremental 481

2017-03-28 03:45:28.867885 146dc700  5 mon.a@0(leader).paxos(paxos updating c 754..1387) is_readable = 1 - now=2017-03-28 03:45:28.867916 lease_expire=2017-03-28 03:45:33.769229 has v0 lc 1387
2017-03-28 03:45:28.883231 146dc700  1 -- 172.21.15.26:6789/0 <== mon.2 172.21.15.26:6790/0 4239 ==== paxos(lease_ack lc 1387 fc 754 pn 0 opn 0) v3 ==== 80+0+0 (262247804 0 0) 0x175ac140 con 0xe6d76c0
2017-03-28 03:45:28.883843 146dc700 10 mon.a@0(leader).paxos(paxos updating c 754..1387) handle_lease_ack from mon.2 -- stray (probably since revoked)

2017-03-28 03:45:29.004579 10ed5700 20 mon.a@0(leader).paxos(paxos writing c 754..1387) commit_finish 1388

2017-03-28 03:45:29.033577 10ed5700  5 mon.a@0(leader).paxos(paxos refresh c 754..1388) is_readable = 0 - now=2017-03-28 03:45:29.033630 lease_expire=0.000000 has v0 lc 1388
2017-03-28 03:45:29.033997 10ed5700 10 mon.a@0(leader).pg v644 check_osd_map -- osdmap not readable, waiting

2017-03-28 03:45:29.037637 10ed5700 10 mon.a@0(leader).log v469 update_from_paxos version 469 summary v 469

2017-03-28 03:45:29.066755 10ed5700 10 mon.a@0(leader).pg v644 check_osd_map applying osdmap e480 to pg_map
2017-03-28 03:45:29.066967 10ed5700 10 update_creating_pgs to 0 pgs, osdmap epoch 481
 << called by pgm.check_osd_map(480), mon.osdmon.osdmap.epoch == 481
 << pending_inc.osdmap_epoch = 480
2017-03-28 03:45:29.068167 10ed5700 10 register_new_pgs scanning pool 167 erasure size 3 min_size 3 crush_ruleset 2 object_hash rjenkins pg_num 8 pgp_num 8 last_change 481 flags hashpspool stripe_width 4096

2017-03-28 03:45:29.068307 10ed5700 10 register_pg  will create 167.0 primary 5 acting [5,0,2]

2017-03-28 03:45:29.069279 10ed5700 10 mon.a@0(leader).pg v644 encode_pending v 645

2017-03-28 03:45:29.143833 12ed9700 10 osdmap epoch 481 mapping took 0.010986 seconds
..
2017-03-28 03:45:29.219897 10ed5700 10 mon.a@0(leader).pg v644 update_from_paxos read_incremental
..
2017-03-28 03:45:29.231502 10ed5700 20 mon.a@0(leader).pg v644  refreshing pg 166.0 0:0 creating
..
2017-03-28 03:45:29.233781 10ed5700 20 mon.a@0(leader).pg v644  refreshing pg 166.7 0:0 creating

2017-03-28 03:45:29.242364 10ed5700 20 mon.a@0(leader).pg v645 send_pg_creates osd.0 from 456 : epoch 481 4 pgs
2017-03-28 03:45:29.242445 10ed5700  1 -- 172.21.15.26:6789/0 --> 172.21.15.26:6800/27436 -- osd_pg_create(e480 166.0:481 167.3:481 167.5:481 167.7:481) v3 -- ?+0 0xe46dda0 con 0x164ac900

Actions

Copy link