Bug 27564 - Загрузка системы стала занимать по 10 минут вместо 15 сек. Множественные застопоривания.
: Загрузка системы стала занимать по 10 минут вместо 15 сек. Множественные заст...
Status: CLOSED FIXED
: Sisyphus
(All bugs in Sisyphus/udev)
: unstable
: x86 Linux
: P3 normal
Assigned To:
:
:
: systemd
:
:
  Show dependency tree
 
Reported: 2012-07-24 01:26 by
Modified: 2013-03-24 09:55 (History)


Attachments
Вывод dmesg после мучительно долгой загрузки. (124.81 KB, text/plain)
2012-07-24 01:29, Vyacheslav Dikonov
no flags Details
Вывод systemd-analyze (977.26 KB, image/svg+xml)
2012-08-11 14:28, Vyacheslav Dikonov
no flags Details
Вывод dmesg с debug режимом systemd. (121.94 KB, text/plain)
2012-08-11 14:30, Vyacheslav Dikonov
no flags Details


Note

You need to log in before you can comment on or make changes to this bug.


Description From 2012-07-24 01:26:11
Система Сизиф на i7 с SSD (еще до systemd) обычно загружалась за 10-15 сек.
Теперь после серии обновлений этот процесс застопоривается в нескольких местах
и в итоге занимает по 10 минут. Тормоза в разные моменты загрузки возникали
после обновлений udev.

Я толком не понимаю, что происходит, где искать концы, и где лежат настройки
теперь, так что описываю симптомы наиболее заметных тормозов: 

1) Во время загрузки в районе подключения разделов тормоза на секунд на 60.
Возможно идет проверка разделов, но зачем это надо при каждой загрузке после
штатного выключения? Имеется softRAID 0 из двух 500Гб дисков (создан
установщиком ALT). Активности довольно шумных винчестеров в этом RAID не
слышно. 

2) Подтормаживание после сообщения "Starting Network connectivity". По времени
похоже на запуск PPTP туннеля в интернет. Возникло сегодня. Ранее это
происходило в фоне уже после запуска dm и не тормозило процесс. Интерфейсы
управляются etcnet. Вручную включать туннель через NM каждый день совсем не
хочется.

3) ГИГАНТСКИЙ ТОРМОЗ после сообщения "Started network connectivity". Причина
мне непонятна. Возник после обновления сегодня. Сопровождается сотнями записей
в dmesg вида  

systemd-udevd[8643]: failed to execute
'/lib/udev/socket:@/org/freedesktop/hal/udev_event'
'socket:@/org/freedesktop/hal/udev_event': No such file or directory

systemd-udevd[8648]: failed to execute
'/lib/udev/socket:/var/run/devkit/udev_socket'
'socket:/var/run/devkit/udev_socket': No such file or directory

Каталога /var/run/devkit действительно нет. Если создать вручную, то он
стирается. Что им управляет и на кой он сдался, если в итоге все работает?

Осложняющее обстоятельство: В ходе обновления 23/07/2012 упал dm и убил apt.
После этого я запустил apt-get -f install и заново dist-upgrade. Ошибок не
показало. После возникновения тормоза №3 пробовал переустановить все пакеты с
dev  в названии. Никаких ошибок и никакого эффекта. 


Что делать?
------- Comment #1 From 2012-07-24 01:29:24 -------
Created an attachment (id=5521) [details]
Вывод dmesg после мучительно долгой загрузки.
------- Comment #2 From 2012-07-24 20:31:58 -------
Сделал видеозапись, чтобы в замедленном режиме прочитать сообщения загрузки на
первой консоли.

после окончания стопора 1 появляется "Started udev Wait for Complete Device
Initialization", "Started Wait for storage scan" Затем все бежит до следующего
затыка. В старых версиях udev этой проблемы не было и работало все как часы.

После стопора 3 за секунду вываливается много сообщений и экран гаснет. Первое
из этих сообщений "[Failed] Failed to start SYSV". пакет udev-sysvinit стоит.
Оказалось, что в самом большом тормозе виноват  hal.

systemctl status haldaemon.service  говорит, что долго висит и не запускается
/etc/rc.d/init.d/haldaemon
------- Comment #3 From 2012-07-25 06:32:20 -------
У меня со вчерашнего дня тоже очень долгий затык на hal получился. Сделал
apt-get remove hal и забыл :)
------- Comment #4 From 2012-07-25 13:15:48 -------
hal давно противопоказан к установке в систему. Зачем он вам?
Если после его удаления всё работает, то я закрою этот баг как "NOTABUG".
Ещё могу в systemd(даже лучше в udev) добавить конфликт на hal.
------- Comment #5 From 2012-07-25 22:55:12 -------
Конфликт IMHO не стоит, ради чего-то этот пакет оставлялся.  Но пользоваться им
тоже не стоит, с другой стороны...
------- Comment #6 From 2012-07-26 06:30:35 -------
"Конфликт IMHO не стоит, ради чего-то этот пакет оставлялся"

Думаю, всё же стоит. А оставлялся пакет из-за libhal, на него ещё есть
зависимости:

> apt-get remove libhal
Reading Package Lists...
Building Dependency Tree...
The following packages will be REMOVED:
  alterator-mkbootflash amarok amarok-engine-xine amarok-mediadevice-daap
amarok-mediadevice-generic
  amarok-mediadevice-ipod amarok-mediadevice-mtp buzztard dekorator digikam
digikam-i18n doublecmd
  hal hal-cups-utils hal-mount-subfs icewm-startup-ivman ivman
kde-screensaver-tempest kdeaddons
  kdeaddons-akregator kdeaddons-kate kdeaddons-kfile kdeaddons-kicker
kdeaddons-konqueror
  kdeartwork-screensavers kdeartwork-styles-cde kdeartwork-styles-cde-kwin
kdeartwork-styles-glow
  kdeartwork-styles-glow-kwin kdeartwork-styles-icewm
kdeartwork-styles-icewm-kwin
  kdeartwork-styles-kde1 kdeartwork-styles-kde1-kwin kdeartwork-styles-kstep
  kdeartwork-styles-kstep-kwin kdeartwork-styles-openlook
kdeartwork-styles-openlook-kwin
  kdeartwork-styles-riscos kdeartwork-styles-riscos-kwin
kdeartwork-styles-smoothblend
  kdeartwork-styles-smoothblend-kwin kdeartwork-styles-system
kdeartwork-styles-system-kwin
  kdebase-common kdebase-devel kdebase-kcontrol kdebase-kdeprint kdebase-kio
kdebase-konqueror
  kdebase-kwrite kdebase-libkonq kdebase-libs kdebase-wm kdenetwork
kdenetwork-devel kdenetwork-kget
  kdepim kdepim-devel kdepim-kmail kdetoys kdetoys-eyes kdetoys-fifteen
kdetoys-kmoon
  kdetoys-kteatime kdetoys-ktux kdetoys-kweather kdeutils-kjots kdeutils-ksim
kdeutils-laptop kima
  kmplayer kpowersave ksplash-engine-moodin libbsl libbuzztard-core-devel
libbuzztard-core0
  libbuzztard-ic-devel libbuzztard-ic0 libhal libhal-devel
libopensync0-plugin-kdepim
  mediainfo-gui-KDE3 openbox-kde powersave qtrayvolman
0 upgraded, 0 newly installed, 85 removed and 0 not upgraded.
Need to get 0B of archives.
After unpacking 207MB disk space will be freed.
Do you want to continue? [Y/n] ^C
------- Comment #7 From 2012-07-26 10:10:24 -------
Прежде чем закрыть этот баг из-за HAL надо еще разобраться с тоже длинным
тормозом 1, после которого видны надписи: 

"Started udev Wait for Complete Device Initialization"
"Started Wait for storage scan" 

В более старой версии udev никакого тормоза не было, так что это регрессия.
------- Comment #8 From 2012-07-26 14:38:42 -------
(В ответ на комментарий №6)
> "Конфликт IMHO не стоит, ради чего-то этот пакет оставлялся"
> 
> Думаю, всё же стоит. А оставлялся пакет из-за libhal, на него ещё есть
> зависимости:

Может стоит удать из репозитория пакет(сервис) hal, оставить только libhal, раз
он кому-то нужен.
hal все равно не рабочий. Без конфликта наверно не обойтись, иначе его никто из
системы не удалит.
------- Comment #9 From 2012-07-26 14:39:47 -------
(В ответ на комментарий №7)
> Прежде чем закрыть этот баг из-за HAL надо еще разобраться с тоже длинным
> тормозом 1, после которого видны надписи: 
> 
> "Started udev Wait for Complete Device Initialization"
> "Started Wait for storage scan" 
> 
> В более старой версии udev никакого тормоза не было, так что это регрессия.

Т.е. этот тормоз остаётся после удаления hal?
------- Comment #10 From 2012-07-28 00:10:22 -------
И ещё стоит lspci на всякий показать (если стоят "странные" платы --
при удобном случае проверить без них).
------- Comment #11 From 2012-07-29 17:56:04 -------
Да. Тормоз №1 остался после удаления HAL. Прислать lspci пока не могу, так как
я в отъезде, но могу сказать, что там стоит Technotrend SkyStar 1 (DVB карта). 

Ядро из p5 на нем зависало из-за попытки повесить на спутниковый DVB-приемник
совершенно левый драйвер какой-то измерительной фигни, но это было много лет
назад. Поддержка SS1 100% обкатана уже очень давно. Тормоз впервые появился
где-то через месяц после внедрения systemd, причем ядро с тех пор не менялось
(hold), а udev - менялся.
------- Comment #12 From 2012-07-30 01:39:56 -------
Так какое ядро-то в итоге?

$ fgrep kernel /usr/share/doc/udev-187/README
        Linux kernel >= 2.6.39
------- Comment #13 From 2012-07-30 18:04:21 -------
> Так какое ядро-то в итоге?
> 
> $ fgrep kernel /usr/share/doc/udev-187/README
>         Linux kernel >= 2.6.39
3.2 или 3.3,  32bit,  Я пересобрал std-def с включением PAE. Точно версию смогу
назвать только к четвергу (я сейчас не дома).
------- Comment #14 From 2012-07-30 18:42:03 -------
(In reply to comment #13)
> > Так какое ядро-то в итоге?
> 3.2 или 3.3,  32bit,  Я пересобрал std-def с включением PAE.
А, ну хоть не 2.6.18... BTW есть std-pae, более-менее работает (только у меня
чаще не выходит из suspend to ram, но это детали).
------- Comment #15 From 2012-08-02 10:02:15 -------
Проверил. Ядро оказалось 3.3.1-std-pae-alt1. Есть ли debug-лог у systemd и как
его увидеть?
------- Comment #16 From 2012-08-04 10:54:34 -------
(В ответ на комментарий №15)
> Проверил. Ядро оказалось 3.3.1-std-pae-alt1. Есть ли debug-лог у systemd и как
> его увидеть?

конечно debug можно включить.
в /etc/systemd/system.conf
или
через параметры ядра
(http://fedoraproject.org/wiki/How_to_debug_Systemd_problems)
----
systemd.log_target= 
Set log target. Argument must be one of console, syslog, kmsg, syslog-or-kmsg,
null.
systemd.log_level= 
Set log level. As argument this accepts a numerical log level or the well-known
syslog symbolic names (lowercase): emerg, alert, crit, err, warning, notice,
info, debug.
-----

Ещё, пожалуйста, изготовьте и пришлите такой файл:
systemd-analyze plot > systemd.svg
------- Comment #17 From 2012-08-11 14:27:36 -------
Я, наконец, получил возможность прислать debug данные systemd.
Система сегодня обновлена через dist-upgrade. Тормоз в районе подключения
дисковых устройств остается.
------- Comment #18 From 2012-08-11 14:28:33 -------
Created an attachment (id=5536) [details]
Вывод systemd-analyze
------- Comment #19 From 2012-08-11 14:30:04 -------
Created an attachment (id=5537) [details]
Вывод dmesg с debug режимом systemd.

Тормоз визуально после "mounted /mnt/disk"
------- Comment #20 From 2012-09-06 08:59:28 -------
systemd-udev-settle.service запускается полминуты. Надо выяснить, почему.
------- Comment #22 From 2013-03-24 09:55:27 -------
Сейчас я такого у себя больше не наблюдаю. Видимо, причина исчезла.