Bug 27564

Summary: Загрузка системы стала занимать по 10 минут вместо 15 сек. Множественные застопоривания.
Product: Sisyphus Reporter: Vyacheslav Dikonov <slava>
Component: udevAssignee: Alexey Shabalin <shaba>
Status: CLOSED FIXED QA Contact: qa-sisyphus
Severity: normal    
Priority: P3 CC: aen, arseny, cetus, dd1email, evg, ildar, mike, real.altlinux.org, robin, shaba, vsu, zerg
Version: unstableKeywords: systemd
Hardware: x86   
OS: Linux   
Attachments:
Description Flags
Вывод dmesg после мучительно долгой загрузки.
none
Вывод systemd-analyze
none
Вывод dmesg с debug режимом systemd. none

Description Vyacheslav Dikonov 2012-07-24 01:26:11 MSK
Система Сизиф на 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 Vyacheslav Dikonov 2012-07-24 01:29:24 MSK
Created attachment 5521 [details]
Вывод dmesg после мучительно долгой загрузки.
Comment 2 Vyacheslav Dikonov 2012-07-24 20:31:58 MSK
Сделал видеозапись, чтобы в замедленном режиме прочитать сообщения загрузки на первой консоли.

после окончания стопора 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 real@altlinux.org 2012-07-25 06:32:20 MSK
У меня со вчерашнего дня тоже очень долгий затык на hal получился. Сделал apt-get remove hal и забыл :)
Comment 4 Alexey Shabalin 2012-07-25 13:15:48 MSK
hal давно противопоказан к установке в систему. Зачем он вам?
Если после его удаления всё работает, то я закрою этот баг как "NOTABUG".
Ещё могу в systemd(даже лучше в udev) добавить конфликт на hal.
Comment 5 Michael Shigorin 2012-07-25 22:55:12 MSK
Конфликт IMHO не стоит, ради чего-то этот пакет оставлялся.  Но пользоваться им тоже не стоит, с другой стороны...
Comment 6 real@altlinux.org 2012-07-26 06:30:35 MSK
"Конфликт 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 Vyacheslav Dikonov 2012-07-26 10:10:24 MSK
Прежде чем закрыть этот баг из-за HAL надо еще разобраться с тоже длинным тормозом 1, после которого видны надписи: 

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

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

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

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

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

$ fgrep kernel /usr/share/doc/udev-187/README
        Linux kernel >= 2.6.39
Comment 13 Vyacheslav Dikonov 2012-07-30 18:04:21 MSK
> Так какое ядро-то в итоге?
> 
> $ fgrep kernel /usr/share/doc/udev-187/README
>         Linux kernel >= 2.6.39
3.2 или 3.3,  32bit,  Я пересобрал std-def с включением PAE. Точно версию смогу назвать только к четвергу (я сейчас не дома).
Comment 14 Michael Shigorin 2012-07-30 18:42:03 MSK
(In reply to comment #13)
> > Так какое ядро-то в итоге?
> 3.2 или 3.3,  32bit,  Я пересобрал std-def с включением PAE.
А, ну хоть не 2.6.18... BTW есть std-pae, более-менее работает (только у меня чаще не выходит из suspend to ram, но это детали).
Comment 15 Vyacheslav Dikonov 2012-08-02 10:02:15 MSK
Проверил. Ядро оказалось 3.3.1-std-pae-alt1. Есть ли debug-лог у systemd и как его увидеть?
Comment 16 Alexey Shabalin 2012-08-04 10:54:34 MSK
(В ответ на комментарий №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 Vyacheslav Dikonov 2012-08-11 14:27:36 MSK
Я, наконец, получил возможность прислать debug данные systemd.
Система сегодня обновлена через dist-upgrade. Тормоз в районе подключения дисковых устройств остается.
Comment 18 Vyacheslav Dikonov 2012-08-11 14:28:33 MSK
Created attachment 5536 [details]
Вывод systemd-analyze
Comment 19 Vyacheslav Dikonov 2012-08-11 14:30:04 MSK
Created attachment 5537 [details]
Вывод dmesg с debug режимом systemd.

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