Ceph » rbd

As it turns out this problem is not that easy.
1) Running CloudLinux 3.10.0-962.3.2.lve1.5.73.el7.x86_64 with virtio-scsi-single disks and discard does not work. However, switching to virtio-blk and still have discard all the way to the mounts works.
2) Running CloudLinux 4.18.0-372.26.1.lve.1.el8.x86_64 with virtio-scsi-single disks and discard does not work, but neither does virtio-blk. Switching off discard in the guest will solve both cases though.
3) Running Debian 5.10.0-19-amd64 with virtio-scsi-single disks and discard does not work, in some cases, as a reference.

It's clear that something happens with discard and commit of a journal entry.

I found out how to log within the qemu-process to a separate file, but even if I used all debug-flags I could set, there was no error. Just that it stopped logging that the commit_position was updated. The logs where quite huge, any hints on what would be interesting?

$ rpm -q kernel-3.10.0-962.3.2.lve1.5.73.el7.x86_64 --changelog | grep 'virtio_blk: add discard'

$ rpm --changelog q kernel-4.18.0-372.26.1.lve.1.el8.x86_64 | grep 'virtio_blk: add discard'
[block] virtio_blk: add discard and write zeroes support (Stefano Garzarella) [1692939]

Which makes a ton of sense. When discards are issued librbd in the qemu-kvm process stops committing to disk.

When running 3.10 with virtio-scsi-single there is discard support, which then also makes the process stops committing to disk.

This will trigger the problem.

`echo 1>a;sync;rm a;sync;fstrim --all`

I managed to reproduce it with rbd-nbd as well.

A simple echo 1>a;sync;rm a; sync will not break it. But fstrim /mnt will.

Trying to parse the logs:

It prints `committed tid=`, but not `updated commit position: `.
Which means that either `!m_pending_commit_tids.empty()` is false, or !commit_entry.committed is true.

```
void JournalMetadata::committed(uint64_t commit_tid,
const CreateContext &create_context) {
ldout(m_cct, 20) << "committed tid=" << commit_tid << dendl;

ObjectSetPosition commit_position;
  Context *stale_ctx = nullptr;
{
    std::scoped_lock locker{*m_timer_lock, m_lock};
    ceph_assert(commit_tid > m_commit_position_tid);

if (!m_commit_position.object_positions.empty()) {
      // in-flight commit position update
      commit_position = m_commit_position;
    } else {
      // safe commit position
      commit_position = m_client.commit_position;
    }

CommitTids::iterator it = m_pending_commit_tids.find(commit_tid);
    ceph_assert(it != m_pending_commit_tids.end());

CommitEntry &commit_entry = it->second;
    commit_entry.committed = true;

bool update_commit_position = false;
    while (!m_pending_commit_tids.empty()) {
      CommitTids::iterator it = m_pending_commit_tids.begin();
      CommitEntry &commit_entry = it->second;
      if (!commit_entry.committed) {
        break;
      }

commit_position.object_positions.emplace_front(
        commit_entry.object_num, commit_entry.tag_tid,
        commit_entry.entry_tid);
      m_pending_commit_tids.erase(it);
      update_commit_position = true;
    }

if (!update_commit_position) {
      return;
    }

// prune the position to have one position per splay offset
    std::set<uint8_t> in_use_splay_offsets;
    ObjectPositions::iterator ob_it = commit_position.object_positions.begin();
    while (ob_it != commit_position.object_positions.end()) {
      uint8_t splay_offset = ob_it->object_number % m_splay_width;
      if (!in_use_splay_offsets.insert(splay_offset).second) {
        ob_it = commit_position.object_positions.erase(ob_it);
      } else {
        ++ob_it;
      }
    }

stale_ctx = m_commit_position_ctx;
    m_commit_position_ctx = create_context();
    m_commit_position = commit_position;
    m_commit_position_tid = commit_tid;

ldout(m_cct, 20) << "updated commit position: " << commit_position << ", " 
                     << "on_safe=" << m_commit_position_ctx << dendl;
    schedule_commit_task();
  }

if (stale_ctx != nullptr) {
    ldout(m_cct, 20) << "canceling stale commit: on_safe=" << stale_ctx
                     << dendl;
    stale_ctx->complete(-ESTALE);
  }
}
```

AFAIK this case is not covered in the test suite.

https://github.com/ceph/ceph/blob/6fee777d603aebce492c57b41f3b5760d50ddb07/src/test/librbd/journal/test_Replay.cc

Since this happens when JournalPlayer is in STATE_READY (from handler_flushing_ready), it seems to be in another state loop (since JournalPlayer handles AioDiscard perfectly fine). I think the test cases needs to be check that the events run fine in all states that handle replay.

Not sure how to tag people or get any feedback on issues here, but hopefully someone hears the echoes :)

To conclude, whenever any AioDiscard is happening when JournalPlayer is in STATE_READY, nothing will be replayed from the journal.

This bug is two fold, first the bug that stops the process. Second, there is no heartbeat that picks up that the player is not committing to disk.

For some reason the following will trigger that journal is never commited to rbd image.

Given

rbd-nbd --device ${device} map ${image} &

blkdiscard  -o $((1996*4096+1024)) -l $((4096*104)) /dev/nbd0

Now nothing will be committed to the rbd image. (updated commit position in JournalMetadata is not touched).

And

blkdiscard  -o $((1996*4096)) -l $((4096*104)) /dev/nbd0

Setting

rbd skip partial discard = false 

Makes the problem go away.

How do I make the test in src/test/librbd/journal/test_Replay.cc actually test this?
I would like to test both cases, my problem is that open_image does not seem to enable handle_flushing_replay.

Pull request to fix the original problem: https://github.com/ceph/ceph/pull/49614