Bug 1283769 - sssd-nss segfault on restart
sssd-nss segfault on restart
Status: ASSIGNED
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: sssd (Show other bugs)
6.7
x86_64 Linux
unspecified Severity medium
: rc
: ---
Assigned To: SSSD Maintainers
Namita Soman
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-11-19 14:06 EST by Orion Poplawski
Modified: 2017-09-14 08:14 EDT (History)
8 users (show)

See Also:
Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed:
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Orion Poplawski 2015-11-19 14:06:59 EST
Description of problem:

My system is very busy copied a large (3+TB) file from one sata disk to a USB disk.  sssd is being affected:

Nov 19 09:27:24 saga sssd: Killing service [default], not responding to pings!
Nov 19 09:28:06 saga sssd[be[default]]: Shutting down
Nov 19 09:28:06 saga sssd[be[default]]: Starting up
Nov 19 10:19:06 saga sssd: Killing service [default], not responding to pings!
Nov 19 10:20:06 saga sssd: [default][10121] is not responding to SIGTERM. Sending SIGKILL.
Nov 19 10:20:06 saga sssd[be[default]]: Starting up
Nov 19 10:20:11 saga kernel: sssd_nss[16928]: segfault at 94 ip 00007f29e6a34fbc sp 00007ffd00ed24a0 error 4 in libdbus-1.so.3.4.0[7f29e6a10000+40000]
Nov 19 10:20:12 saga abrt[344]: Saved core dump of pid 16928 (/usr/libexec/sssd/sssd_nss) to /var/spool/abrt/ccpp-2015-11-19-10:20:11-16928 (1462272 bytes)
Nov 19 10:20:12 saga sssd[nss]: Starting up
Nov 19 10:41:06 saga sssd: Killing service [default], not responding to pings!
Nov 19 10:41:42 saga sssd: Killing service [nss], not responding to pings!
Nov 19 10:42:06 saga sssd: [default][341] is not responding to SIGTERM. Sending SIGKILL.
Nov 19 10:42:06 saga sssd[be[default]]: Starting up
Nov 19 10:42:12 saga sssd[nss]: Shutting down
Nov 19 10:42:12 saga sssd[nss]: Starting up
Nov 19 11:07:32 saga sssd: Killing service [nss], not responding to pings!
Nov 19 11:09:12 saga sssd: [nss][9468] is not responding to SIGTERM. Sending SIGKILL.
Nov 19 11:09:12 saga sssd[nss]: Starting up

# cat sssd.log
(Thu Nov 19 10:20:06 2015) [sssd] [mt_svc_sigkill] (0x0010): [default][10121] is not responding to SIGTERM. Sending SIGKILL.
(Thu Nov 19 10:42:06 2015) [sssd] [mt_svc_sigkill] (0x0010): [default][341] is not responding to SIGTERM. Sending SIGKILL.
(Thu Nov 19 11:08:32 2015) [sssd] [mt_svc_sigkill] (0x0010): [nss][9468] is not responding to SIGTERM. Sending SIGKILL.

# cat sssd_nss.log
(Thu Nov 19 11:09:47 2015) [sssd[nss]] [dp_id_callback] (0x0010): The Monitor returned an error [org.freedesktop.DBus.Error.NoReply]
(Thu Nov 19 11:09:47 2015) [sssd[nss]] [id_callback] (0x0010): The Monitor returned an error [org.freedesktop.DBus.Error.NoReply]

Program terminated with signal 11, Segmentation fault.
#0  dbus_watch_handle (watch=0x90, flags=2) at dbus-watch.c:650
650       if (watch->fd < 0 || watch->flags == 0)
(gdb) bt
#0  dbus_watch_handle (watch=0x90, flags=2) at dbus-watch.c:650
#1  0x00007f29e70bbdbc in sbus_watch_handler (ev=<value optimized out>,
    fde=<value optimized out>, flags=<value optimized out>, data=<value optimized out>)
    at src/sbus/sssd_dbus_common.c:94
#2  0x00007f29e39e7ebe in epoll_event_loop (ev=<value optimized out>,
    location=<value optimized out>) at ../tevent_epoll.c:736
#3  epoll_event_loop_once (ev=<value optimized out>, location=<value optimized out>)
    at ../tevent_epoll.c:931
#4  0x00007f29e39e62e6 in std_event_loop_once (ev=0xe1f3e0,
    location=0x7f29e70dae80 "src/util/server.c:668") at ../tevent_standard.c:112
#5  0x00007f29e39e249d in _tevent_loop_once (ev=0xe1f3e0,
    location=0x7f29e70dae80 "src/util/server.c:668") at ../tevent.c:530
#6  0x00007f29e39e251b in tevent_common_loop_wait (ev=0xe1f3e0,
    location=0x7f29e70dae80 "src/util/server.c:668") at ../tevent.c:634
#7  0x00007f29e39e6256 in std_event_loop_wait (ev=0xe1f3e0,
    location=0x7f29e70dae80 "src/util/server.c:668") at ../tevent_standard.c:138
#8  0x00007f29e70c28d3 in server_loop (main_ctx=0xe20750) at src/util/server.c:668
#9  0x0000000000405fc8 in main (argc=6, argv=<value optimized out>)
    at src/responder/nss/nsssrv.c:610
(gdb) print watch
$1 = (DBusWatch *) 0x90
(gdb) print *watch
Cannot access memory at address 0x90
(gdb) up
#1  0x00007f29e70bbdbc in sbus_watch_handler (ev=<value optimized out>,
    fde=<value optimized out>, flags=<value optimized out>, data=<value optimized out>)
    at src/sbus/sssd_dbus_common.c:94
94                  dbus_watch_handle(watch->dbus_write_watch, DBUS_WATCH_WRITABLE);
(gdb) print watch
$2 = (struct sbus_watch_ctx *) 0xe32a40
(gdb) print *watch
$3 = {prev = 0x0, next = 0x0, conn = 0xe299f0, fde = 0xe2c300, fd = 13, dbus_read_watch = 0x0,
  dbus_write_watch = 0x90}

Version-Release number of selected component (if applicable):
sssd-1.12.4-47.el6_7.4.x86_64
Comment 2 Jakub Hrozek 2015-11-26 11:35:22 EST
Upstream ticket:
https://fedorahosted.org/sssd/ticket/2886
Comment 3 Lukas Slebodnik 2015-11-27 10:28:14 EST
We can try to reproduce but it might a difficult task.

It looks like an use after free due to asynchronous operations.  Could you try to reproduce with valgrind?

Add following line to "[nss]" section
command = valgrind -v --log-file=/var/log/sssd/valgrind_nss_%p.log /usr/libexec/sssd/sssd_nss --uid 0 --gid 0 --debug-to-files


You will need to have enabled installed package valgrind and SELinux in permissive mode. The crash might not be caught by abrt becuase valgind handle crash itself. But you should be able to see errors in valgrind output /var/log/sssd/valgrind_nss_*.log
Comment 4 Orion Poplawski 2015-12-02 13:09:02 EST
Okay, I have this running.  May be very hard for me to reproduce as well as I've only seen this once so far.  I'll let you know if I find anything.
Comment 6 Jakub Hrozek 2016-08-10 08:32:24 EDT
At the moment, I'm giving Conditional NAK to this bug.

The reason is that a) there is no reliable reproducer available and b) there is a workaround available of either moving the cache to tmpfs or increasing the 'timeout' option in the [domain] section.

In addition, more recent releases, like RHEL-7.3 or newer changed the way the memor hierarchy of requests, which will prevent crashes like this in the future.
Comment 9 Orion Poplawski 2017-07-17 12:07:28 EDT
Looks like I'm seeing this occasionally on  EL7.3 with 1.14.0-43.el7_3.18 as well on a busy VM guest.  Will try increasing timeout.

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