Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

samba subtitles and crashing (thread-unsafe libsmbclient used across threads -> crash) #5936

Closed
orbisvicis opened this issue Jun 17, 2018 · 5 comments

Comments

@orbisvicis
Copy link

orbisvicis commented Jun 17, 2018

mpv version

$ ./mpv --version
mpv 0.28.0-618-gcd893626cb Copyright © 2000-2018 mpv/MPlayer/mplayer2 projects
 built on Sun Jun 17 11:06:33 EDT 2018
ffmpeg library versions:
   libavutil       56.18.102
   libavcodec      58.20.102
   libavformat     58.17.100
   libswscale      5.2.100
   libavfilter     7.25.100
   libswresample   3.2.100
ffmpeg version: N-91314-gbd47cca6a7

platform

$ cat /etc/fedora-release 
Fedora release 27 (Twenty Seven)

Reproduction steps

mpv "smb://...mkv" --sub-file "smb://...srt"

Expected behavior

Load subtitles.

Actual behavior

[smb] Could not open from LAN: 'smb://...srt'
Failed to open smb://...srt.
Can not open external file smb://...srt.

Even worse...

After I enable smb debugging, mpv now usually crashes when attempting to load the subtitles, even if run without any debugging. For example:

$ ./mpv --no-config --msg-level=smb=debug "smb://...mkv" --sub-file "smb://...srt"
Playing: smb://...mkv
[smb] Opening smb://...mkv
Using netbios name <NAME>
Using workgroup WORKGROUP.
SPNEGO(ntlmssp) login failed: NT_STATUS_WRONG_CREDENTIAL_HANDLE
[smb] Stream opened successfully.
[smb] Opening smb://...srt
Freed frame ../source3/libsmb/clireadwrite.c:667, expected ../source3/libsmb/clientgen.c:553.
talloc: access after free error - first free may be at ../libcli/smb/smb2cli_read.c:108
Bad talloc magic value - access after free
Aborted (core dumped)

Notice how the video file stream is successfully opened (anonymously), but not the subtitles. The same crash also happens with the repository-provided mpv:

$ mpv --version
mpv 0.27.2 (C) 2000-2017 mpv/MPlayer/mplayer2 projects
 built on UNKNOWN
ffmpeg library versions:
   libavutil       55.58.100
   libavcodec      57.89.100
   libavformat     57.71.100
   libswscale      4.6.100
   libavfilter     6.82.100
   libswresample   2.7.100
ffmpeg version: 3.3.7
@orbisvicis
Copy link
Author

orbisvicis commented Jun 20, 2018

This particular libsmbclient code in mpv causes crashes:

with many various libsmbclient messages, some of which are:

Freed frame ../source3/libsmb/clireadwrite.c:667, expected ../source3/libsmb/clientgen.c:553.
talloc: access after free error - first free may be at ../lib/tevent/tevent_req.c:260
Bad talloc magic value - access after free
Aborted (core dumped)


Freed frame ../source3/libsmb/clireadwrite.c:667, expected ../source3/libsmb/clientgen.c:553.
talloc: access after free error - first free may be at ../libcli/smb/smb2cli_query_info.c:138
Bad talloc magic value - access after free
Aborted (core dumped)


Freed frame ../source3/libsmb/libsmb_context.c:750, expected ../source3/libsmb/libsmb_context.c:750.
Freed frame ../source3/libsmb/libsmb_context.c:750, expected ../source3/libsmb/libsmb_context.c:750.
Freed frame ../source3/libsmb/clireadwrite.c:667, expected ../source3/libsmb/libsmb_context.c:750.
Segmentation fault (core dumped)


Freed frame ../source3/libsmb/clireadwrite.c:667, expected ../source3/libsmb/libsmb_context.c:750.
Bad talloc magic value - unknown value
Aborted (core dumped)

This is with either the latest upstream (git mirror) or 4.7.7 of samba, though all logs and stack traces here are from the latest version. Here is a trace from gdb, though I'm not sure if these vary as much as the above messages:

(gdb) bt full
#0  0x00007ffff2af0660 in raise () from /lib64/libc.so.6
No symbol table info available.
#1  0x00007ffff2af1c41 in abort () from /lib64/libc.so.6
No symbol table info available.
#2  0x00007fffed9ed8f3 in talloc_abort (reason=0x7fffed9f20c8 "Bad talloc magic value - access after free") at ../lib/talloc/talloc.c:500
No locals.
#3  0x00007fffed9ed916 in talloc_abort_access_after_free () at ../lib/talloc/talloc.c:508
No locals.
#4  0x00007fffed9ed99b in talloc_chunk_from_ptr (ptr=0x2450d00) at ../lib/talloc/talloc.c:525
        pp = 0x2450d00 "*$\032\355\377\177"
        tc = 0x2450ca0
#5  0x00007fffed9ef5a3 in __talloc_get_name (ptr=0x2450d00) at ../lib/talloc/talloc.c:1539
        tc = 0x0
#6  0x00007fffed9ef73e in _talloc_get_type_abort (ptr=0x2450d00, name=0x7fffed1a6261 "struct tevent_req", location=0x7fffed1a74a8 "../libcli/smb/smbXcli_base.c:3435") at ../lib/talloc/talloc.c:1596
        pname = 0x2451970 ""
#7  0x00007fffed18d42e in smb2cli_req_writev_done (subreq=0x2451970) at ../libcli/smb/smbXcli_base.c:3433
        req = 0x2451b00
        state = 0x2451b00
        nwritten = 38083232
        err = -415563433
#8  0x00007fffed3bb297 in _tevent_req_notify_callback (req=0x2451970, location=0x7fffe73b19d0 "../lib/async_req/async_sock.c:412") at ../lib/tevent/tevent_req.c:125
No locals.
#9  0x00007fffed3bb36c in tevent_req_finish (req=0x2451970, state=TEVENT_REQ_DONE, location=0x7fffe73b19d0 "../lib/async_req/async_sock.c:412") at ../lib/tevent/tevent_req.c:162
No locals.
#10 0x00007fffed3bb394 in _tevent_req_done (req=0x2451970, location=0x7fffe73b19d0 "../lib/async_req/async_sock.c:412") at ../lib/tevent/tevent_req.c:168
No locals.
#11 0x00007fffe73b0394 in writev_handler (ev=0x2450b20, fde=0x2451ca0, flags=2, private_data=0x2451970) at ../lib/async_req/async_sock.c:412
        req = 0x2451970
        state = 0x2451b00
        written = 72
        ok = true
#12 0x00007fffed3c28d1 in epoll_event_loop (epoll_ev=0x2450c50, tvalp=0x7fffffffce00) at ../lib/tevent/tevent_epoll.c:728
        fde = 0x2451ca0
        flags = 2
        mpx_fde = 0x0
        ret = 1
        i = 0
        events = {{events = 4, data = {ptr = 0x2451890, fd = 38082704, u32 = 38082704, u64 = 38082704}}}
        timeout = 20000
        wait_errno = 17
#13 0x00007fffed3c2f09 in epoll_event_loop_once (ev=0x2450b20, location=0x7fffed3c3590 "../lib/tevent/tevent_req.c:269") at ../lib/tevent/tevent_epoll.c:930
        epoll_ev = 0x2450c50
        tval = {tv_sec = 19, tv_usec = 999965}
        panic_triggered = false
#14 0x00007fffed3bfbfc in std_event_loop_once (ev=0x2450b20, location=0x7fffed3c3590 "../lib/tevent/tevent_req.c:269") at ../lib/tevent/tevent_standard.c:114
        glue_ptr = 0x7fffc801aa90
        glue = 0x7fffc801aa90
        ret = 0
#15 0x00007fffed3b94c4 in _tevent_loop_once (ev=0x2450b20, location=0x7fffed3c3590 "../lib/tevent/tevent_req.c:269") at ../lib/tevent/tevent.c:725
        ret = 0
        nesting_stack_ptr = 0x0
#16 0x00007fffed3bb628 in tevent_req_poll (req=0x221f100, ev=0x2450b20) at ../lib/tevent/tevent_req.c:269
        ret = 0
#17 0x00007fffec7ed243 in tevent_req_poll_ntstatus (req=0x221f100, ev=0x2450b20, status=0x7fffffffcf34) at ../lib/util/tevent_ntstatus.c:109
        ret = false
#18 0x00007fffee6fa71f in cli_echo (cli=0x7fffc8002600, num_echos=1, data=...) at ../source3/libsmb/clientgen.c:578
        frame = 0x7fffc801aa20
        ev = 0x2450b20
        req = 0x221f100
        status = {v = 0}
#19 0x00007ffff42efc57 in SMBC_check_server (context=0x7fffc80035b0, server=0x7fffc801a4b0) at ../source3/libsmb/libsmb_server.c:60
        data = '\000' <repeats 15 times>
        status = {v = 0}
        now = 71657
#20 0x00007ffff42f03b6 in SMBC_find_server (ctx=0x7fffd8014560, context=0x7fffc80035b0, server=0x24503d0 "<server>", share=0x2450440 "<share>", pp_workgroup=0x7fffffffd1b8, 
    pp_username=0x7fffffffd1a8, pp_password=0x7fffffffd1b0) at ../source3/libsmb/libsmb_server.c:226
        srv = 0x7fffc801a4b0
        auth_called = 1
#21 0x00007ffff42f0551 in SMBC_server_internal (ctx=0x7fffd8014560, context=0x7fffc80035b0, connect_if_not_found=true, server=0x24503d0 "<server>", port=0, share=0x2450440 "<share>", 
    pp_workgroup=0x7fffffffd1b8, pp_username=0x7fffffffd1a8, pp_password=0x7fffffffd1b0, in_cache=0x7fffffffd123) at ../source3/libsmb/libsmb_server.c:308
        srv = 0x0
        workgroup = 0x0
        c = 0x0
        server_n = 0x24503d0 "<server>"
        is_ipc = 0
        fs_attrs = 0
        username_used = 0x0
        password_used = 0x0
        status = {v = 0}
        newserver = 0x7fffffffd0c0 "<????>"
        newshare = 0x7fffed9ede22 <__talloc_with_prefix+395> "<????>"
        flags = 0
        tcon = 0x0
        signing_state = -1
        creds = 0x0
        use_kerberos = false
        fallback_after_kerberos = false
        use_ccache = false
        pw_nt_hash = false
        __FUNCTION__ = "SMBC_server_internal"
#22 0x00007ffff42f14b7 in SMBC_server (ctx=0x7fffd8014560, context=0x7fffc80035b0, connect_if_not_found=true, server=0x24503d0 "<server>", port=0, share=0x2450440 "<share>", 
    pp_workgroup=0x7fffffffd1b8, pp_username=0x7fffffffd1a8, pp_password=0x7fffffffd1b0) at ../source3/libsmb/libsmb_server.c:698
        srv = 0x0
        in_cache = false
        __FUNCTION__ = "SMBC_server"
#23 0x00007ffff42ec290 in SMBC_open_ctx (context=0x7fffc80035b0, 
    fname=0x2204400 "smb://...srt", flags=0, mode=420)
    at ../source3/libsmb/libsmb_file.c:93
        server = 0x24503d0 "<server>"
        share = 0x2450440 "<share>"
        user = 0x2450540 "<username>"
        password = 0x7fffc801d620 ""
        workgroup = 0x2208380 "LAN"
        path = 0x2208940 "...srt"
        targetpath = 0x0
        targetcli = 0x0
        srv = 0x0
        file = 0x0
        fd = 0
        port = 0
        status = {v = 3221225529}
        frame = 0x7fffd8014560
#24 0x00007ffff42e274c in smbc_open (furl=0x2204400 "smb://...srt", 
    flags=0, mode=420) at ../source3/libsmb/libsmb_compat.c:166
        file = 0x54113b <smb_auth_fn>
        fd = 1
#25 0x0000000000541428 in open_f (stream=0x224dd60) at ../stream/stream_smb.c:119
        filename = 0x2204400 "smb://...srt"
        len = 35670480
        fd = 19240704
        err = 0
        priv = 0x2450160
        write = false
        m = 0
#26 0x000000000053b01a in open_internal (sinfo=0x129f020 <stream_info_smb>, 
    url=0x2209f30 "smb://...srt", flags=0, c=0x21f0240, 
    global=0x21f0370, ret=0x7fffffffd310) at ../stream/stream.c:259
        path = 0x2209f36 "...srt"
        s = 0x224dd60
        r = 0
        __PRETTY_FUNCTION__ = "open_internal"
#27 0x000000000053b1eb in stream_create (
    url=0x2209f30 "smb://...srt", flags=0, c=0x21f0240, 
    global=0x21f0370) at ../stream/stream.c:295
        r = -2
        i = 3
        log = 0x224dc40
        s = 0x0
        __PRETTY_FUNCTION__ = "stream_create"
        unsafe = false
#28 0x00000000004b1540 in demux_open_url (
    url=0x2209f30 "smb://...srt", params=0x7fffffffd400, 
    cancel=0x21f0240, global=0x21f0370) at ../demux/demux.c:2356
        dummy = {force_format = 0x0, matroska_num_wanted_uids = 0, matroska_wanted_uids = 0x0, matroska_wanted_segment = 0, matroska_was_valid = 0x0, timeline = 0x0, disable_timeline = false, 
          initial_readahead = false, init_fragment = {start = 0x0, len = 0}, skip_lavf_probing = false, stream_flags = 0, disable_cache = false, demuxer_failed = false}
        s = 0x507fb5 <send_event+186>
        d = 0x5082a5 <mp_client_broadcast_event+170>
#29 0x0000000000521287 in mp_add_external_file (mpctx=0x21efbc0, 
    filename=0x2209f30 "smb://...srt", filter=STREAM_SUB)
    at ../player/loadfile.c:603
        opts = 0x21f0b40
        disp_filename = 0x2209f30 "smb://...srt"
        params = {force_format = 0x0, matroska_num_wanted_uids = 0, matroska_wanted_uids = 0x0, matroska_wanted_segment = 0, matroska_was_valid = 0x0, timeline = 0x0, disable_timeline = false, 
          initial_readahead = false, init_fragment = {start = 0x0, len = 0}, skip_lavf_probing = false, stream_flags = 0, disable_cache = false, demuxer_failed = false}
        demuxer = 0x224db70
        has_any = false
        first_num = 0
#30 0x0000000000521579 in open_external_files (mpctx=0x21efbc0, files=0x222d730, filter=STREAM_SUB) at ../player/loadfile.c:655
        n = 0
#31 0x00000000005237a3 in play_current_file (mpctx=0x21efbc0) at ../player/loadfile.c:1255
        opts = 0x21f0b40
        playback_start = -1e+100
        __PRETTY_FUNCTION__ = "play_current_file"
        play_start_pts = 6.9533558073188045e-310
        nothing_played = false
        end_event = {reason = 0, error = 35660128}
#32 0x00000000005245b7 in mp_play_files (mpctx=0x21efbc0) at ../player/loadfile.c:1527
        new_entry = 0x4ffffd730
#33 0x0000000000529a32 in mpv_main (argc=5, argv=0x7fffffffd738) at ../player/main.c:449
        mpctx = 0x21efbc0
        options = 0x7fffffffd740
        r = 0
        rc = 0
        reason = 0x7ffff6d8ed37 "eglWaitSync"
#34 0x0000000000489e17 in main (argc=5, argv=0x7fffffffd738) at ../osdep/main-fn-unix.c:5
No locals.

I've tried duplicating the crash with this minimal example:

#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <libsmbclient.h>

static void smb_auth_fn
    ( const char *server
    , const char *share
    , char *workgroup, int wgmaxlen
    , char *username, int unmaxlen
    , char *password, int pwmaxlen
    ) {
  strncpy(workgroup, "LAN", wgmaxlen - 1);
}

static int open_f(const char* p) {
    // equivalent to 0
    mode_t m = O_RDONLY;

    int err  = smbc_init(smb_auth_fn, 1);
    if (err < 0) {
        printf("Unable to initialize\n");
        exit(1);
    }

    int fd = smbc_open(p, m, 0644);
    if (fd < 0) {
        printf("Unable to open '%s'\n", p);
        exit(2);
    }

    return fd;
}

int main() {
    const char* s1 = "smb://...mkv";
    const char* s2 = "smb://...srt";

    int fd1 = open_f(s1);
    int fd2 = open_f(s2);

    printf("Descriptors: %i %i\n", fd1, fd2);

    smbc_close(fd1);
    smbc_close(fd2);
}

Which does duplicate the original stack trace, but without a crash:

Breakpoint 1, smb2cli_req_writev_done (subreq=0x632910) at ../libcli/smb/smbXcli_base.c:3434
3434			tevent_req_callback_data(subreq,
(gdb) bt
#0  smb2cli_req_writev_done (subreq=0x632910) at ../libcli/smb/smbXcli_base.c:3434
#1  0x00007ffff5dad297 in _tevent_req_notify_callback (req=0x632910, location=0x7ffff23ad9d0 "../lib/async_req/async_sock.c:412") at ../lib/tevent/tevent_req.c:125
#2  0x00007ffff5dad36c in tevent_req_finish (req=0x632910, state=TEVENT_REQ_DONE, location=0x7ffff23ad9d0 "../lib/async_req/async_sock.c:412") at ../lib/tevent/tevent_req.c:162
#3  0x00007ffff5dad394 in _tevent_req_done (req=0x632910, location=0x7ffff23ad9d0 "../lib/async_req/async_sock.c:412") at ../lib/tevent/tevent_req.c:168
#4  0x00007ffff23ac394 in writev_handler (ev=0x620e90, fde=0x634b50, flags=2, private_data=0x632910) at ../lib/async_req/async_sock.c:412
#5  0x00007ffff5db48d1 in epoll_event_loop (epoll_ev=0x63da30, tvalp=0x7fffffffd260) at ../lib/tevent/tevent_epoll.c:728
#6  0x00007ffff5db4f09 in epoll_event_loop_once (ev=0x620e90, location=0x7ffff5db5590 "../lib/tevent/tevent_req.c:269") at ../lib/tevent/tevent_epoll.c:930
#7  0x00007ffff5db1bfc in std_event_loop_once (ev=0x620e90, location=0x7ffff5db5590 "../lib/tevent/tevent_req.c:269") at ../lib/tevent/tevent_standard.c:114
#8  0x00007ffff5dab4c4 in _tevent_loop_once (ev=0x620e90, location=0x7ffff5db5590 "../lib/tevent/tevent_req.c:269") at ../lib/tevent/tevent.c:725
#9  0x00007ffff5dad628 in tevent_req_poll (req=0x63b910, ev=0x620e90) at ../lib/tevent/tevent_req.c:269
#10 0x00007ffff51df243 in tevent_req_poll_ntstatus (req=0x63b910, ev=0x620e90, status=0x7fffffffd394) at ../lib/util/tevent_ntstatus.c:109
#11 0x00007ffff70ec71f in cli_echo (cli=0x620bc0, num_echos=1, data=...) at ../source3/libsmb/clientgen.c:578
#12 0x00007ffff7bc1c57 in SMBC_check_server (context=0x621b70, server=0x638400) at ../source3/libsmb/libsmb_server.c:60
#13 0x00007ffff7bc23b6 in SMBC_find_server (ctx=0x63d9c0, context=0x621b70, server=0x61f770 "<server>", share=0x62fce0 "<share>", pp_workgroup=0x7fffffffd618, pp_username=0x7fffffffd608, 
    pp_password=0x7fffffffd610) at ../source3/libsmb/libsmb_server.c:226
#14 0x00007ffff7bc2551 in SMBC_server_internal (ctx=0x63d9c0, context=0x621b70, connect_if_not_found=true, server=0x61f770 "<server>", port=0, share=0x62fce0 "<share>", pp_workgroup=0x7fffffffd618, 
    pp_username=0x7fffffffd608, pp_password=0x7fffffffd610, in_cache=0x7fffffffd583) at ../source3/libsmb/libsmb_server.c:308
#15 0x00007ffff7bc34b7 in SMBC_server (ctx=0x63d9c0, context=0x621b70, connect_if_not_found=true, server=0x61f770 "<server>", port=0, share=0x62fce0 "<share>", pp_workgroup=0x7fffffffd618, 
    pp_username=0x7fffffffd608, pp_password=0x7fffffffd610) at ../source3/libsmb/libsmb_server.c:698
#16 0x00007ffff7bbe290 in SMBC_open_ctx (context=0x621b70, 
    fname=0x400a08 "smb://...srt", flags=0, mode=420)
    at ../source3/libsmb/libsmb_file.c:93
#17 0x00007ffff7bb474c in smbc_open (furl=0x400a08 "smb://...srt", flags=0, 
    mode=420) at ../source3/libsmb/libsmb_compat.c:166
#18 0x0000000000400828 in open_f ()
#19 0x0000000000400889 in main ()

Which leads to several shot-in-the-dark theories:

  • samba talloc buggy
  • different mpv thread closes the stream causing the samba talloc pointer to have value TALLOC_FLAG_FREE(?) which causes error.
  • mpv talloc interfering with samba talloc (probably not...).
  • ... ?

@orbisvicis
Copy link
Author

orbisvicis commented Jun 20, 2018

Update (from irc):

  • After I enable smb debugging, mpv now usually crashes when attempting to load the subtitles, even if run without any debugging

    By this I mean --msg-level=smb=debug. I think it was a bit of coincidence that the very first crash occurred after I added that option, even though I had run mpv countless times (10-20+) without crashing beforehand and that now crashes occur just as often (usually at least once every 2-3 runs) as non-crashes across all combinations of mpv, samba and with/without that option.

  • The remote file can (always) be opened as the main file (mpv complains about no video/audio streams).

  • If I mount via gvfs-smb and provide the equivalent local paths, mpv can load both the mkv and external subtitles.

  • Strangely if I pass the remote srt file as the main file and the remote mkv file to --sub-file, mpv always loads both without problem (excluding complaining about lack of video/audio streams).

  • Once in a blue moon mpv loads the external remote subtitles without any problems.

  • I built mpv with --disable-optimize in mpv_options and passing CFLAGS="-g3" to ./build` (from the mpv-build repository).

  • My test case loads both files without any problems.

If you look at the stack frames before open_f mpv already knows to expect STREAM_SUB (see mp_add_external_file), so it must somehow do something to the stream that affects the samba talloc.

@orbisvicis
Copy link
Author

orbisvicis commented Jun 20, 2018

Running valgrind's memcheck with--leak-check=yes shows hundreds of thousands of possible memory leaks all starting with talloc allocations. So not very helpful, I think.

Running valgrind's helgrind shows many relevant messages like:

==16624== Possible data race during write of size 8 at 0x217E2A88 by thread #1
==16624== Locks held: none
==16624==    at 0xF024861: _tc_free_internal (talloc.c:1153)
==16624==    by 0xF024AAD: _talloc_free_internal (talloc.c:1227)
==16624==    by 0xF025D75: _talloc_free (talloc.c:1769)
==16624==    by 0x87234F9: SMBC_open_ctx (libsmb_file.c:136)
==16624==    by 0x871974B: smbc_open (libsmb_compat.c:166)
==16624==    by 0x541427: open_f (stream_smb.c:119)
==16624==    by 0x53B019: open_internal (stream.c:259)
==16624==    by 0x53B1EA: stream_create (stream.c:295)
==16624==    by 0x4B153F: demux_open_url (demux.c:2356)
==16624==    by 0x521286: mp_add_external_file (loadfile.c:603)
==16624==    by 0x521578: open_external_files (loadfile.c:655)
==16624==    by 0x5237A2: play_current_file (loadfile.c:1255)
==16624== 
==16624== This conflicts with a previous write of size 8 by thread #7
==16624== Locks held: none
==16624==    at 0xF02360D: _talloc_chunk_set_free (talloc.c:360)
==16624==    by 0xF0248FF: _tc_free_internal (talloc.c:1165)
==16624==    by 0xF02594B: _tc_free_children_internal (talloc.c:1646)
==16624==    by 0xF0248EC: _tc_free_internal (talloc.c:1163)
==16624==    by 0xF02594B: _tc_free_children_internal (talloc.c:1646)
==16624==    by 0xF0248EC: _tc_free_internal (talloc.c:1163)
==16624==    by 0xF024AAD: _talloc_free_internal (talloc.c:1227)
==16624==    by 0xF025D75: _talloc_free (talloc.c:1769)
==16624==  Address 0x217e2a88 is 56 bytes inside a block of size 845 alloc'd
==16624==    at 0x4C2DF7B: malloc (vg_replace_malloc.c:299)
==16624==    by 0xF023DC9: __talloc_with_prefix (talloc.c:763)
==16624==    by 0xF023F89: _talloc_pool (talloc.c:817)
==16624==    by 0xF0240E7: _talloc_pooled_object (talloc.c:885)
==16624==    by 0xF655131: _tevent_req_create (tevent_req.c:78)
==16624==    by 0xF888D16: smb2cli_query_info_send (smb2cli_query_info.c:60)
==16624==    by 0xF8894DE: smb2cli_query_info (smb2cli_query_info.c:244)
==16624==    by 0xE305F6C: cli_smb2_qfileinfo_basic (cli_smb2_fnum.c:1426)
==16624==    by 0xE2E3485: cli_qfileinfo_basic (clirap.c:1176)
==16624==    by 0x8724D0C: SMBC_lseek_ctx (libsmb_file.c:694)
==16624==    by 0x8719930: smbc_lseek (libsmb_compat.c:222)
==16624==    by 0x5411B4: control (stream_smb.c:49)
==16624==  Block was alloc'd by thread #7

Or:

==16624==  Lock at 0x21796240 was first observed
==16624==    at 0x4C34CA3: pthread_mutex_init (hg_intercepts.c:787)
==16624==    by 0x5387DE: stream_cache_init (cache.c:760)
==16624==    by 0x53C37D: stream_enable_cache (stream.c:673)
==16624==    by 0x53C449: stream_enable_cache_defaults (stream.c:696)
==16624==    by 0x4B156E: demux_open_url (demux.c:2361)
==16624==    by 0x521DE7: open_demux_thread (loadfile.c:812)
==16624==    by 0x4C339E1: mythread_wrapper (hg_intercepts.c:389)
==16624==    by 0x9B8D50A: start_thread (in /usr/lib64/libpthread-2.26.so)
==16624==    by 0x9E9916E: clone (in /usr/lib64/libc-2.26.so)
==16624==  Address 0x21796240 is 80 bytes inside a block of size 408 alloc'd
==16624==    at 0x4C2FE2E: calloc (vg_replace_malloc.c:711)
==16624==    by 0x5A24BD: ta_zalloc_size (ta.c:169)
==16624==    by 0x5386B9: stream_cache_init (cache.c:740)
==16624==    by 0x53C37D: stream_enable_cache (stream.c:673)
==16624==    by 0x53C449: stream_enable_cache_defaults (stream.c:696)
==16624==    by 0x4B156E: demux_open_url (demux.c:2361)
==16624==    by 0x521DE7: open_demux_thread (loadfile.c:812)
==16624==    by 0x4C339E1: mythread_wrapper (hg_intercepts.c:389)
==16624==    by 0x9B8D50A: start_thread (in /usr/lib64/libpthread-2.26.so)
==16624==    by 0x9E9916E: clone (in /usr/lib64/libc-2.26.so)
==16624==  Block was alloc'd by thread #6
==16624== 
==16624== Possible data race during read of size 4 at 0x1E7EA0D4 by thread #7
==16624== Locks held: 1, at address 0x21796240
==16624==    at 0xE057C0C: talloc_stackframe_internal (talloc_stack.c:140)
==16624==    by 0xE057D83: _talloc_stackframe (talloc_stack.c:179)
==16624==    by 0xF8721AC: smbXcli_conn_received (smbXcli_base.c:1861)
==16624==    by 0xF655296: _tevent_req_notify_callback (tevent_req.c:125)
==16624==    by 0xF65536B: tevent_req_finish (tevent_req.c:162)
==16624==    by 0xF655393: _tevent_req_done (tevent_req.c:168)
==16624==    by 0x15665297: read_smb_done (read_smb.c:98)
==16624==    by 0xF655296: _tevent_req_notify_callback (tevent_req.c:125)
==16624==    by 0xF65536B: tevent_req_finish (tevent_req.c:162)
==16624==    by 0xF655393: _tevent_req_done (tevent_req.c:168)
==16624==    by 0x15664808: read_packet_handler (async_sock.c:546)
==16624==    by 0xF65C8D0: epoll_event_loop (tevent_epoll.c:728)
==16624== 
==16624== This conflicts with a previous write of size 4 by thread #1
==16624== Locks held: none
==16624==    at 0xE057C72: talloc_stackframe_internal (talloc_stack.c:147)
==16624==    by 0xE057D83: _talloc_stackframe (talloc_stack.c:179)
==16624==    by 0x871C5ED: smbc_set_credentials_with_fallback (libsmb_context.c:743)
==16624==    by 0x8725D90: SMBC_parse_path (libsmb_path.c:430)
==16624==    by 0x8723194: SMBC_open_ctx (libsmb_file.c:68)
==16624==    by 0x871974B: smbc_open (libsmb_compat.c:166)
==16624==    by 0x541427: open_f (stream_smb.c:119)
==16624==    by 0x53B019: open_internal (stream.c:259)
==16624==  Address 0x1e7ea0d4 is 4 bytes inside a block of size 16 alloc'd
==16624==    at 0x4C2FE2E: calloc (vg_replace_malloc.c:711)
==16624==    by 0xE05791E: talloc_stackframe_create (talloc_stack.c:75)
==16624==    by 0xE057C03: talloc_stackframe_internal (talloc_stack.c:137)
==16624==    by 0xE057D83: _talloc_stackframe (talloc_stack.c:179)
==16624==    by 0x871A77A: smbc_new_context (libsmb_context.c:139)
==16624==    by 0x8719650: smbc_init (libsmb_compat.c:121)
==16624==    by 0x5413D7: open_f (stream_smb.c:113)
==16624==    by 0x53B019: open_internal (stream.c:259)
==16624==    by 0x53B1EA: stream_create (stream.c:295)
==16624==    by 0x4B153F: demux_open_url (demux.c:2356)
==16624==    by 0x521DE7: open_demux_thread (loadfile.c:812)
==16624==    by 0x4C339E1: mythread_wrapper (hg_intercepts.c:389)
==16624==  Block was alloc'd by thread #6

Which is a little concerning considering that talloc contexts are not thread-safe (without cross-thread synchronization).

Also I could never trigger a crash (with either tool) when running under valgrind, though the external remote subtitles always failed to load.

@orbisvicis
Copy link
Author

orbisvicis commented Jun 20, 2018

Update:

  • Any remote media with those remote subtitles crashes.
  • Any local media with those remote subtitles loads correctly.

Just streaming any libsmbclient descriptors creates/frees talloc data. That's why loading the srt as the main file and the mkv with --sub-file works fine: because both are successfully loaded before streaming messes with the talloc pool.

...And yes that's it: with --pause everything is loaded successfully.

@orbisvicis orbisvicis changed the title samba subtitles and crashing samba subtitles and crashing (thread-unsafe libsmbclient used across threads -> crash) Jun 20, 2018
orbisvicis pushed a commit to orbisvicis/mpv that referenced this issue Jun 23, 2018
Thread-unsafe libsmbclient crashes when used across threads, for example
when provided more than one "smb://" URI. Fix this by locking all calls
to this library under a single mutex, which as expected will throttle
performance across concurrent smb streams. Subtitles are preloaded and
so don't count.

This is a temporary solution. When the following libsmbclient bug is
fixed, switch to the code from branch `smbclient_threaded_api`:

* https://bugzilla.samba.org/show_bug.cgi?id=11413
orbisvicis pushed a commit to orbisvicis/mpv that referenced this issue Jun 23, 2018
Thread-unsafe libsmbclient crashes when used across threads, for example
when provided more than one "smb://" URI. This patch allows each library
function to run concurrently with itself while locking out other library
functions, in an attempt to boost the performance of the
`smbclient_lock_all` branch. Unfortunately it fails horribly, so just
here for posterity.
orbisvicis pushed a commit to orbisvicis/mpv that referenced this issue Jun 23, 2018
Thread-unsafe libsmbclient crashes when used across threads, for example
when provided more than one "smb://" URI. Switch from the compatibility
api to the new libsmbclient api. Each use - presumably per-thread - of
`open_f` creates a new smb context, the deallocation of which is tied to
the talloc destructor of the stream. As opposed to locking cross-thread
calls, the new thread-safe api provides better streaming performance.
When the following thread-safety issue is fixed, this should be the
preferred solution:

* https://bugzilla.samba.org/show_bug.cgi?id=11413
orbisvicis pushed a commit to orbisvicis/mpv that referenced this issue Jun 25, 2018
Thread-unsafe libsmbclient is likely to crash when used simultaneously
across threads. For example, by:

    mpv "smb://...mkv" --sub-file "smb://...srt"

Work around this by locking all calls to this library under a single
global mutex. This is a temporary solution. When the libsmbclient bug
[1] is fixed, switch to the code from branch [2] which uses a new api to
create per-thread smb contexts. Fixes [3].

[1] https://bugzilla.samba.org/show_bug.cgi?id=11413
[2] https://github.com/orbisvicis/mpv/tree/smbclient_threaded_api
[3] mpv-player#5936
jeeb pushed a commit that referenced this issue Jul 29, 2018
Thread-unsafe libsmbclient is likely to crash when used simultaneously
across threads. For example, by:

    mpv "smb://...mkv" --sub-file "smb://...srt"

Work around this by locking all calls to this library under a single
global mutex. This is a temporary solution. When the libsmbclient bug
[1] is fixed, switch to the code from branch [2] which uses a new api to
create per-thread smb contexts. Fixes [3].

[1] https://bugzilla.samba.org/show_bug.cgi?id=11413
[2] https://github.com/orbisvicis/mpv/tree/smbclient_threaded_api
[3] #5936
jeeb pushed a commit that referenced this issue Jul 29, 2018
Thread-unsafe libsmbclient is likely to crash when used simultaneously
across threads. For example, by:

    mpv "smb://...mkv" --sub-file "smb://...srt"

Work around this by locking all calls to this library under a single
global mutex. This is a temporary solution. When the libsmbclient bug
[1] is fixed, switch to the code from branch [2] which uses a new api to
create per-thread smb contexts. Fixes [3].

[1] https://bugzilla.samba.org/show_bug.cgi?id=11413
[2] https://github.com/orbisvicis/mpv/tree/smbclient_threaded_api
[3] #5936

(cherry picked from commit 112b3fa)
@orbisvicis
Copy link
Author

Thanks.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant