Ubuntu
cups-filters package

Printer notification every day at midnight

Bug #1869981 reported by Alan Pope 🍺🐧🐱 🦄 on 2020-03-31

This bug affects 3 people

Affects		Status	Importance	Assigned to	Milestone
	cups-filters (Ubuntu)	Fix Released	Low	Till Kamppeter

Bug Description

Every day, all my 20.04 machines get a notification that the printer in my house has been detected.

The printer works fine and is already added. So not sure why I need to be told repeatedly that I have a printer on the network?

(see screenshot)

ProblemType: Bug
DistroRelease: Ubuntu 20.04
Package: cups 2.3.1-9ubuntu1
ProcVersionSignature: Ubuntu 5.4.0-21.25-generic 5.4.27
Uname: Linux 5.4.0-21-generic x86_64
NonfreeKernelModules: zfs zunicode zavl icp zcommon znvpair
ApportVersion: 2.20.11-0ubuntu21
Architecture: amd64
CupsErrorLog:

CurrentDesktop: ubuntu:GNOME
Date: Wed Apr 1 00:00:31 2020
InstallationDate: Installed on 2020-03-01 (30 days ago)
InstallationMedia: Ubuntu 20.04 LTS "Focal Fossa" - Alpha amd64 (20200301)
Lpstat: device for HP_LaserJet_100_colorMFP_M175nw_6DCDD4_: implicitclass://HP_LaserJet_100_colorMFP_M175nw_6DCDD4_/
MachineType: LENOVO 20BV001BUK
Papersize: a4
PpdFiles: Error: command ['fgrep', '-H', '*NickName', '/etc/cups/ppd/HP_LaserJet_100_colorMFP_M175nw_6DCDD4_.ppd'] failed with exit code 2: grep: /etc/cups/ppd/HP_LaserJet_100_colorMFP_M175nw_6DCDD4_.ppd: Permission denied
ProcKernelCmdLine: BOOT_IMAGE=/BOOT/ubuntu_pyyy5h@/vmlinuz-5.4.0-21-generic root=ZFS=rpool/ROOT/ubuntu_pyyy5h ro quiet splash vt.handoff=1
SourcePackage: cups
UpgradeStatus: No upgrade log present (probably fresh install)
dmi.bios.date: 08/14/2019
dmi.bios.vendor: LENOVO
dmi.bios.version: JBET73WW (1.37 )
dmi.board.asset.tag: Not Available
dmi.board.name: 20BV001BUK
dmi.board.vendor: LENOVO
dmi.board.version: 0B98417 WIN
dmi.chassis.asset.tag: No Asset Information
dmi.chassis.type: 10
dmi.chassis.vendor: LENOVO
dmi.chassis.version: None
dmi.modalias: dmi:bvnLENOVO:bvrJBET73WW(1.37):bd08/14/2019:svnLENOVO:pn20BV001BUK:pvrThinkPadT450:rvnLENOVO:rn20BV001BUK:rvr0B98417WIN:cvnLENOVO:ct10:cvrNone:
dmi.product.family: ThinkPad T450
dmi.product.name: 20BV001BUK
dmi.product.sku: LENOVO_MT_20BV_BU_Think_FM_ThinkPad T450
dmi.product.version: ThinkPad T450
dmi.sys.vendor: LENOVO

Tags:

Revision history for this message

Alan Pope 🍺🐧🐱 🦄 (popey) wrote on 2020-03-31:

Screenshot from 2020-04-01 00-01-14.png Edit (138.6 KiB, image/png)
CurrentDmesg.txt Edit (256.5 KiB, text/plain; charset="utf-8")
Dependencies.txt Edit (6.8 KiB, text/plain; charset="utf-8")
KernLog.txt Edit (136.9 KiB, text/plain; charset="utf-8")
Locale.txt Edit (335 bytes, text/plain; charset="utf-8")
Lspci.txt Edit (10.1 KiB, text/plain; charset="utf-8")
Lsusb.txt Edit (1.3 KiB, text/plain; charset="utf-8")
Lsusb-t.txt Edit (2.5 KiB, text/plain; charset="utf-8")
Lsusb-v.txt Edit (160.6 KiB, text/plain; charset="utf-8")
PrintingPackages.txt Edit (1.1 KiB, text/plain; charset="utf-8")
ProcCpuinfo.txt Edit (4.8 KiB, text/plain; charset="utf-8")
ProcCpuinfoMinimal.txt Edit (1.2 KiB, text/plain; charset="utf-8")
ProcEnviron.txt Edit (115 bytes, text/plain; charset="utf-8")
ProcInterrupts.txt Edit (3.1 KiB, text/plain; charset="utf-8")
ProcModules.txt Edit (8.8 KiB, text/plain; charset="utf-8")
UdevDb.txt Edit (342.5 KiB, text/plain; charset="utf-8")

Revision history for this message

Marc Deslauriers (mdeslaur) wrote on 2020-04-01:

I just started getting this behaviour on 18.04 for the past few weeks too.

Revision history for this message

Till Kamppeter (till-kamppeter) wrote on 2020-04-01:

When did the notifications start to occur? Are you running 20.04 already for longer and suddenly, probably after an update, the notifications started? Or did you switch from an older Ubuntu version (18.04, 19.10) to 20.04 and after this upgrade the notifications started? Or did you even observe the notifications on an Ubuntu version older than 20.04?

Changed in cups (Ubuntu):
status:	New → Incomplete

Revision history for this message

Alan Pope 🍺🐧🐱 🦄 (popey) wrote on 2020-04-01:

I am getting it on 3 machines. One is a clean install of 20.04 from the media dated 20200301. Another is an upgrade done some weeks back which was previously 18.04 installed from media dated 20190210.

I can't tell you when I started getting it, but it's been a while. The clean install has been getting it and I just thought it was because I was getting software updates that restarted cups or something. Then I noticed a couple of days ago it happens to all the machines at midnight. Then I waited a couple of days before reporting the bug, to confirm that's the case. The screenshot is a collection of 3 notifications over 3 nights. I don't recall seeing it on older releases.

Revision history for this message

Marc Deslauriers (mdeslaur) wrote on 2020-04-01:

I can reproduce the notification just by doing "systemctl restart cups", so perhaps it is related to the logrotate job restarting cups?

Revision history for this message

Marc Deslauriers (mdeslaur) wrote on 2020-04-01:

I have two printers. I've had two printers configured in cups for a long time.

I believe this issue started happening at the same time that a third printer started appearing automatically by cups, which is a duplicate of a printer I already have configured:

Color-LaserJet-CP2025dn
HP_OfficeJet_Pro_7740_series_7646EB_
<email address hidden>

The third printer is being added automatically, even when I remove it, and is the one that is being displayed in notifications.

Revision history for this message

Till Kamppeter (till-kamppeter) wrote on 2020-04-01:

@mdeslaur, could you attach your /etc/cups/cups-browsed.conf file to this bug report? Thanks.

Revision history for this message

Marc Deslauriers (mdeslaur) wrote on 2020-04-01:

cups-browsed.conf Edit (26.3 KiB, text/plain)

Revision history for this message

Till Kamppeter (till-kamppeter) wrote on 2020-04-01:

Could you edit /etc/cups/cups-browsed.conf to have a line

DebugLogging file

and then restart cups-browsed?

Once done, restart CUPS and wait until you get the notification. Then attach /var/log/cups/cups-browsed_log to this bug report.

Revision history for this message

Marc Deslauriers (mdeslaur) wrote on 2020-04-01:

#10

cups-browsed_log Edit (233.0 KiB, text/plain)

Revision history for this message

Till Kamppeter (till-kamppeter) wrote on 2020-04-01:

#11

Please run the command

lpstat -v

and post the output here. Thanks.

Revision history for this message

Marc Deslauriers (mdeslaur) wrote on 2020-04-01:

#12

$ lpstat -v
device for Color-LaserJet-CP2025dn: hp:/net/HP_Color_LaserJet_CP2025dn?ip=192.168.66.6
device for HP_OfficeJet_Pro_7740_series_7646EB_: ipp://HP40B0347646EB.local:631/ipp/print
device for <email address hidden>: ipps://HP40B0347646EB.local:443/ipp/print

Revision history for this message

Till Kamppeter (till-kamppeter) wrote on 2020-04-01:

#13

Could you stp cups-browsed, then run

lpstat -v

post the output here, then run

lpadmin -x <email address hidden>

Now start cups-browsed again and wait until you get a notification, or if there does not show any, for something like two minutes.

Now run

lpstat -v

again and post the output. Also attach /var/log/cups/cups-browsed_log.

Revision history for this message

Marc Deslauriers (mdeslaur) wrote on 2020-04-01:

#14

Sure...

# systemctl stop cups-browsed
# rm /var/log/cups/cups-browsed_log
# lpstat -v
device for Color-LaserJet-CP2025dn: hp:/net/HP_Color_LaserJet_CP2025dn?ip=192.168.66.6
device for HP_OfficeJet_Pro_7740_series_7646EB_: ipp://HP40B0347646EB.local:631/ipp/print
# lpadmin -x <email address hidden>
lpadmin: The printer or class does not exist.
# systemctl start cups-browsed
# lpstat -v
device for Color-LaserJet-CP2025dn: hp:/net/HP_Color_LaserJet_CP2025dn?ip=192.168.66.6
device for HP_OfficeJet_Pro_7740_series_7646EB_: ipp://HP40B0347646EB.local:631/ipp/print
device for <email address hidden>: ipps://HP40B0347646EB.local:443/ipp/print

Revision history for this message

Marc Deslauriers (mdeslaur) wrote on 2020-04-01:

#15

cups-browsed_log Edit (115.6 KiB, text/plain)

Revision history for this message

Till Kamppeter (till-kamppeter) wrote on 2020-04-01:

#16

Could you check which version of cups-browsed are you using?

dpkg -l cups-browsed

Looking into your cups-browsed_log it seems that you have an old version.

To clean up any possible mess you could try

sudo apt install --reinstall cups-browsed

Revision history for this message

Marc Deslauriers (mdeslaur) wrote on 2020-04-01:

#17

I'm using the latest available version on bionic:
cups-browsed 1.20.2-0ubuntu3.1

What version are you expecting me to be running?

Revision history for this message

Till Kamppeter (till-kamppeter) wrote on 2020-04-01:

#18

This thread started with 20.04, so I thought you have 20.04, too. 20.04 comes with cups-browsed 1.27.3 and this version would not create this extra queue any more about which you are complaining.

Revision history for this message

Marc Deslauriers (mdeslaur) wrote on 2020-04-01:

#19

Apologies for hijacking Alan's bug. I thought we were experiencing the same symptoms.
I'll let Alan add his info.

Revision history for this message

Launchpad Janitor (janitor) wrote on 2020-06-01:

#20

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

Changed in cups (Ubuntu):
status:	Incomplete → Expired

Till Kamppeter (till-kamppeter) on 2020-06-05

Changed in cups (Ubuntu):
status:	Expired → Triaged

Revision history for this message

Jonathan Kayne (jzkmath) wrote on 2020-06-11:

#21

This is still occuring in 20.04 along with the notification at bootup. It has not been fixed.

Revision history for this message

Sebastien Bacher (seb128) wrote on 2020-06-16:

#22

Till, could you have a look to that? It has been mentioned on bug #1882462 as well, from the log there

'Jun 12 00:00:01 hero systemd[1]: Starting Rotate log files...
Jun 12 00:00:01 hero systemd[1]: Starting Daily man-db regeneration...
Jun 12 00:00:01 hero systemd[1]: Stopping Make remote CUPS printers available locally...
Jun 12 00:00:01 hero systemd[1]: cups-browsed.service: Succeeded.
Jun 12 00:00:01 hero systemd[1]: Stopped Make remote CUPS printers available locally.
Jun 12 00:00:01 hero systemd[1]: Stopping CUPS Scheduler...
Jun 12 00:00:01 hero systemd[1]: cups.service: Succeeded.
Jun 12 00:00:01 hero systemd[1]: Stopped CUPS Scheduler.
Jun 12 00:00:01 hero systemd[1]: cups.path: Succeeded.
...
'

Could you try to see why cups services restart there? Does it has to do with the log rotation?

Changed in cups (Ubuntu):
importance:	Undecided → Low
assignee:	nobody → Till Kamppeter (till-kamppeter)

Revision history for this message

Sebastien Bacher (seb128) wrote on 2020-06-16:

#23

IRC discussion extract

<ddstreet> seb128 see /etc/logrotate.d/cups-daemon postrotate "invoke-rc.d --quiet cups restart > /dev/null"; and cups-browsed.service has Requires: cups.service so it will restart, too
usually it's so the daemon closes the old logfile and opens the new one, but a full restart does seem excessive

Revision history for this message

Till Kamppeter (till-kamppeter) wrote on 2020-06-16:

#24

I have already found a solution for this and applied it upstream (1.27.5, already in Grrovy).

The problem is that near midnight, for the log rotate cups-browsed is stopped and restarted. Stopping cups-browsed makes the cups-browsed-generated print queues getting removed and when re-starting cups-browsed afterwards they are generated again. This causes the notifications.

My approach is to let cups-browsed not remove the queues on shut-down, on re-start cups-browsed connects to these queues again (as I have designed cups-browsed to cope with crashes) and so no queue-creation happens.

Zdenek Dohnal from Red Hat suggests modifying gnome-settings-daemon to identify queues coming from cups-browsed and not notifying then. See

https://github.com/OpenPrinting/cups-filters/issues/241

Marking as fixed as my approach has made it into Groovy already.