CUPS - Excessive Amounts of UDP Multicast Traffic for BJNP

[Wes]

It appears that the cups-browsed service as of Xenial (version 1.8.3-2ubuntu3.1) sends an excessive amount of UDP multicast requests for ports 8610 (Canon MFNP) and 8612 (Canon BJNP) under unexpected conditions and regardless of a presence or lack of Canon printer devices on the network.

This is manifested by enabling UFW, and observing multicast requests being blocked that are sent from the host machine's network IPv4 or IPv6 address to the multicast address, e.g.
[UFW BLOCK] IN=wlp3s0 OUT= MAC= SRC=<Machine IPv6> DST=ff02:0000:0000:0000:0000:0000:0000:0001 LEN=64 TC=0 HOPLIMIT=1 FLOWLBL=96642 PROTO=UDP SPT=8612 DPT=8612 LEN=24

IN= OUT=wlan0 SRC=192.168.90.45 DST=192.168.91.255 LEN=44 TOS=0x00 PREC=0x00 TTL=64 ID=7742 DF PROTO=UDP SPT=8612 DPT=8610 LEN=24

Users have observed that the requests can be reproduced when any USB device is plugged/unplugged into the computer, regardless of whether the device has anything to do with printing:
https://twitter.com/gertvdijk/status/621790755758178304
https://bugs.kali.org/view.php?id=3094

Just Googling "udp 8612", shows are a large number of results on different websites of people who have observed this behaviour in firewall and traffic logs, and have noticed that it may contribute to network slowdown and latency:
https://askubuntu.com/questions/867739/what-is-this-traffic/867786
https://serverfault.com/questions/667376/watchguard-blocking-internal-udp-packets

https://jehurst.wordpress.com/2016/01/22/small-victories/ recommends disabling the cups-browsed service to stop these requests:
systemctl stop cups-browsed.service
systemctl disable cups-browsed.service

There are probably two things to address here:
1. Connecting any USB device should not cause these requests unless the device is actually a printer or directly related to printing.
2. Requests independent of connecting USB devices should be rate limited to a degree and/or should be dependent on the actual presence of a Canon printer configured on the network.

[Launchpad Janitor (janitor)]

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

[Till Kamppeter (till-kamppeter)]

cups-browsed does not directly interact with USB printers and is not triggered by USB events. Do you have any special software to support Canon printers (Canon MFNP, Canon BJNP) installed? Does this software mirror USB printers to emulated network printers? Does it do this mirroring also if no supported printer is present?

Is there any way to easily reproduce this bug?

Can you please attach your /etc/cups/cups-browsed.conf file?

Does avahi-discover show any suspect (Canon MFNP/BJNP) printers under IPP/_ipps/Internet Printer?

Please also attach your /var/log/cups/cups-browsed_log if you have one.

Please do not compress your attachments and do not package them together, attach them one-by-one. Thanks.

[Till Kamppeter (till-kamppeter)]

Do you have the cups-bjnp package installed? It provides the "bjnp" CUPS backend to use Canon BJNP network printers (not USB printers). It communicates with the printer on port 8611 in both directions.

The package contains the "bjnp" CUPS backend as the only non-documentation file. This backend is only executed by CUPS when looking for printers available for setup ("lpinfo -v" or equivalent IPP request) where each backend is called once without arguments and when a job is sent to a queue using this backend. cups-browsed does not trigger any of these actions.

Do you have any proprietary printer driver software from Canon installed?

[Wes (wesinator)]

cups-browsed conf attached.
I do not have a /var/log/cups/cups-browsed_log

This bug can be reproduced/observed on a default install by enabling UFW. The blocked UDP multicast requests start to show up in /var/log/ufw.log

cups-backend-bjnp is not installed.
There are no special proprietary Canon drivers or software installed. As stated above, this occurs in a default install.

If cups-browsed does not trigger these actions and there is no proprietary Canon software installed, could there be a kernel blob causing this behaviour ?

[Till Kamppeter (till-kamppeter)]

cups-browsed does for sure not send anything to the given ports, and it also does not directly send anything to the multicast addresses. It communicates with avahi-daemon via D-Bus to get informed about network printers appearing or disappearing, updates its internal printer list accordingly and creates CUPS queues or removes them, communicating with CUPS via localhost:631 (using the IPP protocol) or domain socket. It also subscribes to CUPS notifications via D-Bus.

[Wes (wesinator)]

Understood.
Judging by some other reports such as https://discussions.apple.com/thread/6477200, it sounds like this is an upstream behaviour in the core CUPS that may have since been fixed (I'm testing with newer versions to see if I can reproduce).

Shall I mark this Invalid ?

[Wes (wesinator)]

Moving this bug under cups package.

[Till Kamppeter (till-kamppeter)]

Please check with a live system (or on a virtual machine) Artful (Ubuntu 17.10) to check whether the problem is not present any more there.

[Launchpad Janitor (janitor)]

[Expired for cups (Ubuntu) because there has been no activity for 60 days.]

[Wes (wesinator)]

Still seeing CUPS related IPv6 multicast requests from my machine on 18.04 bionic, right after plugging in a USB device:
[11593.578868] usb 2-1.1: new high-speed USB device number 4 using ehci-pci
[11593.693173] usb 2-1.1: New USB device found, idVendor=0e8d, idProduct=1807
[11593.693182] usb 2-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[11593.693187] usb 2-1.1: Product: MT1807
[11593.693192] usb 2-1.1: Manufacturer: MediaTek Inc
[11593.693196] usb 2-1.1: SerialNumber:
[11594.085831] usb-storage 2-1.1:1.0: USB Mass Storage device detected
[11594.086113] scsi host6: usb-storage 2-1.1:1.0
[11594.086272] usbcore: registered new interface driver usb-storage
[11594.257746] [UFW BLOCK] IN=wlp2s0 OUT= MAC= SRC=<Ubuntu machine IPv6> DST=ff02:0000:0000:0000:0000:0000:0000:0001 LEN=64 TC=0 HOPLIMIT=1 FLOWLBL=659619 PROTO=UDP SPT=8612 DPT=8612 LEN=24
[11594.257765] [UFW BLOCK] IN=wlp2s0 OUT= MAC= SRC=<Ubuntu machine IPv6> DST=ff02:0000:0000:0000:0000:0000:0000:0001 LEN=64 TC=0 HOPLIMIT=1 FLOWLBL=952340 PROTO=UDP SPT=8612 DPT=8610 LEN=24
[11594.268122] [UFW BLOCK] IN=wlp2s0 OUT= MAC= SRC=<Ubuntu machine IPv6> DST=ff02:0000:0000:0000:0000:0000:0000:0001 LEN=64 TC=0 HOPLIMIT=1 FLOWLBL=659619 PROTO=UDP SPT=8612 DPT=8612 LEN=24
[11594.268197] [UFW BLOCK] IN=wlp2s0 OUT= MAC= SRC=<Ubuntu machine IPv6> DST=ff02:0000:0000:0000:0000:0000:0000:0001 LEN=64 TC=0 HOPLIMIT=1 FLOWLBL=952340 PROTO=UDP SPT=8612 DPT=8610 LEN=24

No longer seeing IPv4 requests though

[zwigno (zwigno)]

I also see the IPv6 requests when a USB device is plugged in. In this case it is a Z-Wave device. I don't have any cannon stuff. I'm running 18.04.1 LTS.

[jean-christophe manciot (manciot-jeanchristophe)]

I experience the same symptoms on Ubuntu 19.04 disco, but there is no cups* packages installed:

# apt-cache policy cups*| grep Installed | grep -v none
#

The issue is definitely unrelated to CUPS.

Some other process sends many strange IPv6/UDP packets to all IPv6 local nodes with 2 different types; the wireshark trace shows 2 types of "Discover scanner commands":
1. source port 8612 (canon-bjnp2) --> dest port 8610 (canon-mfnp)
2. source port 8612 (canon-bjnp2) --> dest port 8612 (canon-bjnp2)

I have no canon device on the network nor on the server and no USB device connected on the server.
There is no canon related package/kernel module installed.

[jean-christophe manciot (manciot-jeanchristophe)]

If anyone knows a way to pinpoint some process which sends some specific packets, I'd be glad to investigate further.

[Wes (wesinator)]

See if you have any *cups* packages installed

[jean-christophe manciot (manciot-jeanchristophe)]

I ha

[jean-christophe manciot (manciot-jeanchristophe)]

I have just found the following message in syslog:
Feb 12 13:25:56 samsung5-ubuntu colord-sane: message repeated 2 times: [ [bjnp] create_broadcast_socket: ERROR - bind socket to local address failed - Cannot assign requested address]
that matches:
● colord.service - Manage, Install and Generate Color Profiles
   Loaded: loaded (/lib/systemd/system/colord.service; static; vendor preset: enabled)
   Active: active (running) since Tue 2019-02-12 02:30:41 CET; 11h ago
 Main PID: 2098 (colord)
    Tasks: 3 (limit: 4915)
   Memory: 14.9M
   CGroup: /system.slice/colord.service
           └─2098 /usr/lib/colord/colord

Feb 12 02:30:41 samsung5-ubuntu systemd[1]: Starting Manage, Install and Generate Color Profiles...
Feb 12 02:30:41 samsung5-ubuntu systemd[1]: Started Manage, Install and Generate Color Profiles.
Feb 12 02:30:42 samsung5-ubuntu colord[2098]: failed to get session [pid 2118]: No data available
Feb 12 02:30:42 samsung5-ubuntu colord-sane[2240]: [bjnp] create_broadcast_socket: ERROR - bind socket to local address failed - Cannot assign requested address

This lead me to investigate the SANE scanner and more specifically /etc/sane.d/dll.conf which seems to list image scanner hardware drivers, including canon ones.
However, commenting out 'net' or all canon-related lines does not change anything:
# systemctl restart colord
# systemctl status colord
● colord.service - Manage, Install and Generate Color Profiles
   Loaded: loaded (/lib/systemd/system/colord.service; static; vendor preset: enabled)
   Active: active (running) since Tue 2019-02-12 14:21:12 CET; 4s ago
 Main PID: 31838 (colord)
    Tasks: 4 (limit: 4915)
   Memory: 8.0M
   CGroup: /system.slice/colord.service
           └─31838 /usr/lib/colord/colord

Feb 12 14:21:12 samsung5-ubuntu systemd[1]: Starting Manage, Install and Generate Color Profiles...
Feb 12 14:21:12 samsung5-ubuntu systemd[1]: Started Manage, Install and Generate Color Profiles.
Feb 12 14:21:13 samsung5-ubuntu colord-sane[31859]: [bjnp] create_broadcast_socket: ERROR - bind socket to local address failed - Cannot assign requested address