0

During my Vagrant Up process, many tasks run in succession and all does work, however at the end I have a validation test that stalls. The only way I can end the stall is logging into the machine manually from another terminal vagrant ssh

Here is what my syslog looks like:

Feb  1 11:27:34 core NetworkManager[10531]: <info>  [1612207654.4568] manager: (b.17.1): new Generic device (/org/freedesktop/NetworkManager/Devices/13)
Feb  1 11:27:34 core ovs-vsctl: ovs|00001|vsctl|INFO|Called as /bin/ovs-vsctl set bridge b.17.1 stp_enable=false
Feb  1 11:27:34 core ovs-vsctl: ovs|00001|vsctl|INFO|Called as /bin/ovs-vsctl set bridge b.17.1 other_config:stp-max-age=6
Feb  1 11:27:34 core ovs-vsctl: ovs|00001|vsctl|INFO|Called as /bin/ovs-vsctl set bridge b.17.1 other_config:stp-forward-delay=4
Feb  1 11:27:34 core NetworkManager[10531]: <info>  [1612207654.5000] device (b.17.1): carrier: link connected
Feb  1 11:27:34 core ovs-vsctl: ovs|00001|vsctl|INFO|Called as /bin/ovs-vsctl set bridge b.17.1 other_config:mac-aging-time=0
Feb  1 11:27:34 core NetworkManager[10531]: <info>  [1612207654.5309] manager: (veth12.0.1p): new Veth device (/org/freedesktop/NetworkManager/Devices/14)
Feb  1 11:27:34 core kernel: IPv6: ADDRCONF(NETDEV_UP): veth12.0.1: link is not ready
Feb  1 11:27:34 core NetworkManager[10531]: <info>  [1612207654.5316] manager: (veth12.0.1): new Veth device (/org/freedesktop/NetworkManager/Devices/15)
Feb  1 11:34:26 core kernel: INFO: rcu_sched self-detected stall on CPU { 0}  (t=411593 jiffies g=41923 c=41922 q=208)
Feb  1 11:34:26 core kernel: INFO: rcu_sched self-detected stall on CPU { 1}  (t=411593 jiffies g=41923 c=41922 q=208)
Feb  1 11:34:26 core kernel: Task dump for CPU 0:
Feb  1 11:34:26 core kernel: swapper/0       R  running task        0     0      0 0x00000000
Feb  1 11:34:26 core kernel: Call Trace:
Feb  1 11:34:26 core kernel: [<ffffffffa5988c60>] ? __cpuidle_text_start+0x8/0x8
Feb  1 11:34:26 core kernel: [<ffffffffa5988eab>] ? native_safe_halt+0xb/0x20
Feb  1 11:34:26 core kernel: [<ffffffffa5988c7e>] ? default_idle+0x1e/0xc0
Feb  1 11:34:26 core kernel: [<ffffffffa5237ca0>] ? arch_cpu_idle+0x20/0xc0
Feb  1 11:34:26 core kernel: [<ffffffffa530148a>] ? cpu_startup_entry+0x14a/0x1e0
Feb  1 11:34:26 core kernel: [<ffffffffa596f637>] ? rest_init+0x77/0x80
Feb  1 11:34:26 core kernel: [<ffffffffa5f8b1cf>] ? start_kernel+0x44b/0x46c
Feb  1 11:34:26 core kernel: [<ffffffffa5f8ab84>] ? repair_env_string+0x5c/0x5c
Feb  1 11:34:26 core kernel: [<ffffffffa5f8a120>] ? early_idt_handler_array+0x120/0x120
Feb  1 11:34:26 core kernel: [<ffffffffa5f8a738>] ? x86_64_start_reservations+0x24/0x26
Feb  1 11:34:26 core kernel: [<ffffffffa5f8a88e>] ? x86_64_start_kernel+0x154/0x177
Feb  1 11:34:26 core kernel: [<ffffffffa52000d5>] ? start_cpu+0x5/0x14
Feb  1 11:34:26 core kernel: Task dump for CPU 1:
Feb  1 11:34:26 core kernel: systemd-udevd   R  running task        0 15106    518 0x00000080
Feb  1 11:34:26 core kernel: Call Trace:
Feb  1 11:34:26 core kernel: <IRQ>  [<ffffffffa52da318>] sched_show_task+0xa8/0x110
Feb  1 11:34:26 core kernel: [<ffffffffa52de159>] dump_cpu_task+0x39/0x70
Feb  1 11:34:26 core kernel: [<ffffffffa5358480>] rcu_dump_cpu_stacks+0x90/0xd0
Feb  1 11:34:26 core kernel: [<ffffffffa535bb42>] rcu_check_callbacks+0x442/0x730
Feb  1 11:34:26 core kernel: [<ffffffffa5310370>] ? tick_sched_do_timer+0x50/0x50
Feb  1 11:34:26 core kernel: [<ffffffffa52af186>] update_process_times+0x46/0x80
Feb  1 11:34:26 core kernel: [<ffffffffa53100e0>] tick_sched_handle+0x30/0x70
Feb  1 11:34:26 core kernel: [<ffffffffa53103a9>] tick_sched_timer+0x39/0x80
Feb  1 11:34:26 core kernel: [<ffffffffa52ca26e>] __hrtimer_run_queues+0x10e/0x270
Feb  1 11:34:26 core kernel: [<ffffffffa52ca7cf>] hrtimer_interrupt+0xaf/0x1d0
Feb  1 11:34:26 core kernel: [<ffffffffa525cdfb>] local_apic_timer_interrupt+0x3b/0x60
Feb  1 11:34:26 core kernel: [<ffffffffa5998a83>] smp_apic_timer_interrupt+0x43/0x60
Feb  1 11:34:26 core kernel: [<ffffffffa5994fba>] apic_timer_interrupt+0x16a/0x170

Notice the time jump between 11:27 and 11:34 -- this is the time gap between running vagrant up in one terminal and running vagrant ssh in another.

The syslog include a dump for the CPU, it's possible there is some halting happening.

Lastly, I don't think this has anything to do with my validation tests. The tests resume fine after I log in and according to the syslog, literally nothing is happening between 11:27 and 11:34.

  • Running Vagrant 2.2.14 on Windows 10
  • VM is RHEL is 7.9
  • VirtualBox 6.1.16

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.