LINUX.ORG.RU
решено Форум — Desktop  

Очень долгая загрузка системы

 , , , ,


0

1

Система Debian Testing, gnome
После обновления вдруг стала загружаться чудовищно долго

$ systemd-analyze
Startup finished in 3.112s (kernel) + 1min 33.470s (userspace) = 1min 36.583s
graphical.target reached after 1min 33.453s in userspace

это на SSD. Ранее старт всегда был более чем быстрым.

Полдня лазил по логам, из интересного нашел только такое

************
ноя 04 23:56:30 debian systemd[1]: Started User Manager for UID 1000.
ноя 04 23:56:30 debian systemd[1238]: Started D-Bus User Message Bus.
ноя 04 23:57:47 debian systemd[1]: ssh.service: Start-pre operation timed out. Terminating.
ноя 04 23:57:47 debian systemd[1]: ssh.service: Failed with result 'timeout'.
ноя 04 23:57:47 debian systemd[1]: Failed to start OpenBSD Secure Shell server.
ноя 04 23:57:47 debian systemd[1]: Reached target Multi-User System.
ноя 04 23:57:47 debian systemd[1]: Reached target Graphical Interface.
ноя 04 23:57:47 debian systemd[1]: Starting Update UTMP about System Runlevel Changes...
ноя 04 23:57:47 debian systemd[1]: Started Update UTMP about System Runlevel Changes.
ноя 04 23:57:47 debian systemd[1]: Startup finished in 3.112s (kernel) + 1min 33.470s (userspace) = 1min 36.583s.

получается что на запуск dbus ушло 1.17сек. как то слишком много.

Никакой экзотической ругани в логах не нашел.

sudo journalctl -u dbus.service
-- Logs begin at Sun 2018-11-04 23:56:11 MSK, end at Mon 2018-11-05 00:28:04 MSK. --
ноя 04 23:56:14 debian systemd[1]: Started D-Bus System Message Bus.
ноя 04 23:56:14 debian dbus-daemon[705]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.5' (uid=0 pid=677 comm=«/usr/lib/accountsservice/accounts-daemon »)
ноя 04 23:56:14 debian dbus-daemon[705]: [system] Activating via systemd: service name='org.freedesktop.ColorManager' unit='colord.service' requested by ':1.9' (uid=0 pid=696 comm=«/usr/sbin/cupsd -l »)
ноя 04 23:56:14 debian dbus-daemon[705]: [system] Successfully activated service 'org.freedesktop.PolicyKit1'
ноя 04 23:56:14 debian dbus-daemon[705]: [system] Successfully activated service 'org.freedesktop.ColorManager'
ноя 04 23:58:05 debian dbus-daemon[705]: [system] Activating via systemd: service name='org.freedesktop.UPower' unit='upower.service' requested by ':1.35' (uid=1000 pid=1328 comm=«/usr/bin/gnome-shell »)
ноя 04 23:58:05 debian dbus-daemon[705]: [system] Activating via systemd: service name='org.freedesktop.GeoClue2' unit='geoclue.service' requested by ':1.35' (uid=1000 pid=1328 comm=«/usr/bin/gnome-shell »)
ноя 04 23:58:05 debian dbus-daemon[705]: [system] Successfully activated service 'org.freedesktop.GeoClue2'
ноя 04 23:58:05 debian dbus-daemon[705]: [system] Successfully activated service 'org.freedesktop.UPower'
ноя 04 23:58:06 debian dbus-daemon[705]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.51' (uid=1000 pid=1448 comm=«/usr/lib/gnome-settings-daemon/gs
ноя 04 23:58:06 debian dbus-daemon[705]: [system] Activating via systemd: service name='org.freedesktop.locale1' unit='dbus-org.freedesktop.locale1.service' requested by ':1.57' (uid=1000 pid=1487 comm=»/usr/lib/gnome-settings-daemon/gsd-ke
ноя 04 23:58:06 debian dbus-daemon[705]: [system] Successfully activated service 'org.freedesktop.hostname1'
ноя 04 23:58:06 debian dbus-daemon[705]: [system] Successfully activated service 'org.freedesktop.locale1'

посмотрел что там делается между upower.service и colord.service
стартуют без ошибок и быстро. но между ними потерялась минута с лишним.

$ sudo journalctl -u upower.service
-- Logs begin at Sun 2018-11-04 23:56:11 MSK, end at Mon 2018-11-05 00:38:50 MSK. --
ноя 04 23:58:05 debian systemd[1]: Starting Daemon for power management...
ноя 04 23:58:05 debian systemd[1]: Started Daemon for power management.
$ sudo journalctl -u colord.service
-- Logs begin at Sun 2018-11-04 23:56:11 MSK, end at Mon 2018-11-05 00:39:09 MSK. --
ноя 04 23:56:14 debian systemd[1]: Starting Manage, Install and Generate Color Profiles...
ноя 04 23:56:14 debian systemd[1]: Started Manage, Install and Generate Color Profiles.


Можно как то понять на что уходит время?

★

Ответ на: комментарий от Elmer_

нет. не это.
Убил openssh выиграл 2 секунды.

griz ★
() автор топика
Ответ на: комментарий от Elmer_

да, забыл сказать.
я так пробовал. Но ничего ужасающего там не увидел
12.395s ssh.service
1.801s systemd-udev-settle.service
1.662s udisks2.service
602ms vmware-USBArbitrator.service
507ms vboxdrv.service
479ms lvm2-activation-early.service
351ms atd.service
309ms exim4.service
285ms upower.service
240ms systemd-logind.service
234ms rc-local.service
209ms systemd-timesyncd.service
201ms nmbd.service
198ms dev-sda1.device
185ms smbd.service
169ms lvm2-activation-net.service
167ms autofs.service
162ms accounts-daemon.service
135ms systemd-fsck@dev-mapper-debianPC\x2dhome.service
125ms systemd-fsck@dev-mapper-debianPC\x2dbackup.service
106ms user@1000.service
104ms rtkit-daemon.service
102ms keyboard-setup.service
98ms acpi-support.service
97ms systemd-journald.service
79ms wpa_supplicant.service
72ms networking.service
70ms apparmor.service
66ms gdomap.service
62ms alsa-restore.service
58ms systemd-udev-trigger.service
57ms polkit.service
56ms lm-sensors.service
53ms pppd-dns.service
51ms ecbd.service
49ms nodm.service
47ms sysstat.service
43ms fglrx-atieventsd.service
41ms minissdpd.service
41ms media-data.mount
40ms gdm3.service
37ms colord.service
37ms systemd-journal-flush.service
36ms dictd.service
34ms rsyslog.service
33ms lvm2-monitor.service
31ms systemd-udevd.service
31ms lvm2-activation.service
29ms media-backup.mount
29ms lightdm.service
28ms lvm2-pvscan@8:33.service
26ms systemd-modules-load.service
23ms network-manager.service
23ms ntp.service
22ms run-rpc_pipefs.mount
21ms switcheroo-control.service
20ms binfmt-support.service
20ms kmod-static-nodes.service
18ms sys-fs-fuse-connections.mount
17ms systemd-tmpfiles-setup.service
16ms systemd-fsck@dev-sda3.service
15ms systemd-tmpfiles-setup-dev.service
15ms rpcbind.service
14ms home.mount
13ms systemd-user-sessions.service
13ms systemd-update-utmp.service
13ms rpc-statd.service
13ms lvm2-pvscan@8:20.service
12ms systemd-sysusers.service
11ms systemd-update-utmp-runlevel.service
11ms systemd-remount-fs.service
11ms lvm2-pvscan@8:17.service
10ms sys-kernel-debug.mount
10ms vboxweb-service.service
10ms var-spool.mount


с openssh надо конечно разбираться, но это не то.

griz ★
() автор топика

Еще из интересного нашел вот это
$ sudo journalctl -u atd.service
-- Logs begin at Mon 2018-11-05 00:51:23 MSK, end at Mon 2018-11-05 00:53:45 MSK. --
ноя 05 00:51:26 debian systemd[1]: Starting Deferred execution scheduler...
ноя 05 00:51:26 debian find[678]: /usr/bin/find: ‘/var/spool/cron/atjobs’: Нет такого файла или каталога
ноя 05 00:51:26 debian systemd[1]: Started Deferred execution scheduler.
ноя 05 00:51:26 debian atd[721]: Cannot change to /var/spool/cron/atjobs: No such file or directory
ноя 05 00:51:26 debian systemd[1]: atd.service: Main process exited, code=exited, status=1/FAILURE
ноя 05 00:51:26 debian systemd[1]: atd.service: Failed with result 'exit-code'.
ноя 05 00:51:26 debian systemd[1]: atd.service: Service RestartSec=100ms expired, scheduling restart.
ноя 05 00:51:26 debian systemd[1]: atd.service: Scheduled restart job, restart counter is at 1.
ноя 05 00:51:26 debian systemd[1]: Stopped Deferred execution scheduler.
ноя 05 00:51:26 debian systemd[1]: Starting Deferred execution scheduler...
ноя 05 00:51:26 debian find[807]: /usr/bin/find: ‘/var/spool/cron/atjobs’: Нет такого файла или каталога
ноя 05 00:51:26 debian systemd[1]: Started Deferred execution scheduler.
ноя 05 00:51:26 debian atd[819]: Cannot change to /var/spool/cron/atjobs: No such file or directory
ноя 05 00:51:26 debian systemd[1]: atd.service: Main process exited, code=exited, status=1/FAILURE
ноя 05 00:51:26 debian systemd[1]: atd.service: Failed with result 'exit-code'.
ноя 05 00:51:26 debian systemd[1]: atd.service: Service RestartSec=100ms expired, scheduling restart.
ноя 05 00:51:26 debian systemd[1]: atd.service: Scheduled restart job, restart counter is at 2.
ноя 05 00:51:26 debian systemd[1]: Stopped Deferred execution scheduler.
ноя 05 00:51:26 debian systemd[1]: Starting Deferred execution scheduler...
ноя 05 00:51:26 debian find[1006]: /usr/bin/find: ‘/var/spool/cron/atjobs’: Нет такого файла или каталога
ноя 05 00:51:26 debian systemd[1]: Started Deferred execution scheduler.
ноя 05 00:51:26 debian atd[1010]: Cannot change to /var/spool/cron/atjobs: No such file or directory
ноя 05 00:51:26 debian systemd[1]: atd.service: Main process exited, code=exited, status=1/FAILURE
ноя 05 00:51:26 debian systemd[1]: atd.service: Failed with result 'exit-code'.
ноя 05 00:51:26 debian systemd[1]: atd.service: Service RestartSec=100ms expired, scheduling restart.
ноя 05 00:51:26 debian systemd[1]: atd.service: Scheduled restart job, restart counter is at 3.
ноя 05 00:51:26 debian systemd[1]: Stopped Deferred execution scheduler.
ноя 05 00:51:26 debian systemd[1]: Starting Deferred execution scheduler...
ноя 05 00:51:26 debian find[1118]: /usr/bin/find: ‘/var/spool/cron/atjobs’: Нет такого файла или каталога
ноя 05 00:51:26 debian systemd[1]: Started Deferred execution scheduler.
ноя 05 00:51:26 debian atd[1123]: Cannot change to /var/spool/cron/atjobs: No such file or directory
ноя 05 00:51:26 debian systemd[1]: atd.service: Main process exited, code=exited, status=1/FAILURE
ноя 05 00:51:26 debian systemd[1]: atd.service: Failed with result 'exit-code'.
ноя 05 00:51:26 debian systemd[1]: atd.service: Service RestartSec=100ms expired, scheduling restart.
ноя 05 00:51:26 debian systemd[1]: atd.service: Scheduled restart job, restart counter is at 4.
ноя 05 00:51:26 debian systemd[1]: Stopped Deferred execution scheduler.
ноя 05 00:51:26 debian systemd[1]: Starting Deferred execution scheduler...
ноя 05 00:51:26 debian find[1164]: /usr/bin/find: ‘/var/spool/cron/atjobs’: Нет такого файла или каталога
ноя 05 00:51:26 debian systemd[1]: Started Deferred execution scheduler.
ноя 05 00:51:26 debian atd[1169]: Cannot change to /var/spool/cron/atjobs: No such file or directory
ноя 05 00:51:26 debian systemd[1]: atd.service: Main process exited, code=exited, status=1/FAILURE
ноя 05 00:51:26 debian systemd[1]: atd.service: Failed with result 'exit-code'.
ноя 05 00:51:27 debian systemd[1]: atd.service: Service RestartSec=100ms expired, scheduling restart.
ноя 05 00:51:27 debian systemd[1]: atd.service: Scheduled restart job, restart counter is at 5.
ноя 05 00:51:27 debian systemd[1]: Stopped Deferred execution scheduler.
ноя 05 00:51:27 debian systemd[1]: atd.service: Start request repeated too quickly.
ноя 05 00:51:27 debian systemd[1]: atd.service: Failed with result 'exit-code'.
ноя 05 00:51:27 debian systemd[1]: Failed to start Deferred execution scheduler.

но что с ним делать пока не понимаю. у меня /var/spool развернут в памяти и по логике кто там должен на старте в нем свои директории и файлы создавать должны это сами делать.

griz ★
() автор топика
Ответ на: комментарий от griz

у меня /var/spool развернут в памяти и по логике кто там должен на старте в нем свои директории и файлы создавать должны это сами делать.

А кто тебе сказал, что они это могут делать?

Убери монтирование tmpfs в /var/spool, создай директории и проверь как запускается система.

anonymous
()

все страньше и страньше....
отключил загрузку ssh.service (напомню, на него systemd насчитал 12 секунд) и теперь не верю своим глазам
$ systemd-analyze
Startup finished in 3.208s (kernel) + 4.793s (userspace) = 8.001s
graphical.target reached after 4.778s in userspace

и все бы хорошо, но секундомер на телефоне говорит что от груба до рабочего стола ~1мин13сек.
где то теряется время которое systemd даже не считает.....

а отключение ssh на который типа тратилось 12 секунд ускорило загрузку совсем не на 12 секунд по данным systemd....

griz ★
() автор топика
Ответ на: комментарий от anonymous

да это в общем и не важно. отключил atd.service но ничего не изменилось.

griz ★
() автор топика
Ответ на: комментарий от griz

Убери из параметров ядра параметр quiet и допиши туда параметр verbose, после чего загрузись с этими параметрами.

Смотри что будет выводиться на экран.

anonymous
()
Ответ на: комментарий от superuser

вот это да!!!
действительно кончились случайные числа.
Теперь все работает штатно.

СПАСИБО!

griz ★
() автор топика
Ответ на: комментарий от griz

Интересно что виновато. У меня на ПК всё нормально, а на нетбуке на Atom 3735F такая же хрень случилась. И там и там Xubuntu 18.04 но ядра самосборные. Может что-то не хватает в конфиге ядра что под нетбук собрал. Ещё момент - на нетбуке ядро i386. Не знаю на что думать.

superuser ★★★★★
()

У меня кстати тоже после обновлении начал дольше грузиться Debian Testing, но разница составила секунду или две. Правда у меня KDE.

CryNet ★★★★★
()

Всю ночь просидел над похожей проблемой. Чудом вспомнил про эту тему на ЛОРе уже под утро. Потому что гуглил по другим словам.

Оно не просто «долго загружается». Оно ждёт каких-либо событий, чтобы с них генерировать random. Если ни мышь, ни клавиатуру не шевелить - вообще никогда не загрузится. Это в Buster + XFCE при первом логоне (или старте XFCE из консоли). Вход выполняется и тишина. Одна обоина. Не появляется рабочий стол хоть сколько жди, если устройства ввода не шевелить. haveged помогает.

Крайне увлекательна эта игра в линуксы.

Deleted
()
Ответ на: комментарий от Deleted

Ну кстати да, я не уловил связи что шевеление клавы способствует загрузке. Сейчас понимаю что так и было.

griz ★
() автор топика
Вы не можете добавлять комментарии в эту тему. Тема перемещена в архив.
Desktop