Bug 36841

Summary: Нестабильное поведение sssd-kcm
Product: Branch p8 Reporter: fisk <mfiskov>
Component: sssd-kcmAssignee: Evgeny Sinelnikov <sin>
Status: CLOSED FIXED QA Contact: qa-p8 <qa-p8>
Severity: normal    
Priority: P3 CC: cas, iv
Version: не указана   
Hardware: x86_64   
OS: Linux   

Description fisk 2019-06-03 08:15:50 MSK
При настройке sssd и krb5 на работу с кэшем sssd-kcm наблюдаю следующее: демон запускается, какое-то время работает, иногда отдает список ключей по команде klist, но регулярно вываливается с созданием дампа после краха системы.

Версия sssd: 1.16.3-alt2.M80P.1@1549876326
Comment 1 fisk 2019-06-03 08:17:33 MSK
Настройка sssd.conf для kcm:

[kcm]
socket_path = /var/run/.heim_org.h5l.kcm-socket
debug_level = 10

Настройка в krb5.conf:

[libdefaults]
default_cc_type = KCM:
default_ccache_name = KCM:

Поведение klist при сбое:
$ klist
Ticket cache: KCM:1051414227
Default principal: fiskov_m_m@KKOKB.LOCAL

Valid starting       Expires              Service principal
klist: Credentials cache I/O operation failed XXX while retrieving a ticket
[fiskov_m_m@220test-a ~]$ klist
Ticket cache: KCM:1051414227
Default principal: fiskov_m_m@KKOKB.LOCAL

Valid starting       Expires              Service principal

Поведение klist при нормальном ответе:
$ klist
Ticket cache: KCM:1051414227
Default principal: fiskov_m_m@KKOKB.LOCAL

Valid starting       Expires              Service principal
03.06.2019 11:02:55  03.06.2019 20:11:37  cifs/apps@
    renew until 10.06.2019 10:11:37

Нужно отметить, что это были две последовательно выполненных команды. 

Кусок из лога:
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [check_curl_timeouts] (0x4000): Still tracking 0 outstanding requests
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [handle_curlmsg_done] (0x0400): Handled http://localhost/kcm/persistent/1051414227/cca
che/
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [tcurl_request_done] (0x0400): TCURL request finished [0]: Success
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [sec_list_done] (0x2000): Found 1 items
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [sec_list_done] (0x2000): list done
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [sec_get_send] (0x2000): Retrieving ccache eb69f795-93b7-4822-8123-b82537df6332-105141
4227
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [tcurl_request_send] (0x0400): Sending TCURL request for http://localhost/kcm/persiste
nt/1051414227/ccache/eb69f795-93b7-4822-8123-b82537df6332-1051414227, at socket /var/run/secrets.socket
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [schedule_fd_processing] (0x2000): timeout_ms: 0
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [check_curl_timeouts] (0x4000): Still tracking 0 outstanding requests
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [handle_curlmsg_done] (0x0400): Handled http://localhost/kcm/persistent/1051414227/cca
che/eb69f795-93b7-4822-8123-b82537df6332-1051414227
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [tcurl_request_done] (0x0400): TCURL request finished [0]: Success
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [sec_get_done] (0x2000): GET done
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [ccdb_sec_getbyname_done] (0x2000): Got ccache by UUID
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_debug_uuid] (0x4000): UUID: 3200ea19-cba3-4846-9f2d-5887c8f9e291
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_debug_uuid] (0x4000): UUID: 532a3a94-afe8-4e18-bf77-249aaf5eefe2
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_debug_uuid] (0x4000): UUID: 6551665a-2b6c-471f-a741-2224abec9e74
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_debug_uuid] (0x4000): UUID: 80b1d1e4-d34b-439b-8b78-26b91d8b56c2
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_cmd_done] (0x0400): KCM operation GET_CRED_BY_UUID returned [0]: Success
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_send_reply] (0x2000): Sending a reply
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_output_construct] (0x1000): Sending a reply with 1730 bytes of payload
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [queue_removal_cb] (0x0200): Removed queue for 1051414227
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_send] (0x2000): All data sent!
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_input_parse] (0x1000): Received message with length 31
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_get_opt] (0x2000): The client requested operation 10
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_cmd_send] (0x0400): KCM operation GET_CRED_BY_UUID
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_cmd_send] (0x1000): 27 bytes on KCM input
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_op_queue_send] (0x0200): Adding request by 1051414227 to the wait queue
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_op_queue_get] (0x1000): No existing queue for this ID
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_op_queue_send] (0x1000): Queue was empty, running the request immediately
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [kcm_op_get_cred_by_uuid_send] (0x1000): Returning creds by UUID for 1051414227
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [ccdb_sec_getbyname_send] (0x2000): Getting ccache by name
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [sec_list_send] (0x2000): Listing all ccaches in the secrets store
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [tcurl_request_send] (0x0400): Sending TCURL request for http://localhost/kcm/persiste
nt/1051414227/ccache/, at socket /var/run/secrets.socket
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [schedule_fd_processing] (0x2000): timeout_ms: 0
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [talloc_log_fn] (0x0010): talloc: access after free error - first free may be at ../te
vent_timed.c:391
(Mon Jun  3 11:45:56 2019) [sssd[kcm]] [talloc_log_fn] (0x0010): Bad talloc magic value - access after free
(Mon Jun  3 11:45:59 2019) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1884cb0
Comment 2 fisk 2019-06-03 08:19:18 MSK
В заключении предположу, что поведение полностью подходит под это описание ошибки, исправленное в Fedora: https://bugzilla.redhat.com/show_bug.cgi?id=1494843

Вложит дамп после краха sssd-kcm не смог. Ваш nginx говорит, что сильно большой файл.
Comment 3 Andrey Cherepanov 2019-07-26 07:58:34 MSK
Евгений, сверь перечень наших патчей в p8 с https://src.fedoraproject.org/rpms/sssd/tree/0a06c01711171c660da39492209b6252ab75aa8e
Comment 4 Ivan A. Melnikov 2019-07-26 14:15:22 MSK
Похоже на 
* https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=929473
* https://pagure.io/SSSD/sssd/issue/3917

Можно попробовать затащить в p8 https://pagure.io/SSSD/sssd/c/15bde7dab466fc4f2719ce709de9dac7e1e10de8.
Comment 5 Evgeny Sinelnikov 2019-07-26 15:56:57 MSK
Приложил последний предложенный вариант патча из апстрима, отправил на тестовую сборку:
#235136 BUILDING #1 [locked] [test-only] p8 sssd.git=1.16.4-alt2.M80P.1

Прошу проверить, когда (надеюсь, успешно) собирётся.
Comment 6 fisk 2019-07-29 07:52:40 MSK
Большое спасибо!
Все работает. 
sssd-kcm больше не падает.
Подскажите через сколько времени ждать в p8 ?
Comment 7 Evgeny Sinelnikov 2019-07-29 13:53:56 MSK
Сборка находится на стадии тестирования регрессий. Рассчитываю на скорое завершение.
Comment 8 Repository Robot 2019-08-08 22:00:35 MSK
sssd-1.16.4-alt2.M80P.1 -> c8.1:

Fri Jul 26 2019 Evgeny Sinelnikov <sin@altlinux> 1.16.4-alt2
- Apply from upstream SSSD#3917 Double free error in tev_curl (Closes: 36841)