[Pkg-samba-maint] Bug#848935: libnss-winbind: winbind authentication and wbinfo --uid-info no longer work after uprading to 4.5.2+dfsg-1
stephane
ps67.dbg at outlook.com
Tue Dec 20 23:25:42 UTC 2016
Package: libnss-winbind
Version: 2:4.5.2+dfsg-1
Severity: important
Dear maintener,
I'm encountering the following problem since the upgrade of the libnss-winbind, winbind and samba packages from
4.4.7+dfsg-1 to 4.5.2+dfsg-1: users can no longer access network shares
on a file server joined (as a member) to a samba-ad-dc based domain.
After further troubleshooting, it appears that the local UID and GID
numbers fails to be mapped to the domain accounts.
I was able to reproduce the problem in a lab that consists in the
following three virtual machines:
- v-smb-dc: 192.168.101.10: domain controller (using samba-ad-dc)
- v-smb-fs: 192.168.101.11: file server (joined to the domain)
- v-smb-client: 192.168.101.20: client (using smbclient and
cifs-utils, not joined to the domain)
The initial setup is as follows:
*** for v-smb-client
1) ntp synchronization
2) only use v-smb-dc as dns nameserver
3) apt-get install smbclient cifs-utils
(using version 4.5.2+dfsg-1)
*** for v-smb-dc:
0) set up prerequisites: dns resolution, install all updates in
testing, ntp synchronization, add mount flags acl,
user_xattr and barrier=1 to the root filesystem
1) apt-get install samba winbind
(using version 4.5.2+dfsg-1)
2) mv /etc/samba/smb.conf /etc/samba/smb.conf.bak
3) samba-tool domain provision --use-rfc2307 --interactive
(default option left)
4)/etc/samba/smb.conf is as follows:
[global]
netbios name = V-SMB-DC
realm = LAB.LOCAL
workgroup = LAB
dns forwarder = 192.168.101.1
server role = active directory domain controller
idmap_ldb:use rfc2307 = yes
logging level = 7
[netlogon]
path = /var/lib/samba/sysvol/lab.local/scripts
read only = No
[sysvol]
path = /var/lib/samba/sysvol
read only = No
5) systemctl restart samba-ad-dc
6) change /etc/resolv.conf and /etc/network/interfaces to use only v-smb-dc (192.168.101.10) as nameserver
7) smbpasswd -a testusr
8) all tests ok (samba-tool processes, set/getfacl, attr, dns, kinit)
9) the client vm can access netlogon and sysvol successfully
root at v-smb-client:~# smbclient -L v-smb-dc -U%
WARNING: The "syslog" option is deprecated
Domain=[LAB] OS=[Windows 6.1] Server=[Samba 4.5.2-Debian]
Sharename Type Comment
--------- ---- -------
netlogon Disk
sysvol Disk
IPC$ IPC IPC Service (Samba 4.5.2-Debian)
Domain=[LAB] OS=[Windows 6.1] Server=[Samba 4.5.2-Debian]
Server Comment
--------- -------
Workgroup Master
--------- -------
WORKGROUP V-SMB-DC
root at v-smb-client:~# smbclient -L v-smb-dc -UAdministrator
WARNING: The "syslog" option is deprecated
Enter Administrator's password:
Domain=[LAB] OS=[Windows 6.1] Server=[Samba 4.5.2-Debian]
Sharename Type Comment
--------- ---- -------
netlogon Disk
sysvol Disk
IPC$ IPC IPC Service (Samba 4.5.2-Debian)
Domain=[LAB] OS=[Windows 6.1] Server=[Samba 4.5.2-Debian]
Server Comment
--------- -------
Workgroup Master
--------- -------
WORKGROUP V-SMB-DC
root at v-smb-client:~# mount -t cifs //v-smb-dc/sysvol /mnt -o ro,username=administrator,domain=LAB.LOCAL
Password for administrator@//v-smb-dc/sysvol: ********
root at v-smb-client:~# find /mnt
/mnt
/mnt/lab.local
/mnt/lab.local/scripts
/mnt/lab.local/Policies
/mnt/lab.local/Policies/{31B2F340-016D-11D2-945F-00C04FB984F9}
/mnt/lab.local/Policies/{31B2F340-016D-11D2-945F-00C04FB984F9}/USER
/mnt/lab.local/Policies/{31B2F340-016D-11D2-945F-00C04FB984F9}/MACHINE
/mnt/lab.local/Policies/{31B2F340-016D-11D2-945F-00C04FB984F9}/GPT.INI
/mnt/lab.local/Policies/{6AC1786C-016F-11D2-945F-00C04FB984F9}
/mnt/lab.local/Policies/{6AC1786C-016F-11D2-945F-00C04FB984F9}/USER
/mnt/lab.local/Policies/{6AC1786C-016F-11D2-945F-00C04FB984F9}/MACHINE
/mnt/lab.local/Policies/{6AC1786C-016F-11D2-945F-00C04FB984F9}/GPT.INI
*** for v-smb-fs
0) set up prerequisites: ntp synchronisation, only use v-smb-dc as dns nameserver
1) mkdir /shared; apt-get install samba winbind libnss-winbind
(using version 4.5.2+dfsg-1)
2) for p in samba-ad-dc samba smbd nmbd winbind; do systemctl stop $p; done
(and check all process are terminated)
3) edit /etc/samba/smb.conf as follows:
[global]
security = ads
realm = LAB.LOCAL
workgroup = LAB
idmap uid = 10000-20000
idmap gid = 10000-20000
winbind use default domain = yes
winbind enum users = yes
winbind enum groups = yes
winbind nss info = template
template homedir = /data/%U
template shell = /bin/false
encrypt passwords = yes
client use spnego = yes
client ntlmv2 auth = yes
restrict anonymous = 2
valid users = @"Domain Users"
log level = 7
[shared]
write list = @"Domain Admins"
path = /shared
4) net ads join -U administrator
(no errors)
5) for p in winbind smbd nmbd; do systemctl start $p; done
6) test winbind:
root at v-smb-fs:/var/log/samba# wbinfo -t
checking the trust secret for domain LAB via RPC calls succeeded
root at v-smb-fs:/var/log/samba# wbinfo -u
administrator
testusr
krbtgt
guest
root at v-smb-fs:/var/log/samba# wbinfo -g
allowed rodc password replication group
enterprise read-only domain controllers
denied rodc password replication group
read-only domain controllers
group policy creator owners
ras and ias servers
domain controllers
enterprise admins
domain computers
cert publishers
dnsupdateproxy
domain admins
domain guests
schema admins
domain users
dnsadmins
7) edit /etc/nssswitch.conf:
[...]
passwd: compat winbind
group: compat winbind
[...]
8) test that getent can see domain users and groups:
root at v-smb-fs:/var/log/samba# getent passwd
root:x:0:0:root:/root:/bin/bash
daemon:x:1:1:daemon:/usr/sbin:/usr/sbin/nologin
[...]
sshd:x:106:65534::/var/run/sshd:/usr/sbin/nologin
ntp:x:107:111::/home/ntp:/bin/false
administrator:*:100500:100513:Administrator:/data/administrator:/bin/false
testusr:*:101103:100513:testusr:/data/testusr:/bin/false
krbtgt:*:100502:100513:krbtgt:/data/krbtgt:/bin/false
guest:*:100501:100514:Guest:/data/guest:/bin/false
root at v-smb-fs:/var/log/samba# getent group
root:x:0:
daemon:x:1:
[..]
winbindd_priv:x:112:
sambashare:x:113:
allowed rodc password replication group:x:100571:
enterprise read-only domain controllers:x:100498:
denied rodc password replication group:x:100572:
read-only domain controllers:x:100521:
group policy creator owners:x:100520:
ras and ias servers:x:100553:
domain controllers:x:100516:
enterprise admins:x:100519:
domain computers:x:100515:
cert publishers:x:100517:
dnsupdateproxy:x:101102:
domain admins:x:100512:
domain guests:x:100514:
schema admins:x:100518:
domain users:x:100513:
dnsadmins:x:101101:
9) create test file and configure permissions on /shared:
root at v-smb-fs:~# echo 'Hello, World!' > /shared/hello.txt
root at v-smb-fs:~# chown administrator:domain\ users /shared -R
root at v-smb-fs:~# chmod 750 /shared; chmod 640 /shared/hello.txt
Looks good. Now reproduce the bug:
*** client can't access the shared folder on v-smb-dc:
root at v-smb-client:~# mount -t cifs //v-smb-fs/shared /mnt -o ro,username=administrator,domain=LAB.LOCAL
Password for administrator@//v-smb-fs/shared: ********
mount error(5): Input/output error
Refer to the mount.cifs(8) manual page (e.g. man mount.cifs)
See attached file v-smb-fs_debug_4.5_smbclient.txt for the logs produced on v-smb-dc.
Some interesting lines:
==> log.smbd <==
[2016/12/20 20:44:45.753029, 5] ../source3/lib/username.c:159(Get_Pwnam_internals)
Get_Pwnam_internals did find user [LAB\administrator]!
[2016/12/20 20:44:45.753111, 3] ../source3/auth/auth.c:249(auth_check_ntlm_password)
check_ntlm_password: winbind authentication for user [Administrator] succeeded
[2016/12/20 20:44:45.753179, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2016/12/20 20:44:45.753362, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2016/12/20 20:44:45.753422, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2016/12/20 20:44:45.753479, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.753534, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/20 20:44:45.753623, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2016/12/20 20:44:45.753680, 5] ../source3/auth/auth.c:292(auth_check_ntlm_password)
check_ntlm_password: PAM Account for user [LAB\administrator] succeeded
[2016/12/20 20:44:45.753848, 2] ../source3/auth/auth.c:305(auth_check_ntlm_password)
check_ntlm_password: authentication for user [Administrator] -> [Administrator] -> [LAB\administrator] succeeded
[2016/12/20 20:44:45.753928, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
==> log.winbindd <==
[2016/12/20 20:44:45.754213, 3] ../source3/winbindd/winbindd_getpwuid.c:49(winbindd_getpwuid_send)
getpwuid 100500
==> log.winbindd-idmap <==
[2016/12/20 20:44:45.758428, 5] ../source3/passdb/pdb_interface.c:176(make_pdb_method_name)
Found pdb backend tdbsam
[2016/12/20 20:44:45.758490, 5] ../source3/passdb/pdb_interface.c:187(make_pdb_method_name)
pdb backend tdbsam has a valid init
[2016/12/20 20:44:45.759424, 4] ../source3/passdb/pdb_interface.c:1402(pdb_default_uid_to_sid)
pdb_default_uid_to_sid: host has no idea of uid 100500
[2016/12/20 20:44:45.759504, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
==> log.winbindd <==
[2016/12/20 20:44:45.759595, 5] ../source3/winbindd/winbindd_getpwuid.c:111(winbindd_getpwuid_recv)
Could not convert sid S-0-0: NT_STATUS_NO_SUCH_USER
==> log.smbd <==
[2016/12/20 20:44:45.759697, 1] ../source3/auth/token_util.c:430(add_local_groups)
SID S-1-5-21-119579451-791976271-3043243932-500 -> getpwuid(100500) failed
[2016/12/20 20:44:45.759767, 3] ../source3/auth/token_util.c:316(create_local_nt_token_from_info3)
Failed to finalize nt token
[2016/12/20 20:44:45.759833, 1] ../source3/smbd/sesssetup.c:290(reply_sesssetup_and_X_spnego)
Failed to generate session_info (user and group token) for session setup: NT_STATUS_UNSUCCESSFUL
*** on v-smb-fs, the uid and gid, yet correct, aren't resolved in ls:
root at v-smb-fs:~# ls -la /shared
total 12
drwxr-x--- 2 100500 100513 4096 Dec 21 00:01 .
drwxr-xr-x 19 root root 4096 Dec 20 20:20 ..
-rw-r----- 1 100500 100513 14 Dec 21 00:01 hello.txt
See attached file v-smb-fs_debug_4.5_ls.txt for the log produced on v-smb-fs when the above ls command is executed.
We still have those lines:
[2016/12/20 20:53:10.966419, 3] ../source3/winbindd/winbindd_getpwuid.c:49(winbindd_getpwuid_send)
getpwuid 100500
[2016/12/20 20:53:10.966631, 5] ../source3/winbindd/winbindd_getpwuid.c:111(winbindd_getpwuid_recv)
Could not convert sid S-0-0: NT_STATUS_NO_SUCH_USER
[2016/12/20 20:53:10.966577, 4] ../source3/passdb/pdb_interface.c:1402(pdb_default_uid_to_sid)
pdb_default_uid_to_sid: host has no idea of uid 100500
*** on v-smb-fs, wbinfo --uid-info fails:
root at v-smb-fs:~# wbinfo --user-info=testusr
testusr:*:101103:100513:testusr:/data/testusr:/bin/false
root at v-smb-fs:~# wbinfo --uid-info=101103
failed to call wbcGetpwuid: WBC_ERR_DOMAIN_NOT_FOUND
Could not get info for uid 101103
See attached file v-smb-fs_debug_4.5_wbinfo.txt for the log produced on v-smb-fs when the wbinfo --uid-info=101103 command is executed.
Once again, we can see those lines:
[2016/12/20 22:47:30.831788, 3] ../source3/winbindd/winbindd_getpwuid.c:49(winbindd_getpwuid_send)
getpwuid 101103
[2016/12/20 22:47:30.834211, 4] ../source3/passdb/pdb_interface.c:1402(pdb_default_uid_to_sid)
pdb_default_uid_to_sid: host has no idea of uid 101103
[2016/12/20 22:47:30.834288, 5] ../source3/winbindd/winbindd_getpwuid.c:111(winbindd_getpwuid_recv)
Could not convert sid S-0-0: NT_STATUS_NO_SUCH_USER
*** downgrade to 4.4.7+dfsg-1 on v-smb-fs:
1) smbd, nmbd and winbind are stopped and all samba related packages that have been installed on v-smb-fs are downgraded to version 4.4.7+dfsg-1. The 4.5.2+dfsg-1 packages are left in place on v-smb-fs and v-smb-client.
ii libnss-winbind:amd64 2:4.4.7+dfsg-1 amd64 Samba nameservice integration plugins
ii libwbclient0:amd64 2:4.4.7+dfsg-1 amd64 Samba winbind client library
ii python-samba 2:4.4.7+dfsg-1 amd64 Python bindings for Samba
ii samba 2:4.4.7+dfsg-1 amd64 SMB/CIFS file, print, and login server for Unix
ii samba-common 2:4.4.7+dfsg-1 all common files used by both the Samba server and client
ii samba-common-bin 2:4.4.7+dfsg-1 amd64 Samba common files used by both the server and the client
ii samba-dsdb-modules 2:4.4.7+dfsg-1 amd64 Samba Directory Services Database
ii samba-libs:amd64 2:4.4.7+dfsg-1 amd64 Samba core libraries
ii samba-vfs-modules 2:4.4.7+dfsg-1 amd64 Samba Virtual FileSystem plugins
ii winbind 2:4.4.7+dfsg-1 amd64 service to resolve user and group information from Windows NT servers
2) then the same test are done, this time no problem:
root at v-smb-client:~# mount -t cifs //v-smb-fs/shared /mnt -o ro,username=administrator,domain=LAB.LOCAL
Password for administrator@//v-smb-fs/shared: ********
root at v-smb-client:~# cat /mnt/hello.txt
Hello, World!
root at v-smb-client:~# umount /mnt
root at v-smb-fs:~# ls -la /shared
total 12
drwxr-x--- 2 administrator domain users 4096 Dec 21 00:01 .
drwxr-xr-x 19 root root 4096 Dec 20 20:20 ..
-rw-r----- 1 administrator domain users 14 Dec 21 00:01 hello.txt
root at v-smb-fs:~# wbinfo --uid-info=101103
testusr:*:101103:100513:testusr:/data/testusr:/bin/false
*** upgrade to 4.5.2+dfsg-1 and the problem is back there:
root at v-smb-fs:~# for p in samba-ad-dc samba smbd nmbd winbind; do systemctl stop $p; done
root at v-smb-fs:~# apt-get upgrade
Reading package lists... Done
Building dependency tree
Reading state information... Done
Calculating upgrade... Done
The following packages will be upgraded:
libnss-winbind libwbclient0 python-samba samba samba-common samba-common-bin
samba-dsdb-modules samba-libs samba-vfs-modules winbind
10 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
Need to get 0 B/9,691 kB of archives.
After this operation, 1,153 kB of additional disk space will be used.
Do you want to continue? [Y/n]
Preconfiguring packages ...
(Reading database ... 28165 files and directories currently installed.)
Preparing to unpack .../0-samba-dsdb-modules_2%3a4.5.2+dfsg-1_amd64.deb ...
Unpacking samba-dsdb-modules (2:4.5.2+dfsg-1) over (2:4.4.7+dfsg-1) ...
[...]
Setting up libnss-winbind:amd64 (2:4.5.2+dfsg-1) ...
Processing triggers for libc-bin (2.24-8) ...
root at v-smb-client:~# mount -t cifs //v-smb-fs/shared /mnt -o ro,username=administrator,domain=LAB.LOCAL
Password for administrator@//v-smb-fs/shared: ********
mount error(5): Input/output error
Refer to the mount.cifs(8) manual page (e.g. man mount.cifs)
root at v-smb-fs:~# ls -la /shared
total 12
drwxr-x--- 2 100500 100513 4096 Dec 21 00:01 .
drwxr-xr-x 19 root root 4096 Dec 20 20:20 ..
-rw-r----- 1 100500 100513 14 Dec 21 00:01 hello.txt
root at v-smb-fs:~# wbinfo --uid-info=101103
failed to call wbcGetpwuid: WBC_ERR_DOMAIN_NOT_FOUND
Could not get info for uid 101103
Feel free to contact me if you need further information.
Best regards,
Stephane
-- System Information:
Debian Release: stretch/sid
APT prefers testing
APT policy: (500, 'testing')
Architecture: amd64 (x86_64)
Kernel: Linux 4.8.0-2-amd64 (SMP w/2 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
Versions of packages libnss-winbind depends on:
ii dpkg 1.18.15
ii libbsd0 0.8.3-1
ii libc6 2.24-8
ii libwbclient0 2:4.5.2+dfsg-1
ii samba-common 2:4.5.2+dfsg-1
ii samba-libs 2:4.5.2+dfsg-1
ii winbind 2:4.5.2+dfsg-1
libnss-winbind recommends no packages.
Versions of packages libnss-winbind suggests:
pn libpam-winbind <none>
-- no debconf information
-------------- next part --------------
==> log.nmbd <==
[2016/12/20 20:44:37.458602, 4] ../source3/nmbd/nmbd_workgroupdb.c:165(find_workgroup_on_subnet)
find_workgroup_on_subnet: workgroup search for LAB on subnet 192.168.101.11: found.
[2016/12/20 20:44:37.458699, 4] ../source3/nmbd/nmbd_workgroupdb.c:276(dump_workgroups)
dump_workgroups()
dump workgroup on subnet 192.168.101.11: netmask= 255.255.255.0:
LAB(1) current master browser = V-SMB-FS
V-SMB-FS 40849b03 (Samba 4.5.2-Debian)
==> log.smbd <==
[2016/12/20 20:44:45.644528, 5] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
check lock order 2 for /var/run/samba/serverid.tdb
[2016/12/20 20:44:45.644797, 5] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
release lock order 2 for /var/run/samba/serverid.tdb
[2016/12/20 20:44:45.644977, 5] ../lib/util/util_net.c:1057(print_socket_options)
Socket options:
SO_KEEPALIVE = 1
SO_REUSEADDR = 1
SO_BROADCAST = 0
TCP_NODELAY = 1
TCP_KEEPCNT = 9
TCP_KEEPIDLE = 7200
TCP_KEEPINTVL = 75
IPTOS_LOWDELAY = 0
IPTOS_THROUGHPUT = 0
SO_REUSEPORT = 1
SO_SNDBUF = 87040
SO_RCVBUF = 374400
SO_SNDLOWAT = 1
SO_RCVLOWAT = 1
SO_SNDTIMEO = 0
SO_RCVTIMEO = 0
TCP_QUICKACK = 1
TCP_DEFER_ACCEPT = 0
[2016/12/20 20:44:45.645887, 5] ../lib/util/util_net.c:1057(print_socket_options)
Socket options:
SO_KEEPALIVE = 1
SO_REUSEADDR = 1
SO_BROADCAST = 0
TCP_NODELAY = 1
TCP_KEEPCNT = 9
TCP_KEEPIDLE = 7200
TCP_KEEPINTVL = 75
IPTOS_LOWDELAY = 0
IPTOS_THROUGHPUT = 0
SO_REUSEPORT = 1
SO_SNDBUF = 87040
SO_RCVBUF = 374400
SO_SNDLOWAT = 1
SO_RCVLOWAT = 1
SO_SNDTIMEO = 0
SO_RCVTIMEO = 0
TCP_QUICKACK = 1
TCP_DEFER_ACCEPT = 0
[2016/12/20 20:44:45.646608, 3] ../source3/lib/access.c:338(allow_access)
Allowed connection from 192.168.101.20 (192.168.101.20)
[2016/12/20 20:44:45.646787, 6] ../source3/param/loadparm.c:2222(lp_file_list_changed)
lp_file_list_changed()
file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Tue Dec 20 20:40:36 2016
[2016/12/20 20:44:45.647097, 3] ../source3/smbd/oplock.c:1322(init_oplocks)
init_oplocks: initializing messages.
[2016/12/20 20:44:45.647399, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 774 - private_data=0x55b83b32f9f0
[2016/12/20 20:44:45.647547, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 778 - private_data=0x55b83b32f9f0
[2016/12/20 20:44:45.647761, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 770 - private_data=0x55b83b32f9f0
[2016/12/20 20:44:45.647904, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 787 - private_data=0x55b83b32f9f0
[2016/12/20 20:44:45.648060, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 779 - private_data=0x55b83b32f9f0
[2016/12/20 20:44:45.648201, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 15 - private_data=(nil)
[2016/12/20 20:44:45.648342, 5] ../source3/lib/messages.c:371(messaging_register)
Overriding messaging pointer for type 15 - private_data=(nil)
[2016/12/20 20:44:45.648482, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 16 - private_data=(nil)
[2016/12/20 20:44:45.648624, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 16 - private_data=0x55b83b32f9f0
[2016/12/20 20:44:45.648804, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 33 - private_data=0x55b83b30c620
[2016/12/20 20:44:45.648946, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 33 - private_data=0x55b83b32f9f0
[2016/12/20 20:44:45.649087, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 790 - private_data=(nil)
[2016/12/20 20:44:45.649169, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 790 - private_data=0x55b83b32f9f0
[2016/12/20 20:44:45.649180, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 791 - private_data=(nil)
[2016/12/20 20:44:45.649188, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1 - private_data=(nil)
[2016/12/20 20:44:45.649195, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 1 - private_data=(nil)
[2016/12/20 20:44:45.649220, 6] ../source3/smbd/process.c:1955(process_smb)
got message type 0x0 of len 0x4e
[2016/12/20 20:44:45.649232, 3] ../source3/smbd/process.c:1957(process_smb)
Transaction 0 of length 82 (0 toread)
[2016/12/20 20:44:45.649239, 5] ../source3/lib/util.c:171(show_msg)
[2016/12/20 20:44:45.649244, 5] ../source3/lib/util.c:181(show_msg)
size=78
smb_com=0x72
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=0
smb_flg2=51201
smb_tid=0
smb_pid=1729
smb_uid=0
smb_mid=1
smt_wct=0
smb_bcc=43
[2016/12/20 20:44:45.649326, 3] ../source3/smbd/process.c:1538(switch_message)
switch message SMBnegprot (pid 2370) conn 0x0
[2016/12/20 20:44:45.649346, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2016/12/20 20:44:45.649360, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.649371, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/20 20:44:45.649395, 5] ../source3/smbd/uid.c:425(smbd_change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2016/12/20 20:44:45.649933, 3] ../source3/smbd/negprot.c:601(reply_negprot)
Requested protocol [LM1.2X002]
[2016/12/20 20:44:45.649951, 3] ../source3/smbd/negprot.c:601(reply_negprot)
Requested protocol [LANMAN2.1]
[2016/12/20 20:44:45.650064, 3] ../source3/smbd/negprot.c:601(reply_negprot)
Requested protocol [NT LM 0.12]
[2016/12/20 20:44:45.650073, 3] ../source3/smbd/negprot.c:601(reply_negprot)
Requested protocol [POSIX 2]
[2016/12/20 20:44:45.650091, 6] ../source3/param/loadparm.c:2222(lp_file_list_changed)
lp_file_list_changed()
file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Tue Dec 20 20:40:36 2016
[2016/12/20 20:44:45.650109, 5] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
check lock order 2 for /var/run/samba/serverid.tdb
[2016/12/20 20:44:45.650121, 5] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
release lock order 2 for /var/run/samba/serverid.tdb
[2016/12/20 20:44:45.650137, 6] ../source3/param/loadparm.c:2222(lp_file_list_changed)
lp_file_list_changed()
file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Tue Dec 20 20:40:36 2016
[2016/12/20 20:44:45.650177, 5] ../source3/auth/auth.c:477(make_auth_context_subsystem)
Making default auth method list for server role = 'domain member'
[2016/12/20 20:44:45.650192, 5] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend trustdomain
[2016/12/20 20:44:45.650205, 5] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'trustdomain'
[2016/12/20 20:44:45.650214, 5] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend ntdomain
[2016/12/20 20:44:45.650221, 5] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'ntdomain'
[2016/12/20 20:44:45.650228, 5] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend guest
[2016/12/20 20:44:45.650234, 5] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'guest'
[2016/12/20 20:44:45.650241, 5] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend sam
[2016/12/20 20:44:45.650252, 5] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'sam'
[2016/12/20 20:44:45.650260, 5] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend sam_ignoredomain
[2016/12/20 20:44:45.650268, 5] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'sam_ignoredomain'
[2016/12/20 20:44:45.650279, 5] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend winbind
[2016/12/20 20:44:45.650287, 5] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'winbind'
[2016/12/20 20:44:45.650294, 5] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend unix
[2016/12/20 20:44:45.650301, 5] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'unix'
[2016/12/20 20:44:45.650307, 5] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend wbc
[2016/12/20 20:44:45.650314, 5] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'wbc'
[2016/12/20 20:44:45.650321, 5] ../source3/auth/auth.c:378(load_auth_module)
load_auth_module: Attempting to find an auth method to match guest
[2016/12/20 20:44:45.650328, 5] ../source3/auth/auth.c:403(load_auth_module)
load_auth_module: auth method guest has a valid init
[2016/12/20 20:44:45.650335, 5] ../source3/auth/auth.c:378(load_auth_module)
load_auth_module: Attempting to find an auth method to match sam
[2016/12/20 20:44:45.650343, 5] ../source3/auth/auth.c:403(load_auth_module)
load_auth_module: auth method sam has a valid init
[2016/12/20 20:44:45.650350, 5] ../source3/auth/auth.c:378(load_auth_module)
load_auth_module: Attempting to find an auth method to match winbind:ntdomain
[2016/12/20 20:44:45.650357, 5] ../source3/auth/auth.c:378(load_auth_module)
load_auth_module: Attempting to find an auth method to match ntdomain
[2016/12/20 20:44:45.650364, 5] ../source3/auth/auth.c:403(load_auth_module)
load_auth_module: auth method ntdomain has a valid init
[2016/12/20 20:44:45.650371, 5] ../source3/auth/auth.c:403(load_auth_module)
load_auth_module: auth method winbind has a valid init
[2016/12/20 20:44:45.650488, 5] ../auth/gensec/gensec_start.c:681(gensec_start_mech)
Starting GENSEC mechanism spnego
[2016/12/20 20:44:45.650514, 5] ../auth/gensec/gensec_start.c:681(gensec_start_mech)
Starting GENSEC submechanism gse_krb5
[2016/12/20 20:44:45.665333, 3] ../source3/smbd/negprot.c:394(reply_nt1)
using SPNEGO
[2016/12/20 20:44:45.665609, 3] ../source3/smbd/negprot.c:711(reply_negprot)
Selected protocol NT LM 0.12
[2016/12/20 20:44:45.665821, 5] ../source3/smbd/negprot.c:718(reply_negprot)
negprot index=2
[2016/12/20 20:44:45.666044, 5] ../source3/lib/util.c:171(show_msg)
[2016/12/20 20:44:45.666140, 5] ../source3/lib/util.c:181(show_msg)
size=181
smb_com=0x72
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=128
smb_flg2=51201
smb_tid=0
smb_pid=1729
smb_uid=0
smb_mid=1
smt_wct=17
smb_vwv[ 0]= 2 (0x2)
smb_vwv[ 1]=12803 (0x3203)
smb_vwv[ 2]= 256 (0x100)
smb_vwv[ 3]= 1024 (0x400)
smb_vwv[ 4]= 65 (0x41)
smb_vwv[ 5]= 0 (0x0)
smb_vwv[ 6]= 256 (0x100)
smb_vwv[ 7]=16896 (0x4200)
smb_vwv[ 8]= 9 (0x9)
smb_vwv[ 9]=64768 (0xFD00)
smb_vwv[10]=33011 (0x80F3)
smb_vwv[11]=52096 (0xCB80)
smb_vwv[12]= 5417 (0x1529)
smb_vwv[13]=63876 (0xF984)
smb_vwv[14]=53850 (0xD25A)
smb_vwv[15]=50177 (0xC401)
smb_vwv[16]= 255 (0xFF)
smb_bcc=112
[2016/12/20 20:44:45.668725, 6] ../source3/smbd/process.c:1955(process_smb)
got message type 0x0 of len 0xc8
[2016/12/20 20:44:45.668850, 3] ../source3/smbd/process.c:1957(process_smb)
Transaction 1 of length 204 (0 toread)
[2016/12/20 20:44:45.668876, 5] ../source3/lib/util.c:171(show_msg)
[2016/12/20 20:44:45.668881, 5] ../source3/lib/util.c:181(show_msg)
size=200
smb_com=0x73
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=0
smb_flg2=55297
smb_tid=0
smb_pid=1729
smb_uid=0
smb_mid=2
smt_wct=12
smb_vwv[ 0]= 255 (0xFF)
smb_vwv[ 1]= 0 (0x0)
smb_vwv[ 2]=16468 (0x4054)
smb_vwv[ 3]= 50 (0x32)
smb_vwv[ 4]= 1 (0x1)
smb_vwv[ 5]= 0 (0x0)
smb_vwv[ 6]= 0 (0x0)
smb_vwv[ 7]= 32 (0x20)
smb_vwv[ 8]= 0 (0x0)
smb_vwv[ 9]= 0 (0x0)
smb_vwv[10]=53468 (0xD0DC)
smb_vwv[11]=32896 (0x8080)
smb_bcc=141
[2016/12/20 20:44:45.668988, 3] ../source3/smbd/process.c:1538(switch_message)
switch message SMBsesssetupX (pid 2370) conn 0x0
[2016/12/20 20:44:45.669001, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2016/12/20 20:44:45.669009, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.669017, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/20 20:44:45.669059, 5] ../source3/smbd/uid.c:425(smbd_change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2016/12/20 20:44:45.669078, 3] ../source3/smbd/sesssetup.c:623(reply_sesssetup_and_X)
wct=12 flg2=0xd801
[2016/12/20 20:44:45.669090, 3] ../source3/smbd/sesssetup.c:140(reply_sesssetup_and_X_spnego)
Doing spnego session setup
[2016/12/20 20:44:45.669102, 3] ../source3/smbd/sesssetup.c:181(reply_sesssetup_and_X_spnego)
NativeOS=[Linux version 4.8.0-2-amd64] NativeLanMan=[CIFS VFS Client for Linux] PrimaryDomain=[]
[2016/12/20 20:44:45.669120, 5] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
check lock order 1 for /var/run/samba/smbXsrv_session_global.tdb
[2016/12/20 20:44:45.669265, 5] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
release lock order 1 for /var/run/samba/smbXsrv_session_global.tdb
[2016/12/20 20:44:45.669296, 5] ../source3/auth/auth.c:477(make_auth_context_subsystem)
Making default auth method list for server role = 'domain member'
[2016/12/20 20:44:45.669307, 5] ../source3/auth/auth.c:378(load_auth_module)
load_auth_module: Attempting to find an auth method to match guest
[2016/12/20 20:44:45.669328, 5] ../source3/auth/auth.c:403(load_auth_module)
load_auth_module: auth method guest has a valid init
[2016/12/20 20:44:45.669347, 5] ../source3/auth/auth.c:378(load_auth_module)
load_auth_module: Attempting to find an auth method to match sam
[2016/12/20 20:44:45.669355, 5] ../source3/auth/auth.c:403(load_auth_module)
load_auth_module: auth method sam has a valid init
[2016/12/20 20:44:45.669362, 5] ../source3/auth/auth.c:378(load_auth_module)
load_auth_module: Attempting to find an auth method to match winbind:ntdomain
[2016/12/20 20:44:45.669369, 5] ../source3/auth/auth.c:378(load_auth_module)
load_auth_module: Attempting to find an auth method to match ntdomain
[2016/12/20 20:44:45.669377, 5] ../source3/auth/auth.c:403(load_auth_module)
load_auth_module: auth method ntdomain has a valid init
[2016/12/20 20:44:45.669383, 5] ../source3/auth/auth.c:403(load_auth_module)
load_auth_module: auth method winbind has a valid init
[2016/12/20 20:44:45.669427, 5] ../auth/gensec/gensec_start.c:681(gensec_start_mech)
Starting GENSEC mechanism spnego
[2016/12/20 20:44:45.669442, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2016/12/20 20:44:45.669455, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2016/12/20 20:44:45.669477, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2016/12/20 20:44:45.669485, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.669492, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/20 20:44:45.669516, 5] ../auth/gensec/gensec_start.c:681(gensec_start_mech)
Starting GENSEC submechanism ntlmssp
[2016/12/20 20:44:45.669534, 3] ../auth/ntlmssp/ntlmssp_util.c:69(debug_ntlmssp_flags)
Got NTLMSSP neg_flags=0xa0080205
NTLMSSP_NEGOTIATE_UNICODE
NTLMSSP_REQUEST_TARGET
NTLMSSP_NEGOTIATE_NTLM
NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY
NTLMSSP_NEGOTIATE_128
NTLMSSP_NEGOTIATE_56
[2016/12/20 20:44:45.669632, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2016/12/20 20:44:45.669650, 5] ../source3/lib/util.c:171(show_msg)
[2016/12/20 20:44:45.669656, 5] ../source3/lib/util.c:181(show_msg)
size=284
smb_com=0x73
smb_rcls=22
smb_reh=0
smb_err=49152
smb_flg=128
smb_flg2=51203
smb_tid=0
smb_pid=1729
smb_uid=4993
smb_mid=2
smt_wct=4
smb_vwv[ 0]= 255 (0xFF)
smb_vwv[ 1]= 0 (0x0)
smb_vwv[ 2]= 0 (0x0)
smb_vwv[ 3]= 170 (0xAA)
smb_bcc=241
[2016/12/20 20:44:45.670317, 6] ../source3/smbd/process.c:1955(process_smb)
got message type 0x0 of len 0x1be
[2016/12/20 20:44:45.670495, 3] ../source3/smbd/process.c:1957(process_smb)
Transaction 2 of length 450 (0 toread)
[2016/12/20 20:44:45.670754, 5] ../source3/lib/util.c:171(show_msg)
[2016/12/20 20:44:45.670895, 5] ../source3/lib/util.c:181(show_msg)
size=446
smb_com=0x73
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=0
smb_flg2=55297
smb_tid=0
smb_pid=1729
smb_uid=4993
smb_mid=3
smt_wct=12
smb_vwv[ 0]= 255 (0xFF)
smb_vwv[ 1]= 0 (0x0)
smb_vwv[ 2]=16468 (0x4054)
smb_vwv[ 3]= 50 (0x32)
smb_vwv[ 4]= 1 (0x1)
smb_vwv[ 5]= 0 (0x0)
smb_vwv[ 6]= 0 (0x0)
smb_vwv[ 7]= 278 (0x116)
smb_vwv[ 8]= 0 (0x0)
smb_vwv[ 9]= 0 (0x0)
smb_vwv[10]=53468 (0xD0DC)
smb_vwv[11]=32896 (0x8080)
smb_bcc=387
[2016/12/20 20:44:45.671525, 3] ../source3/smbd/process.c:1538(switch_message)
switch message SMBsesssetupX (pid 2370) conn 0x0
[2016/12/20 20:44:45.671538, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2016/12/20 20:44:45.671546, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.671553, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/20 20:44:45.671621, 5] ../source3/smbd/uid.c:425(smbd_change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2016/12/20 20:44:45.671633, 5] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
check lock order 1 for /var/run/samba/smbXsrv_session_global.tdb
[2016/12/20 20:44:45.671657, 5] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
release lock order 1 for /var/run/samba/smbXsrv_session_global.tdb
[2016/12/20 20:44:45.671687, 3] ../source3/smbd/sesssetup.c:623(reply_sesssetup_and_X)
wct=12 flg2=0xd801
[2016/12/20 20:44:45.671712, 3] ../source3/smbd/sesssetup.c:140(reply_sesssetup_and_X_spnego)
Doing spnego session setup
[2016/12/20 20:44:45.671723, 3] ../source3/smbd/sesssetup.c:181(reply_sesssetup_and_X_spnego)
NativeOS=[Linux version 4.8.0-2-amd64] NativeLanMan=[CIFS VFS Client for Linux] PrimaryDomain=[]
[2016/12/20 20:44:45.671746, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2016/12/20 20:44:45.671755, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2016/12/20 20:44:45.671762, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2016/12/20 20:44:45.671769, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.671775, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/20 20:44:45.671852, 3] ../auth/ntlmssp/ntlmssp_server.c:452(ntlmssp_server_preauth)
Got user=[Administrator] domain=[LAB.LOCAL] workstation=[] len1=0 len2=152
[2016/12/20 20:44:45.671880, 3] ../source3/param/loadparm.c:3738(lp_load_ex)
lp_load_ex: refreshing parameters
[2016/12/20 20:44:45.671905, 5] ../source3/param/loadparm.c:1311(free_param_opts)
Freeing parametrics:
[2016/12/20 20:44:45.671966, 3] ../source3/param/loadparm.c:542(init_globals)
Initialising global parameters
[2016/12/20 20:44:45.672038, 3] ../source3/param/loadparm.c:2667(lp_do_section)
Processing section "[global]"
doing parameter security = ads
doing parameter realm = LAB.LOCAL
doing parameter workgroup = LAB
doing parameter idmap uid = 10000-20000
[2016/12/20 20:44:45.672089, 1] ../lib/param/loadparm.c:1729(lpcfg_do_global_parameter)
WARNING: The "idmap uid" option is deprecated
doing parameter idmap gid = 10000-20000
[2016/12/20 20:44:45.672108, 1] ../lib/param/loadparm.c:1729(lpcfg_do_global_parameter)
WARNING: The "idmap gid" option is deprecated
doing parameter winbind use default domain = yes
doing parameter winbind enum users = yes
doing parameter winbind enum groups = yes
doing parameter winbind nss info = template
doing parameter template homedir = /data/%U
doing parameter template shell = /bin/false
doing parameter encrypt passwords = yes
doing parameter client use spnego = yes
doing parameter client ntlmv2 auth = yes
doing parameter restrict anonymous = 2
doing parameter valid users = @"Domain Users"
doing parameter log level = 7
[2016/12/20 20:44:45.672244, 5] ../lib/util/debug.c:642(debug_dump_status)
INFO: Current debug levels:
all: 7
tdb: 7
printdrivers: 7
lanman: 7
smb: 7
rpc_parse: 7
rpc_srv: 7
rpc_cli: 7
passdb: 7
sam: 7
auth: 7
winbind: 7
vfs: 7
idmap: 7
quota: 7
acls: 7
locking: 7
msdfs: 7
dmapi: 7
registry: 7
scavenger: 7
dns: 7
ldb: 7
tevent: 7
[2016/12/20 20:44:45.672299, 2] ../source3/param/loadparm.c:2684(lp_do_section)
Processing section "[shared]"
doing parameter write list = @"Domain Admins"
doing parameter path = /shared
[2016/12/20 20:44:45.672327, 4] ../source3/param/loadparm.c:3779(lp_load_ex)
pm_process() returned Yes
[2016/12/20 20:44:45.672338, 7] ../source3/param/loadparm.c:4095(lp_servicenumber)
lp_servicenumber: couldn't find homes
[2016/12/20 20:44:45.672348, 3] ../source3/param/loadparm.c:1584(lp_add_ipc)
adding IPC service
[2016/12/20 20:44:45.672391, 5] ../source3/auth/auth_util.c:122(make_user_info_map)
Mapping user [LAB.LOCAL]\[Administrator] from workstation []
==> log.winbindd <==
[2016/12/20 20:44:45.672916, 6] ../source3/winbindd/winbindd.c:918(new_connection)
accepted socket 25
[2016/12/20 20:44:45.673165, 3] ../source3/winbindd/winbindd_misc.c:396(winbindd_interface_version)
[ 2370]: request interface version (version = 28)
[2016/12/20 20:44:45.673382, 3] ../source3/winbindd/winbindd_misc.c:429(winbindd_priv_pipe_dir)
[ 2370]: request location of privileged pipe
[2016/12/20 20:44:45.673579, 6] ../source3/winbindd/winbindd.c:918(new_connection)
accepted socket 27
[2016/12/20 20:44:45.673751, 6] ../source3/winbindd/winbindd.c:967(winbind_client_request_read)
closing socket 25, client exited
[2016/12/20 20:44:45.674036, 3] ../source3/winbindd/winbindd_misc.c:238(winbindd_domain_info)
[ 2370]: domain_info [LAB.LOCAL]
==> log.smbd <==
[2016/12/20 20:44:45.674357, 5] ../source3/auth/user_info.c:62(make_user_info)
attempting to make a user_info for Administrator (Administrator)
[2016/12/20 20:44:45.674537, 5] ../source3/auth/user_info.c:70(make_user_info)
making strings for Administrator's user_info struct
[2016/12/20 20:44:45.674704, 5] ../source3/auth/user_info.c:108(make_user_info)
making blobs for Administrator's user_info struct
[2016/12/20 20:44:45.674858, 3] ../source3/auth/auth.c:178(auth_check_ntlm_password)
check_ntlm_password: Checking password for unmapped user [LAB.LOCAL]\[Administrator]@[] with the new password interface
[2016/12/20 20:44:45.674964, 3] ../source3/auth/auth.c:181(auth_check_ntlm_password)
check_ntlm_password: mapped user is: [LAB.LOCAL]\[Administrator]@[]
[2016/12/20 20:44:45.674975, 5] ../lib/util/util.c:555(dump_data)
[0000] BF FC CC 86 1E 1E 1C 6E .......n
[2016/12/20 20:44:45.674999, 6] ../source3/auth/auth_sam.c:88(auth_samstrict_auth)
check_samstrict_security: LAB.LOCAL is not one of my local names (ROLE_DOMAIN_MEMBER)
[2016/12/20 20:44:45.675088, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2016/12/20 20:44:45.675102, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2016/12/20 20:44:45.675110, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2016/12/20 20:44:45.675117, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.675124, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
==> log.winbindd <==
[2016/12/20 20:44:45.675295, 3] ../source3/winbindd/winbindd_pam_auth_crap.c:74(winbindd_pam_auth_crap_send)
[ 2370]: pam auth crap domain: [LAB.LOCAL] user: Administrator
==> log.wb-LAB <==
[2016/12/20 20:44:45.675524, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 14
[2016/12/20 20:44:45.675556, 3] ../source3/winbindd/winbindd_pam.c:2067(winbindd_dual_pam_auth_crap)
[ 2347]: pam auth crap domain: LAB.LOCAL user: Administrator
[2016/12/20 20:44:45.675684, 5] ../source3/rpc_client/cli_pipe.c:826(rpc_api_pipe_send)
rpc_api_pipe: host v-smb-dc.lab.local
[2016/12/20 20:44:45.675706, 5] ../source3/rpc_client/cli_pipe.c:178(rpc_write_send)
rpc_write_send: data_to_write: 552
[2016/12/20 20:44:45.678914, 5] ../source3/rpc_client/cli_pipe.c:98(rpc_read_send)
rpc_read_send: data_to_read: 712
[2016/12/20 20:44:45.679094, 6] ../librpc/rpc/dcerpc_util.c:234(dcerpc_pull_auth_trailer)
../librpc/rpc/dcerpc_util.c:234: auth_pad_length 12
[2016/12/20 20:44:45.679523, 5] ../source3/winbindd/winbindd_pam.c:2039(winbind_dual_SamLogon)
NTLM CRAP authentication for user [LAB.LOCAL]\[Administrator] returned NT_STATUS_OK
[2016/12/20 20:44:45.679731, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 14
==> log.smbd <==
[2016/12/20 20:44:45.679960, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2016/12/20 20:44:45.680148, 5] ../source3/lib/username.c:181(Get_Pwnam_alloc)
Finding user LAB\administrator
[2016/12/20 20:44:45.680236, 5] ../source3/lib/username.c:120(Get_Pwnam_internals)
Trying _Get_Pwnam(), username as lowercase is lab\administrator
==> log.winbindd <==
[2016/12/20 20:44:45.680411, 3] ../source3/winbindd/winbindd_getpwnam.c:56(winbindd_getpwnam_send)
getpwnam lab\administrator
==> log.wb-LAB <==
[2016/12/20 20:44:45.680577, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 56
[2016/12/20 20:44:45.680623, 3] ../source3/winbindd/winbindd_ads.c:1493(sequence_number)
ads: fetch sequence_number for LAB
[2016/12/20 20:44:45.680670, 5] ../source3/libads/sitename_cache.c:104(sitename_fetch)
sitename_fetch: Returning sitename for realm 'lab.local': "Default-First-Site-Name"
[2016/12/20 20:44:45.680682, 4] ../source3/libsmb/namequery_dc.c:77(ads_dc_name)
ads_dc_name: domain=LAB
[2016/12/20 20:44:45.680694, 5] ../source3/libads/sitename_cache.c:104(sitename_fetch)
sitename_fetch: Returning sitename for realm 'lab.local': "Default-First-Site-Name"
[2016/12/20 20:44:45.680703, 6] ../source3/libads/ldap.c:409(resolve_and_ping_dns)
resolve_and_ping_dns: (cldap) looking for realm 'lab.local'
[2016/12/20 20:44:45.680720, 5] ../source3/libsmb/namequery.c:194(saf_fetch)
saf_fetch[join]: Returning "v-smb-dc.lab.local" for "lab.local" domain
[2016/12/20 20:44:45.680731, 3] ../source3/libsmb/namequery.c:3117(get_dc_list)
get_dc_list: preferred server list: "v-smb-dc.lab.local, *"
[2016/12/20 20:44:45.680750, 5] ../source3/libsmb/namecache.c:160(namecache_fetch)
no entry for lab.local#1C found.
[2016/12/20 20:44:45.680761, 5] ../source3/libsmb/namequery.c:2407(resolve_ads)
resolve_ads: Attempting to resolve DCs for lab.local using DNS
[2016/12/20 20:44:45.681306, 4] ../lib/addns/dnsquery.c:435(ads_dns_lookup_srv)
ads_dns_lookup_srv: 1 records returned in the answer section.
[2016/12/20 20:44:45.682056, 5] ../source3/libsmb/namecache.c:78(namecache_store)
namecache_store: storing 1 address for lab.local#1c: 192.168.101.10
[2016/12/20 20:44:45.682229, 5] ../source3/libads/sitename_cache.c:104(sitename_fetch)
sitename_fetch: Returning sitename for realm 'LAB.LOCAL': "Default-First-Site-Name"
[2016/12/20 20:44:45.682383, 5] ../source3/libsmb/namecache.c:160(namecache_fetch)
no entry for v-smb-dc.lab.local#20 found.
[2016/12/20 20:44:45.682537, 3] ../source3/libsmb/namequery.c:2306(resolve_hosts)
resolve_hosts: Attempting host lookup for name v-smb-dc.lab.local<0x20>
[2016/12/20 20:44:45.683215, 5] ../source3/libsmb/namecache.c:78(namecache_store)
namecache_store: storing 1 address for v-smb-dc.lab.local#20: 192.168.101.10
[2016/12/20 20:44:45.683410, 4] ../source3/libsmb/namequery.c:3262(get_dc_list)
get_dc_list: returning 1 ip addresses in an ordered list
[2016/12/20 20:44:45.683426, 4] ../source3/libsmb/namequery.c:3263(get_dc_list)
get_dc_list: 192.168.101.10:389
[2016/12/20 20:44:45.683438, 5] ../source3/libads/ldap.c:254(ads_try_connect)
ads_try_connect: sending CLDAP request to 192.168.101.10 (realm: lab.local)
[2016/12/20 20:44:45.685241, 3] ../source3/libads/ldap.c:618(ads_connect)
Successfully contacted LDAP server 192.168.101.10
[2016/12/20 20:44:45.685269, 5] ../source3/libads/sitename_cache.c:104(sitename_fetch)
sitename_fetch: Returning sitename for realm 'lab.local': "Default-First-Site-Name"
[2016/12/20 20:44:45.685295, 5] ../source3/libsmb/namequery.c:194(saf_fetch)
saf_fetch[join]: Returning "v-smb-dc.lab.local" for "lab.local" domain
[2016/12/20 20:44:45.685306, 3] ../source3/libsmb/namequery.c:3117(get_dc_list)
get_dc_list: preferred server list: "v-smb-dc.lab.local, *"
[2016/12/20 20:44:45.685316, 5] ../source3/libsmb/namequery.c:2416(resolve_ads)
resolve_ads: Attempting to resolve KDCs for lab.local using DNS
[2016/12/20 20:44:45.685723, 4] ../lib/addns/dnsquery.c:435(ads_dns_lookup_srv)
ads_dns_lookup_srv: 1 records returned in the answer section.
[2016/12/20 20:44:45.686379, 5] ../source3/libads/sitename_cache.c:104(sitename_fetch)
sitename_fetch: Returning sitename for realm 'LAB.LOCAL': "Default-First-Site-Name"
[2016/12/20 20:44:45.686547, 5] ../source3/libsmb/namecache.c:165(namecache_fetch)
name v-smb-dc.lab.local#20 found.
[2016/12/20 20:44:45.686573, 4] ../source3/libsmb/namequery.c:3262(get_dc_list)
get_dc_list: returning 1 ip addresses in an ordered list
[2016/12/20 20:44:45.686583, 4] ../source3/libsmb/namequery.c:3263(get_dc_list)
get_dc_list: 192.168.101.10:88
[2016/12/20 20:44:45.686595, 5] ../source3/libsmb/namequery.c:194(saf_fetch)
saf_fetch[join]: Returning "v-smb-dc.lab.local" for "lab.local" domain
[2016/12/20 20:44:45.686604, 3] ../source3/libsmb/namequery.c:3117(get_dc_list)
get_dc_list: preferred server list: "v-smb-dc.lab.local, *"
[2016/12/20 20:44:45.686614, 5] ../source3/libsmb/namequery.c:2416(resolve_ads)
resolve_ads: Attempting to resolve KDCs for lab.local using DNS
[2016/12/20 20:44:45.686958, 4] ../lib/addns/dnsquery.c:435(ads_dns_lookup_srv)
ads_dns_lookup_srv: 1 records returned in the answer section.
[2016/12/20 20:44:45.687647, 5] ../source3/libads/sitename_cache.c:104(sitename_fetch)
sitename_fetch: Returning sitename for realm 'LAB.LOCAL': "Default-First-Site-Name"
[2016/12/20 20:44:45.687752, 5] ../source3/libsmb/namecache.c:165(namecache_fetch)
name v-smb-dc.lab.local#20 found.
[2016/12/20 20:44:45.687772, 4] ../source3/libsmb/namequery.c:3262(get_dc_list)
get_dc_list: returning 1 ip addresses in an ordered list
[2016/12/20 20:44:45.687781, 4] ../source3/libsmb/namequery.c:3263(get_dc_list)
get_dc_list: 192.168.101.10:88
[2016/12/20 20:44:45.687830, 5] ../source3/libads/kerberos.c:962(create_local_private_krb5_conf_for_domain)
create_local_private_krb5_conf_for_domain: wrote file /var/run/samba/smb_krb5/krb5.conf.LAB with realm LAB.LOCAL KDC list = kdc = 192.168.101.10
[2016/12/20 20:44:45.687847, 4] ../source3/libsmb/namequery_dc.c:151(ads_dc_name)
ads_dc_name: using server='V-SMB-DC.LAB.LOCAL' IP=192.168.101.10
[2016/12/20 20:44:45.687856, 6] ../source3/libads/ldap.c:486(ads_find_dc)
ads_find_dc: (ldap) looking for realm 'lab.local' and falling back to domain 'LAB'
[2016/12/20 20:44:45.687867, 5] ../source3/libads/sitename_cache.c:104(sitename_fetch)
sitename_fetch: Returning sitename for realm 'lab.local': "Default-First-Site-Name"
[2016/12/20 20:44:45.687877, 4] ../source3/libsmb/namequery_dc.c:77(ads_dc_name)
ads_dc_name: domain=LAB
[2016/12/20 20:44:45.687886, 5] ../source3/libads/sitename_cache.c:104(sitename_fetch)
sitename_fetch: Returning sitename for realm 'lab.local': "Default-First-Site-Name"
[2016/12/20 20:44:45.687894, 6] ../source3/libads/ldap.c:409(resolve_and_ping_dns)
resolve_and_ping_dns: (cldap) looking for realm 'lab.local'
[2016/12/20 20:44:45.687903, 5] ../source3/libsmb/namequery.c:194(saf_fetch)
saf_fetch[join]: Returning "v-smb-dc.lab.local" for "lab.local" domain
[2016/12/20 20:44:45.687913, 3] ../source3/libsmb/namequery.c:3117(get_dc_list)
get_dc_list: preferred server list: "v-smb-dc.lab.local, *"
[2016/12/20 20:44:45.687923, 5] ../source3/libsmb/namecache.c:165(namecache_fetch)
name lab.local#1C found.
[2016/12/20 20:44:45.687937, 5] ../source3/libads/sitename_cache.c:104(sitename_fetch)
sitename_fetch: Returning sitename for realm 'LAB.LOCAL': "Default-First-Site-Name"
[2016/12/20 20:44:45.687947, 5] ../source3/libsmb/namecache.c:165(namecache_fetch)
name v-smb-dc.lab.local#20 found.
[2016/12/20 20:44:45.687961, 4] ../source3/libsmb/namequery.c:3262(get_dc_list)
get_dc_list: returning 1 ip addresses in an ordered list
[2016/12/20 20:44:45.687970, 4] ../source3/libsmb/namequery.c:3263(get_dc_list)
get_dc_list: 192.168.101.10:389
[2016/12/20 20:44:45.687980, 5] ../source3/libads/ldap.c:254(ads_try_connect)
ads_try_connect: sending CLDAP request to 192.168.101.10 (realm: lab.local)
[2016/12/20 20:44:45.689475, 3] ../source3/libads/ldap.c:618(ads_connect)
Successfully contacted LDAP server 192.168.101.10
[2016/12/20 20:44:45.689570, 5] ../source3/libads/sitename_cache.c:104(sitename_fetch)
sitename_fetch: Returning sitename for realm 'lab.local': "Default-First-Site-Name"
[2016/12/20 20:44:45.689649, 5] ../source3/libsmb/namequery.c:194(saf_fetch)
saf_fetch[join]: Returning "v-smb-dc.lab.local" for "lab.local" domain
[2016/12/20 20:44:45.689713, 3] ../source3/libsmb/namequery.c:3117(get_dc_list)
get_dc_list: preferred server list: "v-smb-dc.lab.local, *"
[2016/12/20 20:44:45.689776, 5] ../source3/libsmb/namequery.c:2416(resolve_ads)
resolve_ads: Attempting to resolve KDCs for lab.local using DNS
[2016/12/20 20:44:45.690211, 4] ../lib/addns/dnsquery.c:435(ads_dns_lookup_srv)
ads_dns_lookup_srv: 1 records returned in the answer section.
[2016/12/20 20:44:45.690883, 5] ../source3/libads/sitename_cache.c:104(sitename_fetch)
sitename_fetch: Returning sitename for realm 'LAB.LOCAL': "Default-First-Site-Name"
[2016/12/20 20:44:45.690971, 5] ../source3/libsmb/namecache.c:165(namecache_fetch)
name v-smb-dc.lab.local#20 found.
[2016/12/20 20:44:45.691051, 4] ../source3/libsmb/namequery.c:3262(get_dc_list)
get_dc_list: returning 1 ip addresses in an ordered list
[2016/12/20 20:44:45.691112, 4] ../source3/libsmb/namequery.c:3263(get_dc_list)
get_dc_list: 192.168.101.10:88
[2016/12/20 20:44:45.691175, 5] ../source3/libsmb/namequery.c:194(saf_fetch)
saf_fetch[join]: Returning "v-smb-dc.lab.local" for "lab.local" domain
[2016/12/20 20:44:45.691237, 3] ../source3/libsmb/namequery.c:3117(get_dc_list)
get_dc_list: preferred server list: "v-smb-dc.lab.local, *"
[2016/12/20 20:44:45.691296, 5] ../source3/libsmb/namequery.c:2416(resolve_ads)
resolve_ads: Attempting to resolve KDCs for lab.local using DNS
[2016/12/20 20:44:45.691897, 4] ../lib/addns/dnsquery.c:435(ads_dns_lookup_srv)
ads_dns_lookup_srv: 1 records returned in the answer section.
[2016/12/20 20:44:45.692579, 5] ../source3/libads/sitename_cache.c:104(sitename_fetch)
sitename_fetch: Returning sitename for realm 'LAB.LOCAL': "Default-First-Site-Name"
[2016/12/20 20:44:45.692672, 5] ../source3/libsmb/namecache.c:165(namecache_fetch)
name v-smb-dc.lab.local#20 found.
[2016/12/20 20:44:45.692745, 4] ../source3/libsmb/namequery.c:3262(get_dc_list)
get_dc_list: returning 1 ip addresses in an ordered list
[2016/12/20 20:44:45.692808, 4] ../source3/libsmb/namequery.c:3263(get_dc_list)
get_dc_list: 192.168.101.10:88
[2016/12/20 20:44:45.692899, 5] ../source3/libads/kerberos.c:962(create_local_private_krb5_conf_for_domain)
create_local_private_krb5_conf_for_domain: wrote file /var/run/samba/smb_krb5/krb5.conf.LAB with realm LAB.LOCAL KDC list = kdc = 192.168.101.10
[2016/12/20 20:44:45.692995, 4] ../source3/libsmb/namequery_dc.c:151(ads_dc_name)
ads_dc_name: using server='V-SMB-DC.LAB.LOCAL' IP=192.168.101.10
[2016/12/20 20:44:45.693152, 5] ../source3/libads/ldap.c:254(ads_try_connect)
ads_try_connect: sending CLDAP request to 192.168.101.10 (realm: lab.local)
[2016/12/20 20:44:45.694634, 3] ../source3/libads/ldap.c:618(ads_connect)
Successfully contacted LDAP server 192.168.101.10
[2016/12/20 20:44:45.694853, 3] ../source3/libads/ldap.c:661(ads_connect)
Connected to LDAP server v-smb-dc.lab.local
[2016/12/20 20:44:45.697647, 4] ../source3/libads/ldap.c:2976(ads_current_time)
KDC time offset is 0 seconds
[2016/12/20 20:44:45.697995, 4] ../source3/libads/sasl.c:1094(ads_sasl_bind)
Found SASL mechanism GSS-SPNEGO
[2016/12/20 20:44:45.698517, 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind)
ads_sasl_spnego_bind: got OID=1.2.840.48018.1.2.2
[2016/12/20 20:44:45.698596, 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind)
ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2
[2016/12/20 20:44:45.698656, 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind)
ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.10
[2016/12/20 20:44:45.724868, 5] ../auth/gensec/gensec_start.c:681(gensec_start_mech)
Starting GENSEC mechanism spnego
[2016/12/20 20:44:45.725021, 5] ../auth/gensec/gensec_start.c:681(gensec_start_mech)
Starting GENSEC submechanism gse_krb5
[2016/12/20 20:44:45.738755, 5] ../source3/libads/ldap_utils.c:81(ads_do_search_retry_internal)
Search for (objectclass=*) in <> gave 1 replies
[2016/12/20 20:44:45.738919, 3] ../source3/winbindd/winbindd_msrpc.c:253(msrpc_name_to_sid)
msrpc_name_to_sid: name=LAB\ADMINISTRATOR
[2016/12/20 20:44:45.738978, 3] ../source3/winbindd/winbindd_msrpc.c:267(msrpc_name_to_sid)
name_to_sid [rpc] LAB\ADMINISTRATOR for domain LAB
[2016/12/20 20:44:45.739183, 3] ../lib/ldb-samba/ldb_wrap.c:325(ldb_wrap_connect)
ldb_wrap open of secrets.ldb
[2016/12/20 20:44:45.739349, 3] ../source3/lib/util_sock.c:515(open_socket_out_send)
Connecting to 192.168.101.10 at port 135
[2016/12/20 20:44:45.739698, 5] ../lib/util/util_net.c:1057(print_socket_options)
Socket options:
SO_KEEPALIVE = 0
SO_REUSEADDR = 0
SO_BROADCAST = 0
TCP_NODELAY = 1
TCP_KEEPCNT = 9
TCP_KEEPIDLE = 7200
TCP_KEEPINTVL = 75
IPTOS_LOWDELAY = 0
IPTOS_THROUGHPUT = 0
SO_REUSEPORT = 0
SO_SNDBUF = 87040
SO_RCVBUF = 372480
SO_SNDLOWAT = 1
SO_RCVLOWAT = 1
SO_SNDTIMEO = 0
SO_RCVTIMEO = 0
TCP_QUICKACK = 1
TCP_DEFER_ACCEPT = 0
[2016/12/20 20:44:45.740442, 5] ../source3/rpc_client/cli_pipe.c:1872(rpc_pipe_bind_send)
Bind RPC Pipe: host v-smb-dc.lab.local auth_type 0, auth_level 1
[2016/12/20 20:44:45.740524, 5] ../source3/rpc_client/cli_pipe.c:826(rpc_api_pipe_send)
rpc_api_pipe: host v-smb-dc.lab.local
[2016/12/20 20:44:45.740584, 5] ../source3/rpc_client/cli_pipe.c:178(rpc_write_send)
rpc_write_send: data_to_write: 72
[2016/12/20 20:44:45.740937, 5] ../source3/rpc_client/cli_pipe.c:98(rpc_read_send)
rpc_read_send: data_to_read: 44
[2016/12/20 20:44:45.741105, 5] ../source3/rpc_client/cli_pipe.c:1745(check_bind_response)
check_bind_response: accepted!
[2016/12/20 20:44:45.741221, 5] ../source3/rpc_client/cli_pipe.c:826(rpc_api_pipe_send)
rpc_api_pipe: host v-smb-dc.lab.local
[2016/12/20 20:44:45.741281, 5] ../source3/rpc_client/cli_pipe.c:178(rpc_write_send)
rpc_write_send: data_to_write: 156
[2016/12/20 20:44:45.742109, 5] ../source3/rpc_client/cli_pipe.c:98(rpc_read_send)
rpc_read_send: data_to_read: 136
[2016/12/20 20:44:45.742307, 3] ../source3/lib/util_sock.c:515(open_socket_out_send)
Connecting to 192.168.101.10 at port 1024
[2016/12/20 20:44:45.742493, 5] ../lib/util/util_net.c:1057(print_socket_options)
Socket options:
SO_KEEPALIVE = 0
SO_REUSEADDR = 0
SO_BROADCAST = 0
TCP_NODELAY = 1
TCP_KEEPCNT = 9
TCP_KEEPIDLE = 7200
TCP_KEEPINTVL = 75
IPTOS_LOWDELAY = 0
IPTOS_THROUGHPUT = 0
SO_REUSEPORT = 0
SO_SNDBUF = 87040
SO_RCVBUF = 372480
SO_SNDLOWAT = 1
SO_RCVLOWAT = 1
SO_SNDTIMEO = 0
SO_RCVTIMEO = 0
TCP_QUICKACK = 1
TCP_DEFER_ACCEPT = 0
[2016/12/20 20:44:45.743154, 5] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
check lock order 2 for /var/run/samba/g_lock.tdb
[2016/12/20 20:44:45.743237, 5] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
release lock order 2 for /var/run/samba/g_lock.tdb
[2016/12/20 20:44:45.743381, 5] ../auth/gensec/gensec_start.c:681(gensec_start_mech)
Starting GENSEC mechanism schannel
[2016/12/20 20:44:45.743454, 5] ../source3/rpc_client/cli_pipe.c:1872(rpc_pipe_bind_send)
Bind RPC Pipe: host v-smb-dc.lab.local auth_type 68, auth_level 6
[2016/12/20 20:44:45.743514, 5] ../source3/rpc_client/cli_pipe.c:1139(create_generic_auth_rpc_bind_req)
create_generic_auth_rpc_bind_req: generate first token
[2016/12/20 20:44:45.743587, 5] ../source3/rpc_client/cli_pipe.c:826(rpc_api_pipe_send)
rpc_api_pipe: host v-smb-dc.lab.local
[2016/12/20 20:44:45.743649, 5] ../source3/rpc_client/cli_pipe.c:178(rpc_write_send)
rpc_write_send: data_to_write: 101
[2016/12/20 20:44:45.744575, 5] ../source3/rpc_client/cli_pipe.c:98(rpc_read_send)
rpc_read_send: data_to_read: 64
[2016/12/20 20:44:45.744720, 5] ../source3/rpc_client/cli_pipe.c:1745(check_bind_response)
check_bind_response: accepted!
[2016/12/20 20:44:45.744793, 6] ../librpc/rpc/dcerpc_util.c:234(dcerpc_pull_auth_trailer)
../librpc/rpc/dcerpc_util.c:234: auth_pad_length 0
[2016/12/20 20:44:45.744863, 5] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
check lock order 2 for /var/run/samba/g_lock.tdb
[2016/12/20 20:44:45.744931, 5] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
release lock order 2 for /var/run/samba/g_lock.tdb
[2016/12/20 20:44:45.745041, 5] ../source3/rpc_client/cli_pipe.c:826(rpc_api_pipe_send)
rpc_api_pipe: host v-smb-dc.lab.local
[2016/12/20 20:44:45.745104, 5] ../source3/rpc_client/cli_pipe.c:178(rpc_write_send)
rpc_write_send: data_to_write: 248
[2016/12/20 20:44:45.747295, 5] ../source3/rpc_client/cli_pipe.c:98(rpc_read_send)
rpc_read_send: data_to_read: 232
[2016/12/20 20:44:45.747385, 6] ../librpc/rpc/dcerpc_util.c:234(dcerpc_pull_auth_trailer)
../librpc/rpc/dcerpc_util.c:234: auth_pad_length 12
[2016/12/20 20:44:45.747516, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
[2016/12/20 20:44:45.747668, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 56
[2016/12/20 20:44:45.747741, 3] ../source3/winbindd/winbindd_ads.c:628(query_user)
ads: query_user
[2016/12/20 20:44:45.747817, 5] ../source3/winbindd/winbindd_ads.c:638(query_user)
query_user: Cache lookup succeeded for S-1-5-21-119579451-791976271-3043243932-500
[2016/12/20 20:44:45.747894, 5] ../source3/winbindd/nss_info.c:80(smb_register_idmap_nss)
smb_register_idmap_nss: Successfully added idmap nss backend 'template'
[2016/12/20 20:44:45.748112, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
==> log.winbindd <==
[2016/12/20 20:44:45.748229, 5] ../source3/lib/gencache.c:69(gencache_init)
Opening cache file at /var/cache/samba/gencache.tdb
[2016/12/20 20:44:45.748435, 5] ../source3/lib/gencache.c:120(gencache_init)
Opening cache file at /var/run/samba/gencache_notrans.tdb
==> log.wb-LAB <==
[2016/12/20 20:44:45.749943, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 56
[2016/12/20 20:44:45.750033, 3] ../source3/winbindd/winbindd_msrpc.c:303(msrpc_sid_to_name)
msrpc_sid_to_name: S-1-5-21-119579451-791976271-3043243932-513 for domain LAB
[2016/12/20 20:44:45.750139, 5] ../source3/rpc_client/cli_pipe.c:826(rpc_api_pipe_send)
rpc_api_pipe: host v-smb-dc.lab.local
[2016/12/20 20:44:45.750201, 5] ../source3/rpc_client/cli_pipe.c:178(rpc_write_send)
rpc_write_send: data_to_write: 168
[2016/12/20 20:44:45.752551, 5] ../source3/rpc_client/cli_pipe.c:98(rpc_read_send)
rpc_read_send: data_to_read: 232
[2016/12/20 20:44:45.752667, 6] ../librpc/rpc/dcerpc_util.c:234(dcerpc_pull_auth_trailer)
../librpc/rpc/dcerpc_util.c:234: auth_pad_length 4
[2016/12/20 20:44:45.752770, 5] ../source3/winbindd/winbindd_msrpc.c:323(msrpc_sid_to_name)
Mapped sid to [LAB]\[Domain Users]
[2016/12/20 20:44:45.752852, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
==> log.smbd <==
[2016/12/20 20:44:45.753029, 5] ../source3/lib/username.c:159(Get_Pwnam_internals)
Get_Pwnam_internals did find user [LAB\administrator]!
[2016/12/20 20:44:45.753111, 3] ../source3/auth/auth.c:249(auth_check_ntlm_password)
check_ntlm_password: winbind authentication for user [Administrator] succeeded
[2016/12/20 20:44:45.753179, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2016/12/20 20:44:45.753362, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2016/12/20 20:44:45.753422, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2016/12/20 20:44:45.753479, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.753534, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/20 20:44:45.753623, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2016/12/20 20:44:45.753680, 5] ../source3/auth/auth.c:292(auth_check_ntlm_password)
check_ntlm_password: PAM Account for user [LAB\administrator] succeeded
[2016/12/20 20:44:45.753848, 2] ../source3/auth/auth.c:305(auth_check_ntlm_password)
check_ntlm_password: authentication for user [Administrator] -> [Administrator] -> [LAB\administrator] succeeded
[2016/12/20 20:44:45.753928, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
==> log.winbindd <==
[2016/12/20 20:44:45.754213, 3] ../source3/winbindd/winbindd_getpwuid.c:49(winbindd_getpwuid_send)
getpwuid 100500
==> log.winbindd-idmap <==
[2016/12/20 20:44:45.755446, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 33 - private_data=(nil)
[2016/12/20 20:44:45.755537, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 13 - private_data=(nil)
[2016/12/20 20:44:45.755594, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1028 - private_data=(nil)
[2016/12/20 20:44:45.755649, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1027 - private_data=(nil)
[2016/12/20 20:44:45.755704, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1029 - private_data=(nil)
[2016/12/20 20:44:45.755977, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1280 - private_data=(nil)
[2016/12/20 20:44:45.756036, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1033 - private_data=(nil)
[2016/12/20 20:44:45.756092, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1 - private_data=(nil)
[2016/12/20 20:44:45.756147, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1036 - private_data=(nil)
[2016/12/20 20:44:45.756202, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1035 - private_data=(nil)
[2016/12/20 20:44:45.756315, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 1028 - private_data=(nil)
[2016/12/20 20:44:45.756479, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 1027 - private_data=(nil)
[2016/12/20 20:44:45.756538, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 1280 - private_data=(nil)
[2016/12/20 20:44:45.756594, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 1 - private_data=(nil)
[2016/12/20 20:44:45.756649, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 1034 - private_data=(nil)
[2016/12/20 20:44:45.756704, 5] ../source3/lib/messages.c:371(messaging_register)
Overriding messaging pointer for type 1034 - private_data=(nil)
[2016/12/20 20:44:45.756769, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 56
[2016/12/20 20:44:45.756951, 5] ../source3/winbindd/idmap.c:324(smb_register_idmap)
Successfully added idmap backend 'tdb'
[2016/12/20 20:44:45.757014, 5] ../source3/winbindd/idmap.c:324(smb_register_idmap)
Successfully added idmap backend 'passdb'
[2016/12/20 20:44:45.757071, 5] ../source3/winbindd/idmap.c:324(smb_register_idmap)
Successfully added idmap backend 'nss'
[2016/12/20 20:44:45.757134, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend smbpasswd
[2016/12/20 20:44:45.757224, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'smbpasswd'
[2016/12/20 20:44:45.757279, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend tdbsam
[2016/12/20 20:44:45.757422, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'tdbsam'
[2016/12/20 20:44:45.757496, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend wbc_sam
[2016/12/20 20:44:45.757552, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'wbc_sam'
[2016/12/20 20:44:45.757606, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend samba_dsdb
[2016/12/20 20:44:45.757678, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'samba_dsdb'
[2016/12/20 20:44:45.757739, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend samba4
[2016/12/20 20:44:45.757793, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'samba4'
[2016/12/20 20:44:45.757947, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend ldapsam
[2016/12/20 20:44:45.758006, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'ldapsam'
[2016/12/20 20:44:45.758059, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend NDS_ldapsam
[2016/12/20 20:44:45.758113, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'NDS_ldapsam'
[2016/12/20 20:44:45.758166, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend IPA_ldapsam
[2016/12/20 20:44:45.758220, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'IPA_ldapsam'
[2016/12/20 20:44:45.758354, 5] ../source3/passdb/pdb_interface.c:155(make_pdb_method_name)
Attempting to find a passdb backend to match tdbsam (tdbsam)
[2016/12/20 20:44:45.758428, 5] ../source3/passdb/pdb_interface.c:176(make_pdb_method_name)
Found pdb backend tdbsam
[2016/12/20 20:44:45.758490, 5] ../source3/passdb/pdb_interface.c:187(make_pdb_method_name)
pdb backend tdbsam has a valid init
[2016/12/20 20:44:45.759424, 4] ../source3/passdb/pdb_interface.c:1402(pdb_default_uid_to_sid)
pdb_default_uid_to_sid: host has no idea of uid 100500
[2016/12/20 20:44:45.759504, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
==> log.winbindd <==
[2016/12/20 20:44:45.759595, 5] ../source3/winbindd/winbindd_getpwuid.c:111(winbindd_getpwuid_recv)
Could not convert sid S-0-0: NT_STATUS_NO_SUCH_USER
==> log.smbd <==
[2016/12/20 20:44:45.759697, 1] ../source3/auth/token_util.c:430(add_local_groups)
SID S-1-5-21-119579451-791976271-3043243932-500 -> getpwuid(100500) failed
[2016/12/20 20:44:45.759767, 3] ../source3/auth/token_util.c:316(create_local_nt_token_from_info3)
Failed to finalize nt token
[2016/12/20 20:44:45.759833, 1] ../source3/smbd/sesssetup.c:290(reply_sesssetup_and_X_spnego)
Failed to generate session_info (user and group token) for session setup: NT_STATUS_UNSUCCESSFUL
[2016/12/20 20:44:45.760113, 5] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
check lock order 1 for /var/run/samba/smbXsrv_session_global.tdb
[2016/12/20 20:44:45.760186, 5] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
release lock order 1 for /var/run/samba/smbXsrv_session_global.tdb
[2016/12/20 20:44:45.760258, 3] ../source3/smbd/error.c:82(error_packet_set)
NT error packet at ../source3/smbd/sesssetup.c(293) cmd=115 (SMBsesssetupX) NT_STATUS_UNSUCCESSFUL
[2016/12/20 20:44:45.760318, 5] ../source3/lib/util.c:171(show_msg)
[2016/12/20 20:44:45.760349, 5] ../source3/lib/util.c:181(show_msg)
size=35
smb_com=0x73
smb_rcls=1
smb_reh=0
smb_err=49152
smb_flg=128
smb_flg2=51203
smb_tid=0
smb_pid=1729
smb_uid=4993
smb_mid=3
smt_wct=0
smb_bcc=0
[2016/12/20 20:44:45.904989, 5] ../source3/lib/util_sock.c:134(read_fd_with_timeout)
read_fd_with_timeout: blocking read. EOF from client.
[2016/12/20 20:44:45.905417, 5] ../source3/smbd/process.c:554(receive_smb_talloc)
receive_smb_raw_talloc failed for client ipv4:192.168.101.20:38154 read error = NT_STATUS_END_OF_FILE.
[2016/12/20 20:44:45.905757, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2016/12/20 20:44:45.906091, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.906370, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/20 20:44:45.906862, 5] ../source3/smbd/uid.c:425(smbd_change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2016/12/20 20:44:45.907157, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2016/12/20 20:44:45.907472, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.907835, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/20 20:44:45.908149, 5] ../source3/smbd/uid.c:425(smbd_change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2016/12/20 20:44:45.908173, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2016/12/20 20:44:45.908189, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.908203, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/20 20:44:45.908224, 5] ../source3/smbd/uid.c:425(smbd_change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2016/12/20 20:44:45.908244, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2016/12/20 20:44:45.908259, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.908272, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/20 20:44:45.908294, 5] ../source3/smbd/uid.c:425(smbd_change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2016/12/20 20:44:45.908644, 3] ../source3/smbd/server_exit.c:246(exit_server_common)
Server exit (failed to receive smb request)
==> log.winbindd <==
[2016/12/20 20:44:45.912679, 6] ../source3/winbindd/winbindd.c:967(winbind_client_request_read)
closing socket 27, client exited
==> log.smbd <==
[2016/12/20 20:44:45.915319, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2016/12/20 20:44:45.915836, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2016/12/20 20:44:45.916143, 4] ../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2016/12/20 20:44:45.916465, 5] ../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/20 20:44:45.916763, 5] ../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/20 20:44:45.917337, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2016/12/20 20:44:45.919750, 3] ../source3/lib/util_procid.c:54(pid_to_procid)
pid_to_procid: messaging_dgm_get_unique failed: No such file or directory
[2016/12/20 20:44:45.920452, 5] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
check lock order 2 for /var/run/samba/serverid.tdb
[2016/12/20 20:44:45.920936, 5] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
release lock order 2 for /var/run/samba/serverid.tdb
==> log.nmbd <==
[2016/12/20 20:44:47.462669, 4] ../source3/nmbd/nmbd_workgroupdb.c:165(find_workgroup_on_subnet)
find_workgroup_on_subnet: workgroup search for LAB on subnet 192.168.101.11: found.
[2016/12/20 20:44:47.463240, 4] ../source3/nmbd/nmbd_workgroupdb.c:276(dump_workgroups)
dump_workgroups()
dump workgroup on subnet 192.168.101.11: netmask= 255.255.255.0:
LAB(1) current master browser = V-SMB-FS
V-SMB-FS 40849b03 (Samba 4.5.2-Debian)
-------------- next part --------------
==> log.winbindd <==
[2016/12/20 20:53:07.621899, 6] ../source3/winbindd/winbindd.c:918(new_connection)
accepted socket 27
[2016/12/20 20:53:07.622016, 3] ../source3/winbindd/winbindd_misc.c:396(winbindd_interface_version)
[ 2378]: request interface version (version = 28)
[2016/12/20 20:53:07.622078, 3] ../source3/winbindd/winbindd_misc.c:429(winbindd_priv_pipe_dir)
[ 2378]: request location of privileged pipe
[2016/12/20 20:53:07.622147, 6] ../source3/winbindd/winbindd.c:918(new_connection)
accepted socket 30
[2016/12/20 20:53:07.622183, 6] ../source3/winbindd/winbindd.c:967(winbind_client_request_read)
closing socket 27, client exited
[2016/12/20 20:53:07.622225, 3] ../source3/winbindd/winbindd_getpwnam.c:56(winbindd_getpwnam_send)
getpwnam administrator
==> log.wb-LAB <==
[2016/12/20 20:53:07.622314, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 56
[2016/12/20 20:53:07.622359, 3] ../source3/winbindd/winbindd_ads.c:1493(sequence_number)
ads: fetch sequence_number for LAB
[2016/12/20 20:53:07.622370, 7] ../source3/winbindd/winbindd_ads.c:62(ads_cached_connection_reuse)
Current tickets expire in 35498 seconds (at 1482299085, time is now 1482263587)
[2016/12/20 20:53:07.623204, 5] ../source3/libads/ldap_utils.c:81(ads_do_search_retry_internal)
Search for (objectclass=*) in <> gave 1 replies
[2016/12/20 20:53:07.623256, 3] ../source3/winbindd/winbindd_msrpc.c:253(msrpc_name_to_sid)
msrpc_name_to_sid: name=LAB\ADMINISTRATOR
[2016/12/20 20:53:07.623267, 3] ../source3/winbindd/winbindd_msrpc.c:267(msrpc_name_to_sid)
name_to_sid [rpc] LAB\ADMINISTRATOR for domain LAB
[2016/12/20 20:53:07.623329, 5] ../source3/rpc_client/cli_pipe.c:826(rpc_api_pipe_send)
rpc_api_pipe: host v-smb-dc.lab.local
[2016/12/20 20:53:07.623342, 5] ../source3/rpc_client/cli_pipe.c:178(rpc_write_send)
rpc_write_send: data_to_write: 184
[2016/12/20 20:53:07.625618, 5] ../source3/rpc_client/cli_pipe.c:98(rpc_read_send)
rpc_read_send: data_to_read: 232
[2016/12/20 20:53:07.625652, 6] ../librpc/rpc/dcerpc_util.c:234(dcerpc_pull_auth_trailer)
../librpc/rpc/dcerpc_util.c:234: auth_pad_length 12
[2016/12/20 20:53:07.625716, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
[2016/12/20 20:53:07.625799, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 56
[2016/12/20 20:53:07.625820, 3] ../source3/winbindd/winbindd_ads.c:628(query_user)
ads: query_user
[2016/12/20 20:53:07.625852, 5] ../source3/winbindd/winbindd_ads.c:638(query_user)
query_user: Cache lookup succeeded for S-1-5-21-119579451-791976271-3043243932-500
[2016/12/20 20:53:07.625884, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
[2016/12/20 20:53:07.625975, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 56
[2016/12/20 20:53:07.625997, 3] ../source3/winbindd/winbindd_msrpc.c:303(msrpc_sid_to_name)
msrpc_sid_to_name: S-1-5-21-119579451-791976271-3043243932-513 for domain LAB
[2016/12/20 20:53:07.626035, 5] ../source3/rpc_client/cli_pipe.c:826(rpc_api_pipe_send)
rpc_api_pipe: host v-smb-dc.lab.local
[2016/12/20 20:53:07.626047, 5] ../source3/rpc_client/cli_pipe.c:178(rpc_write_send)
rpc_write_send: data_to_write: 168
[2016/12/20 20:53:07.627929, 5] ../source3/rpc_client/cli_pipe.c:98(rpc_read_send)
rpc_read_send: data_to_read: 232
[2016/12/20 20:53:07.627960, 6] ../librpc/rpc/dcerpc_util.c:234(dcerpc_pull_auth_trailer)
../librpc/rpc/dcerpc_util.c:234: auth_pad_length 4
[2016/12/20 20:53:07.628001, 5] ../source3/winbindd/winbindd_msrpc.c:323(msrpc_sid_to_name)
Mapped sid to [LAB]\[Domain Users]
[2016/12/20 20:53:07.628024, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
==> log.winbindd <==
[2016/12/20 20:53:07.628210, 3] ../source3/winbindd/winbindd_getgrnam.c:56(winbindd_getgrnam_send)
getgrnam domain users
==> log.wb-LAB <==
[2016/12/20 20:53:07.628258, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 56
[2016/12/20 20:53:07.628279, 3] ../source3/winbindd/winbindd_msrpc.c:253(msrpc_name_to_sid)
msrpc_name_to_sid: name=LAB\DOMAIN USERS
[2016/12/20 20:53:07.628294, 3] ../source3/winbindd/winbindd_msrpc.c:267(msrpc_name_to_sid)
name_to_sid [rpc] LAB\DOMAIN USERS for domain LAB
[2016/12/20 20:53:07.628328, 5] ../source3/rpc_client/cli_pipe.c:826(rpc_api_pipe_send)
rpc_api_pipe: host v-smb-dc.lab.local
[2016/12/20 20:53:07.628339, 5] ../source3/rpc_client/cli_pipe.c:178(rpc_write_send)
rpc_write_send: data_to_write: 184
[2016/12/20 20:53:07.630160, 5] ../source3/rpc_client/cli_pipe.c:98(rpc_read_send)
rpc_read_send: data_to_read: 232
[2016/12/20 20:53:07.630191, 6] ../librpc/rpc/dcerpc_util.c:234(dcerpc_pull_auth_trailer)
../librpc/rpc/dcerpc_util.c:234: auth_pad_length 12
[2016/12/20 20:53:07.630255, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
==> log.winbindd <==
[2016/12/20 20:53:07.630614, 6] ../source3/winbindd/winbindd.c:967(winbind_client_request_read)
closing socket 30, client exited
==> log.nmbd <==
[2016/12/20 20:53:08.112091, 4] ../source3/nmbd/nmbd_workgroupdb.c:165(find_workgroup_on_subnet)
find_workgroup_on_subnet: workgroup search for LAB on subnet 192.168.101.11: found.
[2016/12/20 20:53:08.112188, 4] ../source3/nmbd/nmbd_workgroupdb.c:276(dump_workgroups)
dump_workgroups()
dump workgroup on subnet 192.168.101.11: netmask= 255.255.255.0:
LAB(1) current master browser = V-SMB-FS
V-SMB-FS 40849b03 (Samba 4.5.2-Debian)
==> log.winbindd <==
[2016/12/20 20:53:10.966128, 6] ../source3/winbindd/winbindd.c:918(new_connection)
accepted socket 27
[2016/12/20 20:53:10.966230, 3] ../source3/winbindd/winbindd_misc.c:396(winbindd_interface_version)
[ 2379]: request interface version (version = 28)
[2016/12/20 20:53:10.966285, 3] ../source3/winbindd/winbindd_misc.c:429(winbindd_priv_pipe_dir)
[ 2379]: request location of privileged pipe
[2016/12/20 20:53:10.966344, 6] ../source3/winbindd/winbindd.c:918(new_connection)
accepted socket 30
[2016/12/20 20:53:10.966378, 6] ../source3/winbindd/winbindd.c:967(winbind_client_request_read)
closing socket 27, client exited
[2016/12/20 20:53:10.966419, 3] ../source3/winbindd/winbindd_getpwuid.c:49(winbindd_getpwuid_send)
getpwuid 100500
[2016/12/20 20:53:10.966631, 5] ../source3/winbindd/winbindd_getpwuid.c:111(winbindd_getpwuid_recv)
Could not convert sid S-0-0: NT_STATUS_NO_SUCH_USER
==> log.winbindd-idmap <==
[2016/12/20 20:53:10.966487, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 56
[2016/12/20 20:53:10.966577, 4] ../source3/passdb/pdb_interface.c:1402(pdb_default_uid_to_sid)
pdb_default_uid_to_sid: host has no idea of uid 100500
[2016/12/20 20:53:10.966594, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
==> log.winbindd <==
[2016/12/20 20:53:10.966738, 3] ../source3/winbindd/winbindd_getgrgid.c:52(winbindd_getgrgid_send)
getgrgid 100513
==> log.winbindd-idmap <==
[2016/12/20 20:53:10.966948, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 56
[2016/12/20 20:53:10.967049, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
==> log.wb-LAB <==
[2016/12/20 20:53:10.967122, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 56
[2016/12/20 20:53:10.967156, 3] ../source3/winbindd/winbindd_msrpc.c:303(msrpc_sid_to_name)
msrpc_sid_to_name: S-0-0 for domain LAB
[2016/12/20 20:53:10.967210, 5] ../source3/rpc_client/cli_pipe.c:826(rpc_api_pipe_send)
rpc_api_pipe: host v-smb-dc.lab.local
[2016/12/20 20:53:10.967222, 5] ../source3/rpc_client/cli_pipe.c:178(rpc_write_send)
rpc_write_send: data_to_write: 152
[2016/12/20 20:53:10.969321, 5] ../source3/rpc_client/cli_pipe.c:98(rpc_read_send)
rpc_read_send: data_to_read: 152
[2016/12/20 20:53:10.969356, 6] ../librpc/rpc/dcerpc_util.c:234(dcerpc_pull_auth_trailer)
../librpc/rpc/dcerpc_util.c:234: auth_pad_length 0
[2016/12/20 20:53:10.969392, 2] ../source3/winbindd/winbindd_msrpc.c:314(msrpc_sid_to_name)
msrpc_sid_to_name: failed to lookup sids: STATUS_SOME_UNMAPPED
[2016/12/20 20:53:10.969415, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
==> log.winbindd <==
[2016/12/20 20:53:10.969460, 5] ../source3/winbindd/winbindd_getgrgid.c:116(winbindd_getgrgid_recv)
Could not convert sid S-0-0: STATUS_SOME_UNMAPPED
[2016/12/20 20:53:10.970070, 6] ../source3/winbindd/winbindd.c:967(winbind_client_request_read)
closing socket 30, client exited
==> log.smbd <==
[2016/12/20 20:53:12.859790, 5] ../source3/printing/queue_process.c:162(print_queue_housekeeping)
print queue housekeeping
[2016/12/20 20:53:12.859892, 3] ../source3/printing/pcap.c:140(pcap_cache_reload)
reloading printcap cache
[2016/12/20 20:53:12.859927, 5] ../source3/printing/print_cups.c:456(cups_pcap_load_async)
cups_pcap_load_async: asynchronously loading cups printers
[2016/12/20 20:53:12.862449, 3] ../source3/printing/pcap.c:189(pcap_cache_reload)
reload status: ok
[2016/12/20 20:53:12.863130, 5] ../source3/printing/print_cups.c:325(cups_cache_reload_async)
reloading cups printcap cache
[2016/12/20 20:53:12.863905, 3] ../source3/printing/print_cups.c:158(cups_connect)
Unable to connect to CUPS server localhost:631 - Bad file descriptor
[2016/12/20 20:53:12.864039, 5] ../source3/printing/print_cups.c:520(cups_async_callback)
cups_async_callback: callback received for printer data. fd = 15
[2016/12/20 20:53:12.864129, 3] ../source3/printing/print_cups.c:536(cups_async_callback)
failed to retrieve printer list: NT_STATUS_UNSUCCESSFUL
[2016/12/20 20:53:12.864207, 2] ../lib/util/tevent_debug.c:66(samba_tevent_debug)
samba_tevent: EPOLL_CTL_DEL EBADF for fde[0x55b83b31eab0] mpx_fde[(nil)] fd[15] - disabling
[2016/12/20 20:53:12.865079, 6] ../source3/printing/queue_process.c:265(bq_sig_chld_handler)
Bq child process 2380 terminated with 0
==> log.nmbd <==
[2016/12/20 20:53:18.133311, 4] ../source3/nmbd/nmbd_workgroupdb.c:165(find_workgroup_on_subnet)
find_workgroup_on_subnet: workgroup search for LAB on subnet 192.168.101.11: found.
[2016/12/20 20:53:18.133417, 4] ../source3/nmbd/nmbd_workgroupdb.c:276(dump_workgroups)
dump_workgroups()
dump workgroup on subnet 192.168.101.11: netmask= 255.255.255.0:
LAB(1) current master browser = V-SMB-FS
V-SMB-FS 40849b03 (Samba 4.5.2-Debian)
-------------- next part --------------
==> log.winbindd <==
[2016/12/20 22:47:30.831440, 6] ../source3/winbindd/winbindd.c:918(new_connection)
accepted socket 25
[2016/12/20 22:47:30.831541, 3] ../source3/winbindd/winbindd_misc.c:396(winbindd_interface_version)
[ 9367]: request interface version (version = 28)
[2016/12/20 22:47:30.831592, 3] ../source3/winbindd/winbindd_misc.c:429(winbindd_priv_pipe_dir)
[ 9367]: request location of privileged pipe
[2016/12/20 22:47:30.831719, 6] ../source3/winbindd/winbindd.c:918(new_connection)
accepted socket 27
[2016/12/20 22:47:30.831750, 6] ../source3/winbindd/winbindd.c:967(winbind_client_request_read)
closing socket 25, client exited
[2016/12/20 22:47:30.831788, 3] ../source3/winbindd/winbindd_getpwuid.c:49(winbindd_getpwuid_send)
getpwuid 101103
[2016/12/20 22:47:30.834288, 5] ../source3/winbindd/winbindd_getpwuid.c:111(winbindd_getpwuid_recv)
Could not convert sid S-0-0: NT_STATUS_NO_SUCH_USER
==> log.winbindd-idmap <==
[2016/12/20 22:47:30.832928, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 33 - private_data=(nil)
[2016/12/20 22:47:30.832956, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 13 - private_data=(nil)
[2016/12/20 22:47:30.832963, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1028 - private_data=(nil)
[2016/12/20 22:47:30.832970, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1027 - private_data=(nil)
[2016/12/20 22:47:30.832977, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1029 - private_data=(nil)
[2016/12/20 22:47:30.832983, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1280 - private_data=(nil)
[2016/12/20 22:47:30.832990, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1033 - private_data=(nil)
[2016/12/20 22:47:30.832997, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1 - private_data=(nil)
[2016/12/20 22:47:30.833003, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1036 - private_data=(nil)
[2016/12/20 22:47:30.833010, 5] ../source3/lib/messages.c:403(messaging_deregister)
Deregistering messaging pointer for type 1035 - private_data=(nil)
[2016/12/20 22:47:30.833056, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 1028 - private_data=(nil)
[2016/12/20 22:47:30.833068, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 1027 - private_data=(nil)
[2016/12/20 22:47:30.833075, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 1280 - private_data=(nil)
[2016/12/20 22:47:30.833082, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 1 - private_data=(nil)
[2016/12/20 22:47:30.833088, 5] ../source3/lib/messages.c:356(messaging_register)
Registering messaging pointer for type 1034 - private_data=(nil)
[2016/12/20 22:47:30.833095, 5] ../source3/lib/messages.c:371(messaging_register)
Overriding messaging pointer for type 1034 - private_data=(nil)
[2016/12/20 22:47:30.833110, 4] ../source3/winbindd/winbindd_dual.c:1388(child_handler)
child daemon request 56
[2016/12/20 22:47:30.833199, 5] ../source3/winbindd/idmap.c:324(smb_register_idmap)
Successfully added idmap backend 'tdb'
[2016/12/20 22:47:30.833215, 5] ../source3/winbindd/idmap.c:324(smb_register_idmap)
Successfully added idmap backend 'passdb'
[2016/12/20 22:47:30.833222, 5] ../source3/winbindd/idmap.c:324(smb_register_idmap)
Successfully added idmap backend 'nss'
[2016/12/20 22:47:30.833238, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend smbpasswd
[2016/12/20 22:47:30.833252, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'smbpasswd'
[2016/12/20 22:47:30.833261, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend tdbsam
[2016/12/20 22:47:30.833268, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'tdbsam'
[2016/12/20 22:47:30.833274, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend wbc_sam
[2016/12/20 22:47:30.833281, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'wbc_sam'
[2016/12/20 22:47:30.833287, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend samba_dsdb
[2016/12/20 22:47:30.833294, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'samba_dsdb'
[2016/12/20 22:47:30.833308, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend samba4
[2016/12/20 22:47:30.833315, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'samba4'
[2016/12/20 22:47:30.833324, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend ldapsam
[2016/12/20 22:47:30.833333, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'ldapsam'
[2016/12/20 22:47:30.833339, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend NDS_ldapsam
[2016/12/20 22:47:30.833346, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'NDS_ldapsam'
[2016/12/20 22:47:30.833352, 5] ../source3/passdb/pdb_interface.c:79(smb_register_passdb)
Attempting to register passdb backend IPA_ldapsam
[2016/12/20 22:47:30.833359, 5] ../source3/passdb/pdb_interface.c:92(smb_register_passdb)
Successfully added passdb backend 'IPA_ldapsam'
[2016/12/20 22:47:30.833365, 5] ../source3/passdb/pdb_interface.c:155(make_pdb_method_name)
Attempting to find a passdb backend to match tdbsam (tdbsam)
[2016/12/20 22:47:30.833372, 5] ../source3/passdb/pdb_interface.c:176(make_pdb_method_name)
Found pdb backend tdbsam
[2016/12/20 22:47:30.833381, 5] ../source3/passdb/pdb_interface.c:187(make_pdb_method_name)
pdb backend tdbsam has a valid init
[2016/12/20 22:47:30.834211, 4] ../source3/passdb/pdb_interface.c:1402(pdb_default_uid_to_sid)
pdb_default_uid_to_sid: host has no idea of uid 101103
[2016/12/20 22:47:30.834240, 4] ../source3/winbindd/winbindd_dual.c:1396(child_handler)
Finished processing child request 56
==> log.winbindd <==
[2016/12/20 22:47:30.835267, 6] ../source3/winbindd/winbindd.c:967(winbind_client_request_read)
closing socket 27, client exited
-------------- next part --------------
[global]
netbios name = V-SMB-DC
realm = LAB.LOCAL
workgroup = LAB
dns forwarder = 192.168.101.1
server role = active directory domain controller
idmap_ldb:use rfc2307 = yes
[netlogon]
path = /var/lib/samba/sysvol/lab.local/scripts
read only = No
[sysvol]
path = /var/lib/samba/sysvol
read only = No
-------------- next part --------------
[global]
security = ads
realm = LAB.LOCAL
workgroup = LAB
idmap uid = 10000-20000
idmap gid = 10000-20000
winbind use default domain = yes
winbind enum users = yes
winbind enum groups = yes
winbind nss info = template
template homedir = /data/%U
template shell = /bin/false
encrypt passwords = yes
client use spnego = yes
client ntlmv2 auth = yes
restrict anonymous = 2
valid users = @"Domain Users"
[shared]
write list = @"Domain Admins"
path = /shared
More information about the Pkg-samba-maint
mailing list