Segmentation fault in ServerSideSort overlay

[dzolotov]

When ldapsearch executed with enabled sssvlv overlay, server falls with SIGSEGV (During startup program terminated with signal SIGSEGV, Segmentation fault.)

Search command example:

ldapsearch -E 'sss=cn:caseIgnoreOrderingMatch' -D "cn=admin,dc=example,dc=org" -w admin -b "dc=example,dc=org" '(objectClass=*)' cn

We've tried to detect error source via gdb, but no debug information available, even if -g3 -O0 -ggdb3 flags are specified in CFLAGS and CXXFLAGS and sources are built in maintainer mode.

[erthink]

Я смогу заняться проблемой только в выходные, надеюсь будет время.

Будет здорово, если Вы предоставите готовый тест-кейс для воспроизведения проблемы.

Лучше всего сделать отдельный тест на основе test015-xsearch и/или test042-valsort (здесь проверяется наличие и загрузка оверлея valsort).

---

Что у вас с отладочными символами мне не понятно. На всякий случай я только-что проверил, что ./configure && make install сохраняют символы, а обрезаются они только при make install-strip.

Кроме этого в ReOpenLDAP есть backtrace-feature, т.е. сервер сам умеет делать дам стека при падении, см crash-backtrace в man slapd.conf . Но для этого требуется чтобы при сборке были необходимые компоненты, в частности libelf-dev, см configure.ac. А там где slapd будет работать был gdb.

Гляньте config.log после ./configure, что там про HAVE_ENOUGH4BACKTRACE?
Завел #148 чтобы поведение ./configure было более контролируемым в этом месте.

[dzolotov]

Посмотрел в HAVE_ENOUGHBACKTRACE, он равен 1. В man-странице информации про crash-backtrace нет, нашёл информацию в README, включил.
Тесты пока написать затруднительно, сделаю немножко позднее, когда появится ясность в происхождении ошибки. Сделал докер-контейнер со сборкой из исходных текстов и воспроизводимой ошибкой (даже на пустом домене с минимальной настройкой), присоединяю его вместе с backtrace (запуск через run.sh, в нём же также записана команда поиска, которая вызывает ошибку).
slapd-backtrace.2018-01-19-183908-69.log
sssfail.tar.gz

[erthink]

В man-странице информации про crash-backtrace нет

Не пугайте меня:

• На русском = https://github.com/leo-yuriev/ReOpenLDAP/blob/devel/doc/man/ru/man5/slapd.conf.soelim#L1042
• На английском = https://github.com/leo-yuriev/ReOpenLDAP/blob/devel/doc/man/en/man5/slapd.conf.soelim#L1146

[erthink]

К сожалению лог почти бесполезен.
Внутри можно видеть ptrace: Operation not permitted. при запуске gdb и соответственно нужной информации нет.
Эта ошибка уже один раз исправлялась, но видимо в результате какой-то правки случился регрес.
Сейчас я еще раз её поправил в ветке devel (9204cc0).

Попробую воспроизвести скриптом.

[dzolotov]

Здесь может быть ещё и ограничение докера на права доступа к внешней системе, можно попробовать запустить в привилегированном режиме (docker run --privileged).

[erthink]

Ваш скрипт не помог, он сырой.
Потратил впустую почти час чтобы им воспользоваться.
Его наверно можно запустить на чистой виртуалке с root-правали, и потом итеративно понять что/где нужно создавать/почистить и т.д.

Жду backtace, либо тест на основе test015-xsearch и/или test042-valsort (здесь проверяется наличие и загрузка оверлея valsort).
Но никаких докеров, ибо там неудобно отлаживать и непонятно из-за чего проблема.
Например в bactrace видно, что в памяти so-библиотеки от системного openldap - в принципе этого достаточно для 'dll hell'.

[dzolotov]

Убрал из сборки libldap-utils, не помогло, при поиске с sss сервер падает. Все зависимости установлены, в конфигурации olcCrashBacktrace=TRUE, не могу найти backtrace... раньше создавался в каталоге accesslog, теперь там его нет. Возможно ли каким-то образом указать его местоположение?

[erthink]

С каталогом для backtrace есть недоделка (чтобы не забыть добавил #150).
По историческим причинам он попадает в каталог с последней настроенной mdb-базой.

Если будут сложности, то попробуйте запустить slapd -D -d -1, так сервер будет запущен в отладочном режиме с контролем памяти и логированием на консоль.

---

Постарайтесь сделать простой slapd.conf и runme.sh. При их наличии высока вероятность, что у меня получится поправить баг сегодня. Как вариант - дайте ssh-доступ к окружению где воспроизводится проблема (реквизиты доступа отправляйте на leo@yuriev.ru).

[dzolotov]

Отправил данные для входа на почту, сделал устойчиво воспроизводимый сценарий ошибки

[erthink]

0x0000560d871beef4 in sssvlv_op_search (op=0x7f77dc002c90, rs=0x7f77ea529600) at sssvlv.c:984
984				sort_conns[op->o_conn->c_conn_idx][sess_id]->so_session = sess_id;
(gdb) bt
#0  0x0000560d871beef4 in sssvlv_op_search (op=0x7f77dc002c90, rs=0x7f77ea529600) at sssvlv.c:984
#1  0x0000560d870c61bf in overlay_op_walk (op=0x7f77dc002c90, rs=0x7f77ea529600, which=op_search, oi=0x7f77e0104900, on=0x7f77e0104ae0) at backover.c:682
#2  0x0000560d870c64a4 in over_op_func (op=0x7f77dc002c90, rs=0x7f77ea529600, which=op_search) at backover.c:752
#3  0x0000560d870c65b3 in over_op_search (op=0x7f77dc002c90, rs=0x7f77ea529600) at backover.c:779
#4  0x0000560d8714ce5b in fe_op_search (op=0x7f77dc002c90, rs=0x7f77ea529600) at search.c:394
#5  0x0000560d8714c61b in do_search (op=0x7f77dc002c90, rs=0x7f77ea529600) at search.c:237
#6  0x0000560d870edad5 in connection_operation (ctx=0x7f77ea529760, arg_v=0x7f77dc002c90) at connection.c:1205
#7  0x0000560d870ee1a5 in connection_read_thread (ctx=0x7f77ea529760, argv=0xd) at connection.c:1351
#8  0x00007f782ffc7b7d in ldap_int_thread_pool_wrapper (xpool=0x560d87f90080) at tpool.c:982
#9  0x00007f782f1c57fc in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#10 0x00007f782eef2b5f in clone () from /lib/x86_64-linux-gnu/libc.so.6
(gdb) info locals
cb = 0x7f77dc0032f8
on = 0x7f77e0104ae0
si = 0x7f77e0104cc0
rc = 32768
ok = 1
need_unlock = 1
sc = 0x7f77dc0032d0
ps = 0x0
vc = 0x0
sess_id = 0
so = 0x7f77dc001460
__FUNCTION__ = "sssvlv_op_search"
(gdb) p *op
$1 = {o_hdr = 0x7f77dc002e08, o_tag = 99, o_time = 1516635201, o_tincr = 1, o_bd = 0x7f77ea5282f0, o_req_dn = {bv_len = 17, bv_val = 0x7f77dc0031f8 "dc=example,dc=org"}, o_req_ndn = {bv_len = 17, 
    bv_val = 0x7f77dc003238 "dc=example,dc=org"}, o_request = {oq_add = {rs_modlist = 0x2, rs_e = 0xffffffffffffffff}, oq_bind = {rb_method = 2, rb_cred = {bv_len = 18446744073709551615, bv_val = 0x0}, rb_edn = {bv_len = 0, 
        bv_val = 0x0}, rb_ssf = 3691000408, rb_mech = {bv_len = 15, bv_val = 0x7f77dc003278 "(objectClass=*)"}}, oq_compare = {rs_ava = 0x2}, oq_modify = {rs_mods = {rs_modlist = 0x2, rs_no_opattrs = -1 '\377'}, rs_increment = 0}, 
    oq_modrdn = {rs_mods = {rs_modlist = 0x2, rs_no_opattrs = -1 '\377'}, rs_deleteoldrdn = 0, rs_newrdn = {bv_len = 0, bv_val = 0x0}, rs_nnewrdn = {bv_len = 140152768836184, bv_val = 0xf <error: Cannot access memory at address 0xf>}, 
      rs_newSup = 0x7f77dc003278, rs_nnewSup = 0x0}, oq_search = {rs_scope = 2, rs_deref = 0, rs_slimit = -1, rs_tlimit = -1, rs_limit = 0x0, rs_attrsonly = 0, rs_attrs = 0x0, rs_filter = 0x7f77dc003258, rs_filterstr = {bv_len = 15, 
        bv_val = 0x7f77dc003278 "(objectClass=*)"}}, oq_abandon = {rs_msgid = 2}, oq_cancel = {rs_msgid = 2}, oq_extended = {rs_reqoid = {bv_len = 2, 
        bv_val = 0xffffffffffffffff <error: Cannot access memory at address 0xffffffffffffffff>}, rs_flags = 0, rs_reqdata = 0x0}, oq_pwdexop = {rs_extended = {rs_reqoid = {bv_len = 2, 
          bv_val = 0xffffffffffffffff <error: Cannot access memory at address 0xffffffffffffffff>}, rs_flags = 0, rs_reqdata = 0x0}, rs_old = {bv_len = 0, bv_val = 0x7f77dc003258 "\207"}, rs_new = {bv_len = 15, 
        bv_val = 0x7f77dc003278 "(objectClass=*)"}, rs_mods = 0x0, rs_modtail = 0x0}}, _o_abandon = 0, _o_cancel = 0, o_groups = 0x0, o_do_not_cache = 0 '\000', o_is_auth_check = 0 '\000', o_dont_replicate = 0 '\000', 
  o_hollow = 0 '\000', o_acl_priv = ACL_NONE, o_nocaching = 0 '\000', o_delete_glue_parent = 0 '\000', o_no_schema_check = 0 '\000', o_no_subordinate_glue = 0 '\000', 
  o_ctrlflag = '\000' <repeats 20 times>, "\002\000\000\000\000\000\000\000\000\000\000", o_controls = 0x7f77dc002f50, o_authz = {sai_method = 128, sai_mech = {bv_len = 0, bv_val = 0x0}, sai_dn = {bv_len = 26, 
      bv_val = 0x7f77dc000c80 "cn=admin,dc=example,dc=org"}, sai_ndn = {bv_len = 26, bv_val = 0x7f77dc0021b0 "cn=admin,dc=example,dc=org"}, sai_ssf = 0, sai_transport_ssf = 0, sai_tls_ssf = 0, sai_sasl_ssf = 0}, o_ber = 0x7f77e01039d0, 
  o_res_ber = 0x0, o_callback = 0x7f77dc0032f8, o_ctrls = 0x7f77dc003290, o_csn_master = 0x0, o_csn = {bv_len = 0, bv_val = 0x0}, o_private = 0x0, o_extra = {slh_first = 0x0}, o_next = {stqe_next = 0x0}}
(gdb) p *op->o_hdr->oh_conn
$2 = {c_struct_state = SLAP_C_USED, c_conn_state = SLAP_C_ACTIVE, c_conn_idx = 13, c_sd = 13, c_close_reason = 0x560d8724456b "?", c_mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, 
      __elision = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}, c_sb = 0x7f77dc000d50, c_starttime = {ns = 1516635201458451676}, c_activitytime = {ns = 1516635201460366742}, 
  c_connid = 1002, c_peer_domain = {bv_len = 7, bv_val = 0x7f77dc000cb0 "unknown"}, c_peer_name = {bv_len = 18, bv_val = 0x7f77dc002050 "IP=127.0.0.1:33462"}, c_listener = 0x560d87f72eb0, c_sasl_bind_mech = {bv_len = 0, bv_val = 0x0}, 
  c_sasl_dn = {bv_len = 0, bv_val = 0x0}, c_sasl_authz_dn = {bv_len = 0, bv_val = 0x0}, c_authz_backend = 0x560d880242a0, c_authz_cookie = 0x0, c_authz = {sai_method = 128, sai_mech = {bv_len = 0, bv_val = 0x0}, sai_dn = {bv_len = 26, 
      bv_val = 0x7f77e0101590 "cn=admin,dc=example,dc=org"}, sai_ndn = {bv_len = 26, bv_val = 0x7f77e0101560 "cn=admin,dc=example,dc=org"}, sai_ssf = 0, sai_transport_ssf = 0, sai_tls_ssf = 0, sai_sasl_ssf = 0}, c_protocol = 3, c_ops = {
    stqh_first = 0x7f77dc002c90, stqh_last = 0x7f77dc002e00}, c_pending_ops = {stqh_first = 0x0, stqh_last = 0x560d8808aba8}, c_write1_mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, 
      __elision = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}, c_write1_cv = {__data = {{__wseq = 0, __wseq32 = {__low = 0, __high = 0}}, {__g1_start = 0, __g1_start32 = {__low = 0, 
          __high = 0}}, __g_refs = {0, 0}, __g_size = {0, 0}, __g1_orig_size = 0, __wrefs = 0, __g_signals = {0, 0}}, __size = '\000' <repeats 47 times>, __align = 0}, c_write2_mutex = {__data = {__lock = 0, __count = 0, __owner = 0, 
      __nusers = 0, __kind = 0, __spins = 0, __elision = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}, c_write2_cv = {__data = {{__wseq = 0, __wseq32 = {__low = 0, __high = 0}}, {
        __g1_start = 0, __g1_start32 = {__low = 0, __high = 0}}, __g_refs = {0, 0}, __g_size = {0, 0}, __g1_orig_size = 0, __wrefs = 0, __g_signals = {0, 0}}, __size = '\000' <repeats 47 times>, __align = 0}, 
  c_currentber = 0x7f77dc001400, c_writers = 0, c_writing = 0 '\000', c_sasl_bind_in_progress = 0 '\000', c_writewaiter = 0 '\000', c_gentle_kick = 0 '\000', c_is_tls = 0 '\000', c_needs_tls_accept = 0 '\000', c_sasl_layers = 0 '\000', 
  c_sasl_done = 0 '\000', c_sasl_authctx = 0x7f77dc103070, c_sasl_sockctx = 0x0, c_sasl_extra = 0x7f77dc000e70, c_sasl_bindop = 0x0, c_pagedresults_state = {ps_be = 0x0, ps_size = 0, ps_count = 0, ps_cookie = 0, ps_cookieval = {
      bv_len = 0, bv_val = 0x0}}, c_n_ops_received = 2, c_n_ops_executing = 1, c_n_ops_pending = 0, c_n_ops_completed = 1, c_n_get = 2, c_n_read = 2, c_n_write = 0, c_extensions = 0x0, c_clientfunc = 0x0, c_clientarg = 0x0, 
  c_send_ldap_result = 0x560d8712838e <slap_send_ldap_result>, c_send_search_entry = 0x560d87128f49 <slap_send_search_entry>, c_send_search_reference = 0x560d8712afc8 <slap_send_search_reference>, 
  c_send_ldap_extended = 0x560d87128b08 <slap_send_ldap_extended>, c_send_ldap_intermediate = 0x560d87128d63 <slap_send_ldap_intermediate>}
(gdb) p sort_conns[0][13]
$3 = (sort_op *) 0x0
(gdb)