Also, these clusters aren't mixed argonaut and next, are they? (Not
that that shouldn't work, but it would be a useful data point.)
-Sam
On Wed, Nov 28, 2012 at 1:11 PM, Samuel Just <sam.just@xxxxxxxxxxx> wrote:
> Did you observe hung io along with that error? Both sub_op_commit and
> sub_op_applied have happened, so the sub_op_reply should have been
> sent back to the primary. This looks more like a leak. If you also
> observed hung io, then it's possible that the problem is occurring
> between the sub_op_applied event and the response.
> -Sam
>
> On Tue, Nov 27, 2012 at 11:47 PM, Andrey Korolyov <andrey@xxxxxxx> wrote:
>> On Wed, Nov 28, 2012 at 5:51 AM, Sage Weil <sage@xxxxxxxxxxx> wrote:
>>> Hi Stefan,
>>>
>>> On Thu, 15 Nov 2012, Sage Weil wrote:
>>>> On Thu, 15 Nov 2012, Stefan Priebe - Profihost AG wrote:
>>>> > Am 14.11.2012 15:59, schrieb Sage Weil:
>>>> > > Hi Stefan,
>>>> > >
>>>> > > I would be nice to confirm that no clients are waiting on replies for
>>>> > > these requests; currently we suspect that the OSD request tracking is the
>>>> > > buggy part. If you query the OSD admin socket you should be able to dump
>>>> > > requests and see the client IP, and then query the client.
>>>> > >
>>>> > > Is it librbd? In that case you likely need to change the config so that
>>>> > > it is listening on an admin socket ('admin socket = path').
>>>> >
>>>> > Yes it is. So i have to specify admin socket at the KVM host?
>>>>
>>>> Right. IIRC the disk line is a ; (or \;) separated list of key/value
>>>> pairs.
>>>>
>>>> > How do i query the admin socket for requests?
>>>>
>>>> ceph --admin-daemon /path/to/socket help
>>>> ceph --admin-daemon /path/to/socket objecter_dump (i think)
>>>
>>> Were you able to reproduce this?
>>>
>>> Thanks!
>>> sage
>>
>> Meanwhile, I did. :)
>> Such requests will always be created if you have restarted or marked
>> an osd out and then back in and scrub didn`t happen in the meantime
>> (after such operation and before request arrival).
>> What is more interesting, the hangup happens not exactly at the time
>> of operation, but tens of minutes later.
>>
>> { "description": "osd_sub_op(client.1292013.0:45422 4.731
>> a384cf31\/rbd_data.1415fb1075f187.00000000000000a7\/head\/\/4 [] v
>> 16444'21693 snapset=0=[]:[] snapc=0=[])",
>> "received_at": "2012-11-28 03:54:43.094151",
>> "age": "27812.942680",
>> "duration": "2.676641",
>> "flag_point": "started",
>> "events": [
>> { "time": "2012-11-28 03:54:43.094222",
>> "event": "waiting_for_osdmap"},
>> { "time": "2012-11-28 03:54:43.386890",
>> "event": "reached_pg"},
>> { "time": "2012-11-28 03:54:43.386894",
>> "event": "started"},
>> { "time": "2012-11-28 03:54:43.386973",
>> "event": "commit_queued_for_journal_write"},
>> { "time": "2012-11-28 03:54:45.360049",
>> "event": "write_thread_in_journal_buffer"},
>> { "time": "2012-11-28 03:54:45.586183",
>> "event": "journaled_completion_queued"},
>> { "time": "2012-11-28 03:54:45.586262",
>> "event": "sub_op_commit"},
>> { "time": "2012-11-28 03:54:45.770792",
>> "event": "sub_op_applied"}]}]}
>>
>>
>>>
>>>
>>>>
>>>> sage
>>>>
>>>> >
>>>> > Stefan
>>>> >
>>>> >
>>>> > > On Wed, 14 Nov 2012, Stefan Priebe - Profihost AG wrote:
>>>> > >
>>>> > > > Hello list,
>>>> > > >
>>>> > > > i see this several times. Endless flying slow requests. And they never
>>>> > > > stop
>>>> > > > until i restart the mentioned osd.
>>>> > > >
>>>> > > > 2012-11-14 10:11:57.513395 osd.24 [WRN] 1 slow requests, 1 included below;
>>>> > > > oldest blocked for > 31789.858457 secs
>>>> > > > 2012-11-14 10:11:57.513399 osd.24 [WRN] slow request 31789.858457 seconds
>>>> > > > old,
>>>> > > > received at 2012-11-14 01:22:07.654922: osd_op(client.30286.0:6719
>>>> > > > rbd_data.75c55bf2fdd7.0000000000001399 [write 282624~4096] 3.3f6d2373) v4
>>>> > > > currently delayed
>>>> > > > 2012-11-14 10:11:58.513584 osd.24 [WRN] 1 slow requests, 1 included below;
>>>> > > > oldest blocked for > 31790.858646 secs
>>>> > > > 2012-11-14 10:11:58.513586 osd.24 [WRN] slow request 31790.858646 seconds
>>>> > > > old,
>>>> > > > received at 2012-11-14 01:22:07.654922: osd_op(client.30286.0:6719
>>>> > > > rbd_data.75c55bf2fdd7.0000000000001399 [write 282624~4096] 3.3f6d2373) v4
>>>> > > > currently delayed
>>>> > > > 2012-11-14 10:11:59.513766 osd.24 [WRN] 1 slow requests, 1 included below;
>>>> > > > oldest blocked for > 31791.858827 secs
>>>> > > > 2012-11-14 10:11:59.513768 osd.24 [WRN] slow request 31791.858827 seconds
>>>> > > > old,
>>>> > > > received at 2012-11-14 01:22:07.654922: osd_op(client.30286.0:6719
>>>> > > > rbd_data.75c55bf2fdd7.0000000000001399 [write 282624~4096] 3.3f6d2373) v4
>>>> > > > currently delayed
>>>> > > > 2012-11-14 10:12:00.513909 osd.24 [WRN] 1 slow requests, 1 included below;
>>>> > > > oldest blocked for > 31792.858971 secs
>>>> > > > 2012-11-14 10:12:00.513916 osd.24 [WRN] slow request 31792.858971 seconds
>>>> > > > old,
>>>> > > > received at 2012-11-14 01:22:07.654922: osd_op(client.30286.0:6719
>>>> > > > rbd_data.75c55bf2fdd7.0000000000001399 [write 282624~4096] 3.3f6d2373) v4
>>>> > > > currently delayed
>>>> > > > 2012-11-14 10:12:01.514061 osd.24 [WRN] 1 slow requests, 1 included below;
>>>> > > > oldest blocked for > 31793.859124 secs
>>>> > > > 2012-11-14 10:12:01.514063 osd.24 [WRN] slow request 31793.859124 seconds
>>>> > > > old,
>>>> > > > received at 2012-11-14 01:22:07.654922: osd_op(client.30286.0:6719
>>>> > > > rbd_data.75c55bf2fdd7.0000000000001399 [write 282624~4096] 3.3f6d2373) v4
>>>> > > > currently delayed
>>>> > > >
>>>> > > > When i now restart osd 24 they go away and everything is fine again.
>>>> > > >
>>>> > > > Stefan
>>>> > > > --
>>>> > > > To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>> > > > the body of a message to majordomo@xxxxxxxxxxxxxxx
>>>> > > > More majordomo info at http://vger.kernel.org/majordomo-info.html
>>>> > > >
>>>> > > >
>>>> > > --
>>>> > > To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>> > > the body of a message to majordomo@xxxxxxxxxxxxxxx
>>>> > > More majordomo info at http://vger.kernel.org/majordomo-info.html
>>>> > >
>>>> > --
>>>> > To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>> > the body of a message to majordomo@xxxxxxxxxxxxxxx
>>>> > More majordomo info at http://vger.kernel.org/majordomo-info.html
>>>> >
>>>> >
>>>> --
>>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>> the body of a message to majordomo@xxxxxxxxxxxxxxx
>>>> More majordomo info at http://vger.kernel.org/majordomo-info.html
>>>>
>>>>
>>> --
>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>> the body of a message to majordomo@xxxxxxxxxxxxxxx
>>> More majordomo info at http://vger.kernel.org/majordomo-info.html
>> --
>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>> the body of a message to majordomo@xxxxxxxxxxxxxxx
>> More majordomo info at http://vger.kernel.org/majordomo-info.html
--
To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
