* xenwatch thread deadlock after dynamic network attach
@ 2026-07-30 14:03 Marek Marczykowski-Górecki
2026-07-31 22:20 ` Marek Marczykowski-Górecki
0 siblings, 1 reply; 2+ messages in thread
From: Marek Marczykowski-Górecki @ 2026-07-30 14:03 UTC (permalink / raw)
To: xen-devel; +Cc: Jürgen Groß
[-- Attachment #1: Type: text/plain, Size: 7701 bytes --]
Hi,
I've hit yet another issue with network attach. This time, it looks like
the code to handle forceful re-attach triggers when it shouldn't. The
test is basically:
1. Start the backend domain
2. Start the frontend domain without any vif attached.
3. Attach vif (equivalent of xl network-attach).
First I get:
[ 17.476245] xen vif-0: xenbus: state reset occurred, reconnecting
[ 17.502933] xen vif-0: xenbus: state reset occurred, reconnecting
[ 17.551204] xen vif-0: xenbus: state reset occurred, reconnecting
[ 17.612171] xen vif-0: xenbus: state reset occurred, reconnecting
[ 17.654823] xen vif-0: xenbus: state reset occurred, reconnecting
[ 17.676268] xen vif-0: xenbus: state reset occurred, reconnecting
[ 17.691250] xen_netfront: Initialising Xen virtual ethernet driver
[ 17.692288] vif vif-0: xenbus: state reset occurred, reconnecting
I'm not sure why it's repeated this many times (xenstore watch triggers
this many times?), but then, all xenstore watch operations in that
domain hangs. Inspecting tasks ("t" sysrq) shows:
[ 1494.201304] task:xenbus state:S stack:0 pid:62 tgid:62 ppid:2 task_flags:0x208040 flags:0x00080000
[ 1494.201607] Call Trace:
[ 1494.201659] <TASK>
[ 1494.201711] __schedule+0x2f3/0x780
[ 1494.201789] ? __pfx_xenbus_thread+0x10/0x10
[ 1494.201890] schedule+0x27/0xa0
[ 1494.201966] xenbus_thread+0x1a8/0x200
[ 1494.202044] ? __pfx_autoremove_wake_function+0x10/0x10
[ 1494.202144] kthread+0xfc/0x240
[ 1494.202347] ? __pfx_kthread+0x10/0x10
[ 1494.202418] ret_from_fork+0x158/0x170
[ 1494.202568] ? __pfx_kthread+0x10/0x10
[ 1494.202636] ret_from_fork_asm+0x1a/0x30
[ 1494.202704] </TASK>
[ 1494.202773] task:xenwatch state:D stack:0 pid:63 tgid:63 ppid:2 task_flags:0x208040 flags:0x00080000
[ 1494.202936] Call Trace:
[ 1494.202980] <TASK>
[ 1494.203023] __schedule+0x2f3/0x780
[ 1494.203091] schedule+0x27/0xa0
[ 1494.203177] schedule_preempt_disabled+0x15/0x30
[ 1494.203381] __mutex_lock.constprop.0+0x544/0xa60
[ 1494.203560] ? xenbus_scanf+0xbd/0x100
[ 1494.203636] device_del+0x3a/0x3e0
[ 1494.203717] device_unregister+0x17/0x60
[ 1494.203791] xenbus_dev_changed+0x247/0x2a0
[ 1494.203865] ? __pfx_xenwatch_thread+0x10/0x10
[ 1494.354139] xenwatch_thread+0x92/0x1c0
[ 1494.354274] ? __pfx_autoremove_wake_function+0x10/0x10
[ 1494.354545] kthread+0xfc/0x240
[ 1494.355389] ? __pfx_kthread+0x10/0x10
[ 1494.355615] ret_from_fork+0x158/0x170
[ 1494.355706] ? __pfx_kthread+0x10/0x10
[ 1494.355805] ret_from_fork_asm+0x1a/0x30
[ 1494.355890] </TASK>
...
[ 1496.396208] task:(udev-worker) state:D stack:0 pid:824 tgid:824 ppid:270 task_flags:0x400140 flags:0x00080003
[ 1496.398700] Call Trace:
[ 1496.398753] <TASK>
[ 1496.398805] __schedule+0x2f3/0x780
[ 1496.398884] schedule+0x27/0xa0
[ 1496.398961] schedule_timeout+0x83/0x100
[ 1496.399036] ? __pfx_process_timeout+0x10/0x10
[ 1496.399141] xennet_create_dev+0x27e/0x340 [xen_netfront]
[ 1496.399246] ? split+0xac/0x130
[ 1496.399326] ? __pfx_autoremove_wake_function+0x10/0x10
[ 1496.399727] netfront_probe+0x16/0x70 [xen_netfront]
[ 1496.399833] xenbus_dev_probe+0xe6/0x1d0
[ 1496.399920] really_probe+0xde/0x340
[ 1496.400005] ? pm_runtime_barrier+0x54/0x90
[ 1496.400084] ? __pfx___driver_attach+0x10/0x10
[ 1496.400213] __driver_probe_device+0x84/0x140
[ 1496.400339] driver_probe_device+0x1f/0xa0
[ 1496.400416] __driver_attach+0xba/0x1c0
[ 1496.400632] bus_for_each_dev+0x8e/0xe0
[ 1496.400714] bus_add_driver+0x142/0x220
[ 1496.400790] driver_register+0x72/0xd0
[ 1496.400876] __xenbus_register_frontend+0x2b/0x50
[ 1496.400977] ? __pfx_netif_init+0x10/0x10 [xen_netfront]
[ 1496.401079] do_one_initcall+0x5a/0x310
[ 1496.401159] do_init_module+0x90/0x250
[ 1496.401239] init_module_from_file+0x88/0xd0
[ 1496.401345] ? __pfx_ovl_file_accessed+0x10/0x10 [overlay]
[ 1496.401557] idempotent_init_module+0x114/0x310
[ 1496.401656] __x64_sys_finit_module+0x6d/0xd0
[ 1496.401773] do_syscall_64+0x87/0x7e0
[ 1496.401848] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1496.401946] RIP: 0033:0x7abadbeba7b9
[ 1496.402029] RSP: 002b:00007ffc0ffba5d8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[ 1496.402163] RAX: ffffffffffffffda RBX: 00005aa7d2036580 RCX: 00007abadbeba7b9
[ 1496.556946] RDX: 0000000000000000 RSI: 00007abadb36d44d RDI: 000000000000001b
[ 1496.557171] RBP: 0000000000000000 R08: 0000000000000000 R09: 00005aa7d20518c0
[ 1496.560779] R10: 0000000000000000 R11: 0000000000000246 R12: 00007abadb36d44d
[ 1496.561000] R13: 0000000000020000 R14: 00005aa7d1f24b00 R15: 0000000000000000
[ 1496.561301] </TASK>
Xenstore content at this time is:
device/vif = "" (n0,r61)
device/vif/0 = "" (n61,r59)
device/vif/0/backend = "/local/domain/59/backend/vif/61/0" (n61,r59)
device/vif/0/backend-id = "59" (n61,r59)
device/vif/0/state = "1" (n61,r59)
device/vif/0/handle = "0" (n61,r59)
device/vif/0/mac = "00:16:3e:5e:6c:00" (n61,r59)
device/vif/0/trusted = "0" (n61,r59)
device/vif/0/mtu = "1500" (n59,r61)
/local/domain/59/backend/vif/61/0/frontend = "/local/domain/61/device/vif/0" (n59,r61)
/local/domain/59/backend/vif/61/0/frontend-id = "61" (n59,r61)
/local/domain/59/backend/vif/61/0/online = "1" (n59,r61)
/local/domain/59/backend/vif/61/0/state = "2" (n59,r61)
/local/domain/59/backend/vif/61/0/script = "/etc/xen/scripts/vif-route-qubes" (n59,r61)
/local/domain/59/backend/vif/61/0/mac = "00:16:3e:5e:6c:00" (n59,r61)
/local/domain/59/backend/vif/61/0/ip = "10.137.0.19 fd09:24ef:4179::a89:13" (n59,r61)
/local/domain/59/backend/vif/61/0/bridge = "xenbr0" (n59,r61)
/local/domain/59/backend/vif/61/0/handle = "0" (n59,r61)
/local/domain/59/backend/vif/61/0/type = "vif" (n59,r61)
/local/domain/59/backend/vif/61/0/hotplug-status = "connected" (n59,r61)
/local/domain/59/backend/vif/61/0/feature-sg = "1" (n59,r61)
/local/domain/59/backend/vif/61/0/feature-gso-tcpv4 = "1" (n59,r61)
/local/domain/59/backend/vif/61/0/feature-gso-tcpv6 = "1" (n59,r61)
/local/domain/59/backend/vif/61/0/feature-ipv6-csum-offload = "1" (n59,r61)
/local/domain/59/backend/vif/61/0/feature-rx-copy = "1" (n59,r61)
/local/domain/59/backend/vif/61/0/feature-xdp-headroom = "1" (n59,r61)
/local/domain/59/backend/vif/61/0/feature-rx-flip = "0" (n59,r61)
/local/domain/59/backend/vif/61/0/feature-multicast-control = "1" (n59,r61)
/local/domain/59/backend/vif/61/0/feature-dynamic-multicast-control = "1" (n59,r61)
/local/domain/59/backend/vif/61/0/feature-split-event-channels = "1" (n59,r61)
/local/domain/59/backend/vif/61/0/multi-queue-max-queues = "2" (n59,r61)
/local/domain/59/backend/vif/61/0/feature-ctrl-ring = "1" (n59,r61)
So, from what I see, the attach happens quite early in practice -
during, or even before loading xen-netfront module. But then, the device
is misinterpreted as a stale one.
This does not happen every time, only sometimes. I guess it's related to
the timing of the network-attach call.
I'll try to add some more logging (especially what state it got from
xenstore vs what it expected), but maybe you have some ideas already?
--
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]
^ permalink raw reply [flat|nested] 2+ messages in thread* Re: xenwatch thread deadlock after dynamic network attach
2026-07-30 14:03 xenwatch thread deadlock after dynamic network attach Marek Marczykowski-Górecki
@ 2026-07-31 22:20 ` Marek Marczykowski-Górecki
0 siblings, 0 replies; 2+ messages in thread
From: Marek Marczykowski-Górecki @ 2026-07-31 22:20 UTC (permalink / raw)
To: xen-devel; +Cc: Jürgen Groß
[-- Attachment #1: Type: text/plain, Size: 8430 bytes --]
On Thu, Jul 30, 2026 at 04:03:59PM +0200, Marek Marczykowski-Górecki wrote:
> Hi,
>
> I've hit yet another issue with network attach. This time, it looks like
> the code to handle forceful re-attach triggers when it shouldn't. The
> test is basically:
> 1. Start the backend domain
> 2. Start the frontend domain without any vif attached.
> 3. Attach vif (equivalent of xl network-attach).
>
> First I get:
>
> [ 17.476245] xen vif-0: xenbus: state reset occurred, reconnecting
> [ 17.502933] xen vif-0: xenbus: state reset occurred, reconnecting
> [ 17.551204] xen vif-0: xenbus: state reset occurred, reconnecting
> [ 17.612171] xen vif-0: xenbus: state reset occurred, reconnecting
> [ 17.654823] xen vif-0: xenbus: state reset occurred, reconnecting
> [ 17.676268] xen vif-0: xenbus: state reset occurred, reconnecting
> [ 17.691250] xen_netfront: Initialising Xen virtual ethernet driver
> [ 17.692288] vif vif-0: xenbus: state reset occurred, reconnecting
>
> I'm not sure why it's repeated this many times (xenstore watch triggers
> this many times?), but then, all xenstore watch operations in that
> domain hangs. Inspecting tasks ("t" sysrq) shows:
>
> [ 1494.201304] task:xenbus state:S stack:0 pid:62 tgid:62 ppid:2 task_flags:0x208040 flags:0x00080000
> [ 1494.201607] Call Trace:
> [ 1494.201659] <TASK>
> [ 1494.201711] __schedule+0x2f3/0x780
> [ 1494.201789] ? __pfx_xenbus_thread+0x10/0x10
> [ 1494.201890] schedule+0x27/0xa0
> [ 1494.201966] xenbus_thread+0x1a8/0x200
> [ 1494.202044] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 1494.202144] kthread+0xfc/0x240
> [ 1494.202347] ? __pfx_kthread+0x10/0x10
> [ 1494.202418] ret_from_fork+0x158/0x170
> [ 1494.202568] ? __pfx_kthread+0x10/0x10
> [ 1494.202636] ret_from_fork_asm+0x1a/0x30
> [ 1494.202704] </TASK>
> [ 1494.202773] task:xenwatch state:D stack:0 pid:63 tgid:63 ppid:2 task_flags:0x208040 flags:0x00080000
> [ 1494.202936] Call Trace:
> [ 1494.202980] <TASK>
> [ 1494.203023] __schedule+0x2f3/0x780
> [ 1494.203091] schedule+0x27/0xa0
> [ 1494.203177] schedule_preempt_disabled+0x15/0x30
> [ 1494.203381] __mutex_lock.constprop.0+0x544/0xa60
> [ 1494.203560] ? xenbus_scanf+0xbd/0x100
> [ 1494.203636] device_del+0x3a/0x3e0
> [ 1494.203717] device_unregister+0x17/0x60
> [ 1494.203791] xenbus_dev_changed+0x247/0x2a0
> [ 1494.203865] ? __pfx_xenwatch_thread+0x10/0x10
> [ 1494.354139] xenwatch_thread+0x92/0x1c0
> [ 1494.354274] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 1494.354545] kthread+0xfc/0x240
> [ 1494.355389] ? __pfx_kthread+0x10/0x10
> [ 1494.355615] ret_from_fork+0x158/0x170
> [ 1494.355706] ? __pfx_kthread+0x10/0x10
> [ 1494.355805] ret_from_fork_asm+0x1a/0x30
> [ 1494.355890] </TASK>
> ...
> [ 1496.396208] task:(udev-worker) state:D stack:0 pid:824 tgid:824 ppid:270 task_flags:0x400140 flags:0x00080003
> [ 1496.398700] Call Trace:
> [ 1496.398753] <TASK>
> [ 1496.398805] __schedule+0x2f3/0x780
> [ 1496.398884] schedule+0x27/0xa0
> [ 1496.398961] schedule_timeout+0x83/0x100
> [ 1496.399036] ? __pfx_process_timeout+0x10/0x10
> [ 1496.399141] xennet_create_dev+0x27e/0x340 [xen_netfront]
> [ 1496.399246] ? split+0xac/0x130
> [ 1496.399326] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 1496.399727] netfront_probe+0x16/0x70 [xen_netfront]
> [ 1496.399833] xenbus_dev_probe+0xe6/0x1d0
> [ 1496.399920] really_probe+0xde/0x340
> [ 1496.400005] ? pm_runtime_barrier+0x54/0x90
> [ 1496.400084] ? __pfx___driver_attach+0x10/0x10
> [ 1496.400213] __driver_probe_device+0x84/0x140
> [ 1496.400339] driver_probe_device+0x1f/0xa0
> [ 1496.400416] __driver_attach+0xba/0x1c0
> [ 1496.400632] bus_for_each_dev+0x8e/0xe0
> [ 1496.400714] bus_add_driver+0x142/0x220
> [ 1496.400790] driver_register+0x72/0xd0
> [ 1496.400876] __xenbus_register_frontend+0x2b/0x50
> [ 1496.400977] ? __pfx_netif_init+0x10/0x10 [xen_netfront]
> [ 1496.401079] do_one_initcall+0x5a/0x310
> [ 1496.401159] do_init_module+0x90/0x250
> [ 1496.401239] init_module_from_file+0x88/0xd0
> [ 1496.401345] ? __pfx_ovl_file_accessed+0x10/0x10 [overlay]
> [ 1496.401557] idempotent_init_module+0x114/0x310
> [ 1496.401656] __x64_sys_finit_module+0x6d/0xd0
> [ 1496.401773] do_syscall_64+0x87/0x7e0
> [ 1496.401848] entry_SYSCALL_64_after_hwframe+0x76/0x7e
> [ 1496.401946] RIP: 0033:0x7abadbeba7b9
> [ 1496.402029] RSP: 002b:00007ffc0ffba5d8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
> [ 1496.402163] RAX: ffffffffffffffda RBX: 00005aa7d2036580 RCX: 00007abadbeba7b9
> [ 1496.556946] RDX: 0000000000000000 RSI: 00007abadb36d44d RDI: 000000000000001b
> [ 1496.557171] RBP: 0000000000000000 R08: 0000000000000000 R09: 00005aa7d20518c0
> [ 1496.560779] R10: 0000000000000000 R11: 0000000000000246 R12: 00007abadb36d44d
> [ 1496.561000] R13: 0000000000020000 R14: 00005aa7d1f24b00 R15: 0000000000000000
> [ 1496.561301] </TASK>
>
> Xenstore content at this time is:
>
> device/vif = "" (n0,r61)
> device/vif/0 = "" (n61,r59)
> device/vif/0/backend = "/local/domain/59/backend/vif/61/0" (n61,r59)
> device/vif/0/backend-id = "59" (n61,r59)
> device/vif/0/state = "1" (n61,r59)
> device/vif/0/handle = "0" (n61,r59)
> device/vif/0/mac = "00:16:3e:5e:6c:00" (n61,r59)
> device/vif/0/trusted = "0" (n61,r59)
> device/vif/0/mtu = "1500" (n59,r61)
>
> /local/domain/59/backend/vif/61/0/frontend = "/local/domain/61/device/vif/0" (n59,r61)
> /local/domain/59/backend/vif/61/0/frontend-id = "61" (n59,r61)
> /local/domain/59/backend/vif/61/0/online = "1" (n59,r61)
> /local/domain/59/backend/vif/61/0/state = "2" (n59,r61)
> /local/domain/59/backend/vif/61/0/script = "/etc/xen/scripts/vif-route-qubes" (n59,r61)
> /local/domain/59/backend/vif/61/0/mac = "00:16:3e:5e:6c:00" (n59,r61)
> /local/domain/59/backend/vif/61/0/ip = "10.137.0.19 fd09:24ef:4179::a89:13" (n59,r61)
> /local/domain/59/backend/vif/61/0/bridge = "xenbr0" (n59,r61)
> /local/domain/59/backend/vif/61/0/handle = "0" (n59,r61)
> /local/domain/59/backend/vif/61/0/type = "vif" (n59,r61)
> /local/domain/59/backend/vif/61/0/hotplug-status = "connected" (n59,r61)
> /local/domain/59/backend/vif/61/0/feature-sg = "1" (n59,r61)
> /local/domain/59/backend/vif/61/0/feature-gso-tcpv4 = "1" (n59,r61)
> /local/domain/59/backend/vif/61/0/feature-gso-tcpv6 = "1" (n59,r61)
> /local/domain/59/backend/vif/61/0/feature-ipv6-csum-offload = "1" (n59,r61)
> /local/domain/59/backend/vif/61/0/feature-rx-copy = "1" (n59,r61)
> /local/domain/59/backend/vif/61/0/feature-xdp-headroom = "1" (n59,r61)
> /local/domain/59/backend/vif/61/0/feature-rx-flip = "0" (n59,r61)
> /local/domain/59/backend/vif/61/0/feature-multicast-control = "1" (n59,r61)
> /local/domain/59/backend/vif/61/0/feature-dynamic-multicast-control = "1" (n59,r61)
> /local/domain/59/backend/vif/61/0/feature-split-event-channels = "1" (n59,r61)
> /local/domain/59/backend/vif/61/0/multi-queue-max-queues = "2" (n59,r61)
> /local/domain/59/backend/vif/61/0/feature-ctrl-ring = "1" (n59,r61)
>
> So, from what I see, the attach happens quite early in practice -
> during, or even before loading xen-netfront module. But then, the device
> is misinterpreted as a stale one.
>
> This does not happen every time, only sometimes. I guess it's related to
> the timing of the network-attach call.
>
> I'll try to add some more logging (especially what state it got from
> xenstore vs what it expected), but maybe you have some ideas already?
It considers initial attach a reset because backend-id from xenstore
doesn't match dev->otherend_id (which is 0 at this point). My guess is
that another xenstore watch triggers xenbus_dev_changed() before
xenbus_read_otherend_details() gets called to fill dev->otherend_id.
Maybe the dev->otherend_id check should be conditional on
dev->otherend != NULL?
--
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]
^ permalink raw reply [flat|nested] 2+ messages in thread
end of thread, other threads:[~2026-07-31 22:20 UTC | newest]
Thread overview: 2+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2026-07-30 14:03 xenwatch thread deadlock after dynamic network attach Marek Marczykowski-Górecki
2026-07-31 22:20 ` Marek Marczykowski-Górecki
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.