I digged through a lot of logs now and I am absolutely sure that samba is the cause, why it is not working.
If I start a spotlight search the query is built perfectly fine. It is sent to ES and is answered as well. At the next step, samba is unmarshalling the received blob. And here I see differences between my samba versions log output and the actual source code in github, as the line descriptions don't match. Here is the stacktrace:
Code:
[2022/09/29 15:56:50.691385, 10, pid=93402, effective(1000, 1000), real(0, 0), class=rpc_srv] ../../source3/rpc_server/mdssvc/mdssvc.c:1054(slrpc_fetch_query_results)
fetch slq[0x5c0c5167,0x6b0000a0], start: 2022/09/29 15:56:50.293702, last_used: 2022/09/29 15:56:50.691383, expires: 2022/09/29 15:57:20.691383, query: '*=="SEARCHSTRINGFROMSPOTLIGHT*"cdw||kMDItemTextContent=="SEARCHSTRINGFROMSPOTLIGHT*"cdw'
[2022/09/29 15:56:50.691395, 10, pid=93402, effective(1000, 1000), real(0, 0), class=rpc_srv] ../../source3/rpc_server/mdssvc/mdssvc.c:1808(mds_dispatch)
mds_dispatch: DALLOC_CTX(#1): {
sl_array_t(#3): {
uint64_t: 0x0000
CNIDs: unkn1: 0xadd, unkn2: 0x6b0000a0
DALLOC_CTX(#0): {
}
sl_filemeta_t(#0): {
}
}
}
[2022/09/29 15:56:50.691430, 4, pid=93402, effective(1000, 1000), real(0, 0)] ../../source3/smbd/sec_ctx.c:444(pop_sec_ctx)
pop_sec_ctx (1000, 1000) - sec_ctx_stack_ndx = 0
[2022/09/29 15:56:50.691437, 1, pid=93402, effective(1000, 1000), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:484(ndr_print_function_debug)
mdssvc_cmd: struct mdssvc_cmd
out: struct mdssvc_cmd
fragment : *
fragment : 0x00000000 (0)
response_blob : *
response_blob: struct mdssvc_blob
length : 0x00000068 (104)
size : 0x00010000 (65536)
spotlight_blob : *
spotlight_blob: ARRAY(104)
[0] : 0x34 (52)
[1] : 0x33 (51)
[2] : 0x32 (50)
... Array ...
[103] : 0x00 (0)
unkn9 : *
unkn9 : 0x00000000 (0)
[2022/09/29 15:56:50.691901, 10, pid=93402, effective(1000, 1000), real(0, 0), class=smb2] ../../source3/smbd/smb2_server.c:2227(smbd_smb2_request_pending_timer)
smbd_smb2_request_pending_queue: opcode[SMB2_OP_IOCTL] mid 32 going async
[2022/09/29 15:56:50.691909, 10, pid=93402, effective(1000, 1000), real(0, 0), class=smb2_credits] ../../source3/smbd/smb2_server.c:980(smb2_set_operation_credit)
smb2_set_operation_credit: smb2_set_operation_credit: requested 256, charge 1, granted 256, current possible/max 542/8192, total granted/max/low/range 7906/8192/33/7906
[2022/09/29 15:56:50.691916, 10, pid=93402, effective(1000, 1000), real(0, 0), class=smb2] ../../source3/smbd/smb2_server.c:2338(smbd_smb2_request_pending_timer)
state->vector[0/5].iov_len = 4
state->vector[1/5].iov_len = 0
state->vector[2/5].iov_len = 64
state->vector[3/5].iov_len = 8
state->vector[4/5].iov_len = 1
[2022/09/29 15:56:50.691955, 10, pid=93402, effective(1000, 1000), real(0, 0), class=rpc_srv] ../../source3/rpc_server/srv_pipe_hnd.c:419(np_read_recv)
Received 160 bytes. There is no more data outstanding
[2022/09/29 15:56:50.691963, 10, pid=93402, effective(1000, 1000), real(0, 0), class=smb2] ../../source3/smbd/smb2_ioctl_named_pipe.c:172(smbd_smb2_ioctl_pipe_read_done)
smbd_smb2_ioctl_pipe_read_done: np_read_recv nread = 160 is_data_outstanding = 0, status = NT_STATUS_OK
[2022/09/29 15:56:50.691971, 10, pid=93402, effective(1000, 1000), real(0, 0), class=smb2] ../../source3/smbd/smb2_ioctl.c:317(smbd_smb2_request_ioctl_done)
smbd_smb2_request_ioctl_done: smbd_smb2_ioctl_recv returned 160 status NT_STATUS_OK
[2022/09/29 15:56:50.691980, 10, pid=93402, effective(1000, 1000), real(0, 0), class=smb2] ../../source3/smbd/smb2_server.c:3847(smbd_smb2_request_done_ex)
smbd_smb2_request_done_ex: mid [32] idx[1] status[NT_STATUS_OK] body[48] dyn[yes:160] at ../../source3/smbd/smb2_ioctl.c:410
[2022/09/29 15:56:50.691988, 10, pid=93402, effective(1000, 1000), real(0, 0), class=smb2_credits] ../../source3/smbd/smb2_server.c:980(smb2_set_operation_credit)
smb2_set_operation_credit: smb2_set_operation_credit: requested 256, charge 1, granted 0, current possible/max 286/8192, total granted/max/low/range 7906/8192/33/7906
... from Array to here Information seems to be unimportant from my understanding ...
[2022/09/29 15:56:50.745574, 0, pid=93402, effective(1000, 1000), real(0, 0)] ../../libcli/http/http.c:199(http_parse_response_line)
http_parse_response_line: Error parsing header
<----- ouch, that's bad
[2022/09/29 15:56:50.745727, 0, pid=93402, effective(1000, 1000), real(0, 0)] ../../lib/util/fault.c:172(smb_panic_log)
===============================================================
[2022/09/29 15:56:50.745739, 0, pid=93402, effective(1000, 1000), real(0, 0)] ../../lib/util/fault.c:176(smb_panic_log)
INTERNAL ERROR: Signal 11: Segmentation fault in pid 93402 (4.15.9)
[2022/09/29 15:56:50.745754, 0, pid=93402, effective(1000, 1000), real(0, 0)] ../../lib/util/fault.c:181(smb_panic_log)
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
[2022/09/29 15:56:50.745771, 0, pid=93402, effective(1000, 1000), real(0, 0)] ../../lib/util/fault.c:182(smb_panic_log)
===============================================================
[2022/09/29 15:56:50.745793, 0, pid=93402, effective(1000, 1000), real(0, 0)] ../../lib/util/fault.c:184(smb_panic_log)
PANIC (pid 93402): Signal 11: Segmentation fault in 4.15.9
[2022/09/29 15:56:50.746522, 0, pid=93402, effective(1000, 1000), real(0, 0)] ../../lib/util/fault.c:288(log_stack_trace)
BACKTRACE: 27 stack frames:
#0 0x801d35087 <log_stack_trace+0x37> at /usr/local/lib/samba4/libsamba-util.so.0
#1 0x801d35161 <smb_panic+0x11> at /usr/local/lib/samba4/libsamba-util.so.0
#2 0x801d34ed9 <fault_setup+0xa9> at /usr/local/lib/samba4/libsamba-util.so.0
#3 0x805dd76d0 <pthread_sigmask+0x540> at /lib/libthr.so.3
#4 0x805dd6c8f <pthread_setschedparam+0x82f> at /lib/libthr.so.3
#5 0x7ffffffff8a3 <???> at ???
#6 0x804c412b1 <__realloc+0xc21> at /lib/libc.so.7
#7 0x806765c77 <http_read_response_send+0xae7> at /usr/local/lib/samba4/private/libhttp-samba4.so
#8 0x806b9801a <tstream_readv_pdu_send+0x14a> at /usr/local/lib/samba4/private/libsamba-sockets-samba4.so
#9 0x806b98757 <tstream_writev_queue_recv+0x1c7> at /usr/local/lib/samba4/private/libsamba-sockets-samba4.so
#10 0x806b976cf <tstream_readv_send+0x22f> at /usr/local/lib/samba4/private/libsamba-sockets-samba4.so
#11 0x80408f989 <tevent_common_invoke_immediate_handler+0xc9> at /usr/local/lib/samba4/private/libtevent.so.0
#12 0x80408fa3c <tevent_common_loop_immediate+0x1c> at /usr/local/lib/samba4/private/libtevent.so.0
#13 0x8040953ab <_tevent_add_aio_fsync+0x2cb> at /usr/local/lib/samba4/private/libtevent.so.0
#14 0x804094120 <tevent_signal_get_tag+0x230> at /usr/local/lib/samba4/private/libtevent.so.0
#15 0x80408e4e1 <_tevent_loop_once+0xe1> at /usr/local/lib/samba4/private/libtevent.so.0
#16 0x80408e742 <tevent_common_loop_wait+0x32> at /usr/local/lib/samba4/private/libtevent.so.0
#17 0x8040941a0 <tevent_signal_get_tag+0x2b0> at /usr/local/lib/samba4/private/libtevent.so.0
#18 0x8019b9f13 <smbd_process+0x7b3> at /usr/local/lib/samba4/private/libsmbd-base-samba4.so
#19 0x102cec3 <main+0x44b3> at /usr/local/sbin/smbd
#20 0x80408f4cd <tevent_common_invoke_fd_handler+0x9d> at /usr/local/lib/samba4/private/libtevent.so.0
#21 0x80409575d <_tevent_add_aio_fsync+0x67d> at /usr/local/lib/samba4/private/libtevent.so.0
#22 0x804094120 <tevent_signal_get_tag+0x230> at /usr/local/lib/samba4/private/libtevent.so.0
#23 0x80408e4e1 <_tevent_loop_once+0xe1> at /usr/local/lib/samba4/private/libtevent.so.0
#24 0x80408e742 <tevent_common_loop_wait+0x32> at /usr/local/lib/samba4/private/libtevent.so.0
#25 0x8040941a0 <tevent_signal_get_tag+0x2b0> at /usr/local/lib/samba4/private/libtevent.so.0
#26 0x102b42f <main+0x2a1f> at /usr/local/sbin/smbd
So either our/my samba version is out of date or I picked a wrong version of ES. I don't want to investigate further today. Maybe at the weekend. Maybe I should report a bug, Idk...