freeipa

Clone
Source Code
GIT

#8687 Nightly failure (rawhide/f34) reinstalling samba client: winbindd coredump
Closed: fixed 7 months ago by rcritten. Opened a year ago by frenaud.

Closed: fixed
Reopen Issue

The nightly test test_smb failed in test_integration/test_smb.py::TestSMB::test_samba_reinstall on rawhide, see PR #681 with the following logs and report:

self = <ipatests.test_integration.test_smb.TestSMB object at 0x7f2d939a09a0>

    def test_samba_reinstall(self):
        """Test samba can be reinstalled.

        Test installation after uninstallation and do some sanity checks.
        Test for bug https://pagure.io/freeipa/issue/8021
        """
>       self.test_install_samba()

test_integration/test_smb.py:403: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
test_integration/test_smb.py:238: in test_install_samba
    self.smbserver.run_command(['systemctl', 'status', service])
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <ipatests.pytest_ipa.integration.host.Host client1.ipa.test (client)>
argv = ['systemctl', 'status', 'winbind'], set_env = True, stdin_text = None
log_stdout = True, raiseonerr = True, cwd = None, bg = False, encoding = 'utf-8'
ok_returncode = 0

    def run_command(self, argv, set_env=True, stdin_text=None,
                    log_stdout=True, raiseonerr=True,
                    cwd=None, bg=False, encoding='utf-8', ok_returncode=0):
        """Wrapper around run_command to log stderr on raiseonerr=True

        :param ok_returncode: return code considered to be correct,
                              you can pass an integer or sequence of integers
        """
        result = super().run_command(
            argv, set_env=set_env, stdin_text=stdin_text,
            log_stdout=log_stdout, raiseonerr=False, cwd=cwd, bg=bg,
            encoding=encoding
        )
        # in FIPS mode SSH may print noise to stderr, remove the string
        # "FIPS mode initialized" + optional newline.
        result.stderr_bytes = FIPS_NOISE_RE.sub(b'', result.stderr_bytes)
        try:
            result_ok = result.returncode in ok_returncode
        except TypeError:
            result_ok = result.returncode == ok_returncode
        if not result_ok and raiseonerr:
            result.log.error('stderr: %s', result.stderr_text)
>           raise subprocess.CalledProcessError(
                result.returncode, argv,
                result.stdout_text, result.stderr_text
            )
E           subprocess.CalledProcessError: Command '['systemctl', 'status', 'winbind']' returned non-zero exit status 3.

pytest_ipa/integration/host.py:200: CalledProcessError

The journal shows that winbindd coredumped:

Jan 30 12:27:36 client1.ipa.test systemd[1]: Starting Samba Winbind Daemon...
Jan 30 12:27:36 client1.ipa.test winbindd[31146]: [2021/01/30 12:27:36.429596,  0] ../../source3/winbindd/winbindd_cache.c:3204(initialize_winbindd_cache)
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:   initialize_winbindd_cache: clearing cache and re-creating with version number 2
Jan 30 12:27:36 client1.ipa.test audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=winbind comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 30 12:27:36 client1.ipa.test systemd[1]: Started Samba Winbind Daemon.
Jan 30 12:27:36 client1.ipa.test winbindd[31146]: [2021/01/30 12:27:36.442880,  0] ../../lib/util/become_daemon.c:135(daemon_ready)
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:   daemon_ready: daemon 'winbindd' finished starting up and ready to serve connections
Jan 30 12:27:36 client1.ipa.test systemd[1]: Starting Samba SMB Daemon...
Jan 30 12:27:36 client1.ipa.test winbindd[31148]: [2021/01/30 12:27:36.489004,  0] ../../source3/winbindd/winbindd_cm.c:1893(wb_open_internal_pipe)
Jan 30 12:27:36 client1.ipa.test winbindd[31148]:   open_internal_pipe: Could not connect to dssetup pipe: NT_STATUS_RPC_INTERFACE_NOT_FOUND
Jan 30 12:27:36 client1.ipa.test winbindd[31148]: [2021/01/30 12:27:36.491526,  0] ../../librpc/rpc/dcesrv_core.c:3007(dcesrv_call_dispatch_local)
Jan 30 12:27:36 client1.ipa.test winbindd[31148]:   dcesrv_call_dispatch_local: DCE/RPC fault in call lsarpc:2E - DCERPC_NCA_S_OP_RNG_ERROR
Jan 30 12:27:36 client1.ipa.test winbindd[31146]: [2021/01/30 12:27:36.676076,  0] ../../lib/util/fault.c:172(smb_panic_log)
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:   ===============================================================
Jan 30 12:27:36 client1.ipa.test winbindd[31146]: [2021/01/30 12:27:36.676996,  0] ../../lib/util/fault.c:173(smb_panic_log)
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:   INTERNAL ERROR: Signal 11: Segmentation fault in pid 31146 (4.14.0rc1)
Jan 30 12:27:36 client1.ipa.test winbindd[31146]: [2021/01/30 12:27:36.677666,  0] ../../lib/util/fault.c:177(smb_panic_log)
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:   If you are running a recent Samba version, and if you think this problem is not yet fixed in the latest versions, please consider reporting this bug, see https://wiki.samba.org/index.php/Bug_Reporting
Jan 30 12:27:36 client1.ipa.test winbindd[31146]: [2021/01/30 12:27:36.678298,  0] ../../lib/util/fault.c:182(smb_panic_log)
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:   ===============================================================
Jan 30 12:27:36 client1.ipa.test winbindd[31146]: [2021/01/30 12:27:36.678582,  0] ../../lib/util/fault.c:183(smb_panic_log)
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:   PANIC (pid 31146): Signal 11: Segmentation fault in 4.14.0rc1
Jan 30 12:27:36 client1.ipa.test winbindd[31146]: [2021/01/30 12:27:36.680211,  0] ../../lib/util/fault.c:287(log_stack_trace)
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:   BACKTRACE: 17 stack frames:
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #0 /lib64/libsamba-util.so.0(log_stack_trace+0x34) [0x7f8bafcc4834]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #1 /lib64/libsamba-util.so.0(smb_panic+0xd) [0x7f8bafcc4a8d]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #2 /lib64/libsamba-util.so.0(+0x11b28) [0x7f8bafcc4b28]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #3 /lib64/libpthread.so.0(+0x13970) [0x7f8baf3a3970]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #4 /lib64/libdcerpc-binding.so.0(dcerpc_binding_handle_call_send+0x76) [0x7f8bb02e59d6]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #5 /usr/lib64/samba/libdcerpc-samba4.so(dcerpc_wbint_AllocateGid_r_send+0xa3) [0x7f8bafefaa73]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #6 /usr/lib64/samba/libdcerpc-samba4.so(dcerpc_wbint_AllocateGid_send+0xba) [0x7f8bafefad4a]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #7 /usr/sbin/winbindd(winbindd_allocate_gid_send+0x76) [0x558e3d243606]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #8 /usr/sbin/winbindd(+0x3450c) [0x558e3d1e950c]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #9 /usr/sbin/winbindd(+0x9b55f) [0x558e3d25055f]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #10 /lib64/libtevent.so.0(tevent_common_invoke_fd_handler+0x7d) [0x7f8baf2a1a4d]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #11 /lib64/libtevent.so.0(+0xd4e7) [0x7f8baf2a54e7]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #12 /lib64/libtevent.so.0(+0x5f57) [0x7f8baf29df57]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #13 /lib64/libtevent.so.0(_tevent_loop_once+0x94) [0x7f8baf2a1414]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #14 /usr/sbin/winbindd(main+0xe50) [0x558e3d1df270]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #15 /lib64/libc.so.6(__libc_start_main+0xd5) [0x7f8baeef7b75]
Jan 30 12:27:36 client1.ipa.test audit[31146]: ANOM_ABEND auid=4294967295 uid=0 gid=0 ses=4294967295 subj=system_u:system_r:winbind_t:s0 pid=31146 comm="winbindd" exe="/usr/sbin/winbindd" sig=6 res=1
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:    #16 /usr/sbin/winbindd(_start+0x2e) [0x558e3d1dfade]
Jan 30 12:27:36 client1.ipa.test winbindd[31146]: [2021/01/30 12:27:36.684856,  0] ../../source3/lib/dumpcore.c:317(dump_core)
Jan 30 12:27:36 client1.ipa.test winbindd[31146]:   coredump is handled by helper binary specified at /proc/sys/kernel/core_pattern
Jan 30 12:27:36 client1.ipa.test winbindd[31146]: 
Jan 30 12:27:36 client1.ipa.test systemd[1]: Created slice system-systemd\x2dcoredump.slice.

Failed in [testing_master_latest]

PR #913

report

Failure observed in test_smb of [testing_ipa-4.9_latest] Nightly PR #920 , report
Edited a year ago by mpolovka

The reproducer is the following: configure samba file server on an IPA client, unconfigure, reconfigure:

ipa-client-install --domain ipa.test --realm IPA.TEST --principal admin --password Secret123 -U
ipa-client-samba -U
systemctl enable --now smb winbind
ipa-client-samba --uninstall -U
ipa-client-samba -U
systemctl enable --now smb winbind

winbind crashes and produces a coredump. This happens on Fedora 34.

Packages:
samba-winbind-4.14.5-0.fc34.x86_64
freeipa-client-samba-4.9.4-1.fc34.x86_64

samba.tar.gz

Uploaded tar file with samba logs, obtained after

# date; systemctl enable --now smb winbind
Fri Jul  2 02:03:04 PM EDT 2021

On start winbindd needs to allocate some GID on a request and cannot do so because there are no available IDs in the range it is assigned. The range is configured intentionally to not have any IDs: idmap config * : range = 0 - 0. This is due to us handling all IDs through SSSD and having those ranges read-only to Samba.

Judging by the timestamps, it would be an attempt to resolve Users alias:

[2021/07/02 14:03:05.940629, 10, pid=42140, effective(0, 0), real(0, 0), class=passdb] ../../source3/passdb/pdb_interface.c:1574(pdb_default_sid_to_id)
  Could not find map for sid S-1-5-32-545
[2021/07/02 14:03:05.940777, 10, pid=42140, effective(0, 0), real(0, 0)] ../../source3/groupdb/mapping.c:836(pdb_create_builtin_alias)
  Trying to create builtin alias 545
[2021/07/02 14:03:05.940786, 10, pid=42140, effective(0, 0), real(0, 0)] ../../source3/passdb/lookup_sid.c:1085(lookup_sid)
  lookup_sid called for SID 'S-1-5-32-545'
[2021/07/02 14:03:05.940805, 10, pid=42140, effective(0, 0), real(0, 0)] ../../source3/passdb/lookup_sid.c:833(check_dom_sid_to_level)
  Accepting SID S-1-5-32 in level 1
[2021/07/02 14:03:05.940814, 10, pid=42140, effective(0, 0), real(0, 0)] ../../source3/passdb/lookup_sid.c:594(lookup_rids)
  lookup_rids called for domain sid 'S-1-5-32'
[2021/07/02 14:03:05.940823, 10, pid=42140, effective(0, 0), real(0, 0)] ../../source3/passdb/lookup_sid.c:1120(lookup_sid)
  Sid S-1-5-32-545 -> BUILTIN\Users(4)
[2021/07/02 14:03:06.115925,  3, pid=42140, effective(0, 0), real(0, 0)] ../../source3/groupdb/mapping.c:855(pdb_create_builtin_alias)
  pdb_create_builtin_alias: Could not get a gid out of winbind
[2021/07/02 14:03:06.116010,  5, pid=42140, effective(0, 0), real(0, 0)] ../../source3/passdb/pdb_util.c:132(create_builtin_users)
  create_builtin_users: Failed to create Users
[2021/07/02 14:03:06.116071,  4, pid=42140, effective(0, 0), real(0, 0)] ../../source3/smbd/sec_ctx.c:437(pop_sec_ctx)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2021/07/02 14:03:06.116081,  2, pid=42140, effective(0, 0), real(0, 0)] ../../source3/auth/token_util.c:739(finalize_local_nt_token)
  WARNING: Failed to create BUILTIN\Users group! Can Winbind allocate gids?

I need to look at what is different at the reinstall but I suspect we need to clean some of TDBs in /var/lib/samba/ on uninstall as well.

Metadata Update from @sorlov:
- Custom field rhbz adjusted to https://bugzilla.redhat.com/show_bug.cgi?id=1980356
10 months ago

Metadata Update from @frenaud:
- Issue assigned to frenaud
7 months ago

Metadata Update from @frenaud:
- Custom field on_review adjusted to https://github.com/freeipa/freeipa/pull/6056
7 months ago

Metadata Update from @frenaud:
- Custom field rhbz adjusted to https://bugzilla.redhat.com/show_bug.cgi?id=1980356, https://bugzilla.redhat.com/show_bug.cgi?id=2001500 (was: https://bugzilla.redhat.com/show_bug.cgi?id=1980356)
7 months ago

master:

  • 91334b2 ipa-client-samba uninstall: remove tdb files
  • bbe554a ipa-server-install uninstall: remove tdb files

ipa-4-9:

  • 82eaa2e ipa-client-samba uninstall: remove tdb files
  • 6302769 ipa-server-install uninstall: remove tdb files

Metadata Update from @rcritten:
- Issue close_status updated to: fixed
- Issue status updated to: Closed (was: Open)
7 months ago

Login to comment on this ticket.

Metadata

tests test-failure

None
None
None
None
None
None
None
None
None
None
None
None
None
https://github.com/freeipa/freeipa/pull/6056
None
None
None
None
https://bugzilla.redhat.com/show_bug.cgi?id=1980356, https://bugzilla.redhat.com/show_bug.cgi?id=2001500
None
None
None
Attachments 1
samba.tar.gz
Attached 10 months ago View Comment
Powered by Pagure 5.13.3
Documentation • File an Issue • About • SSH Hostkey/Fingerprint
© Red Hat, Inc. and others.