[SRU] ovs-vswitchd crashed with SIGSEGV in nl_attr_get_size()

Status changed to 'Confirmed' because the bug affects multiple users.

Same here:
Ubuntu 14.04 64bit
openvswitch 2.0.1+git20140120-0ubuntu2
ovs-vsctl (Open vSwitch) 2.0.1
Compiled Feb 23 2014 14:42:32

Running network node for OpenStack

Hi,

Is there a way I can get a core from this process? I suppose that leaving ulimit -c unlimited is not enough. And I don't know where it will be left. But I can try.

To make it happen more ofter, is needed a lot of transfer connections through the network node. I have GB eth with two interfaces on each host to make it happen. But only 4-5 vmachines on the cloud.

Do you have anything in /var/crash?

Hi Nooope, I had to restart the computer and I think I don't have it. It didn't hapened for a while.

Hi,

I have the same problem. There is just one difference: I'm using ubuntu 12.04 with linux kernel 3.13.

When the crash happens I can no longer access virtual machines. If I restart neutron-plugin-openvswitch-switch the communication to vms is restored.

ProblemType: Crash
Architecture: amd64
CrashCounter: 1
Date: Wed Aug 6 21:19:18 2014
DistroRelease: Ubuntu 12.04
ExecutablePath: /usr/sbin/ovs-vswitchd
ExecutableTimestamp: 1397658071
ProcCmdline: ovs-vswitchd unix:/var/run/openvswitch/db.sock -vconsole:emer -vsyslog:err -vfile:info --mlockall --no-chdir --log-file=/var/log/openvswitch/ovs-vswitchd.log --pidfile=/var/run/openvswitch/ovs-vswitchd.pid --detach --monitor
ProcCwd: /
ProcEnviron:
 TERM=linux
 PATH=(custom, no user)
ProcMaps:
 00400000-00535000 r-xp 00000000 08:01 174237 /usr/sbin/ovs-vswitchd
...
ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0 [vsyscall]
ProcStatus:
 Name: ovs-vswitchd
 State: S (sleeping)
 Tgid: 1413
 Ngid: 0
 Pid: 1413
 PPid: 1412
 TracerPid: 0
 Uid: 0 0 0 0
 Gid: 0 0 0 0
 FDSize: 64
 Groups:
 VmPeak: 236840 kB
 VmSize: 171984 kB
 VmLck: 171976 kB
 VmPin: 0 kB
 VmHWM: 32396 kB
 VmRSS: 32396 kB
 VmData: 148604 kB
 VmStk: 252 kB
 VmExe: 1236 kB
 VmLib: 5176 kB
 VmPTE: 124 kB
 VmSwap: 0 kB
 Threads: 3
 SigQ: 6/7775
 SigPnd: 0000000000000000
 ShdPnd: 0000000000000000
 SigBlk: 0000000000000000
 SigIgn: 0000000000001000
 SigCgt: 0000000180016003
 CapInh: 0000000000000000
 CapPrm: 0000001fffffffff
 CapEff: 0000001fffffffff
 CapBnd: 0000001fffffffff
 Seccomp: 0
 Cpus_allowed: 3
 Cpus_allowed_list: 0-1
 Mems_allowed: 00000000,00000001
 Mems_allowed_list: 0
 voluntary_ctxt_switches: 324391
 nonvoluntary_ctxt_switches: 45330
Signal: 11
Uname: Linux 3.13.0-32-generic x86_64
UserGroups:

After updating kernel in ubuntu 14.04 I found this again. But this time with kernel panic.

ct 12 00:56:30 red-compute kernel: [ 2139.850867] ovs-vswitchd[19280]: segfault at 0 ip 0000000000459340 sp 00007fff2d88c3e8 error 4 in ovs-vswitchd[400000+133000]
Oct 12 00:56:31 red-compute ovs-vswitchd: ovs|00010|daemon(monitor)|ERR|7 crashes: pid 19280 died, killed (Segmentation fault), core dumped, restarting
Oct 12 00:57:01 red-compute CRON[19736]: (root) CMD (if [ -x /usr/share/mdadm/checkarray ] && [ $(date +%d) -le 7 ]; then /usr/share/mdadm/checkarray --cron --all --idle --quiet; fi)
Oct 12 00:58:28 red-compute ovsdb-client: ovs|00001|fatal_signal|WARN|terminating with signal 15 (Terminated)
Oct 12 00:58:34 red-compute kernel: [ 2264.419340] init: neutron-plugin-openvswitch-agent main process (14411) killed by KILL signal
Oct 12 00:58:56 red-compute kernel: [ 2286.159789] INFO: task jbd2/rbd1-8:10184 blocked for more than 120 seconds.
Oct 12 00:58:56 red-compute kernel: [ 2286.159802] Tainted: P W OX 3.13.0-37-generic #64-Ubuntu
Oct 12 00:58:56 red-compute kernel: [ 2286.159807] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Oct 12 00:58:56 red-compute kernel: [ 2286.159812] jbd2/rbd1-8 D ffff88032fc54480 0 10184 2 0x00000000
Oct 12 00:58:56 red-compute kernel: [ 2286.159822] ffff88029baadbc8 0000000000000046 ffff8802d1ac8000 ffff88029baadfd8
Oct 12 00:58:56 red-compute kernel: [ 2286.159832] 0000000000014480 0000000000014480 ffff8802d1ac8000 ffff88032fc54d18
Oct 12 00:58:56 red-compute kernel: [ 2286.159840] ffff88032ffb1020 0000000000000002 ffffffff811ee820 ffff88029baadc40
Oct 12 00:58:56 red-compute kernel: [ 2286.159847] Call Trace:
Oct 12 00:58:56 red-compute kernel: [ 2286.159864] [<ffffffff811ee820>] ? generic_block_bmap+0x50/0x50
Oct 12 00:58:56 red-compute kernel: [ 2286.159875] [<ffffffff8172344d>] io_schedule+0x9d/0x140
Oct 12 00:58:56 red-compute kernel: [ 2286.159884] [<ffffffff811ee82e>] sleep_on_buffer+0xe/0x20
Oct 12 00:58:56 red-compute kernel: [ 2286.159892] [<ffffffff817238d2>] __wait_on_bit+0x62/0x90
Oct 12 00:58:56 red-compute kernel: [ 2286.159899] [<ffffffff811ee820>] ? generic_block_bmap+0x50/0x50
Oct 12 00:58:56 red-compute kernel: [ 2286.159907] [<ffffffff81723977>] out_of_line_wait_on_bit+0x77/0x90
Oct 12 00:58:56 red-compute kernel: [ 2286.159916] [<ffffffff810ab010>] ? autoremove_wake_function+0x40/0x40
Oct 12 00:58:56 red-compute kernel: [ 2286.159924] [<ffffffff811efb5a>] __wait_on_buffer+0x2a/0x30
Oct 12 00:58:56 red-compute kernel: [ 2286.159933] [<ffffffff812888f0>] jbd2_journal_commit_transaction+0xee0/0x1a70
Oct 12 00:58:56 red-compute kernel: [ 2286.159943] [<ffffffff810754ff>] ? try_to_del_timer_sync+0x4f/0x70
Oct 12 00:58:56 red-compute kernel: [ 2286.159951] [<ffffffff8128d4ad>] kjournald2+0xbd/0x250
Oct 12 00:58:56 red-compute kernel: [ 2286.159959] [<ffffffff810aafd0>] ? prepare_to_wait_event+0x100/0x100
Oct 12 00:58:56 red-compute kernel: [ 2286.159967] [<ffffffff8128d3f0>] ? commit_timeout+0x10/0x10
Oct 12 00:58:56 red-compute kernel: [ 2286.159974] [<ffffffff8108b492>] kthread+0xd2/0xf0
Oct 12 00:58:56 red-compute kernel: [ 2...

ovs-vsctl (Open vSwitch) 2.0.2
Compiled Aug 15 2014 14:31:02

I did:
apport-collect 1336555
Package openvswitch not installed and no hook available, ignoring

But no luck.

I'm still seeing the problem with new kernels. It breaks my ceph installation badly.

[1368555.197934] ------------[ cut here ]------------
[1368555.197945] WARNING: CPU: 3 PID: 4400 at /build/buildd/linux-3.13.0/fs/proc/generic.c:511 remove_proc_entry+0x139/0x1b0()
[1368555.197947] name 'fs/nfsfs'
[1368555.197949] Modules linked in: gspca_ov534 nls_iso8859_1 usb_storage xt_TCPMSS xt_tcpmss arc4 ppp_mppe ppp_async crc_ccitt vhost_net vhost macvtap macvlan nf_conntrack_ipv6 nf_defrag_ipv6 xt_mac xt_physdev xt_multiport pci_stub vboxpci(OX) vboxnetadp(OX) vboxnetflt(OX) vboxdrv(OX) xt_conntrack ipt_REJECT veth ip6table_filter ip6_tables ebtable_nat ebtables xt_CHECKSUM iptable_mangle ipt_MASQUERADE iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack xt_tcpudp bridge stp llc iptable_filter ip_tables x_tables nbd ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi rfcomm rbd libceph openvswitch gre vxlan ip_tunnel binfmt_misc nfsd auth_rpcgss nfs_acl nfs lockd sunrpc fscache dm_crypt xfs snd_usb_audio snd_usbmidi_lib fglrx(POX) kvm_amd kvm gspca_main videodev wacom serio_raw dm_multipath scsi_dh joydev edac_core edac_mce_amd k10temp snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_intel btusb snd_hda_codec snd_hwdep snd_pcm bluetooth snd_page_alloc snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device snd_timer snd soundcore sp5100_tco amd_iommu_v2 i2c_piix4 asus_atk0110 mac_hid parport_pc ppdev lp parport btrfs libcrc32c raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq raid1 raid0 multipath linear dm_mirror dm_region_hash dm_log hid_generic hid_logitech_dj usbhid hid pata_acpi psmouse pata_atiixp ahci e1000e pata_marvell libahci firewire_ohci ptp firewire_core pps_core r8169 crc_itu_t mii floppy wmi [last unloaded: gspca_ov534]
[1368555.198044] CPU: 3 PID: 4400 Comm: kworker/u12:1 Tainted: P W OX 3.13.0-37-generic #64-Ubuntu
[1368555.198046] Hardware name: System manufacturer System Product Name/M4A79T Deluxe, BIOS 3503 05/06/2011
[1368555.198051] Workqueue: netns cleanup_net
[1368555.198053] 0000000000000009 ffff880119017c80 ffffffff8171ed09 ffff880119017cc8
[1368555.198057] ffff880119017cb8 ffffffff8106773d 0000000000000000 0000000000000005
[1368555.198060] ffffffffa06e48a8 ffff880323019ab0 0000000000000180 ffff880119017d18
[1368555.198063] Call Trace:
[1368555.198070] [<ffffffff8171ed09>] dump_stack+0x45/0x56
[1368555.198074] [<ffffffff8106773d>] warn_slowpath_common+0x7d/0xa0
[1368555.198079] [<ffffffff810677ac>] warn_slowpath_fmt+0x4c/0x50
[1368555.198084] [<ffffffff81229839>] remove_proc_entry+0x139/0x1b0
[1368555.198103] [<ffffffffa06c44e2>] nfs_fs_proc_net_exit+0x62/0x70 [nfs]
[1368555.198115] [<ffffffffa06ca5b2>] nfs_net_exit+0x12/0x20 [nfs]
[1368555.198118] [<ffffffff8161b409>] ops_exit_list.isra.1+0x39/0x60
[1368555.198122] [<ffffffff8161bc90>] cleanup_net+0x110/0x250
[1368555.198126] [<ffffffff810839c2>] process_one_work+0x182/0x450
[1368555.198130] [<ffffffff810847b1>] worker_thread+0x121/0x410
[1368555.198133] [<ffffffff81084690>] ? rescuer_thread+0x430/0x430
[1368555.198137...

I think this is probably the cause of the SIGSEGV - I've seen this same trace reported twice upstream as well.

This was generated in one of the Ubuntu QA openstack deployments.

Upstream references:

http://openvswitch.org/pipermail/discuss/2014-December/015931.html
http://openvswitch.org/pipermail/discuss/2014-October/015360.html

Plus comment from Ben (upstream developer):

"""This backtrace doesn't quite add up.

We can see from frames 4 and 3 that we've got a nonnull 'key', which
becomes a nonnull nlattr 'a' in frame 2. Along the same chain, we
have a null 'mask' that becomes a null 'ma'. I often don't trust GDB
to give me correct arguments in backtraces but all of that adds up
nicely so I tend to believe it.

Take a look at the code for format_odp_key_attr(). It always
dereferences 'a' to get its type 'attr':

    enum ovs_key_attr attr = nl_attr_type(a);

A few lines later we can see 'is_exact' getting set to true (since
'ma' is NULL):

    bool is_exact;

    is_exact = ma ? odp_mask_attr_is_exact(ma) : true;

We're evidently hitting the default case in the switch statement given
the line number cited in the backtrace, which runs this code:

    case OVS_KEY_ATTR_UNSPEC:
    case __OVS_KEY_ATTR_MAX:
    default:
        format_generic_odp_key(a, ds);
        if (!is_exact) {
            ds_put_char(ds, '/');
            format_generic_odp_key(ma, ds); <---- line 1332
        }
        break;

but that doesn't make sense--we should never get there, because
is_exact is true. So--WTF?"""

@gad

Does your installation rely on openvswitch management network connectivity for Ceph RBD access?

Its probably that the fix for bug 1352570 improved the situation (i.e. occasional rather than regular failures), but it still appears that this is the same/similar backtrace.

I've uploaded ovs 2.0.2 packages with the optimizer disabled to:

  https://launchpad.net/~james-page/+archive/ubuntu/openvswitch

It would be helpful is someone who see's this regularly could try with these packages; right now we really need to get a reliable reproducer for this problem, so that we can debug it more effectively.

Yes I use openvswitch for everything.

I tried to mix br-utils with openvswitch and gave me no goood results.

I also see alot of:

2015-01-08T13:36:07.822Z|80336|dpif|WARN|system@ovs-system: failed to flow_del (No such file or directory) skb_priority(0),in_port(4),skb_mark(0),eth(src=ae:c4:93:ba:85:3e,dst=33:33:ff:5f:c4:32),eth_type(0x86dd),ipv6(src=::,dst=ff02::1:ff5f:c432,label=0,proto=58,tclass=0,hlimit=255,frag=no),icmpv6(type=135,code=0),nd(target=fe80::8412:d1ff:fe5f:c432)
2015-01-08T13:36:08.823Z|80337|dpif|WARN|system@ovs-system: failed to flow_del (No such file or directory) skb_priority(0),in_port(4),skb_mark(0),eth(src=ae:c4:93:ba:85:3e,dst=33:33:ff:5f:c4:32),eth_type(0x86dd),ipv6(src=::,dst=ff02::1:ff5f:c432,label=0,proto=58,tclass=0,hlimit=255,frag=no),icmpv6(type=135,code=0),nd(target=fe80::8412:d1ff:fe5f:c432)
2015-01-08T13:36:09.822Z|80338|dpif|WARN|system@ovs-system: failed to flow_del (No such file or directory) skb_priority(0),in_port(4),skb_mark(0),eth(src=ae:c4:93:ba:85:3e,dst=33:33:ff:5f:c4:32),eth_type(0x86dd),ipv6(src=::,dst=ff02::1:ff5f:c432,label=0,proto=58,tclass=0,hlimit=255,frag=no),icmpv6(type=135,code=0),nd(target=fe80::8412:d1ff:fe5f:c432)
2015-01-08T13:36:10.823Z|80339|dpif|WARN|system@ovs-system: failed to flow_del (No such file or directory) skb_priority(0),in_port(4),skb_mark(0),eth(src=ae:c4:93:ba:85:3e,dst=33:33:ff:5f:c4:32),eth_type(0x86dd),ipv6(src=::,dst=ff02::1:ff5f:c432,label=0,proto=58,tclass=0,hlimit=255,frag=no),icmpv6(type=135,code=0),nd(target=fe80::8412:d1ff:fe5f:c432)
2015-01-08T13:36:11.824Z|80340|dpif|WARN|system@ovs-system: failed to flow_del (No such file or directory) skb_priority(0),in_port(4),skb_mark(0),eth(src=ae:c4:93:ba:85:3e,dst=33:33:ff:5f:c4:32),eth_type(0x86dd),ipv6(src=::,dst=ff02::1:ff5f:c432,label=0,proto=58,tclass=0,hlimit=255,frag=no),icmpv6(type=135,code=0),nd(target=fe80::8412:d1ff:fe5f:c432)

which is related to https://github.com/openvswitch/ovs/commit/3601bd879

this is not present in the 3.13 kernel in trusty. Might be 2+2 =5 but who knows.

Ubuntu kernel source for reference:

http://kernel.ubuntu.com/git?p=ubuntu/ubuntu-trusty.git;a=blob;f=net/openvswitch/datapath.c;h=654e058a6e2775f203c785583343cf6180baaacb;hb=HEAD

I am testing the unoptimized version of these and will update this bug report with any of our findings.

OK - so I managed to not disable the optimization in January - so the PPA packages where the same as in the archive.

I've now hit the packaging a bit harder with the noopt flag, and the PPA has updates which have unoptimized ovs binaries.

Apologies for any confusion caused.

After running with the unoptimized packages for a bit, we hit:

  https://github.com/openvswitch/ovs/commit/417d7a008b9f280f0e0c603cb6f2871ab75b8d49

some further discussion with upstream would indicate that this is probably the source of the original problem, but the code optimizer was concealing the actual root cause in the code.

proxied from Joe Stringer@VMware

"I wonder if this patch fixes the issue:
https://github.com/openvswitch/ovs/commit/546953509095cec6fad42663b659171618b765d2

Note that the last three lines within the bad_key_len / bad_mask_len
conditional statement are the following:

format_generic_odp_key(ma, ds);
ds_put_char(ds, ')');
return;

This is the same logic as the end of the function, where the backtrace
is reporting the callstack to be. Jarno pointed out that the compiler
could optimize out the first copy of this code to turn into a jump
instruction which jumps inside the if (!is_exact) statement. Hence the
backtrace shows this confusing callstack.

Note that this problem would only present itself if there is:
A) A mismatch between a newer kernel version and an older userspace
(OVS<2.3), where
B) The kernel has a new flow match field available which ovs-vswitchd
doesn't understand, and
C) A flow_del command fails for some reason."

It would be great if we could confirm by getting the existing build of
OVS and applying the patch above.

The testing PPA:

  https://launchpad.net/~james-page/+archive/ubuntu/openvswitch

has held this patch for a few weeks now - we're running this in our test cloud and have not seen a recurrence of the problem.

What's version with patch applied. I want to test. Latest?

Hello gadLinux, or anyone else affected,

Accepted openvswitch into trusty-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/openvswitch/2.0.2-0ubuntu0.14.04.2 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

We've had this in our main QA cloud for two weeks now - not seen a crash since it was applied.

Marking verfication-done.

This bug was fixed in the package openvswitch - 2.0.2-0ubuntu0.14.04.2

---------------
openvswitch (2.0.2-0ubuntu0.14.04.2) trusty; urgency=medium

  * d/p/dont-use-mask-if-null.patch: Cherry pick fix from upstream VCS to
    ensure that mask is not printed in diagnostic code if null, avoiding
    SIGSEGV (LP: #1336555).

 -- James Page <email address hidden> Mon, 11 May 2015 08:43:47 +0100

The verification of the Stable Release Update for openvswitch has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.