Bug 35844

Summary: Не запускается на i586
Product: Sisyphus Reporter: Антон Мидюков <antohami>
Component: lightdmAssignee: manowar <manowar>
Status: CLOSED FIXED QA Contact: qa-sisyphus
Severity: critical    
Priority: P3 CC: grenka, iv, manowar, mike, vladimir.didenko
Version: unstable   
Hardware: x86   
OS: Linux   
Bug Depends on:    
Bug Blocks: 33000    

Description Антон Мидюков 2019-01-03 15:30:14 MSK
Проблема воспроизводится на регулярках i586: cinnamon, enlightenment, lxde, mate, xfce. http://nightly.altlinux.org/sisyphus/snapshots/20190102/

При этом автологин отрабатывает нормально. Чтобы воспроизвести проблему можно даже не устанавливать систему. Достаточно отключить автологин в центре управления и завершить сеанс. Экран три раза моргнёт и всё.

systemctl status lightdm показывает failed.
Comment 1 Владимир Диденко 2019-01-04 08:56:02 MSK
Я посмотрю, но только после праздников. Как быстрый фикс, можно на i586 использовать gtk greeter - я, так понимаю, он работает?
Comment 2 Антон Мидюков 2019-01-04 10:18:30 MSK
Поторопился с выводами. Проблема у lightdm, так как lightdm-gtk-greeter тоже не работает. Проблема запуска службы lightdm.service, ориентировочно, так как от root:
lightdm

работает.

В логе /var/log/lightdm/lightdm.log есть строчка после которой служба начинает завершаться:
Critical: session_get_login1_session_id:assertion 'session !=NULL' failed

На sysv служба стартует нормально. Может связано с обновлением systemd?
Comment 3 Антон Мидюков 2019-01-05 19:15:23 MSK
А слона я не приметил, сообщение в журнале:
kernel: traps: lightdm-gtk-gre[1749] trap int3 ip:b717e834 sp;bfba6af90 error:0 in libglib-2.0.so.0.5800.2[b7145000+80000]

Пробую сделать ребилд lightdm.
Comment 4 Антон Мидюков 2019-01-05 20:23:44 MSK
(В ответ на комментарий №3)
> А слона я не приметил, сообщение в журнале:
> kernel: traps: lightdm-gtk-gre[1749] trap int3 ip:b717e834 sp;bfba6af90 error:0
> in libglib-2.0.so.0.5800.2[b7145000+80000]
> 
> Пробую сделать ребилд lightdm.

Установил пересобранный lightdm. Не помогло. Но похоже дело в другом. Продолжаю примечать слонов.
Лог /var/log/lightdm/x-0-greeter.log заканчивается строкой:

ERROR: gmem.c:135 failed to allocate 256 bytes lightdm
Comment 5 Антон Мидюков 2019-01-05 20:35:00 MSK
(В ответ на комментарий №4)
> (В ответ на комментарий №3)
> > А слона я не приметил, сообщение в журнале:
> > kernel: traps: lightdm-gtk-gre[1749] trap int3 ip:b717e834 sp;bfba6af90 error:0
> > in libglib-2.0.so.0.5800.2[b7145000+80000]
> > 
> > Пробую сделать ребилд lightdm.
> 
> Установил пересобранный lightdm. Не помогло. Но похоже дело в другом. Продолжаю
> примечать слонов.
> Лог /var/log/lightdm/x-0-greeter.log заканчивается строкой:
> 
> ERROR: gmem.c:135 failed to allocate 256 bytes lightdm

Это, когда используется slick-greeter. Когда используется lightdm-gtk-greeter, в том же логе:
OpenGL Error: Out of memory trying to allocate 640 bytes!
Comment 6 Grigory Ustinov 2019-01-06 04:48:27 MSK
(In reply to comment #5)

Я использую 586ую машинку, вчера как раз захотел переехать со слима на лайтдм и был ужасно расстроен, когда комп превратился в тыкву. Спасибо за багу, если бы не она, совсем бы не знал, что делать. Пока использую гдм, но для моего железа он тяжеловат. Жду с нетерпением починки lightdm.
Comment 7 Антон Мидюков 2019-01-08 18:32:18 MSK
Похоже проблема ещё и на aarch64. Сборки со slick-greeter не могут загрузить dm, но переключиться в другой tty никак там не получается, сразу же перебрасывает обратно.

Подтверждаю, что проблема только на systemd, по крайней мере для i586.
Comment 8 Антон Мидюков 2019-01-08 19:18:03 MSK
На mipsel тоже воспроизводится.
Comment 9 Ivan A. Melnikov 2019-01-09 12:43:35 MSK
(In reply to comment #2)
> На sysv служба стартует нормально. Может связано с обновлением systemd?

Взял рабочую машину на mipsel и обновил на ней systemd 239 -> 240-alt2. Сломалось именно так. Так что это точно связанно с обновлением systemd.

> В логе /var/log/lightdm/lightdm.log есть строчка после которой служба начинает
> завершаться:
> Critical: session_get_login1_session_id:assertion 'session !=NULL' failed

Это похоже на самую интересную ниточку. Вот stacktrace того, где это происходит:

(gdb) bt
#0  session_get_login1_session_id (session=0x0) at session.c:677
#1  0x0040ffa8 in login1_active_session_changed_cb (login1_seat=<optimized out>, login1_session_id=0x47c470 "") at lightdm.c:1105
#2  0x772ff1ac in g_cclosure_marshal_VOID__STRINGv (closure=0x461a58, return_value=<optimized out>, instance=<optimized out>, args=<optimized out>, marshal_data=0x0, n_params=1,
    param_types=0x47a818) at gmarshal.c:1794
#3  0x772fbd20 in _g_closure_invoke_va (closure=0x461a58, return_value=0x0, instance=0x467618, args=0x7fd5916c, n_params=1, param_types=0x47a818) at gclosure.c:873
#4  0x7731e23c in g_signal_emit_valist (instance=0x47a350, signal_id=<optimized out>, detail=2144702948, var_args=0x7fd5916c) at gsignal.c:3300
#5  0x7731e62c in g_signal_emit (instance=<optimized out>, signal_id=<optimized out>, detail=<optimized out>) at gsignal.c:3447
#6  0x004138a4 in update_property (name=<optimized out>, value=0x74e0ca40, seat=0x467618) at login1.c:97
#7  update_property (seat=0x467618, name=0x47b760 "ActiveSession", value=0x74e0ca40) at login1.c:86
#8  0x00413934 in seat_properties_changed_cb (connection=0x476818, sender_name=<optimized out>, object_path=<optimized out>, interface_name=<optimized out>,
    signal_name=0x482800 "PropertiesChanged", parameters=0x46a060, user_data=0x467618) at login1.c:117
#9  0x7743e0f0 in emit_signal_instance_in_idle_cb (data=0x74e0feb0) at gdbusconnection.c:3711
#10 0x77212588 in g_main_dispatch (context=0x461ab8) at gmain.c:3182
#11 g_main_context_dispatch (context=0x461ab8) at gmain.c:3847
#12 0x77212a24 in g_main_context_iterate (context=0x461ab8, block=<optimized out>, dispatch=1, self=<optimized out>) at gmain.c:3920
#13 0x77212f48 in g_main_loop_run (loop=0x463c78) at gmain.c:4116
#14 0x00408ce4 in main (argc=<optimized out>, argv=<optimized out>) at lightdm.c:1543
Comment 10 Ivan A. Melnikov 2019-01-09 13:27:09 MSK
>Это похоже на самую интересную ниточку.

А вот и нет, хотя это тоже интересно.

На самом деле падает lightdm-gtk-greeter, и падает просто очень жестко:

(gdb) bt
#0  raise (sig=<optimized out>) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x76e134e0 in g_log_default_handler (log_domain=<optimized out>, log_level=<optimized out>, message=<optimized out>, unused_data=<optimized out>) at gmessages.c:3111
#2  0x76e137a4 in g_logv (log_domain=0x76e6d990 "GLib", log_level=G_LOG_LEVEL_ERROR, format=<optimized out>, args=<optimized out>) at gmessages.c:1350
#3  0x76e139ac in g_log (log_domain=<optimized out>, log_level=<optimized out>, format=<optimized out>) at gmessages.c:1413
#4  0x76e11b80 in g_malloc0 (n_bytes=32) at gmem.c:134
#5  0x76df261c in g_hash_table_new_full (hash_func=<optimized out>, key_equal_func=0x76df4064 <g_str_equal>, key_destroy_func=0x76e11c14 <g_free>,
    value_destroy_func=0x76ef9f3c <g_object_unref>) at ghash.c:731
#6  0x774c7968 in gtk_builder_init (builder=<optimized out>) at gtkbuilder.c:305
#7  0x76f23184 in g_type_create_instance (type=<optimized out>) at gtype.c:1864
#8  0x76efac3c in g_object_new_internal (class=0x5511f0, params=0x0, n_params=0) at gobject.c:1805
#9  0x76efcb24 in g_object_new_with_properties (object_type=6008944, n_properties=0, names=0x0, values=0x0) at gobject.c:1973
#10 0x76efd520 in g_object_new (object_type=<optimized out>, first_property_name=<optimized out>) at gobject.c:1645
#11 0x77823004 in gtk_widget_init_template (widget=0x73ef11f8) at gtkwidget.c:16946
#12 0x777b7eb0 in gtk_tooltip_window_init (self=0x73ef11f8) at gtktooltipwindow.c:80
#13 0x76f23184 in g_type_create_instance (type=<optimized out>) at gtype.c:1864
#14 0x76efac3c in g_object_new_internal (class=0x76fce8, params=0x7f986bac, n_params=1) at gobject.c:1805
#15 0x76efd3ec in g_object_new_valist (object_type=7080672, first_property_name=<optimized out>, var_args=0x7f986c90) at gobject.c:2128
#16 0x76efd504 in g_object_new (object_type=<optimized out>, first_property_name=<optimized out>) at gobject.c:1648
#17 0x777b5728 in gtk_tooltip_init (tooltip=0x7466e8) at gtktooltip.c:191
#18 0x76f23184 in g_type_create_instance (type=<optimized out>) at gtype.c:1864
#19 0x76efac3c in g_object_new_internal (class=0x6c0a98, params=0x0, n_params=0) at gobject.c:1805
#20 0x76efcb24 in g_object_new_with_properties (object_type=4813488, n_properties=0, names=0x0, values=0x0) at gobject.c:1973
#21 0x76efd520 in g_object_new (object_type=<optimized out>, first_property_name=<optimized out>) at gobject.c:1645
#22 0x777b7090 in gtk_tooltip_handle_event_internal (event=0x6bf080) at gtktooltip.c:1411
#23 0x776505dc in gtk_main_do_event (event=<optimized out>) at gtkmain.c:1952
#24 0x772baa70 in _gdk_event_emit (event=0x6bf080) at gdkevents.c:73
#25 0x772fd964 in gdk_event_source_dispatch (source=<optimized out>, callback=<optimized out>, user_data=<optimized out>) at gdkeventsource.c:367
#26 0x76e0a720 in g_main_dispatch (context=0x441c68) at gmain.c:3182
#27 g_main_context_dispatch (context=0x441c68) at gmain.c:3847
#28 0x76e0aa24 in g_main_context_iterate (context=0x441c68, block=<optimized out>, dispatch=1, self=<optimized out>) at gmain.c:3920
#29 0x76e0af48 in g_main_loop_run (loop=0x760b00) at gmain.c:4116
#30 0x7764f518 in gtk_main () at gtkmain.c:1323
#31 0x00408db4 in main (argc=<optimized out>, argv=<optimized out>) at lightdm-gtk-greeter.c:3221


Если постораться, можно вынуть из корки сообщение, которое оно пыталось залогироавть: "gmem.c:135: failed to allocate 32 bytes"

То есть, ему тупо не хватило памяти.
Comment 11 Ivan A. Melnikov 2019-01-09 13:30:35 MSK
> То есть, ему тупо не хватило памяти.

И... у нас есть workaround!

[root@localhost ~]# cat /etc/systemd/system/lightdm.service.d/override.conf
[Service]
LimitMEMLOCK=infinity

После чего, естественно, нужен systemctl daemon-reolad, или перезагрузка. Проверил и так, и так.

Почему у systemd вдруг такие жесткие лимиты?
Comment 12 Grigory Ustinov 2019-01-09 13:45:09 MSK
(В ответ на комментарий №11 
> И... у нас есть workaround!

Можно это увидеть в сизифе?
Comment 13 Ivan A. Melnikov 2019-01-09 13:50:20 MSK
(In reply to comment #11)
> Почему у systemd вдруг такие жесткие лимиты?

Не такие и жесткие -- 64M. Однако lightdm, чтобы нормально запустить lightdm-gtk-greeter, нужно хотя бы LimitMEMLOCK=140M (на mipsel). И то при попытке посмотреть список языков память кончилась.

Иконки нынче тяжелые пошли...
Comment 14 Антон Мидюков 2019-01-09 13:54:59 MSK
(В ответ на комментарий №13)
> (In reply to comment #11)
> > Почему у systemd вдруг такие жесткие лимиты?
> 
> Не такие и жесткие -- 64M. Однако lightdm, чтобы нормально запустить
> lightdm-gtk-greeter, нужно хотя бы LimitMEMLOCK=140M (на mipsel). И то при
> попытке посмотреть список языков память кончилась.
> 
> Иконки нынче тяжелые пошли...

Т.е. проблему можно решить превратив svg в png в greeter'ах?
Comment 15 Ivan A. Melnikov 2019-01-09 14:28:19 MSK
Дело вряд ли в иконках, это я не подумав написал.

Информация для размышления: вот кусок /proc/$pid/status для slick-greeter на моём ноутбуке (x86_64):

VmPeak:   707160 kB
VmSize:   689840 kB
VmLck:         0 kB
VmPin:         0 kB
VmHWM:     66568 kB
VmRSS:     53380 kB
VmData:    56724 kB
VmStk:       132 kB
VmExe:       280 kB
VmLib:     26740 kB
VmPTE:       472 kB
VmSwap:        0 kB


А вот то же самое с Таволги:

[root@localhost ~]# grep '^Vm' /proc/$(pidof slick-greeter)/status
VmPeak:   175472 kB
VmSize:   163312 kB
VmLck:    163296 kB
VmPin:         0 kB
VmHWM:    119536 kB
VmRSS:    107376 kB
VmData:    56192 kB
VmStk:       160 kB
VmExe:       416 kB
VmLib:     30832 kB
VmPTE:        80 kB
VmSwap:        0 kB


Почему почти вся память, которую выделяет себе greeter, на mipsel попадает в VmLck? Это стоит понять.

Тем временем, очевидно, что на mipsel нужно поднимать lightdm на memlock хотя бы до 200M.

Кто-нибудь может повторить эксперимент на i586 и написать, что там получается в VmLck?
Comment 16 Антон Мидюков 2019-01-09 14:59:47 MSK
i586

grep '^Vm' /proc/$(pidof slick-greeter)/status
VmPeak:   184408 kB
VmSize:   173512 kB
VmLck:    173492 kB
VmPin:         0 kB
VmHWM:    182196 kB
VmRSS:    171448 kB
VmData:    61576 kB
VmStk:       132 kB
VmExe:       276 kB
VmLib:     26952 kB
VmPTE:       188 kB
VmPMD:         0 kB
VmSwap:        0 kB
Comment 17 Ivan A. Melnikov 2019-01-09 15:21:10 MSK
(In reply to comment #15)
> Почему почти вся память, которую выделяет себе greeter, на mipsel попадает в
> VmLck? Это стоит понять.

И понять это достаточно просто: сделано это на всякий случай в самом начале main:

http://git.altlinux.org/gears/l/lightdm-gtk-greeter.git?p=lightdm-gtk-greeter.git;a=blob;f=src/lightdm-gtk-greeter.c;h=39eb7cfab6316fdd20f5e357e4d2bf7b468d5fc1;hb=d93b64418e12f85e862d9091816ff49a150b16b0#l2697
 
Как это работало раньше, и почему на x86_64 это не приводит к проблемам -- это следующий вопрос.
Comment 18 Ivan A. Melnikov 2019-01-09 15:29:17 MSK
(In reply to comment #16)
> i586
> 
> grep '^Vm' /proc/$(pidof slick-greeter)/status
> VmPeak:   184408 kB
> VmSize:   173512 kB
> VmLck:    173492 kB
[...]

Спасибо!

Итого: greeter'ы (и lightdm-gtk-greeter, и slick-greeter) лочат всю свою память, и это наверное правильно, а памяти ему нужно до гига.

Думаю, надо написать LimitMEMLOCK=infinity в lightdm.service.

shaba@?
Comment 19 Антон Мидюков 2019-01-14 09:54:23 MSK
(В ответ на комментарий №18)
> (In reply to comment #16)
> > i586
> > 
> > grep '^Vm' /proc/$(pidof slick-greeter)/status
> > VmPeak:   184408 kB
> > VmSize:   173512 kB
> > VmLck:    173492 kB
> [...]
> 
> Спасибо!
> 
> Итого: greeter'ы (и lightdm-gtk-greeter, и slick-greeter) лочат всю свою
> память, и это наверное правильно, а памяти ему нужно до гига.
> 
> Думаю, надо написать LimitMEMLOCK=infinity в lightdm.service.
> 
> shaba@?

Алексей Шабалин, откликнетесь, пожалуйста. Сегодня, очень желательно, с этим что-то решить, так как уже завтра сборка тестовых регулярок.
Comment 20 Ivan A. Melnikov 2019-01-14 10:21:10 MSK
Думаю, можно и самим, благо Ева в acl.

Сделал  test-only таск #219337.

http://git.altlinux.org/people/iv/packages/lightdm.git?p=lightdm.git;a=commitdiff;h=3d4528fc8952bd05ed06eef6712594bf52f561f3
Comment 21 Ivan A. Melnikov 2019-01-15 11:27:30 MSK
Время офигительных историй!

(In reply to comment #17)
> (In reply to comment #15)
> > Почему почти вся память, которую выделяет себе greeter, на mipsel попадает в
> > VmLck? Это стоит понять.
> 
> И понять это достаточно просто: сделано это на всякий случай в самом начале
> main:
> 
> http://git.altlinux.org/gears/l/lightdm-gtk-greeter.git?p=lightdm-gtk-greeter.git;a=blob;f=src/lightdm-gtk-greeter.c;h=39eb7cfab6316fdd20f5e357e4d2bf7b468d5fc1;hb=d93b64418e12f85e862d9091816ff49a150b16b0#l2697
> 
> Как это работало раньше, и почему на x86_64 это не приводит к проблемам -- это
> следующий вопрос.

Если кого-то так же, как и меня, интересовал этот вопрос, то вот разгадка: результат вызова mlockall в гритерах не проверяется, а на x86_64 к началу main сразу выделено столько памяти, что залочить её не удаётся:

mlockall(MCL_CURRENT|MCL_FUTURE)        = -1 ENOMEM (Cannot allocate memory)

То есть, чтобы всё упало, limit на mlock должен быть достаточным чтобы вызов mlockall прошёл вначале main greeter'а, но недостаточным для полноценной работы. Найти такое значение лимита можно и для x86_64. Например, для slick-greeter оно больше 128M и меньше 512M -- если выставить лимит в 256M, проблема воспроизводится на моём боевом ноуте.

В systemd 240 подняли значение лимита на mlock для сервисов по умолчанию с 32M до 64M. Этого оказалось недостаточно чтобы попасть в "проблемное окно" на x86_64, но хватило 32-битным системам.
Comment 22 Ivan A. Melnikov 2019-01-15 11:31:33 MSK
А может кто-нибудь затестить lightdm из таски

#219399 TESTED #1 [test-only] sisyphus lightdm.git=1.16.7-alt24

?
Comment 23 Антон Мидюков 2019-01-15 11:34:55 MSK
(В ответ на комментарий №22)
> А может кто-нибудь затестить lightdm из таски
> 
> #219399 TESTED #1 [test-only] sisyphus lightdm.git=1.16.7-alt24
> 
> ?

Я проверю на i586
Comment 24 Антон Мидюков 2019-01-15 11:45:57 MSK
(В ответ на комментарий №23)
> (В ответ на комментарий №22)
> > А может кто-нибудь затестить lightdm из таски
> > 
> > #219399 TESTED #1 [test-only] sisyphus lightdm.git=1.16.7-alt24
> > 
> > ?
> 
> Я проверю на i586

Работает
Comment 25 Ivan A. Melnikov 2019-01-15 11:49:09 MSK
(In reply to comment #22)
> А может кто-нибудь затестить lightdm из таски
> 
> #219399 TESTED #1 [test-only] sisyphus lightdm.git=1.16.7-alt24
> 
> ?

x86_64 не сломалось.

Но при этом обнаружилось внезапное: у нас же есть не только ligtdm.service, но и prefdm.servcie; если lightdm запускается через последний, то фикс из 1.16.7-alt23 ничем не поможет.

Я бы предположил, что prefdm, если он нужен, надо чинить отдельно.
Comment 26 Repository Robot 2019-01-15 12:09:05 MSK
lightdm-1.16.7-alt24 -> sisyphus:

Tue Jan 15 2019 Ivan A. Melnikov <iv@altlinux> 1.16.7-alt24
- Replace 'Conflicts <>' with auxiliary package

Mon Jan 14 2019 Ivan A. Melnikov <iv@altlinux> 1.16.7-alt23
- Remove MEMLOCK limit in systemd unit file (closes: #35844).
Comment 27 Michael Shigorin 2019-01-15 14:44:26 MSK
(В ответ на комментарий №21)
> Время офигительных историй!
Феерия #ubuntu...
Comment 28 Grigory Ustinov 2019-01-20 15:36:43 MSK
Спасибо огромное! Всё отлично работает.