Re: xen-unstable linux-5.14: 1 of 2 multicall(s) failed: cpu 0

[Jan Beulich <jbeulich@xxxxxxxx>]

On 06.09.2021 23:35, Sander Eikelenboom wrote:
> L.S.,
> 
> On my AMD box running:
>      xen-unstable changeset: Fri Sep 3 15:10:43 2021 +0200 git:2d4978ead4
>      linux kernel: 5.14.1
> 
> With this setup I'm encountering some issues in dom0, see below.

Any indication as to "since when"? Xen update, kernel update, config
change, ...?

> xl dmesg gives:
> 
> (XEN) [2021-09-06 18:15:04.089] mm.c:3506:d0v0 mfn 63b936 already pinned
> (XEN) [2021-09-06 18:15:04.089] mm.c:3506:d0v0 mfn 6a0622 already pinned
> (XEN) [2021-09-06 18:15:04.089] mm.c:3506:d0v0 mfn 6b63da already pinned
> (XEN) [2021-09-06 18:15:04.089] mm.c:3506:d0v0 mfn 638dd9 already pinned
> (XEN) [2021-09-06 18:15:04.089] mm.c:3506:d0v0 mfn 68a7bc already pinned
> (XEN) [2021-09-06 18:15:04.089] mm.c:3506:d0v0 mfn 63c27d already pinned
> (XEN) [2021-09-06 18:15:04.089] mm.c:3506:d0v0 mfn 6a04f2 already pinned
> (XEN) [2021-09-06 18:15:04.089] mm.c:3506:d0v0 mfn 690d49 already pinned
> (XEN) [2021-09-06 18:15:04.089] mm.c:3506:d0v0 mfn 6959a0 already pinned
> (XEN) [2021-09-06 18:15:04.089] mm.c:3506:d0v0 mfn 6a055e already pinned
> (XEN) [2021-09-06 18:15:04.090] mm.c:3506:d0v0 mfn 639437 already pinned

This hints more towards a kernel issue, but I wouldn't outright exclude
other reasons.

> dmesg gives:
> 
> [34321.304270] ------------[ cut here ]------------
> [34321.304277] WARNING: CPU: 0 PID: 23628 at arch/x86/xen/multicalls.c:102 
> xen_mc_flush+0x176/0x1a0
> [34321.304288] Modules linked in:
> [34321.304291] CPU: 0 PID: 23628 Comm: apt-get Not tainted 
> 5.14.1-20210906-doflr-mac80211debug+ #1
> [34321.304294] Hardware name: MSI MS-7640/890FXA-GD70 (MS-7640)  , BIOS 
> V1.8B1 09/13/2010
> [34321.304296] RIP: e030:xen_mc_flush+0x176/0x1a0
> [34321.304300] Code: 89 45 18 48 c1 e9 3f 48 89 ce e9 20 ff ff ff e8 60 03 00 
> 00 66 90 5b 5d 41 5c 41 5d c3 48 c7 45 18 ea ff ff ff be 01 00 00 00 <0f> 0b 
> 8b 55 00 48 c7 c7 10 97 aa 82 31 db 49 c7 c5 38 97 aa 82 65
> [34321.304303] RSP: e02b:ffffc90000a97c90 EFLAGS: 00010002
> [34321.304305] RAX: ffff88807d416398 RBX: ffff88807d416350 RCX: 
> ffff88807d416398
> [34321.304306] RDX: 0000000000000001 RSI: 0000000000000001 RDI: 
> deadbeefdeadf00d
> [34321.304308] RBP: ffff88807d416300 R08: aaaaaaaaaaaaaaaa R09: 
> ffff888006160cc0
> [34321.304309] R10: deadbeefdeadf00d R11: ffffea000026a600 R12: 
> 0000000000000000
> [34321.304310] R13: ffff888012f6b000 R14: 0000000012f6b000 R15: 
> 0000000000000001
> [34321.304320] FS:  00007f5071177800(0000) GS:ffff88807d400000(0000) 
> knlGS:0000000000000000
> [34321.304322] CS:  10000e030 DS: 0000 ES: 0000 CR0: 0000000080050033
> [34321.304323] CR2: 00007f506f542000 CR3: 00000000160cc000 CR4: 
> 0000000000000660
> [34321.304326] Call Trace:
> [34321.304331]  xen_alloc_pte+0x294/0x320
> [34321.304334]  move_pgt_entry+0x165/0x4b0
> [34321.304339]  move_page_tables+0x6fa/0x8d0
> [34321.304342]  move_vma.isra.44+0x138/0x500
> [34321.304345]  __x64_sys_mremap+0x296/0x410
> [34321.304348]  do_syscall_64+0x3a/0x80
> [34321.304352]  entry_SYSCALL_64_after_hwframe+0x44/0xae
> [34321.304355] RIP: 0033:0x7f507196301a
> [34321.304358] Code: 73 01 c3 48 8b 0d 76 0e 0c 00 f7 d8 64 89 01 48 83 c8 ff 
> c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 49 89 ca b8 19 00 00 00 0f 05 <48> 3d 
> 01 f0 ff ff 73 01 c3 48 8b 0d 46 0e 0c 00 f7 d8 64 89 01 48
> [34321.304360] RSP: 002b:00007ffda1eecd38 EFLAGS: 00000246 ORIG_RAX: 
> 0000000000000019
> [34321.304362] RAX: ffffffffffffffda RBX: 000056205f950f30 RCX: 
> 00007f507196301a
> [34321.304363] RDX: 0000000001a00000 RSI: 0000000001900000 RDI: 
> 00007f506dc56000
> [34321.304364] RBP: 0000000001a00000 R08: 0000000000000010 R09: 
> 0000000000000004
> [34321.304365] R10: 0000000000000001 R11: 0000000000000246 R12: 
> 00007f506dc56060
> [34321.304367] R13: 00007f506dc56000 R14: 00007f506dc56060 R15: 
> 000056205f950f30
> [34321.304368] ---[ end trace a19885b78fe8f33e ]---
> [34321.304370] 1 of 2 multicall(s) failed: cpu 0
> [34321.304371]   call  2: op=12297829382473034410 arg=[aaaaaaaaaaaaaaaa] 
> result=-22

Just as an observation: This (decimal) output of course isn't very helpful
for investigating issues like this one. But the 0xAA pattern indicates
anyway that what is being logged has been clobbered by the hypervisor.
For the output to be useful, MC_DEBUG needs to be enabled in the sources.

Jan