Ceph » rbd

(to be clear - in that log, the problem happens on the second wait_event for tid=132078)

Looking at the code, I'm not sure how this was supposed to work. In AbstractImageWriteRequest<I>::send_request(), if there are multiple object extents to submit, we append journal entries for them, but only the last journal tid is used for all of the submitted extents. Shouldn't each extent be associated with the correct journal tid?

Joshua Baergen wrote:

Looking at the code, I'm not sure how this was supposed to work. In AbstractImageWriteRequest<I>::send_request(), if there are multiple object extents to submit, we append journal entries for them, but only the last journal tid is used for all of the submitted extents. Shouldn't each extent be associated with the correct journal tid?

Mykola might be able to answer this question.

OK, looking forward to more info! I started to look into modifications along the line of my thinking in #3, but quickly realized that the journal events are dealing in image_extents vs. the rest of this path dealing in object_extents, which makes things a bit more difficult.

Joshua Baergen wrote:

Looking at the code, I'm not sure how this was supposed to work. In AbstractImageWriteRequest<I>::send_request(), if there are multiple object extents to submit, we append journal entries for them, but only the last journal tid is used for all of the submitted extents. Shouldn't each extent be associated with the correct journal tid?

In AbstractImageWriteRequest<I>::send_request() we submit requests to write to journal and then in journal::ObjectDispatch just wait for them to complete. And we need to know only the latest tid. When it is complete all previous ones are expected to be complete too.

Thanks Mykola - that confirms what I suspected was the intent here. I've posted a proposed fix for the issue reported here at https://github.com/ceph/ceph/pull/54362; it includes a somewhat length description of what is going wrong and the solution that I chose. Could folks please take a look and confirm that my understanding of the problem is correct and comment on my solution? I've originally wrote this patch against 16.2.13 and there it passes the reproducer that I posted previously in this ticket.

1. Can we submit a single journal event for all image extents and have it know about how many object requests will be issued?
2. Do we need to commit journal events via the dispatcher path? Can they automatically clean themselves up, and then all the dispatcher path needs to worry about is waiting on the event if it still exists?

Digging into journal events further, there already is a mechanism for keeping an event around until all parts have been committed: pending extents. This extent interval gets updated as each part of the journal event gets committed, and only once the interval is empty does the event get cleaned up.

The issue here of course is that all of the object requests get associated with the last journal event, which in turn has only a subset of the overall interval, and thus some of the object requests will not be represented in the event.

Here's what I wrote in the PR:

In the case where an image request is split across multiple object extents and journaling is enabled, multiple journal events are appended. Prior to this change, all object requests would wait for the last journal event to complete, since journal events complete in order and thus the last one completing implies that all prior journal events were safe at that point.

While conceptually correct, journal events don't have a mechanism for knowing how many requests might be associated with them (but as noted above the extent interval is supposed to do this). Thus, it's entirely possible for the following sequence to occur:

1. An image request gets split into two object requests. Journal events are appended, one object request gets submitted and starts waiting on the last journal event (which also causes a C_CommitIOEvent to be instantiated against that journal event), but the other object request gets delayed due to an overlap.
2. Journaling completes, and the C_CommitIOEvent fires, which causes the event to be cleaned up.
3. The second object request from above is allowed to make progress; it tries to wait for the journal event that was just cleaned up which causes the assert in wait_event() to fire.

It might seem that the simple solution exists of allowing for wait_event() to return early when the event no longer exists, and indeed the code worked this way when originally written and was later changed to enforce that the event existed. However, there appears to be another problem here, which is that there is no C_CommitIOEvent instantiated for the earlier journal event that were appended, which means they are actually leaked and hang around forever. As far as I can tell, this happens today whenever multiple journal events are appended.

Here's another attempt at fixing this that I think better honours the original intent of the relationship between image requests and journal events: https://github.com/ceph/ceph/pull/54377

• Fix WriteSame in the same way as Write and Discard
• Refactor CompareAndWrite so that I can clean up the duplicated code
• Update some tests, probably

As I've been trying to write a unit test covering this, I've come to realize that I don't think this condition is possible on anything except the discard path, and there only recently. Up until 21a26a752843295ff946d1543c2f5f9fac764593 (librbd: Fix local rbd mirror journals growing forever), unless I'm missing something, m_image_extents always contained a single extent for all I/O types. This commit updated discard to have the possibility of multiple extents since it can translate object requests back to image extents without trying to merge them. This commit was fixing 7ca1bab (librbd: align discard requests to default bluestore allocation size), which first became available in Nautilus.

It makes me wonder if there is any utility in allowing multiple image extents for an image request (and whether I'm just missing the place where this is actually useful).

As a consequence for the above, a very simple workaround for this crash appears to be to set rbd_skip_partial_discard=false.

Joshua Baergen wrote:

As a consequence for the above, a very simple workaround for this crash appears to be to set rbd_skip_partial_discard=false.

Hello Joshua,

in this comment, do you mean to set rbd_skip_partial_discard to false, or to true? Because it seems it defaults to false already.

Thank you

Hey Raimund, as far as I can tell, the default is true in all recent releases. Which release do you see this in? What does "ceph config help rbd_skip_partial_discard" say the default is?

Raimund Sacherer wrote:

Joshua Baergen wrote:

As a consequence for the above, a very simple workaround for this crash appears to be to set rbd_skip_partial_discard=false.

Hello Joshua,

in this comment, do you mean to set rbd_skip_partial_discard to false, or to true? Because it seems it defaults to false already.

Thank you

Please ignore my comment. Unfortunatly I got confused as the documentation (wrongly) did state that this is set to false per default. It turns out it is actually default true and setting it to false fixed the issue.

Best regards
Raimund