You are not logged in.
This seems like an inordinate amout of time to start:
$ systemd-analyze blame | grep cups
4.321s org.cups.cupsd.service
The biggest delay in it's chain is systemd-networkd.service, but 335ms seems fine:
$ systemd-analyze critical-chain org.cups.cupsd.service
The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.
org.cups.cupsd.service +4.321s
└─network.target @9.787s
└─systemd-networkd.service @9.451s +335ms
└─dbus.service @7.845s
└─basic.target @7.842s
└─sockets.target @7.842s
└─pcscd.socket @7.842s
└─sysinit.target @7.812s
└─systemd-timesyncd.service @7.690s +122ms
└─systemd-tmpfiles-setup.service @7.557s +121ms
└─local-fs.target @7.556s
└─boot.mount @7.447s +109ms
└─dev-disk-by\x2duuid-552E\x2d4A68.device @7.418s
::EDIT:: The service logs nothing; status looks good:
$ systemctl status org.cups.cupsd.service
● org.cups.cupsd.service - CUPS Scheduler
Loaded: loaded (/usr/lib/systemd/system/org.cups.cupsd.service; enabled; vendor preset: disabled)
Active: active (running) since Sun 2017-05-28 13:47:28 JST; 15min ago
Docs: man:cupsd(8)
Main PID: 545 (cupsd)
Status: "Scheduler is running..."
Tasks: 5 (limit: 4915)
CGroup: /system.slice/org.cups.cupsd.service
├─545 /usr/bin/cupsd -l
├─732 /usr/lib/cups/notifier/dbus dbus://
├─748 /usr/lib/cups/notifier/dbus dbus://
└─749 /usr/lib/cups/notifier/dbus dbus://
In case you were curious, a full plot:
Last edited by quequotion (2017-06-25 00:08:38)
makepkg-optimize · indicator-powersave · pantheon-{3d,lite} · {pantheon,higan}-qq
Offline
At first I thought it might be wasting time looking for my network connected printer, but it takes the same amount of time even if the printer is on and ready when the computer boots. Either it's still wasting time looking for other network connected printers or this has nothing to do with it.
Last edited by quequotion (2017-06-22 03:57:26)
makepkg-optimize · indicator-powersave · pantheon-{3d,lite} · {pantheon,higan}-qq
Offline
├─732 /usr/lib/cups/notifier/dbus dbus:// ├─748 /usr/lib/cups/notifier/dbus dbus:// └─749 /usr/lib/cups/notifier/dbus dbus://
What is that about? Neither of my boxes have those processes running. Is this related to your other thread?
Offline
├─732 /usr/lib/cups/notifier/dbus dbus:// ├─748 /usr/lib/cups/notifier/dbus dbus:// └─749 /usr/lib/cups/notifier/dbus dbus://
What is that about?
I have no idea at all.
EDIT again: I suspect they are something that only exists temporarily; ie to notify about a print job or cache jobs for a printer. Perhaps you would find them existing intermittently.
Is this related to your other thread?
No.
EDIT: I posted this thread a month ago; the service still takes too long to load on boot (4.111s on the last boot), but the extra dbus notifiers are not present at the moment:
● org.cups.cupsd.service - CUPS Scheduler
Loaded: loaded (/usr/lib/systemd/system/org.cups.cupsd.service; disabled; vendor preset: disabled)
Active: active (running) since Thu 2017-06-22 11:54:30 JST; 1h 20min ago
Docs: man:cupsd(8)
Main PID: 548 (cupsd)
Status: "Scheduler is running..."
Tasks: 2 (limit: 4915)
CGroup: /system.slice/org.cups.cupsd.service
└─548 /usr/bin/cupsd -l
In case you were curious, today's blame:
4.790s dev-md126p2.device
4.178s udisks2.service
4.111s org.cups.cupsd.service
2.597s polkit.service
2.212s upower.service
1.775s lm_sensors.service
1.584s lightdm.service
1.396s systemd-logind.service
1.155s systemd-udevd.service
1.089s systemd-tmpfiles-setup-dev.service
960ms systemd-journald.service
644ms systemd-modules-load.service
578ms dev-hugepages.mount
577ms dev-mqueue.mount
530ms systemd-networkd.service
509ms resume.swap
456ms systemd-binfmt.service
444ms accounts-daemon.service
411ms sys-kernel-debug.mount
356ms proc-sys-fs-binfmt_misc.mount
333ms colord.service
276ms systemd-udev-trigger.service
274ms alsa-restore.service
273ms systemd-tmpfiles-clean.service
268ms systemd-random-seed.service
192ms kmod-static-nodes.service
189ms bluetooth.service
174ms systemd-sysctl.service
151ms systemd-timesyncd.service
139ms systemd-tmpfiles-setup.service
138ms systemd-remount-fs.service
102ms systemd-localed.service
94ms boot.mount
86ms rtkit-daemon.service
82ms systemd-journal-flush.service
78ms systemd-hostnamed.service
76ms user@1000.service
46ms systemd-user-sessions.service
37ms systemd-update-utmp.service
27ms sys-kernel-config.mount
12ms sys-fs-fuse-connections.mount
1ms tmp.mount
EDIT again: Keep in mind this thread is for cups's service. dev-md126p2.device takes a long time setting up a the root partition, which is on a 4-disk RAID:0 and I don't expect it can do much better; udisks2.service is probably waiting for that and has several other devices to configure (another hard disk, an optical drive, multiple virtual devices on a card reader) so I don't expect it can be much faster either; in any case neither should have anything to do with org.cups.cupsd.service's sluggishness.
Last edited by quequotion (2017-07-23 00:07:24)
makepkg-optimize · indicator-powersave · pantheon-{3d,lite} · {pantheon,higan}-qq
Offline
Could it be that cups suffers from the same cause?
Can you try w/o the raid? Does it provide any path that could be relevant for cups?
Online
Can you try w/o the raid?
It is the root partition
Does it provide any path that could be relevant for cups?
If loading files from the drive were a problem for cups, I feel like it would be a problem for everything else; like all the services would take much longer to load. To be honest, I do not know why this is not the case, but it does not seem to be the case (for everything else).
EDIT: There are these two disk-related services in its critical chain:
└─boot.mount @7.446s +228ms
└─dev-disk-by\x2duuid-552E\x2d4A68.device @7.434s
552E-4A68 is the UEFI boot partition, which is also on the raid device:
$ udevadm info /dev/disk/by-uuid/552E-4A68
P: /devices/virtual/block/md126/md126p1
N: md126p1
L: 100
S: disk/by-id/md-uuid-959bead4:9ce389c6:6cf4caa1:71ffd6b2-part1
S: disk/by-uuid/552E-4A68
S: md/core_0p1
E: DEVLINKS=/dev/md/core_0p1 /dev/disk/by-id/md-uuid-959bead4:9ce389c6:6cf4caa1:71ffd6b2-part1 /dev/disk/by-uuid/552E-4A68
E: DEVNAME=/dev/md126p1
E: DEVPATH=/devices/virtual/block/md126/md126p1
E: DEVTYPE=partition
E: ID_FS_TYPE=vfat
E: ID_FS_USAGE=filesystem
E: ID_FS_UUID=552E-4A68
E: ID_FS_UUID_ENC=552E-4A68
E: ID_FS_VERSION=FAT32
E: ID_PART_ENTRY_DISK=9:126
E: ID_PART_ENTRY_NUMBER=1
E: ID_PART_ENTRY_OFFSET=2048
E: ID_PART_ENTRY_SCHEME=gpt
E: ID_PART_ENTRY_SIZE=999424
E: ID_PART_ENTRY_TYPE=c12a7328-f81f-11d2-ba4b-00a0c93ec93b
E: ID_PART_ENTRY_UUID=fa65eb50-0667-4593-b7f9-3971b0e0e578
E: MAJOR=259
E: MD_CONTAINER=/dev/md/imsm0
E: MD_DEVICES=4
E: MD_DEVICE_sda_DEV=/dev/sda
E: MD_DEVICE_sda_ROLE=0
E: MD_DEVICE_sdb_DEV=/dev/sdb
E: MD_DEVICE_sdb_ROLE=1
E: MD_DEVICE_sdc_DEV=/dev/sdc
E: MD_DEVICE_sdc_ROLE=2
E: MD_DEVICE_sdd_DEV=/dev/sdd
E: MD_DEVICE_sdd_ROLE=3
E: MD_DEVNAME=core_0
E: MD_LEVEL=raid0
E: MD_MEMBER=0
E: MD_UUID=959bead4:9ce389c6:6cf4caa1:71ffd6b2
E: MINOR=0
E: PARTN=1
E: SUBSYSTEM=block
E: TAGS=:systemd:
E: UDISKS_IGNORE=1
E: USEC_INITIALIZED=14998117
And in case you were curious, today's full critical-chain:
graphical.target @14.115s
└─multi-user.target @14.115s
└─cups-browsed.service @14.115s
└─org.cups.cupsd.service @9.955s +4.159s (RED)
└─network.target @9.952s
└─systemd-networkd.service @9.471s +480ms (RED)
└─dbus.service @8.012s
└─basic.target @7.944s
└─sockets.target @7.944s
└─pcscd.socket @7.944s
└─sysinit.target @7.944s
└─systemd-timesyncd.service @7.805s +138ms (RED)
└─systemd-tmpfiles-setup.service @7.675s +129ms (RED)
└─local-fs.target @7.674s
└─boot.mount @7.446s +228ms (RED)
└─dev-disk-by\x2duuid-552E\x2d4A68.device @7.434s
Last edited by quequotion (2017-06-23 00:47:28)
makepkg-optimize · indicator-powersave · pantheon-{3d,lite} · {pantheon,higan}-qq
Offline
mmm... does it take equally long to (stop and) start the service at runtime?
Network printers or smb shares?
Online
mmm... does it take equally long to (stop and) start the service at runtime?
EDIT: I did not realize systemd-analyze can be used on services started after boot:
systemd-analyze critical-chain org.cups.cupsd.service
The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.
org.cups.cupsd.service +140ms
└─network.target @10.056s
└─systemd-networkd.service @9.560s +495ms
└─dbus.service @8.088s
└─basic.target @8.010s
└─sockets.target @8.010s
└─pcscd.socket @8.010s
└─sysinit.target @7.964s
└─systemd-timesyncd.service @7.811s +152ms
└─systemd-tmpfiles-setup.service @7.686s +122ms
└─local-fs.target @7.685s
└─boot.mount @7.526s +158ms
└─dev-disk-by\x2duuid-552E\x2d4A68.device @7.502s
Network printer
Yes, the printer (wifi) and the pc (ethernet) are connected to a local router and have fixed IPs.
smb shares?
No.
Last edited by quequotion (2017-06-23 20:27:21)
makepkg-optimize · indicator-powersave · pantheon-{3d,lite} · {pantheon,higan}-qq
Offline
I guess I don't have to tell what to try next, right? ;-)
Online
I guess I don't have to tell what to try next, right? ;-)
I've already tested with the printer on and off during boot (look back a few posts), which was inconclusive. I haven't tried uninstalling the printer because I still have nightmares about getting it to work in the first place. If you think that's what I need to do, I can give it a shot, but it might be weeks before I can reliably print again.
makepkg-optimize · indicator-powersave · pantheon-{3d,lite} · {pantheon,higan}-qq
Offline
And if you pull eth0 for a test?
Online
And if you pull eth0 for a test?
It's an onboard NIC, so I'll have to do that with something like modprobe.blacklist=tg3 as a kernel paramater (and not use the internet for a while).
I'll be back with results... probably...
Last edited by quequotion (2017-06-23 20:59:09)
makepkg-optimize · indicator-powersave · pantheon-{3d,lite} · {pantheon,higan}-qq
Offline
It should suffice to unplug the cable.
Online
Unfortunately, not much difference.
Offline blame:
5.390s dev-md126p2.device
4.014s org.cups.cupsd.service
2.978s ldconfig.service
2.873s udisks2.service
2.228s polkit.service
2.205s systemd-hwdb-update.service
1.990s upower.service
1.476s lm_sensors.service
1.386s systemd-udevd.service
1.283s systemd-journald.service
1.277s systemd-logind.service
1.268s bluetooth.service
1.103s lightdm.service
1.040s accounts-daemon.service
907ms systemd-modules-load.service
689ms systemd-tmpfiles-setup-dev.service
642ms systemd-sysusers.service
560ms resume.swap
403ms systemd-networkd.service
325ms systemd-sysctl.service
301ms systemd-journal-catalog-update.service
289ms sys-kernel-debug.mount
289ms dev-mqueue.mount
274ms systemd-tmpfiles-setup.service
268ms systemd-random-seed.service
253ms colord.service
238ms alsa-restore.service
225ms systemd-localed.service
213ms dev-hugepages.mount
212ms systemd-remount-fs.service
194ms systemd-timesyncd.service
193ms systemd-udev-trigger.service
123ms systemd-binfmt.service
121ms boot.mount
102ms user@1000.service
91ms kmod-static-nodes.service
73ms systemd-journal-flush.service
69ms systemd-hostnamed.service
57ms systemd-update-utmp.service
35ms rtkit-daemon.service
33ms systemd-update-done.service
11ms sys-fs-fuse-connections.mount
6ms systemd-user-sessions.service
5ms proc-sys-fs-binfmt_misc.mount
1ms sys-kernel-config.mount
1ms tmp.mount
Offline chain:
The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.
graphical.target @17.014s
└─multi-user.target @17.013s
└─cups-browsed.service @17.013s
└─org.cups.cupsd.service @12.998s +4.014s
└─network.target @12.995s
└─systemd-networkd.service @12.591s +403ms
└─dbus.service @11.348s
└─basic.target @11.321s
└─sockets.target @11.321s
└─pcscd.socket @11.321s
└─sysinit.target @11.301s
└─systemd-update-done.service @11.267s +33ms
└─ldconfig.service @8.288s +2.978s
└─local-fs.target @8.288s
└─boot.mount @8.166s +121ms
└─dev-disk-by\x2duuid-552E\x2d4A68.device @8.126s
makepkg-optimize · indicator-powersave · pantheon-{3d,lite} · {pantheon,higan}-qq
Offline
Can you not switch from target based activation to socket based activation for cups?
Offline
Can you not switch from target based activation to socket based activation for cups?
As far as I know this is the default systemd configuration for cups. The nightmares I mentioned before derive from getting my particular printer drivers installed and working (it's an Epson EP-806A multifunction unit; getting both the scanner and the printer working correctly over wifi at the same time was hell, but did not involve doing anything to systemd services).
There is already a socket active:
$ systemctl status org.cups.cupsd.socket
● org.cups.cupsd.socket - CUPS Scheduler
Loaded: loaded (/usr/lib/systemd/system/org.cups.cupsd.socket; enabled; vendor preset: disabled)
Active: active (running) since Sat 2017-06-24 18:50:27 JST; 7min ago
Listen: /run/cups/cups.sock (Stream)
Which must be responsible for launching the service, as it is--and as far as I know always has been--"disabled":
$ systemctl status org.cups.cupsd.service
● org.cups.cupsd.service - CUPS Scheduler
Loaded: loaded (/usr/lib/systemd/system/org.cups.cupsd.service; disabled; vendor preset: disabled)
Active: active (running) since Sat 2017-06-24 18:50:34 JST; 10min ago
Docs: man:cupsd(8)
Main PID: 540 (cupsd)
Status: "Scheduler is running..."
Tasks: 2 (limit: 4915)
CGroup: /system.slice/org.cups.cupsd.service
└─540 /usr/bin/cupsd -l
Last edited by quequotion (2017-06-24 10:08:58)
makepkg-optimize · indicator-powersave · pantheon-{3d,lite} · {pantheon,higan}-qq
Offline
cups-browsed.service has this install section
[Install]
WantedBy=multi-user.target
You can see this in the critical chain cups-browsed.service under multi-user.target, from /usr/lib/systemd/system/cups-browsed.service
Requires=org.cups.cupsd.service
This starts org.cups.cupsd.service. So booting the system to graphical.target or multi-user.target will start org.cups.cupsd.service not socket based activation.
You have followed CUPS#cups-browsed and I agree the wiki page does not mention socket based activation.
However if all the printer queues are fully configured you may be able to disable cups-browsed.service and use org.cups.cupsd.socket to starts cups when something attempts to connect to the service via the socket.
Edit:
To test you would also need to disable org.cups.cupsd.service then ensure org.cups.cupsd.socket is still enabled.
Last edited by loqs (2017-06-24 11:46:37)
Offline
You have followed CUPS#cups-browsed and I agree the wiki page does not mention socket based activation.
However if all the printer queues are fully configured you may be able to disable cups-browsed.service and use org.cups.cupsd.socket to starts cups when something attempts to connect to the service via the socket.
That's the ticket! Thank you loqs (and everyone else who helped)!
Cups is down to a much more reasonable time:
$ systemd-analyze blame | grep cups
1.352s org.cups.cupsd.service
EDIT: Added a note in the wiki, linked to loqs's post.
Last edited by quequotion (2017-06-25 00:30:06)
makepkg-optimize · indicator-powersave · pantheon-{3d,lite} · {pantheon,higan}-qq
Offline