Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

vhost: when using qemu and vhost, an IO error may occur when the vhost is restarted. #3504

Open
ygtzf opened this issue Aug 26, 2024 · 7 comments
Open

vhost: when using qemu and vhost, an IO error may occur when the vhost is restarted. #3504

ygtzf opened this issue Aug 26, 2024 · 7 comments
Labels
Sighting

Comments

@ygtzf
Copy link

ygtzf commented Aug 26, 2024 •
edited
Loading

Sighting report

We use vhost to provide vhost-user-blk backend server for qemu. Recently we encountered some problems: when restarting the vhost service, the VM corresponding to qemu had an IO error and the file system became readonly mode.

We found some error logs in the vhost log. These memory addresses were too large, and there were obviously some incorrect accesses.
rte_vhost_user.c: 653:vhost_vring_desc_payload_to_iov: ERROR: gpa_to_vva(0xe1ec329e50c1e048) == NULL
rte_vhost_user.c: 653:vhost_vring_desc_payload_to_iov: ERROR: gpa_to_vva((nil)) == NULL

I see that this memory address is taken from vring. Can it be understood that the guest or qemu mapped the wrong address?

VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) guest memory region size: 0x80000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          guest physical addr: 0x0
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          guest virtual  addr: 0x7fc600000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          host  virtual  addr: 0x7f2180000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          mmap addr : 0x7f2180000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          mmap size : 0x80000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          mmap align: 0x40000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          mmap off  : 0x0
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) guest memory region size: 0x780000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          guest physical addr: 0x100000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          guest virtual  addr: 0x7fc680000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          host  virtual  addr: 0x7f1a00000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          mmap addr : 0x7f1980000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          mmap size : 0x800000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          mmap align: 0x40000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock)          mmap off  : 0x80000000
rte_vhost_user.c: 844:vhost_register_memtable_if_required: *INFO*: Start to set memtable
rte_vhost_user.c: 769:vhost_session_mem_register: *INFO*: Registering VM memory for vtophys translation - 0x7f1980000000 len:0x800000000
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) read message VHOST_USER_SET_VRING_ADDR
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) read message VHOST_USER_SET_VRING_KICK
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) vring kick idx:6 file:294
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) read message VHOST_USER_SET_VRING_NUM
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) read message VHOST_USER_SET_VRING_BASE
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) vring base idx:7 last_used_idx:5387 last_avail_idx:5387.
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) read message VHOST_USER_SET_VRING_ADDR
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) read message VHOST_USER_SET_VRING_KICK
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) vring kick idx:7 file:311
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) read message VHOST_USER_SET_VRING_NUM
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) read message VHOST_USER_SET_VRING_BASE
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) vring base idx:8 last_used_idx:51594 last_avail_idx:51594.
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) read message VHOST_USER_SET_VRING_ADDR
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) read message VHOST_USER_SET_VRING_KICK
VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) vring kick idx:8 file:330
rte_vhost_user.c: 653:vhost_vring_desc_payload_to_iov: *ERROR*: gpa_to_vva(0xe1ec329e50c1e048) == NULL
rte_vhost_user.c: 653:vhost_vring_desc_payload_to_iov: *ERROR*: gpa_to_vva((nil)) == NULL
rte_vhost_user.c: 653:vhost_vring_desc_payload_to_iov: *ERROR*: gpa_to_vva((nil)) == NULL
rte_vhost_user.c: 653:vhost_vring_desc_payload_to_iov: *ERROR*: gpa_to_vva(0xffff91f1c90b6d80) == NULL
rte_vhost_user.c: 653:vhost_vring_desc_payload_to_iov: *ERROR*: gpa_to_vva((nil)) == NULL
rte_vhost_user.c: 653:vhost_vring_desc_payload_to_iov: *ERROR*: gpa_to_vva(0x50c05fc55043b4d8) == NULL

Expected Behavior

Current Behavior

Possible Solution

Steps to Reproduce

So far, we have not found any way to reproduce this problem, but there have been several cases in production.

Context (Environment including OS version, SPDK version, etc.)

Qemu version: v8.2.0
SPDK version: v24.01
@ygtzf ygtzf added the Sighting label Aug 26, 2024
@changpe1
Copy link
Contributor

@ygtzf do you use the vhost recovery feature for your case? restart a new vhost process while the QEMU is running?

@ygtzf
Copy link
Author

ygtzf commented Sep 12, 2024

@changpe1 Yes, the live recovery feature is in our vhost version and we use it as well. QEMU is running, and we use systemctl to restart the vhost service.

@ygtzf
Copy link
Author

ygtzf commented Sep 18, 2024

@changpe1 Could you please provide some guidance or methods to investigate the issue? We've encountered this problem multiple times in our production environment.Thank you very much.

@changpe1
Copy link
Contributor

@changpe1 Could you please provide some guidance or methods to investigate the issue? We've encountered this problem multiple times in our production environment.Thank you very much.

You can run fio tests in your VM and restart vhost process to reproduce this issue, and check your log such as "VHOST_CONFIG: (/tmp/nvm-15x3hhwnspnm13-disk0.sock) vring base idx:8 last_used_idx:51594 last_avail_idx:51594." to see if any vring has different values for 'last_used_idx' and 'last_avail_idx', these values mean there are inflight IOs in the shared memory, we need to know this IO error request is from inflight IOs or just garbage values.

@mikeBashStuff mikeBashStuff mentioned this issue Sep 24, 2024
Open
@ygtzf
Copy link
Author

ygtzf commented Sep 26, 2024

@changpe1 I've been running tests many days, but it's difficult to reproduce this issue.
In the production environment, we've noticed that vhost_session_mem_unregister can sometimes be quite slow, possibly taking dozens of seconds. I'm not sure if there's a connection between the two.
Assuming there is a connection, I'm thinking of using kill -9 to terminate the vhost process in the production environment. What potential issues might this cause? Thank you very much.

@changpe1
Copy link
Contributor

@changpe1 I've been running tests many days, but it's difficult to reproduce this issue. In the production environment, we've noticed that vhost_session_mem_unregister can sometimes be quite slow, possibly taking dozens of seconds. I'm not sure if there's a connection between the two. Assuming there is a connection, I'm thinking of using kill -9 to terminate the vhost process in the production environment. What potential issues might this cause? Thank you very much.

I know it's difficult to reproduce such an issue in production environment, from my experience on this issue, most likely there were outstanding IOs when doing hot upgrade, when stopping vhost service, vhost should first stop fetching new requests from VRINGs and then waiting for all outstanding IOs sent to backend to be completed, you can watch the normal cases to see if your vhost restart process follow above steps.

I would not suggest to use kill -9 some cleanup steps may be skipped.

@ygtzf
Copy link
Author

ygtzf commented Sep 27, 2024

I know it's difficult to reproduce such an issue in production environment, from my experience on this issue, most likely there were outstanding IOs when doing hot upgrade, when stopping vhost service, vhost should first stop fetching new requests from VRINGs and then waiting for all outstanding IOs sent to backend to be completed, you can watch the normal cases to see if your vhost restart process follow above steps.

I would not suggest to use kill -9 some cleanup steps may be skipped.

Thank you for the reply. We have added additional logging to the shutdown and start-up paths, and we are also comparing the hot upgrade process you mentioned to see if we can identify any potential issues.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Sighting
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@ygtzf @changpe1 and others