[ovs-dev] [PATCH] datapath: remove flow member from struct ovs_skb_cb

Joe Stringer joestringer at nicira.com
Wed Aug 27 06:43:32 UTC 2014 

I've been having a bit of trouble with ovs after this patch was applied,
ovs-vswitchd locks up on Debian 7.6 (VBox VM). Kernel is 3.2.0-4-amd64 #1
SMP Debian 3.2.60-1+deb7u3 x86_64 GNU/Linux.

I have a fairly typical phy bridge + int bridge setup, with dhclient
running on br-int:

# ovs-vsctl show
a9624cfa-2ae8-42ee-9275-3f5b022d09a5
    Bridge "breth0"
        Port "breth0+"
            Interface "breth0+"
                type: patch
                options: {peer="breth0-"}
        Port "eth0"
            Interface "eth0"
        Port "breth0"
            Interface "breth0"
                type: internal
    Bridge br-int
        Port br-int
            Interface br-int
                type: internal
        Port "breth0-"
            Interface "breth0-"
                type: patch
                options: {peer="breth0+"}
    ovs_version: "2.3.90"

>From one terminal, I send a bunch of traffic to a neighbour:
# ovs-appctl upcall/disable-megaflows && hping3 --flood 10.0.2.2

>From another terminal, I observe the upcall output:
# watch -n 0.2 'ovs-appctl upcall/show'

After 10-20 seconds, the output in the second terminal freezes. Around 2-5
minutes later, dmesg starts complaining about blocked threads:

[9957.804271] openvswitch: Open vSwitch switching datapath 2.3.90, built
Aug 27 2014 14:15:14
[10088.874770] device ovs-system entered promiscuous mode
[10088.883911] openvswitch: netlink: Key attribute has unexpected length
(type=21, length=8, expected=4).
[10088.913387] device br-int entered promiscuous mode
[10088.917780] device eth0 entered promiscuous mode
[10088.946122] device breth0 entered promiscuous mode
[10117.536276] ADDRCONF(NETDEV_UP): eth0: link is not ready
[10117.576174] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow
Control: RX
[10117.576174] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[10127.808269] eth0: no IPv6 routers present
[10131.104185] br-int: no IPv6 routers present
[10133.976474] breth0: no IPv6 routers present
[10321.389028] INFO: task ovs-vswitchd:7073 blocked for more than 120
seconds.
[10321.389028] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[10321.389028] ovs-vswitchd    D ffff88011fc13780     0  7073      1
0x00000000
[10321.389028]  ffff8800c398e800 0000000000000082 0000000300000246
ffff8801178610c0
[10321.389028]  0000000000013780 ffff8800ca8bffd8 ffff8800ca8bffd8
ffff8800c398e800
[10321.389028]  ffff8800c398e800 0000000000000000 00000000ffffffff
ffffffff8165c0f0
[10321.389028] Call Trace:
[10321.389028]  [<ffffffff8134fa44>] ? __mutex_lock_common.isra.5+0xff/0x164
[10321.389028]  [<ffffffff8134f932>] ? mutex_lock+0x1a/0x2d
[10321.389028]  [<ffffffff812af40c>] ? netlink_trim+0x13/0x7a
[10321.389028]  [<ffffffff812b1178>] ? genl_rcv+0xe/0x28
[10321.389028]  [<ffffffff812b0929>] ? netlink_unicast+0xe6/0x14e
[10321.389028]  [<ffffffff812b0c05>] ? netlink_sendmsg+0x274/0x2ac
[10321.389028]  [<ffffffff81280011>] ? sock_sendmsg+0xc1/0xde
[10321.389028]  [<ffffffff8127fef0>] ? sock_recvmsg+0xcd/0xec
[10321.389028]  [<ffffffff8110cdbf>] ? file_update_time+0x30/0x105
[10321.389028]  [<ffffffff81036628>] ? should_resched+0x5/0x23
[10321.389028]  [<ffffffff8134f144>] ? _cond_resched+0x7/0x1c
[10321.389028]  [<ffffffff812894a8>] ? copy_from_user+0x18/0x30
[10321.389028]  [<ffffffff81036628>] ? should_resched+0x5/0x23
[10321.389028]  [<ffffffff812802c7>] ? ___sys_sendmsg+0x209/0x2a9
[10321.389028]  [<ffffffff81037f8b>] ? __wake_up+0x35/0x46
[10321.389028]  [<ffffffff8135049f>] ? _raw_spin_unlock_irqrestore+0xe/0xf
[10321.389028]  [<ffffffff812afe3d>] ? netlink_insert+0x109/0x130
[10321.389028]  [<ffffffff81036628>] ? should_resched+0x5/0x23
[10321.389028]  [<ffffffff8134f144>] ? _cond_resched+0x7/0x1c
[10321.389028]  [<ffffffff8128171e>] ? sys_getsockname+0x8e/0xb7
[10321.389028]  [<ffffffff810fc0b3>] ? fget_light+0x67/0x7b
[10321.389028]  [<ffffffff81281c37>] ? __sys_sendmsg+0x39/0x58
[10321.389028]  [<ffffffff81355452>] ? system_call_fastpath+0x16/0x1b
[10321.389028] INFO: task handler10:7112 blocked for more than 120 seconds.
[10321.389028] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[10321.389028] handler10       D ffff8800d2c59800     0  7112      1
0x00000000
[10321.389028]  ffff8800d2c59800 0000000000000082 0000000000000000
ffff880118292800
[10321.389028]  0000000000013780 ffff8800d0f73fd8 ffff8800d0f73fd8
ffff8800d2c59800
[10321.389028]  ffffffff8103661f 0000000000000010 0000000000000246
ffffffff8165c0f0
[10321.389028] Call Trace:
[10321.389028]  [<ffffffff8103661f>] ? need_resched+0x14/0x18
[10321.389028]  [<ffffffff8134fa44>] ? __mutex_lock_common.isra.5+0xff/0x164
[10321.389028]  [<ffffffff8134f932>] ? mutex_lock+0x1a/0x2d
[10321.389028]  [<ffffffff812af40c>] ? netlink_trim+0x13/0x7a
[10321.389028]  [<ffffffff812b1178>] ? genl_rcv+0xe/0x28
[10321.389028]  [<ffffffff812b0929>] ? netlink_unicast+0xe6/0x14e
[10321.389028]  [<ffffffff812b1192>] ? genl_rcv+0x28/0x28
[10321.389028]  [<ffffffff812b0e0f>] ? netlink_rcv_skb+0x53/0x7a
[10321.389028]  [<ffffffff812b1189>] ? genl_rcv+0x1f/0x28
[10321.389028]  [<ffffffff812b0929>] ? netlink_unicast+0xe6/0x14e
[10321.389028]  [<ffffffff812b0c05>] ? netlink_sendmsg+0x274/0x2ac
[10321.389028]  [<ffffffff81280011>] ? sock_sendmsg+0xc1/0xde
[10321.389028]  [<ffffffff8134f144>] ? _cond_resched+0x7/0x1c
[10321.389028]  [<ffffffff810be188>] ? update_page_reclaim_stat+0x17/0x44
[10321.389028]  [<ffffffff812833dc>] ? sock_kmalloc+0x41/0x63
[10321.389028]  [<ffffffff812833dc>] ? sock_kmalloc+0x41/0x63
[10321.389028]  [<ffffffff810ecd8f>] ? __kmalloc+0x100/0x112
[10321.389028]  [<ffffffff81036628>] ? should_resched+0x5/0x23
[10321.389028]  [<ffffffff8134f144>] ? _cond_resched+0x7/0x1c
[10321.389028]  [<ffffffff812894a8>] ? copy_from_user+0x18/0x30
[10321.389028]  [<ffffffff812802c7>] ? ___sys_sendmsg+0x209/0x2a9
[10321.389028]  [<ffffffff810ceb49>] ? pte_offset_kernel+0x16/0x35
[10321.389028]  [<ffffffff813533d8>] ? do_page_fault+0x30a/0x345
[10321.389028]  [<ffffffff8135049f>] ? _raw_spin_unlock_irqrestore+0xe/0xf
[10321.389028]  [<ffffffff8112a6db>] ? ep_scan_ready_list.isra.7+0x13b/0x15b
[10321.389028]  [<ffffffff8100d750>] ? __switch_to+0x1e5/0x258
[10321.389028]  [<ffffffff8112b2b6>] ? sys_epoll_wait+0x29f/0x308
[10321.389028]  [<ffffffff81039a92>] ? finish_task_switch+0x4e/0xb9
[10321.389028]  [<ffffffff810fc0b3>] ? fget_light+0x67/0x7b
[10321.389028]  [<ffffffff81281c37>] ? __sys_sendmsg+0x39/0x58
[10321.389028]  [<ffffffff81355452>] ? system_call_fastpath+0x16/0x1b
[10321.389028] INFO: task handler12:7113 blocked for more than 120 seconds.
[10321.389028] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[10321.389028] handler12       D ffff88011fc93780     0  7113      1
0x00000000
[10321.389028]  ffff8800c3a1d080 0000000000000082 dead000000000000
ffff88011aeb0180
[10321.389028]  0000000000013780 ffff8800dba07fd8 ffff8800dba07fd8
ffff8800c3a1d080
[10321.389028]  ffff8800ca807b98 00000001ca807b48 0000000000000041
ffffffff8165c0f0
[10321.389028] Call Trace:
[10321.389028]  [<ffffffff8134fa44>] ? __mutex_lock_common.isra.5+0xff/0x164
[10321.389028]  [<ffffffff8134f932>] ? mutex_lock+0x1a/0x2d
[10321.389028]  [<ffffffff812af40c>] ? netlink_trim+0x13/0x7a
[10321.389028]  [<ffffffff812b1178>] ? genl_rcv+0xe/0x28
[10321.389028]  [<ffffffff812b0929>] ? netlink_unicast+0xe6/0x14e
[10321.389028]  [<ffffffff812b0c05>] ? netlink_sendmsg+0x274/0x2ac
[10321.389028]  [<ffffffff81280011>] ? sock_sendmsg+0xc1/0xde
[10321.389028]  [<ffffffff81108b29>] ? __pollwait+0xce/0xce
[10321.389028]  [<ffffffff8107116d>] ? arch_local_irq_save+0x11/0x17
[10321.389028]  [<ffffffff8135049f>] ? _raw_spin_unlock_irqrestore+0xe/0xf
[10321.389028]  [<ffffffff8112a7c8>] ? ep_poll_callback+0xbf/0xdb
[10321.389028]  [<ffffffff81036628>] ? should_resched+0x5/0x23
[10321.389028]  [<ffffffff8134f144>] ? _cond_resched+0x7/0x1c
[10321.389028]  [<ffffffff812894a8>] ? copy_from_user+0x18/0x30
[10321.389028]  [<ffffffff81036628>] ? should_resched+0x5/0x23
[10321.389028]  [<ffffffff812802c7>] ? ___sys_sendmsg+0x209/0x2a9
[10321.389028]  [<ffffffff810ceb49>] ? pte_offset_kernel+0x16/0x35
[10321.389028]  [<ffffffff813533d8>] ? do_page_fault+0x30a/0x345
[10321.389028]  [<ffffffff81036628>] ? should_resched+0x5/0x23
[10321.389028]  [<ffffffff8134f144>] ? _cond_resched+0x7/0x1c
[10321.389028]  [<ffffffff8128171e>] ? sys_getsockname+0x8e/0xb7
[10321.389028]  [<ffffffff810fc0b3>] ? fget_light+0x67/0x7b
[10321.389028]  [<ffffffff81281c37>] ? __sys_sendmsg+0x39/0x58
[10321.389028]  [<ffffffff81355452>] ? system_call_fastpath+0x16/0x1b
[10321.389028] INFO: task revalidator13:7114 blocked for more than 120
seconds.
[10321.389028] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[10321.389028] revalidator13   D ffff88011fd13780     0  7114      1
0x00000000
[10321.389028]  ffff8800cabf2040 0000000000000082 0000000000000000
ffff88011aec4780
[10321.389028]  0000000000013780 ffff8800db83ffd8 ffff8800db83ffd8
ffff8800cabf2040
[10321.389028]  ffffffff8165c0f0 00000001ffffff10 ffffffff81040480
ffffffff8165c0f0
[10321.389028] Call Trace:
[10321.389028]  [<ffffffff81040480>] ? mutex_spin_on_owner+0x24/0x39
[10321.389028]  [<ffffffff8134fa44>] ? __mutex_lock_common.isra.5+0xff/0x164
[10321.389028]  [<ffffffff8134f932>] ? mutex_lock+0x1a/0x2d
[10321.389028]  [<ffffffff812af40c>] ? netlink_trim+0x13/0x7a
[10321.389028]  [<ffffffff812b1178>] ? genl_rcv+0xe/0x28
[10321.389028]  [<ffffffff812b0929>] ? netlink_unicast+0xe6/0x14e
[10321.389028]  [<ffffffff812b0c05>] ? netlink_sendmsg+0x274/0x2ac
[10321.389028]  [<ffffffff81280011>] ? sock_sendmsg+0xc1/0xde
[10321.389028]  [<ffffffff8103f6d2>] ? try_to_wake_up+0x187/0x197
[10321.389028]  [<ffffffff8106d63a>] ? wake_futex+0x5d/0x69
[10321.389028]  [<ffffffff8106d5ce>] ? put_task_struct+0xd/0x1c
[10321.389028]  [<ffffffff8106e397>] ? futex_wake+0xe9/0xfb
[10321.389028]  [<ffffffff810fc0b3>] ? fget_light+0x67/0x7b
[10321.389028]  [<ffffffff812818f8>] ? sys_sendto+0xf7/0x137
[10321.389028]  [<ffffffff8106fcef>] ? sys_futex+0x120/0x151
[10321.389028]  [<ffffffff81066311>] ? timekeeping_get_ns+0xd/0x2a
[10321.389028]  [<ffffffff810667ff>] ? ktime_get_ts+0x5c/0x82
[10321.389028]  [<ffffffff81036628>] ? should_resched+0x5/0x23
[10321.389028]  [<ffffffff81355452>] ? system_call_fastpath+0x16/0x1b
[10327.256206] br-int: no IPv6 routers present

These repeat every 120 seconds, and I can no longer kill ovs-vswitchd or
unload the ovs kmod.

Reverting this patch seems to fix the issue. I tried some basic things
(like shifting the sf_acts dereference within the disable_bh() section),
but I can't figure out what's wrong. Perhaps some odd interaction with this
particular kernel?

For completeness, there are often some other pieces in dmesg that might be
relevant (but these are shown when I revert the patch, too):

[  646.800101] ------------[ cut here ]------------
[  646.800101] WARNING: at
/build/linux-eKuxrT/linux-3.2.60/net/sched/sch_generic.c:256
dev_watchdog+0xf2/0x151()
[  646.800101] Hardware name: VirtualBox
[  646.800101] NETDEV WATCHDOG: eth0 (e1000): transmit queue 0 timed out
[  646.800101] Modules linked in: openvswitch(O) ip6table_filter ip6_tables
iptable_filter ip_tables ebtable_nat ebtables x_tables ppdev lp rfcomm bnep
bluetooth rfkill vboxsf(O) binfmt_misc uinput deflate zlib_deflate ctr t
wofish_generic twofish_x86_64_3way twofish_x86_64 twofish_common camellia
serpent blowfish_generic blowfish_x86_64 blowfish_common cast5 des_generic
cbc cryptd aes_x86_64 aes_generic xcbc rmd160 sha512_generic sha256_generic
 sha1_ssse3 sha1_generic hmac crypto_null af_key nfsd nfs nfs_acl
auth_rpcgss fscache lockd sunrpc gre crc32c libcrc32c loop snd_intel8x0
snd_ac97_codec snd_pcm psmouse joydev serio_raw pcspkr ac evdev parport_pc
vboxvideo(O
) snd_page_alloc battery drm snd_seq snd_seq_device i2c_piix4 parport
power_supply snd_timer i2c_core snd soundcore processor ac97_bus
vboxguest(O) button thermal_sys ext4 crc16 jbd2 mbcache dm_mod usbhid hid
sg sr_mod cdrom
 sd_mod crc_t10dif ata_generic ata_piix ahci libahci libata ohci_hcd
ehci_hcd usbcore scsi_mod e1000 usb_common [last unloaded: openvswitch]
[  646.800139] Pid: 5917, comm: hping3 Tainted: G           O 3.2.0-4-amd64
#1 Debian 3.2.60-1+deb7u3
[  646.800153] Call Trace:
[  646.800159]  <IRQ>  [<ffffffff81046cd9>] ? warn_slowpath_common+0x78/0x8c
[  646.800173]  [<ffffffff81046d85>] ? warn_slowpath_fmt+0x45/0x4a
[  646.800181]  [<ffffffff8103a340>] ? sched_slice.isra.106+0x69/0x78
[  646.800190]  [<ffffffff812a8169>] ? netif_tx_lock+0x40/0x75
[  646.800203]  [<ffffffff812a82d9>] ? dev_watchdog+0xf2/0x151
[  646.800211]  [<ffffffff810524f8>] ? run_timer_softirq+0x19a/0x261
[  646.800219]  [<ffffffff812a81e7>] ? netif_tx_unlock+0x49/0x49
[  646.800226]  [<ffffffff81066311>] ? timekeeping_get_ns+0xd/0x2a
[  646.800233]  [<ffffffff8104c36e>] ? __do_softirq+0xb9/0x177
[  646.800241]  [<ffffffff813576ac>] ? call_softirq+0x1c/0x30
[  646.800250]  [<ffffffff8100fa21>] ? do_softirq+0x3c/0x7b
[  646.800257]  [<ffffffff8104c5d6>] ? irq_exit+0x3c/0x99
[  646.800265]  [<ffffffff81024324>] ? smp_apic_timer_interrupt+0x74/0x82
[  646.800273]  [<ffffffff81355f1e>] ? apic_timer_interrupt+0x6e/0x80
[  646.800278]  <EOI>  [<ffffffff8104a93a>] ? spin_unlock_irq+0xa/0xb
[  646.800287]  [<ffffffff8104af20>] ? do_setitimer+0x1cd/0x1fd
[  646.800294]  [<ffffffff8104af84>] ? alarm_setitimer+0x34/0x62
[  646.800302]  [<ffffffff81052cf6>] ? sys_alarm+0x6/0xa
[  646.800309]  [<ffffffff81355452>] ? system_call_fastpath+0x16/0x1b
[  646.800315] ---[ end trace 6c797ed5347670e1 ]---
[  646.860656] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow
Control: RX
[  653.670376] openvswitch: netlink: Invalid IPv6 flow label value
(value=ffffffff, max=fffff).

On 26 August 2014 12:59, Pravin Shelar <pshelar at nicira.com> wrote:

> On Thu, Aug 21, 2014 at 10:25 AM, Lorand Jakab <lojakab at cisco.com> wrote:
> > struct ovs_skb_cb is full on kernels < 3.11 due to compatibility code.
> > This patch removes the 'flow' member in order to make room for data
> > needed by layer 3 flow/port support that will be added in an upcoming
> > patch.  The 'flow' memeber was chosen for removal because it's only used
> > in ovs_execute_actions().
> >
> > Signed-off-by: Lorand Jakab <lojakab at cisco.com>
>
> Thanks, I pushed it to master.
> _______________________________________________
> dev mailing list
> dev at openvswitch.org
> http://openvswitch.org/mailman/listinfo/dev
>

More information about the dev mailing list