New issue
Advanced search Search tips

Issue 807076 link

Starred by 1 user

Issue metadata

Status: Untriaged
Owner: ----
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 3
Type: Bug



Sign in to add a comment

avahi-daemon IP_ADD_MEMBERSHIP failed: No buffer space available

Project Member Reported by grundler@google.com, Jan 29 2018

Issue description

I tried to run:
   test_that -b kefka 100.127.1.163 network_EthernetStressPlug --args num_iterations=10000

and the test failed after about 653 iterations with:
2018-01-29T23:16:57.470004+00:00 INFO kernel: [16984.932073] usb 2-1: USB disconnect, device number 4
2018-01-29T23:16:57.677809+00:00 INFO kernel: [16985.140106] usb 2-1: new SuperSpeed USB device number 5 using xhci_hcd
2018-01-29T23:16:57.692868+00:00 INFO kernel: [16985.154206] usb 2-1: New USB device found, idVendor=13b1, idProduct=0041
2018-01-29T23:16:57.692898+00:00 INFO kernel: [16985.154225] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=6
2018-01-29T23:16:57.692901+00:00 INFO kernel: [16985.154235] usb 2-1: Product: Linksys USB3GIGV1
2018-01-29T23:16:57.692903+00:00 INFO kernel: [16985.154243] usb 2-1: Manufacturer: Linksys
2018-01-29T23:16:57.692905+00:00 INFO kernel: [16985.154250] usb 2-1: SerialNumber: 000001000000
2018-01-29T23:16:57.695790+00:00 INFO kernel: [16985.157783] platform vpd: Driver vpd requests probe deferral
2018-01-29T23:16:57.805827+00:00 INFO kernel: [16985.267682] usb 2-1: reset SuperSpeed USB device number 5 using xhci_hcd
2018-01-29T23:16:57.855839+00:00 INFO kernel: [16985.317176] r8152 2-1:1.0 eth0: v1.09.9
2018-01-29T23:16:57.855869+00:00 INFO kernel: [16985.317362] platform vpd: Driver vpd requests probe deferral
2018-01-29T23:16:57.877828+00:00 INFO kernel: [16985.339303] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
2018-01-29T23:16:57.998477+00:00 INFO permission_broker[1765]: ProcessPath(/dev/bus/usb/002/005)
2018-01-29T23:16:58.098423+00:00 INFO permission_broker[1765]:   AllowUsbDeviceRule: ALLOW
2018-01-29T23:16:58.098452+00:00 INFO permission_broker[1765]:   AllowTtyDeviceRule: IGNORE
2018-01-29T23:16:58.218021+00:00 WARNING permission_broker[1765]: Could not load the device policy file.
2018-01-29T23:16:58.218228+00:00 INFO permission_broker[1765]:   DenyClaimedUsbDeviceRule: DENY
2018-01-29T23:16:58.218252+00:00 INFO permission_broker[1765]: Verdict for /dev/bus/usb/002/005: DENY
2018-01-29T23:16:58.218349+00:00 ERR permission_broker[1765]: OpenPath(...): Domain=permission_broker, Code=permission_denied, Message=Permission to open '/dev/bus/usb/002/005' denied
2018-01-29T23:16:58.968111+00:00 ERR mtpd[1796]: LIBMTP_Detect_Raw_Devices failed with 5
2018-01-29T23:17:01.706305+00:00 INFO kernel: [16989.167553] r8152 2-1:1.0 eth0: carrier on
2018-01-29T23:17:01.706337+00:00 INFO kernel: [16989.167629] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
2018-01-29T23:17:01.884529+00:00 INFO avahi-daemon[1850]: Joining mDNS multicast group on interface eth0.IPv4 with address 100.127.1.163.
2018-01-29T23:17:01.884588+00:00 WARNING avahi-daemon[1850]: IP_ADD_MEMBERSHIP failed: No buffer space available
2018-01-29T23:17:01.884605+00:00 INFO avahi-daemon[1850]: Registering new address record for 100.127.1.163 on eth0.IPv4.
2018-01-29T23:17:01.884664+00:00 INFO avahi-daemon[1850]: Joining mDNS multicast group on interface eth0.IPv4 with address 100.127.1.163.
2018-01-29T23:17:01.884684+00:00 WARNING avahi-daemon[1850]: IP_ADD_MEMBERSHIP failed: No buffer space available
2018-01-29T23:17:35.024250+00:00 INFO sshd[21363]: Accepted publickey for root from 127.0.0.1 port 33619 ssh2: RSA SHA256:Fp1qWjFLyK1cTpiI5rdk7iEJwoK9lcnYAgbQtGC3jzU

but I was able to ssh into the machine. (IP is working...but maybe sshd timedout for other reasons). And I noticed avahi-daemon was spewing "No buffer space available" WARNING most of the time this test was running:

kefka ~ # fgrep "IP_ADD_MEMBERSHIP" /var/log/messages  | wc -l
1272

Here are the first successful iterations of the test (/var/log/messages output) for reference:
...
2018-01-29T18:47:46.761236+00:00 INFO kernel: [  834.756464] usb 2-1: authorized to connect
2018-01-29T18:47:46.868360+00:00 INFO kernel: [  834.863784] usb 2-1: reset SuperSpeed USB device number 3 using xhci_hcd
2018-01-29T18:47:46.909170+00:00 INFO avahi-daemon[1850]: Server startup complete. Host name is daed361e083f29c2e26bcfeb5a6f6c52.local. Local service cookie is 942169308.
2018-01-29T18:47:46.922289+00:00 INFO kernel: [  834.916667] r8152 2-1:1.0 eth0: v1.09.9
2018-01-29T18:47:46.922317+00:00 INFO kernel: [  834.916773] platform vpd: Driver vpd requests probe deferral
2018-01-29T18:47:46.937809+00:00 INFO kernel: [  834.933797] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
2018-01-29T18:47:47.924530+00:00 ERR mtpd[1796]: LIBMTP_Detect_Raw_Devices failed with 5
2018-01-29T18:47:50.642825+00:00 INFO kernel: [  838.639042] r8152 2-1:1.0 eth0: carrier on
2018-01-29T18:47:50.642858+00:00 INFO kernel: [  838.639090] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
2018-01-29T18:47:51.180601+00:00 INFO avahi-daemon[1850]: Joining mDNS multicast group on interface eth0.IPv4 with address 100.127.1.163.
2018-01-29T18:47:51.180662+00:00 INFO avahi-daemon[1850]: New relevant interface eth0.IPv4 for mDNS.
2018-01-29T18:47:51.180680+00:00 INFO avahi-daemon[1850]: Registering new address record for 100.127.1.163 on eth0.IPv4.
2018-01-29T18:47:53.261724+00:00 INFO avahi-daemon[1850]: Interface eth0.IPv4 no longer relevant for mDNS.
2018-01-29T18:47:53.261757+00:00 INFO avahi-daemon[1850]: Leaving mDNS multicast group on interface eth0.IPv4 with address 100.127.1.163.
2018-01-29T18:47:53.264219+00:00 ERR dhcpcd[4577]: eth0: dhcp if_readrawpacket: Network is down
2018-01-29T18:47:53.271204+00:00 ERR dhcpcd[4577]: dhcp_open: eth0: No such device
2018-01-29T18:47:53.274917+00:00 WARNING avahi-daemon[1850]: IP_DROP_MEMBERSHIP failed: No such device
2018-01-29T18:47:53.274992+00:00 INFO avahi-daemon[1850]: Withdrawing address record for 100.127.1.163 on eth0.
2018-01-29T18:47:53.392374+00:00 INFO avahi-daemon[1850]: Withdrawing address record for 100.115.92.1 on arcbr0.
2018-01-29T18:47:53.392425+00:00 INFO avahi-daemon[1850]: Registering new address record for 100.115.92.1 on arcbr0.IPv4.
2018-01-29T18:47:53.392527+00:00 INFO avahi-daemon[1850]: Changing host name to '5787ec30fc68ebdccdf730775a6f6c59'.
2018-01-29T18:47:53.399369+00:00 NOTICE cros-machine-id-regen[4633]: Regenerated /var/lib/dbus/machine-id (reason: network).
2018-01-29T18:47:54.275862+00:00 INFO avahi-daemon[1850]: Server startup complete. Host name is 5787ec30fc68ebdccdf730775a6f6c59.local. Local service cookie is 942169308.
2018-01-29T18:47:55.310355+00:00 INFO kernel: [  843.304552] usb 2-1: authorized to connect
2018-01-29T18:47:55.414753+00:00 INFO kernel: [  843.409481] usb 2-1: reset SuperSpeed USB device number 3 using xhci_hcd
2018-01-29T18:47:55.462807+00:00 INFO kernel: [  843.458375] r8152 2-1:1.0 eth0: v1.09.9
2018-01-29T18:47:55.462835+00:00 INFO kernel: [  843.458542] platform vpd: Driver vpd requests probe deferral
2018-01-29T18:47:55.482031+00:00 INFO kernel: [  843.477416] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
2018-01-29T18:47:56.539830+00:00 ERR mtpd[1796]: LIBMTP_Detect_Raw_Devices failed with 5
2018-01-29T18:47:59.222092+00:00 INFO kernel: [  847.217513] r8152 2-1:1.0 eth0: carrier on
2018-01-29T18:47:59.222113+00:00 INFO kernel: [  847.217656] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
2018-01-29T18:48:00.305870+00:00 INFO avahi-daemon[1850]: Joining mDNS multicast group on interface eth0.IPv4 with address 100.127.1.163.
2018-01-29T18:48:00.305926+00:00 INFO avahi-daemon[1850]: New relevant interface eth0.IPv4 for mDNS.
2018-01-29T18:48:00.305945+00:00 INFO avahi-daemon[1850]: Registering new address record for 100.127.1.163 on eth0.IPv4.
2018-01-29T18:48:01.828885+00:00 INFO avahi-daemon[1850]: Interface eth0.IPv4 no longer relevant for mDNS.
2018-01-29T18:48:01.828909+00:00 INFO avahi-daemon[1850]: Leaving mDNS multicast group on interface eth0.IPv4 with address 100.127.1.163.
2018-01-29T18:48:01.831388+00:00 ERR dhcpcd[4679]: eth0: dhcp if_readrawpacket: Network is down
2018-01-29T18:48:01.833263+00:00 WARNING avahi-daemon[1850]: IP_DROP_MEMBERSHIP failed: No such device
2018-01-29T18:48:01.833333+00:00 INFO avahi-daemon[1850]: Withdrawing address record for 100.127.1.163 on eth0.
2018-01-29T18:48:01.836040+00:00 ERR shill[1292]: [ERROR:object_proxy.cc(582)] Failed to call method: org.chromium.dhcpcd.Release: object_path= /org/chromium/dhcpcd: org.freedesktop.DBus.Error.ServiceUnknown: The name :1.46 was not provided by any .service files
2018-01-29T18:48:01.836074+00:00 ERR shill[1292]: [ERROR:dbus_method_invoker.h(111)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.ServiceUnknown, Message=The name :1.46 was not provided by any .service files
2018-01-29T18:48:01.963263+00:00 INFO avahi-daemon[1850]: Withdrawing address record for 100.115.92.1 on arcbr0.
2018-01-29T18:48:01.963311+00:00 INFO avahi-daemon[1850]: Registering new address record for 100.115.92.1 on arcbr0.IPv4.
2018-01-29T18:48:01.963410+00:00 INFO avahi-daemon[1850]: Changing host name to 'd9f951c56dabb8d26c8b00bc5a6f6c61'.
2018-01-29T18:48:01.970435+00:00 NOTICE cros-machine-id-regen[4736]: Regenerated /var/lib/dbus/machine-id (reason: network).
2018-01-29T18:48:02.847019+00:00 INFO avahi-daemon[1850]: Server startup complete. Host name is d9f951c56dabb8d26c8b00bc5a6f6c61.local. Local service cookie is 942169308.
2018-01-29T18:48:02.932362+00:00 INFO kernel: [  850.927031] usb 2-1: authorized to connect
2018-01-29T18:48:03.038820+00:00 INFO kernel: [  851.034712] usb 2-1: reset SuperSpeed USB device number 3 using xhci_hcd
2018-01-29T18:48:03.090211+00:00 INFO kernel: [  851.085105] r8152 2-1:1.0 eth0: v1.09.9
...

kefka ~ # lsusb -t
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
    |__ Port 1: Dev 5, If 0, Class=Vendor Specific Class, Driver=r8152, 5000M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/7p, 480M
    |__ Port 3: Dev 2, If 0, Class=Human Interface Device, Driver=usbhid, 12M
    |__ Port 3: Dev 2, If 1, Class=Communications, Driver=cdc_acm, 12M
    |__ Port 3: Dev 2, If 2, Class=CDC Data, Driver=cdc_acm, 12M
    |__ Port 4: Dev 3, If 0, Class=Video, Driver=uvcvideo, 480M
    |__ Port 4: Dev 3, If 1, Class=Video, Driver=uvcvideo, 480M
    |__ Port 5: Dev 4, If 0, Class=Wireless, Driver=btusb, 12M
    |__ Port 5: Dev 4, If 1, Class=Wireless, Driver=btusb, 12M

kefka ~ # uname -a
Linux kefka 3.18.0-16501-g5fe5d5aecd79-dirty #1 SMP PREEMPT Fri Jan 26 12:32:38 PST 2018 x86_64 Intel(R) Celeron(R) CPU N3060 @ 1.60GHz GenuineIntel GNU/Linux

It shouldn't matter, but the dongle used is Linksys USB3GIGV1.
 

Sign in to add a comment