Dear Danthank you for response. followed your proposal with increasing debugging, but for whatever reason it did not produced anything more into syslog. my rsyslog.conf was setup this way (followed by restarting rsyslog daemon) as the first option in list:
*.* -/var/log/debugbut rather I did strace of imapd daemon and paralel packet capture of communication to samba server.
I hope this can be helpful. thanks again michal On 4/13/2020 5:19 PM, Dan White wrote:
On 04/11/20 00:53 +0200, Michal Bruncko wrote:I am trying to use NTLM autentication (using cyrus-sasl-ntlm) for cyrus-imapd server for user authentication.in imapd.conf: sasl_ntlm_server: dc1.example.com sasl_ntlm_v2: yes sasl_mech_list: PLAIN NTLM LOGINdc1.example.com is samba 4 AD DC, I have tried also samba 4.2 in NT4 PDC mode, but with same results.in maillog: Apr 10 23:32:30 mail cyrus/imaps[10078]: NTLM server step 1 Apr 10 23:32:30 mail cyrus/imaps[10078]: client flags: ffff8207Apr 10 23:32:33 mail cyrus/imaps[10078]: badlogin: client.example.local [172.17.0.13] NTLM [SASL(0): successful result: ]which corresponds to following samba log messages:[2020/04/10 23:52:00.583266, 3] ../source3/smbd/process.c:1880(process_smb)Transaction 0 of length 51 (0 toread)[2020/04/10 23:52:00.583359, 3] ../source3/smbd/process.c:1489(switch_message)switch message SMBnegprot (pid 28556) conn 0x0[2020/04/10 23:52:00.586326, 3] ../source3/smbd/negprot.c:576(reply_negprot)Requested protocol [NT LM 0.12][2020/04/10 23:52:00.586887, 3] ../source3/smbd/negprot.c:377(reply_nt1)not using SPNEGO[2020/04/10 23:52:00.586969, 3] ../source3/smbd/negprot.c:684(reply_negprot)Selected protocol NT LM 0.12[2020/04/10 23:52:00.591116, 3] ../source3/smbd/server_exit.c:249(exit_server_common)Server exit (failed to receive smb request)Hi Michal, You can increase libsasl's logging with the following in your imapd.conf: sasl_log_level: 7See: https://github.com/cyrusimap/cyrus-sasl/blob/master/include/sasl.h fora description of the available log levels. You may need to modify your syslog configuration to accept more verbose auth.* levels.
Attachment:
imapd.pcap
Description: Binary data
18268 accept(4, NULL, NULL) = 16
18268 fcntl(15, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
18268 alarm(0) = 0
18268 getpeername(16, {sa_family=AF_INET, sin_port=htons(58417), sin_addr=inet_addr("172.30.0.103")}, [16]) = 0
18268 getpeername(16, {sa_family=AF_INET, sin_port=htons(58417), sin_addr=inet_addr("172.30.0.103")}, [16]) = 0
18268 getsockname(16, {sa_family=AF_INET, sin_port=htons(143), sin_addr=inet_addr("172.31.0.70")}, [16]) = 0
18268 open("/etc/hosts.allow", O_RDONLY) = 17
18268 fstat(17, {st_mode=S_IFREG|0644, st_size=370, ...}) = 0
18268 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe9e76ea000
18268 read(17, "#\n# hosts.allow\tThis file contains access rules which are used to\n#\t\tallow or deny connections to network services that\n#\t\teithe"..., 4096) = 370
18268 read(17, "", 4096) = 0
18268 close(17) = 0
18268 munmap(0x7fe9e76ea000, 4096) = 0
18268 open("/etc/hosts.deny", O_RDONLY) = 17
18268 fstat(17, {st_mode=S_IFREG|0644, st_size=460, ...}) = 0
18268 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe9e76ea000
18268 read(17, "#\n# hosts.deny\tThis file contains access rules which are used to\n#\t\tdeny connections to network services that either use\n#\t\tthe "..., 4096) = 460
18268 read(17, "", 4096) = 0
18268 close(17) = 0
18268 munmap(0x7fe9e76ea000, 4096) = 0
18268 write(3, "\2\0\0\0\\G\0\0", 8) = 8
18268 dup2(16, 0) = 0
18268 dup2(16, 1) = 1
18268 dup2(16, 2) = 2
18268 close(16) = 0
18268 write(3, "\3\0\0\0\\G\0\0", 8) = 8
18268 getpeername(0, {sa_family=AF_INET, sin_port=htons(58417), sin_addr=inet_addr("172.30.0.103")}, [16]) = 0
18268 stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=115, ...}) = 0
18268 open("/etc/host.conf", O_RDONLY|O_CLOEXEC) = 16
18268 fstat(16, {st_mode=S_IFREG|0644, st_size=9, ...}) = 0
18268 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe9e76ea000
18268 read(16, "multi on\n", 4096) = 9
18268 read(16, "", 4096) = 0
18268 close(16) = 0
18268 munmap(0x7fe9e76ea000, 4096) = 0
18268 futex(0x7fe9e4ffa9f0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
18268 open("/etc/resolv.conf", O_RDONLY|O_CLOEXEC) = 16
18268 fstat(16, {st_mode=S_IFREG|0644, st_size=115, ...}) = 0
18268 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe9e76ea000
18268 read(16, "# Generated by NetworkManager\nsearch ad.ssrk.sk ssrk.sk\nnameserver 172.30.0.180\nnameserver 2001:4118:804:f000::180\n", 4096) = 115
18268 read(16, "", 4096) = 0
18268 close(16) = 0
18268 munmap(0x7fe9e76ea000, 4096) = 0
18268 socket(AF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 16
18268 connect(16, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
18268 close(16) = 0
18268 socket(AF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 16
18268 connect(16, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
18268 close(16) = 0
18268 open("/etc/nsswitch.conf", O_RDONLY|O_CLOEXEC) = 16
18268 fstat(16, {st_mode=S_IFREG|0644, st_size=1965, ...}) = 0
18268 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe9e76ea000
18268 read(16, "#\n# /etc/nsswitch.conf\n#\n# An example Name Service Switch config file. This file should be\n# sorted with the most-used services "..., 4096) = 1965
18268 read(16, "", 4096) = 0
18268 close(16) = 0
18268 munmap(0x7fe9e76ea000, 4096) = 0
18268 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 16
18268 fstat(16, {st_mode=S_IFREG|0644, st_size=38281, ...}) = 0
18268 mmap(NULL, 38281, PROT_READ, MAP_PRIVATE, 16, 0) = 0x7fe9e7613000
18268 close(16) = 0
18268 open("/lib64/libnss_files.so.2", O_RDONLY|O_CLOEXEC) = 16
18268 read(16, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000!\0\0\0\0\0\0@\0\0\0\0\0\0\0x\350\0\0\0\0\0\0\0\0\0\0@\0008\0\7\0@\0!\0 \0\1\0\0\0\5\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0(\262\0\0\0\0\0\0(\262\0\0\0\0\0\0\0\0 \0\0\0\0\0\1\0\0\0\6\0\0\0"..., 832) = 832
18268 fstat(16, {st_mode=S_IFREG|0755, st_size=61624, ...}) = 0
18268 mmap(NULL, 2173016, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 16, 0) = 0x7fe9dfd4a000
18268 mprotect(0x7fe9dfd56000, 2093056, PROT_NONE) = 0
18268 mmap(0x7fe9dff55000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 16, 0xb000) = 0x7fe9dff55000
18268 mmap(0x7fe9dff57000, 22616, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fe9dff57000
18268 close(16) = 0
18268 mprotect(0x7fe9dff55000, 4096, PROT_READ) = 0
18268 munmap(0x7fe9e7613000, 38281) = 0
18268 open("/etc/hosts", O_RDONLY|O_CLOEXEC) = 16
18268 fstat(16, {st_mode=S_IFREG|0644, st_size=183, ...}) = 0
18268 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe9e76ea000
18268 read(16, "127.0.0.1 localhost localhost.localdomain localhost4 localhost4.localdomain4\n::1 localhost localhost.localdomain local"..., 4096) = 183
18268 read(16, "", 4096) = 0
18268 close(16) = 0
18268 munmap(0x7fe9e76ea000, 4096) = 0
18268 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 16
18268 fstat(16, {st_mode=S_IFREG|0644, st_size=38281, ...}) = 0
18268 mmap(NULL, 38281, PROT_READ, MAP_PRIVATE, 16, 0) = 0x7fe9e7613000
18268 close(16) = 0
18268 open("/lib64/libnss_dns.so.2", O_RDONLY|O_CLOEXEC) = 16
18268 read(16, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 \20\0\0\0\0\0\0@\0\0\0\0\0\0\0pr\0\0\0\0\0\0\0\0\0\0@\0008\0\7\0@\0!\0 \0\1\0\0\0\5\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0,P\0\0\0\0\0\0,P\0\0\0\0\0\0\0\0 \0\0\0\0\0\1\0\0\0\6\0\0\0"..., 832) = 832
18268 fstat(16, {st_mode=S_IFREG|0755, st_size=31408, ...}) = 0
18268 mmap(NULL, 2121952, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 16, 0) = 0x7fe9dfb43000
18268 mprotect(0x7fe9dfb49000, 2093056, PROT_NONE) = 0
18268 mmap(0x7fe9dfd48000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 16, 0x5000) = 0x7fe9dfd48000
18268 close(16) = 0
18268 mprotect(0x7fe9dfd48000, 4096, PROT_READ) = 0
18268 munmap(0x7fe9e7613000, 38281) = 0
18268 socket(AF_INET, SOCK_DGRAM|SOCK_CLOEXEC|SOCK_NONBLOCK, IPPROTO_IP) = 16
18268 connect(16, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.30.0.180")}, 16) = 0
18268 poll([{fd=16, events=POLLOUT}], 1, 0) = 1 ([{fd=16, revents=POLLOUT}])
18268 sendto(16, "*?\1\0\0\1\0\0\0\0\0\0\003103\0010\00230\003172\7in-addr\4arpa\0\0\f\0\1", 43, MSG_NOSIGNAL, NULL, 0) = 43
18268 poll([{fd=16, events=POLLIN}], 1, 5000) = 1 ([{fd=16, revents=POLLIN}])
18268 ioctl(16, FIONREAD, [74]) = 0
18268 recvfrom(16, "*?\205\200\0\1\0\1\0\0\0\0\003103\0010\00230\003172\7in-addr\4arpa\0\0\f\0\1\300\f\0\f\0\1\0\0\4\260\0\23\6server\2ad\4ssrk\2sk\0", 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.30.0.180")}, [16]) = 74
18268 close(16) = 0
18268 getsockname(0, {sa_family=AF_INET, sin_port=htons(143), sin_addr=inet_addr("172.31.0.70")}, [16]) = 0
18268 open("/var/lib/imap/proc/18268", O_RDWR|O_CREAT|O_TRUNC, 0666) = 16
18268 fstat(16, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
18268 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe9e76ea000
18268 lseek(16, 0, SEEK_SET) = 0
18268 write(16, "server.ad.ssrk.sk [172.30.0.103]\n", 33) = 33
18268 lseek(16, 0, SEEK_CUR) = 33
18268 ftruncate(16, 33) = 0
18268 open("/var/lib/imap/msg/motd", O_RDONLY) = -1 ENOENT (No such file or directory)
18268 write(1, "* OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE STARTTLS AUTH=PLAIN AUTH=NTLM AUTH=LOGIN AUTH=GSSAPI SASL-IR] mail.ssrk.sk Cyrus I"..., 179) = 179
18268 select(1, [0], NULL, NULL, {1800, 0}) = 1 (in [0], left {1799, 987972})
18268 select(1, [0], NULL, NULL, {1800, 0}) = 1 (in [0], left {1799, 999996})
18268 read(0, "1 authenticate NTLM\r\n", 4096) = 21
18268 socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 17
18268 connect(17, {sa_family=AF_INET, sin_port=htons(139), sin_addr=inet_addr("172.30.0.54")}, 16) = 0
18268 writev(17, [{"\201\0\0D", 4}, {" DBDHDCCACACACACACACACACACACACACA\0", 34}, {" ENEBEJEMCACACACACACACACACACACACA\0", 34}], 3) = 72
18268 recvfrom(17, "\202\0\0\0", 4, 0, NULL, NULL) = 4
18268 write(1, "+ \r\n", 4) = 4
18268 select(1, [0], NULL, NULL, {1800, 0}) = 1 (in [0], left {1799, 998186})
18268 read(0, "TlRMTVNTUAABAAAAB4IIAAAAAAAAAAAAAAAAAAAAAAA=\r\n", 4096) = 46
18268 writev(17, [{"\0\0\0/", 4}, {"\377SMBr\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\\G\0\0\0\0", 32}, {"\0", 1}, {"\f\0", 2}, {"\2NT LM 0.12\0", 12}], 5) = 51
18268 recvfrom(17, "\0\0\0g", 4, 0, NULL, NULL) = 4
18268 recvfrom(17, "\377SMBr\0\0\0\0\200\3@\0\0\0\0\0\0\0\0\0\0\0\0\0\0\\G\0\0\0\0\21\0\0\0032\0\1\0\4A\0\0\0\0\1\0\336O\0\0\375\363\200\0008\204L\177\317\21\326\1\210\377\10\"\0=\361d\26\373\376%{Z\0S\0S\0O\0S\0\0\0A\0P\0O\0L\0L\0O\0\0\0", 103, 0, NULL, NULL) = 103
18268 write(1, "+ TlRMTVNTUAACAAAACgAKADAAAAAFggEAPfFkFvv+JXsAAAAAAAAAAAAAAAAAAAAAWgBTAFMATwBTAA==\r\n", 84) = 84
18268 select(1, [0], NULL, NULL, {1800, 0}) = 1 (in [0], left {1798, 48229})
18268 read(0, "3 authenticate NTLM\r\n", 4096) = 21
18268 open("/etc/localtime", O_RDONLY|O_CLOEXEC) = 18
18268 fstat(18, {st_mode=S_IFREG|0644, st_size=2312, ...}) = 0
18268 fstat(18, {st_mode=S_IFREG|0644, st_size=2312, ...}) = 0
18268 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe9e76e9000
18268 read(18, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\7\0\0\0\7\0\0\0\0\0\0\0\220\0\0\0\7\0\0\0\r\233\f\27`\233\325\332\360\234\331\256\220\235\244\265\220\236\271\220\220\237\204\227\220\310\tq\220\314\347K\20\315\251\27\220\316\242C\20\317\2224\20\320\202%\20\321r\26\20\321\242\263`\322b\7\20\323\200\34\220\324I\322\20\324\223\264 \325\2r \325L8\20\326)\264\20"..., 4096) = 2312
18268 lseek(18, -1479, SEEK_CUR) = 833
18268 read(18, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\t\0\0\0\t\0\0\0\0\0\0\0\222\0\0\0\t\0\0\0\25\377\377\377\377\36I\222\370\377\377\377\377l\317\352\370\377\377\377\377\233\f\27`\377\377\377\377\233\325\332\360\377\377\377\377\234\331\256\220\377\377\377\377\235\244\265\220\377\377\377\377\236\271\220\220\377\377\377\377\237\204\227\220\377\377\377\377\310\tq\220\377\377\377\377\314\347K\20\377\377\377\377"..., 4096) = 1479
18268 close(18) = 0
18268 munmap(0x7fe9e76e9000, 4096) = 0
18268 socket(AF_LOCAL, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 18
18268 connect(18, {sa_family=AF_LOCAL, sun_path="/dev/log"}, 110) = 0
18268 sendto(18, "<21>Apr 13 22:09:56 cyrus/imap2[18268]: badlogin: server.ad.ssrk.sk [172.30.0.103] NTLM [SASL(0): successful result: ]", 118, MSG_NOSIGNAL, NULL, 0) = 118
18268 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
18268 rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
18268 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
18268 nanosleep({3, 0}, 0x7fff807c2b20) = 0
18268 close(17) = 0
18268 write(1, "1 NO bad protocol / cancel\r\n", 28) = 28
18268 select(1, [0], NULL, NULL, {1797, 0} <detached ...>
