recvfrom SYSCALL infinite loop/deadlock chewing 100% CPU (MSG_PEEK|MSG_WAITALL)

[Joseph Salisbury]

In a multi-threaded pthreads process running on Ubuntu 14.04 AMD64 (with over 1000 threads) which uses real time FIFO scheduling, we occasionally see calls to recv() with flags (MSG_PEEK | MSG_WAITALL) get stuck in an infinte loop or deadlock meaning the threads lock up chewing as much CPU as they can (due to FIFO scheduling) while stuck inside recv().

Here's an example gdb back trace:

[Switching to thread 4 (Thread 0x7f6040546700 (LWP 27251))]
#0 0x00007f6231d2f7eb in __libc_recv (fd=fd@entry=146, buf=buf@entry=0x7f6040543600, n=n@entry=5, flags=-1, flags@entry=258) at ../sysdeps/unix/sysv/linux/x86_64/recv.c:33
33 ../sysdeps/unix/sysv/linux/x86_64/recv.c: No such file or directory.
(gdb) bt
#0 0x00007f6231d2f7eb in __libc_recv (fd=fd@entry=146, buf=buf@entry=0x7f6040543600, n=n@entry=5, flags=-1, flags@entry=258) at ../sysdeps/unix/sysv/linux/x86_64/recv.c:33
#1 0x0000000000421945 in recv (__flags=258, __n=5, __buf=0x7f6040543600, __fd=146) at /usr/include/x86_64-linux-gnu/bits/socket2.h:44
[snip]

The socket is a TCP socket in blocking mode, the recv() call is inside an outer loop with a counter, and I've checked the counter with gdb and it's always at 1, meaning that I'm sure that the outer loop isn't the problem, the thread is indeed deadlocked inside the recv() internals.

Other nodes:
* There always seems to be 2 or more threads deadlocked in the same place (same recv() call but with distinct FDs)
* The threads calling recv() have cancellation disbaled by previously executing: thread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);

I've even tried adding a poll() call for POLLRDNORM on the socket before calling recv() with MSG_PEEK | MSG_WAITALL flags to try to make sure there's data available on the socket before calling *recv()*, but it makes no difference.

So, I don't know what is wrong here, I've read all the recv() documentation and believe that recv() is being used correctly, the only conclusion I can come to is that there is a bug in libc recv() when using flags MSG_PEEK | MSG_WAITALL with thousands of pthreads running.

===
break-fix: - dfbafc995304ebb9a9b03f65083e6e9cea143b20

[Andy Whitcroft (apw)]

According to the upstream bug:

"This bug is now fixed in the net tree:
https://git.kernel.org/cgit/linux/kernel/git/davem/net.git/commit/?id=dfbafc995304ebb9a9b03f65083e6e9cea143b20"

This commit is already applied to mainline:

$ git describe --contains dfbafc995304ebb9a9b03f65083e6e9cea143b20
v4.2-rc5~9^2~26

commit dfbafc995304ebb9a9b03f65083e6e9cea143b20
Author: Sabrina Dubroca <email address hidden>
Date: Fri Jul 24 18:19:25 2015 +0200

    tcp: fix recv with flags MSG_WAITALL | MSG_PEEK

[Joseph Salisbury (jsalisbury)]

I built a Trusty test kernel with a cherry-pick of dfbafc99. This test kernel can be downloaded from:

http://kernel.ubuntu.com/~jsalisbury/lp1486146/

Can you test this kernel and see if it resolves this bug?

Thanks in advance!

[Dan Searle (dan-censornet)]

Hi Joseph,

I re-created the issue on a new install of Ubuntu 14.04.3 (amd64) running the linux-image-3.19.0-26-generic kernel using the following code:

#include <stdlib.h>
#include <netinet/ip.h>

int main(void)
{
                struct sockaddr_in addr = {
                                .sin_family = AF_INET,
                                .sin_port = htons(1234),
                                .sin_addr = { INADDR_ANY }
                };
                int conn;
                char buf[16];

                int s = socket(AF_INET, SOCK_STREAM, 0);

                bind(s, (void *)&addr, sizeof addr);
                listen(s, 1);

                conn = accept(s, NULL, 0);

                recv(conn, buf, sizeof buf, MSG_PEEK|MSG_WAITALL);
}
----
$ gcc x.c
$ ./a.out &

$ nc 127.0.0.1 1234
1234<enter>

--> 'a.out' consumes 100% CPU

----

After downloading and installing kernel packages from http://kernel.ubuntu.com/~jsalisbury/lp1486146/ I rebooted, and re-ran the test as above, this time 'a.out' does not consume 100% CPU any more, so the bug seems fixed at least in this simple test case using the replacement kernel.

[Joseph Salisbury (jsalisbury)]

Thanks for testing, Dan. I'll submit a SRU request for this commit to be included in all Ubuntu releases.

[Brad Figg (brad-figg)]

This bug is awaiting verification that the kernel in -proposed solves the problem. Please test the kernel and update this bug with the results. If the problem is solved, change the tag 'verification-needed-trusty' to 'verification-done-trusty'.

If verification is not done by 5 working days from today, this fix will be dropped from the source code, and this bug will be closed.

See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you!

[Brad Figg (brad-figg)]

This bug is awaiting verification that the kernel in -proposed solves the problem. Please test the kernel and update this bug with the results. If the problem is solved, change the tag 'verification-needed-vivid' to 'verification-done-vivid'.

If verification is not done by 5 working days from today, this fix will be dropped from the source code, and this bug will be closed.

See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you!

[Joseph Salisbury (jsalisbury)]

Hi Dan,

Can you verify this bug is now fixed in the -proposed kernel as requested in comments 5 and 6?

[Joseph Salisbury (jsalisbury)]

Verified this is fixed in Wily.

[Launchpad Janitor (janitor)]

This bug was fixed in the package linux - 3.13.0-65.105

---------------
linux (3.13.0-65.105) trusty; urgency=low

  [ Brad Figg ]

  * Release Tracking Bug
    - LP: #1498108

  [ Upstream Kernel Changes ]

  * net: Fix skb_set_peeked use-after-free bug
      - LP: #1497184

linux (3.13.0-64.104) trusty; urgency=low

  [ Luis Henriques ]

  * Release Tracking Bug
    - LP: #1493803

  [ Chris J Arges ]

  * [Config] DEFAULT_IOSCHED="deadline" for ppc64el
    - LP: #1469829

  [ Upstream Kernel Changes ]

  * tcp: fix recv with flags MSG_WAITALL | MSG_PEEK
    - LP: #1486146
  * libceph: abstract out ceph_osd_request enqueue logic
    - LP: #1488035
  * libceph: resend lingering requests with a new tid
    - LP: #1488035
  * n_tty: Refactor input_available_p() by call site
    - LP: #1397976
  * tty: Fix pty master poll() after slave closes v2
    - LP: #1397976
  * md: use kzalloc() when bitmap is disabled
    - LP: #1493305
  * ata: pmp: add quirk for Marvell 4140 SATA PMP
    - LP: #1493305
  * libata: add ATA_HORKAGE_BROKEN_FPDMA_AA quirk for HP 250GB SATA disk
    VB0250EAVER
    - LP: #1493305
  * libata: add ATA_HORKAGE_NOTRIM
    - LP: #1493305
  * libata: force disable trim for SuperSSpeed S238
    - LP: #1493305
  * libata: increase the timeout when setting transfer mode
    - LP: #1493305
  * libata: Do not blacklist M510DC
    - LP: #1493305
  * mac80211: clear subdir_stations when removing debugfs
    - LP: #1493305
  * ALSA: hda - Add new GPU codec ID 0x10de007d to snd-hda
    - LP: #1493305
  * drm: Stop resetting connector state to unknown
    - LP: #1493305
  * usb: dwc3: Reset the transfer resource index on SET_INTERFACE
    - LP: #1493305
  * usb: xhci: Bugfix for NULL pointer deference in xhci_endpoint_init()
    function
    - LP: #1493305
  * xhci: Calculate old endpoints correctly on device reset
    - LP: #1493305
  * xhci: report U3 when link is in resume state
    - LP: #1493305
  * xhci: prevent bus_suspend if SS port resuming in phase 1
    - LP: #1493305
  * xhci: do not report PLC when link is in internal resume state
    - LP: #1493305
  * USB: OHCI: Fix race between ED unlink and URB submission
    - LP: #1493305
  * usb-storage: ignore ZTE MF 823 card reader in mode 0x1225
    - LP: #1493305
  * blkcg: fix gendisk reference leak in blkg_conf_prep()
    - LP: #1493305
  * tile: use free_bootmem_late() for initrd
    - LP: #1493305
  * Input: usbtouchscreen - avoid unresponsive TSC-30 touch screen
    - LP: #1493305
  * md/raid1: fix test for 'was read error from last working device'.
    - LP: #1493305
  * mmc: omap_hsmmc: Fix DTO and DCRC handling
    - LP: #1493305
  * isdn/gigaset: reset tty->receive_room when attaching ser_gigaset
    - LP: #1493305
  * mmc: sdhci-pxav3: fix platform_data is not initialized
    - LP: #1493305
  * mmc: block: Add missing mmc_blk_put() in power_ro_lock_show()
    - LP: #1493305
  * mmc: sdhci-esdhc: Make 8BIT bus work
    - LP: #1493305
  * bonding: correctly handle bonding type change on enslave failure
    - LP: #1493305
  * net: Clone skb before setting peeked flag
    - LP: #1493305
  * bridge: mdb: fix double add notification
    - LP: #1493305
  * usb: gadget: mv_udc_c...

[Launchpad Janitor (janitor)]

This bug was fixed in the package linux-lts-utopic - 3.16.0-50.66~14.04.1

---------------
linux-lts-utopic (3.16.0-50.66~14.04.1) trusty; urgency=low

  [ Luis Henriques ]

  * Release Tracking Bug
    - LP: #1494371

  [ Chris J Arges ]

  * [Config] DEFAULT_IOSCHED="deadline" for ppc64el
    - LP: #1469829

  [ Upstream Kernel Changes ]

  * tcp: fix recv with flags MSG_WAITALL | MSG_PEEK
    - LP: #1486146
  * netfilter: nfnetlink_cthelper: Remove 'const' and '&' to avoid warnings
    - LP: #1490901
  * Bluetooth: ath3k: Add a new ID 0cf3:e006 to ath3k list
    - LP: #1490901
  * Btrfs: use kmem_cache_free when freeing entry in inode cache
    - LP: #1490901
  * Btrfs: fix race between caching kthread and returning inode to inode
    cache
    - LP: #1490901
  * Btrfs: fix fsync data loss after append write
    - LP: #1490901
  * ext4: fix reservation release on invalidatepage for delalloc fs
    - LP: #1490901
  * ext4: be more strict when migrating to non-extent based file
    - LP: #1490901
  * ext4: correctly migrate a file with a hole at the beginning
    - LP: #1490901
  * ext4: replace open coded nofail allocation in ext4_free_blocks()
    - LP: #1490901
  * drm/radeon: Handle irqs only based on irq ring, not irq status regs.
    - LP: #1490901
  * drm/radeon: unpin cursor BOs on suspend and pin them again on resume
    (v2)
    - LP: #1490901
  * hpfs: kstrdup() out of memory handling
    - LP: #1490901
  * hpfs: hpfs_error: Remove static buffer, use vsprintf extension %pV
    instead
    - LP: #1490901
  * 9p: don't leave a half-initialized inode sitting around
    - LP: #1490901
  * MIPS: kernel: traps: Fix broken indentation
    - LP: #1490901
  * thermal: step_wise: fix: Prevent from binary overflow when trend is
    dropping
    - LP: #1490901
  * spi: pl022: Specify 'num-cs' property as required in devicetree binding
    - LP: #1490901
  * iio: twl4030-madc: Pass the IRQF_ONESHOT flag
    - LP: #1490901
  * iio: inv-mpu: Specify the expected format/precision for write channels
    - LP: #1490901
  * iio: DAC: ad5624r_spi: fix bit shift of output data value
    - LP: #1490901
  * iio: adc: at91_adc: allow to use full range of startup time
    - LP: #1490901
  * ALSA: usb-audio: Add MIDI support for Steinberg MI2/MI4
    - LP: #1490901
  * iio: tmp006: Check channel info on write
    - LP: #1490901
  * dm btree remove: fix bug in redistribute3
    - LP: #1490901
  * kbuild: Allow arch Makefiles to override {cpp,ld,c}flags
    - LP: #1490901
  * ARC: Override toplevel default -O2 with -O3
    - LP: #1490901
  * crypto: omap-des - Fix unmapping of dma channels
    - LP: #1490901
  * USB: option: add 2020:4000 ID
    - LP: #1490901
  * USB: cp210x: add ID for Aruba Networks controllers
    - LP: #1490901
  * dm btree: silence lockdep lock inversion in dm_btree_del()
    - LP: #1490901
  * usb: musb: host: rely on port_mode to call musb_start()
    - LP: #1490901
  * usb: f_mass_storage: limit number of reported LUNs
    - LP: #1490901
  * drm: add a check for x/y in drm_mode_setcrtc
    - LP: #1490901
  * bio integrity: do not assume bio_integrity_pool exists if bioset exists
    - LP: #1490901
  * ARM: dts: mx23: fix iio-hwmon s...

[Launchpad Janitor (janitor)]

This bug was fixed in the package linux - 3.19.0-30.33

---------------
linux (3.19.0-30.33) vivid; urgency=low

  [ Brad Figg ]

  * Release Tracking Bug
    - LP: #1498065
  * Revert "[Config]
    MFD_INTEL_LPSS/MFD_INTEL_LPSS_ACPI/MFD_INTEL_LPSS_PCI=m"
    - LP: #1498137
  * [Config] Disable the MFD_INTEL_LPSS* driver

linux (3.19.0-30.32) vivid; urgency=low

  [ Brad Figg ]

  * Release Tracking Bug
    - LP: #1498065

  [ Upstream Kernel Changes ]

  * net: Fix skb_set_peeked use-after-free bug
    - LP: #1497184

linux (3.19.0-29.31) vivid; urgency=low

  [ Luis Henriques ]

  * Release Tracking Bug
    - LP: #1493902

  [ Ander Conselvan de Oliveira ]

  * SAUCE: i915_bpo: Set ddi_pll_sel in DP MST path
    - LP: #1483320

  [ Chris J Arges ]

  * [Config] DEFAULT_IOSCHED="deadline" for ppc64el
    - LP: #1469829

  [ Chris Wilson ]

  * SAUCE: i915_bpo: drm/i915: Flag the execlists context object as dirty
    after every use
    - LP: #1489501

  [ Daniel Vetter ]

  * SAUCE: i915_bpo: drm/i915: Only dither on 6bpc panels
    - LP: #1489501

  [ David Henningsson ]

  * SAUCE: drm/i915: Add audio pin sense / ELD callback
    - LP: #1490895
  * SAUCE: drm/i915: Call audio pin/ELD notify function
    - LP: #1490895
  * SAUCE: ubuntu/i915: Call audio pin/ELD notify function
    - LP: #1490895
  * SAUCE: ALSA: hda - Add "hdac_acomp" global variable
    - LP: #1490895
  * SAUCE: ALSA: hda - allow codecs to access the i915 pin/ELD callback
    - LP: #1490895
  * SAUCE: ALSA: hda - Wake the codec up on pin/ELD notify events
    - LP: #1490895

  [ Jani Nikula ]

  * SAUCE: i915_bpo: Revert "drm/i915: Allow parsing of variable size child
    device entries from VBT"
    - LP: #1489501

  [ Maarten Lankhorst ]

  * SAUCE: i915_bpo: drm/i915: calculate primary visibility changes instead
    of calling from set_config
    - LP: #1489501
  * SAUCE: i915_bpo: drm/i915: Commit planes on each crtc separately.
    - LP: #1489501

  [ Thulasimani,Sivakumar ]

  * SAUCE: i915_bpo: Revert "drm/i915: Add eDP intermediate frequencies for
    CHV"
    - LP: #1489501
  * SAUCE: i915_bpo: drm/i915: remove HBR2 from chv supported list
    - LP: #1489501
  * SAUCE: i915_bpo: drm/i915: Avoid TP3 on CHV
    - LP: #1489501

  [ Timo Aaltonen ]

  * Revert "SAUCE: i915_bpo: drm/i915: Allow parsing of variable size child
    device entries from VBT, addendum v2"
    - LP: #1489501
  * SAUCE: Migrate Broadwell to i915_bpo.
    - LP: #1483320

  [ Upstream Kernel Changes ]

  * tcp: fix recv with flags MSG_WAITALL | MSG_PEEK
    - LP: #1486146
  * powerpc/powernv: Fix the overflow of OPAL message notifiers head array
    - LP: #1487085
  * xhci: call BIOS workaround to enable runtime suspend on Intel Braswell
    - LP: #1489292
  * PM / QoS: Make it possible to expose device latency tolerance to
    userspace
    - LP: #1488395
  * ACPI / PM: Attach ACPI power domain only once
    - LP: #1488395
  * Driver core: wakeup the parent device before trying probe
    - LP: #1488395
  * klist: implement klist_prev()
    - LP: #1488395
  * driver core: implement device_for_each_child_reverse()
    - LP: #1488395
  * mfd: make mfd_remove_devices() iterate in reverse order
    ...