[2014/12/24 11:53:58.185648, 6, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2152(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf.local -> /etc/samba/smb.conf.local last mod_time: Thu Jan 1 01:00:00 1970 file /usr/local/webmanager/var/etc/vmhomes.smb.conf.include -> /usr/local/webmanager/var/etc/vmhomes.smb.conf.include last mod_time: Thu Jan 1 01:00:00 1970 file /usr/local/webmanager/var/etc/vmmedia.smb.conf.include -> /usr/local/webmanager/var/etc/vmmedia.smb.conf.include last mod_time: Thu Jan 1 01:00:00 1970 file /usr/local/webmanager/var/etc/archives.smb.conf.include -> /usr/local/webmanager/var/etc/archives.smb.conf.include last mod_time: Thu Jan 1 01:00:00 1970 file /usr/local/webmanager/var/etc/smb.conf.include -> /usr/local/webmanager/var/etc/smb.conf.include last mod_time: Wed Dec 24 11:44:12 2014 file /etc/samba/smb.conf.arch.%a -> /etc/samba/smb.conf.arch.UNKNOWN last mod_time: Thu Jan 1 01:00:00 1970 file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Dec 24 11:53:51 2014 [2014/12/24 11:53:58.185788, 3, pid=6978, effective(0, 0), real(0, 0), class=locking] ../source3/smbd/oplock.c:1306(init_oplocks) init_oplocks: initializing messages. [2014/12/24 11:53:58.185801, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 774 - private_data=0x7fdaeea7f610 [2014/12/24 11:53:58.185810, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 778 - private_data=0x7fdaeea7f610 [2014/12/24 11:53:58.185816, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 770 - private_data=0x7fdaeea7f610 [2014/12/24 11:53:58.185823, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 787 - private_data=0x7fdaeea7f610 [2014/12/24 11:53:58.185830, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 779 - private_data=0x7fdaeea7f610 [2014/12/24 11:53:58.185842, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 15 - private_data=(nil) [2014/12/24 11:53:58.185849, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:399(messaging_register) Overriding messaging pointer for type 15 - private_data=(nil) [2014/12/24 11:53:58.185861, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:431(messaging_deregister) Deregistering messaging pointer for type 16 - private_data=(nil) [2014/12/24 11:53:58.185869, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 16 - private_data=0x7fdaeea7f610 [2014/12/24 11:53:58.185876, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:431(messaging_deregister) Deregistering messaging pointer for type 33 - private_data=0x7fdaeea59bd0 [2014/12/24 11:53:58.185883, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 33 - private_data=0x7fdaeea7f610 [2014/12/24 11:53:58.185890, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:431(messaging_deregister) Deregistering messaging pointer for type 790 - private_data=(nil) [2014/12/24 11:53:58.185896, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 790 - private_data=0x7fdaeea7f610 [2014/12/24 11:53:58.185903, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:431(messaging_deregister) Deregistering messaging pointer for type 791 - private_data=(nil) [2014/12/24 11:53:58.185910, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:431(messaging_deregister) Deregistering messaging pointer for type 1 - private_data=(nil) [2014/12/24 11:53:58.185924, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 1 - private_data=(nil) [2014/12/24 11:53:58.185950, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/events.c:483(event_add_idle) event_add_idle: idle_evt(keepalive) 0x7fdaeea8a9a0 [2014/12/24 11:53:58.185960, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/events.c:483(event_add_idle) event_add_idle: idle_evt(deadtime) 0x7fdaeea8e890 [2014/12/24 11:53:58.185969, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/events.c:483(event_add_idle) event_add_idle: idle_evt(housekeeping) 0x7fdaeea8eae0 [2014/12/24 11:53:58.186034, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util_sock.c:369(read_smb_length_return_keepalive) got smb length of 190 [2014/12/24 11:53:58.186079, 6, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1877(process_smb) got message type 0x0 of len 0xbe [2014/12/24 11:53:58.186089, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1879(process_smb) Transaction 0 of length 194 (0 toread) [2014/12/24 11:53:58.186103, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:168(show_msg) [2014/12/24 11:53:58.186110, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:178(show_msg) size=190 smb_com=0x72 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=24 smb_flg2=51267 smb_tid=0 smb_pid=65534 smb_uid=0 smb_mid=0 smt_wct=0 smb_bcc=155 [2014/12/24 11:53:58.186133, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/util/util.c:559(dump_data) [0000] 02 50 43 20 4E 45 54 57 4F 52 4B 20 50 52 4F 47 .PC NETW ORK PROG [0010] 52 41 4D 20 31 2E 30 00 02 4D 49 43 52 4F 53 4F RAM 1.0. .MICROSO [0020] 46 54 20 4E 45 54 57 4F 52 4B 53 20 31 2E 30 33 FT NETWO RKS 1.03 [0030] 00 02 4D 49 43 52 4F 53 4F 46 54 20 4E 45 54 57 ..MICROS OFT NETW [0040] 4F 52 4B 53 20 33 2E 30 00 02 4C 41 4E 4D 41 4E ORKS 3.0 ..LANMAN [0050] 31 2E 30 00 02 4C 4D 31 2E 32 58 30 30 32 00 02 1.0..LM1 .2X002.. [0060] 44 4F 53 20 4C 41 4E 4D 41 4E 32 2E 31 00 02 4C DOS LANM AN2.1..L [0070] 41 4E 4D 41 4E 32 2E 31 00 02 53 61 6D 62 61 00 ANMAN2.1 ..Samba. [0080] 02 4E 54 20 4C 41 4E 4D 41 4E 20 31 2E 30 00 02 .NT LANM AN 1.0.. [0090] 4E 54 20 4C 4D 20 30 2E 31 32 00 NT LM 0. 12. [2014/12/24 11:53:58.186294, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1489(switch_message) switch message SMBnegprot (pid 6978) conn 0x0 [2014/12/24 11:53:58.186318, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2014/12/24 11:53:58.186330, 5, pid=6978, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2014/12/24 11:53:58.186341, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2014/12/24 11:53:58.186363, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2014/12/24 11:53:58.188810, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:575(reply_negprot) Requested protocol [PC NETWORK PROGRAM 1.0] [2014/12/24 11:53:58.188845, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:575(reply_negprot) Requested protocol [MICROSOFT NETWORKS 1.03] [2014/12/24 11:53:58.188854, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:575(reply_negprot) Requested protocol [MICROSOFT NETWORKS 3.0] [2014/12/24 11:53:58.188862, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:575(reply_negprot) Requested protocol [LANMAN1.0] [2014/12/24 11:53:58.188869, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:575(reply_negprot) Requested protocol [LM1.2X002] [2014/12/24 11:53:58.188890, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:575(reply_negprot) Requested protocol [DOS LANMAN2.1] [2014/12/24 11:53:58.188897, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:575(reply_negprot) Requested protocol [LANMAN2.1] [2014/12/24 11:53:58.188904, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:575(reply_negprot) Requested protocol [Samba] [2014/12/24 11:53:58.188912, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:575(reply_negprot) Requested protocol [NT LANMAN 1.0] [2014/12/24 11:53:58.188919, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:575(reply_negprot) Requested protocol [NT LM 0.12] [2014/12/24 11:53:58.188935, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:1289(set_remote_arch) set_remote_arch: Client arch is 'Samba' [2014/12/24 11:53:58.188955, 6, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2152(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf.local -> /etc/samba/smb.conf.local last mod_time: Thu Jan 1 01:00:00 1970 file /usr/local/webmanager/var/etc/vmhomes.smb.conf.include -> /usr/local/webmanager/var/etc/vmhomes.smb.conf.include last mod_time: Thu Jan 1 01:00:00 1970 file /usr/local/webmanager/var/etc/vmmedia.smb.conf.include -> /usr/local/webmanager/var/etc/vmmedia.smb.conf.include last mod_time: Thu Jan 1 01:00:00 1970 file /usr/local/webmanager/var/etc/archives.smb.conf.include -> /usr/local/webmanager/var/etc/archives.smb.conf.include last mod_time: Thu Jan 1 01:00:00 1970 file /usr/local/webmanager/var/etc/smb.conf.include -> /usr/local/webmanager/var/etc/smb.conf.include last mod_time: Wed Dec 24 11:44:12 2014 file /etc/samba/smb.conf.arch.%a -> /etc/samba/smb.conf.arch.Samba last mod_time: Thu Jan 1 01:00:00 1970 file /etc/samba/smb.conf.arch.Samba modified: Thu Oct 17 15:08:15 2013 [2014/12/24 11:53:58.189097, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1259(free_service) free_service: Freeing service extranet [2014/12/24 11:53:58.189145, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1259(free_service) free_service: Freeing service intranet [2014/12/24 11:53:58.189164, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1259(free_service) free_service: Freeing service IPC$ [2014/12/24 11:53:58.189181, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1259(free_service) free_service: Freeing service homes [2014/12/24 11:53:58.189199, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1259(free_service) free_service: Freeing service profile [2014/12/24 11:53:58.189213, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1259(free_service) free_service: Freeing service netlogon [2014/12/24 11:53:58.189230, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1259(free_service) free_service: Freeing service printers [2014/12/24 11:53:58.189246, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1259(free_service) free_service: Freeing service print$ [2014/12/24 11:53:58.189261, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1259(free_service) free_service: Freeing service pdf [2014/12/24 11:53:58.189278, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3647(lp_load_ex) lp_load_ex: refreshing parameters [2014/12/24 11:53:58.189288, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1234(free_param_opts) Freeing parametrics: [2014/12/24 11:53:58.189360, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:564(init_globals) Initialising global parameters [2014/12/24 11:53:58.189382, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:353(max_open_files) rlimit_max: increasing rlimit_max (4040) to minimum Windows limit (16384) [2014/12/24 11:53:58.189466, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2597(lp_do_section) Processing section "[global]" doing parameter workgroup = S4 doing parameter netbios name = SAMBA4 doing parameter server string = samba4 doing parameter interfaces = 192.168.173.1/24 127.255.255.255/8 doing parameter bind interfaces only = Yes doing parameter hosts allow = 192.168.0.0/255.255.0.0 127.0.0.1 doing parameter max protocol = SMB2 doing parameter encrypt passwords = Yes doing parameter passwd program = /usr/local/webmanager/bin/samba_passwd_change.sh '%u' doing parameter passwd chat = *password* %n\n *changed* doing parameter passwd chat timeout = 3 doing parameter check password script = /usr/lib/samba/passcheck/passcheck.pl doing parameter username map = /etc/samba/smbusers doing parameter unix password sync = Yes doing parameter log level = 10 [2014/12/24 11:53:58.189550, 5, pid=6978, effective(0, 0), real(0, 0)] ../lib/util/debug.c:334(debug_dump_status) INFO: Current debug levels: all: 10 tdb: 10 printdrivers: 10 lanman: 10 smb: 10 rpc_parse: 10 rpc_srv: 10 rpc_cli: 10 passdb: 10 sam: 10 auth: 10 winbind: 10 vfs: 10 idmap: 10 quota: 10 acls: 10 locking: 10 msdfs: 10 dmapi: 10 registry: 10 scavenger: 10 dns: 10 ldb: 10 doing parameter log file = /var/log/samba/samba.log.%m doing parameter max log size = 1500 doing parameter max open files = 4000 doing parameter syslog = No doing parameter lanman auth = No doing parameter client lanman auth = No doing parameter client NTLMv2 auth = Yes doing parameter domain logons = Yes doing parameter logon script = %U.bat doing parameter logon path = doing parameter logon drive = H: doing parameter logon home = doing parameter add machine script = /usr/local/webmanager/bin/samba_2k.sh '%m' doing parameter os level = 254 doing parameter preferred master = Yes doing parameter domain master = Yes doing parameter local master = Yes doing parameter wins support = Yes doing parameter time server = Yes doing parameter name resolve order = host wins bcast doing parameter passdb backend = ldapsam:ldap://localhost doing parameter ldap suffix = dc=s4,dc=local doing parameter ldap machine suffix = ou=Computers doing parameter ldap user suffix = ou=Users doing parameter ldap group suffix = ou=Groups doing parameter ldap idmap suffix = ou=Idmap doing parameter ldap admin dn = cn=admin,dc=s4,dc=local doing parameter ldap ssl = No doing parameter idmap config * : backend = tdb doing parameter idmap config * : range = 1000000-1999999 doing parameter idmap config S4 : backend = rid doing parameter idmap config S4 : range = 10000-20000 doing parameter idmap config S4 : base_rid = 0 doing parameter printing = cups doing parameter min print space = 1000 doing parameter create mask = 0660 doing parameter force create mode = 0660 doing parameter directory mask = 0770 doing parameter force directory mode = 0770 doing parameter oplocks = Yes doing parameter veto oplock files = /*.mdb/*.MDB/*.mde/*.MDE/*.dbf/*.DBF/*.lck/*.LCK/*.cnv/*.CNV/*.stm/*.STM/*.dat/*.DAT/*.tbm/*.TBM/*.loc/*.LOC/*.fbk/*.FBK/*.fdb/*.FDB/*.spd/*.SPD/*.adb/*.ADB/*.adx/*.ADX/*.blb/*.BLB/*.ddb/*.DDB/*.ddf/*.DDF/*.ddx/*.DDX/*.edb/*.EDB/*.edx/*.EDX/*.gdb/*.GDB/*.gdx/*.GDX/*.hdb/*.HDB/*.hdx/*.HDX/*.hk4/*.HK4/*.mdx/*.MDX/*.rel/*.REL/*.rem/*.REM/*.rex/*.REX/*.sdb/*.SDB/*.sdx/*.SDX/*.tdb/*.TDB/*.tdx/*.TDX/*.fmt/*.FMT/*.bom/*.BOM/*.dbc/*.DBC/*.dbk/*.DBK/*.dpc/*.DPC/*.dra/*.DRA/*.drc/*.DRC/*.drt/*.DRT/*.dsn/*.DSN/*.lib/*.LIB/*.max/*.MAX/*.mnl/*.MNL/*.net/*.NET/*.obk/*.OBK/*.olb/*.OLB/*.opj/*.OPJ/*.sch/*.SCH/*.nsx/*.NSX/*.ndx/*.NDX/*.dbx/*.DBX/*.dbt/*.DBT/*.fpt/*.FPT/*.cdx/*.CDX/*.dwf/*.DWF/*.dwg/*.DWG/*.rvt/*.RVT/*.lock/ doing parameter level2 oplocks = No doing parameter unix extensions = No doing parameter wide links = Yes doing parameter include = /etc/samba/smb.conf.arch.%a [2014/12/24 11:53:58.190053, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2597(lp_do_section) Processing section "[global]" doing parameter create mask = 777 doing parameter force create mode = 000 doing parameter include = /usr/local/webmanager/var/etc/smb.conf.include [2014/12/24 11:53:58.190115, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[extranet]" [2014/12/24 11:53:58.190152, 8, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1340(add_a_service) add_a_service: Creating snum = 9 for extranet [2014/12/24 11:53:58.190161, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1390(hash_a_service) hash_a_service: hashing index 9 for service name extranet doing parameter comment = doing parameter create mask = 0664 doing parameter directory mask = 0775 doing parameter force create mode = 0664 doing parameter force directory mode = 0775 doing parameter force group = www doing parameter path = /home/vol1/shares/extranet doing parameter readlist = doing parameter validusers = user1a ad doing parameter writelist = ad [2014/12/24 11:53:58.190229, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[intranet]" [2014/12/24 11:53:58.190250, 8, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1340(add_a_service) add_a_service: Creating snum = 10 for intranet [2014/12/24 11:53:58.190258, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1390(hash_a_service) hash_a_service: hashing index 10 for service name intranet doing parameter comment = intranet doing parameter create mask = 0664 doing parameter directory mask = 0775 doing parameter force create mode = 0664 doing parameter force directory mode = 0775 doing parameter force group = www doing parameter path = /home/vol1/shares/intranet doing parameter readlist = doing parameter validusers = user1a ad doing parameter writelist = ad doing parameter include = /usr/local/webmanager/var/etc/archives.smb.conf.include [2014/12/24 11:53:58.190349, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2276(lp_include) Can't find include file /usr/local/webmanager/var/etc/archives.smb.conf.include doing parameter include = /usr/local/webmanager/var/etc/vmmedia.smb.conf.include [2014/12/24 11:53:58.190375, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2276(lp_include) Can't find include file /usr/local/webmanager/var/etc/vmmedia.smb.conf.include doing parameter include = /usr/local/webmanager/var/etc/vmhomes.smb.conf.include [2014/12/24 11:53:58.190398, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2276(lp_include) Can't find include file /usr/local/webmanager/var/etc/vmhomes.smb.conf.include [2014/12/24 11:53:58.190406, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[IPC$]" [2014/12/24 11:53:58.190427, 8, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1340(add_a_service) add_a_service: Creating snum = 11 for IPC$ [2014/12/24 11:53:58.190434, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1390(hash_a_service) hash_a_service: hashing index 11 for service name IPC$ doing parameter admin users = @Administrators, user1a doing parameter path = /var/empty [2014/12/24 11:53:58.190455, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[homes]" [2014/12/24 11:53:58.190475, 8, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1340(add_a_service) add_a_service: Creating snum = 12 for homes [2014/12/24 11:53:58.190482, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1390(hash_a_service) hash_a_service: hashing index 12 for service name homes doing parameter read only = No doing parameter browseable = No doing parameter invalid users = root doing parameter valid users = %S doing parameter force user = %S doing parameter create mask = 0601 doing parameter force create mode = 0600 doing parameter directory mask = 0700 doing parameter force directory mode = 0700 doing parameter map hidden = Yes doing parameter csc policy = disable [2014/12/24 11:53:58.190576, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[profile]" [2014/12/24 11:53:58.190599, 8, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1340(add_a_service) add_a_service: Creating snum = 13 for profile [2014/12/24 11:53:58.190607, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1390(hash_a_service) hash_a_service: hashing index 13 for service name profile doing parameter path = /home/users/%U/.profileNT doing parameter read only = No doing parameter browseable = No doing parameter invalid users = root doing parameter create mask = 0645 doing parameter force create mode = 0644 doing parameter map hidden = Yes doing parameter csc policy = disable [2014/12/24 11:53:58.190676, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[netlogon]" [2014/12/24 11:53:58.190696, 8, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1340(add_a_service) add_a_service: Creating snum = 14 for netlogon [2014/12/24 11:53:58.190704, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1390(hash_a_service) hash_a_service: hashing index 14 for service name netlogon doing parameter path = /usr/local/webmanager/var/etc/smb_netlogon/ doing parameter read only = Yes doing parameter browseable = No doing parameter invalid users = user1a doing parameter write list = @Administrators doing parameter locking = no [2014/12/24 11:53:58.190756, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[printers]" [2014/12/24 11:53:58.190776, 8, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1340(add_a_service) add_a_service: Creating snum = 15 for printers [2014/12/24 11:53:58.190784, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1390(hash_a_service) hash_a_service: hashing index 15 for service name printers doing parameter comment = All Printers doing parameter path = /var/spool/print/tmp doing parameter create mask = 0700 doing parameter guest ok = Yes doing parameter printable = Yes doing parameter printing = cups doing parameter use client driver = No doing parameter min print space = 2000 [2014/12/24 11:53:58.190851, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[print$]" [2014/12/24 11:53:58.190871, 8, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1340(add_a_service) add_a_service: Creating snum = 16 for print$ [2014/12/24 11:53:58.190879, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1390(hash_a_service) hash_a_service: hashing index 16 for service name print$ doing parameter comment = Printer Drivers doing parameter path = /var/spool/samba/drivers doing parameter guest ok = Yes doing parameter browsable = yes doing parameter readonly = yes doing parameter write list = root,@Administrators [2014/12/24 11:53:58.190929, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[pdf]" [2014/12/24 11:53:58.190951, 8, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1340(add_a_service) add_a_service: Creating snum = 17 for pdf [2014/12/24 11:53:58.190959, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1390(hash_a_service) hash_a_service: hashing index 17 for service name pdf doing parameter comment = PDF printer doing parameter path = /var/spool/print/tmp doing parameter read only = No doing parameter create mask = 0700 doing parameter print ok = yes doing parameter browseable = Yes doing parameter printing = BSD doing parameter print command = /usr/local/bin/printpdf %s %U doing parameter lpq command = doing parameter lprm command = doing parameter lppause command = doing parameter lpresume command = doing parameter queuepause command = doing parameter queueresume command = doing parameter include = /etc/samba/smb.conf.local [2014/12/24 11:53:58.191105, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2276(lp_include) Can't find include file /etc/samba/smb.conf.local [2014/12/24 11:53:58.191125, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3688(lp_load_ex) pm_process() returned Yes [2014/12/24 11:53:58.191145, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1495(lp_add_ipc) adding IPC service [2014/12/24 11:53:58.191285, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/interface.c:479(interpret_interface) interpret_interface: Adding interface 192.168.173.1/24 [2014/12/24 11:53:58.191299, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/interface.c:341(add_interface) added interface 192.168.173.1/2 ip=192.168.173.1 bcast=192.168.173.255 netmask=255.255.255.0 [2014/12/24 11:53:58.191326, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/interface.c:464(interpret_interface) interpret_interface: using netmask value 8 from config file on interface lo [2014/12/24 11:53:58.191336, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/interface.c:341(add_interface) added interface lo ip=127.0.0.1 bcast=127.255.255.255 netmask=255.0.0.0 [2014/12/24 11:53:58.191349, 5, pid=6978, effective(0, 0), real(0, 0)] ../lib/util/util_net.c:890(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_SNDBUF = 171800 SO_RCVBUF = 87380 SO_SNDLOWAT = 1 SO_RCVLOWAT = 1 SO_SNDTIMEO = 0 SO_RCVTIMEO = 0 TCP_QUICKACK = 1 TCP_DEFER_ACCEPT = 0 [2014/12/24 11:53:58.191393, 5, pid=6978, effective(0, 0), real(0, 0)] ../lib/util/util_net.c:890(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_SNDBUF = 171800 SO_RCVBUF = 87380 SO_SNDLOWAT = 1 SO_RCVLOWAT = 1 SO_SNDTIMEO = 0 SO_RCVTIMEO = 0 TCP_QUICKACK = 1 TCP_DEFER_ACCEPT = 0 [2014/12/24 11:53:58.191441, 5, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order) check lock order 2 for /var/lock/samba/serverid.tdb [2014/12/24 11:53:58.191449, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order) lock order: 1: 2:/var/lock/samba/serverid.tdb 3: [2014/12/24 11:53:58.191460, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key) Locking key 421B000000000000FFFF [2014/12/24 11:53:58.191477, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal) Allocated locked data 0x0x7fdaeea91f40 [2014/12/24 11:53:58.191501, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key) Unlocking key 421B000000000000FFFF [2014/12/24 11:53:58.191511, 5, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor) release lock order 2 for /var/lock/samba/serverid.tdb [2014/12/24 11:53:58.191518, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order) lock order: 1: 2: 3: [2014/12/24 11:53:58.191543, 6, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2152(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf.local -> /etc/samba/smb.conf.local last mod_time: Thu Jan 1 01:00:00 1970 file /usr/local/webmanager/var/etc/vmhomes.smb.conf.include -> /usr/local/webmanager/var/etc/vmhomes.smb.conf.include last mod_time: Thu Jan 1 01:00:00 1970 file /usr/local/webmanager/var/etc/vmmedia.smb.conf.include -> /usr/local/webmanager/var/etc/vmmedia.smb.conf.include last mod_time: Thu Jan 1 01:00:00 1970 file /usr/local/webmanager/var/etc/archives.smb.conf.include -> /usr/local/webmanager/var/etc/archives.smb.conf.include last mod_time: Thu Jan 1 01:00:00 1970 file /usr/local/webmanager/var/etc/smb.conf.include -> /usr/local/webmanager/var/etc/smb.conf.include last mod_time: Wed Dec 24 11:44:12 2014 file /etc/samba/smb.conf.arch.%a -> /etc/samba/smb.conf.arch.Samba last mod_time: Thu Oct 17 15:08:15 2013 file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Dec 24 11:53:51 2014 [2014/12/24 11:53:58.191789, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:484(make_auth_context_subsystem) Making default auth method list for DC [2014/12/24 11:53:58.191820, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend sam [2014/12/24 11:53:58.191832, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'sam' [2014/12/24 11:53:58.191839, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend sam_ignoredomain [2014/12/24 11:53:58.191853, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'sam_ignoredomain' [2014/12/24 11:53:58.191864, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend unix [2014/12/24 11:53:58.191871, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'unix' [2014/12/24 11:53:58.191881, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend winbind [2014/12/24 11:53:58.191887, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'winbind' [2014/12/24 11:53:58.191897, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend wbc [2014/12/24 11:53:58.191904, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'wbc' [2014/12/24 11:53:58.191914, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend trustdomain [2014/12/24 11:53:58.191921, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'trustdomain' [2014/12/24 11:53:58.191927, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend ntdomain [2014/12/24 11:53:58.191934, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'ntdomain' [2014/12/24 11:53:58.191943, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend guest [2014/12/24 11:53:58.191950, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'guest' [2014/12/24 11:53:58.191960, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend samba4 [2014/12/24 11:53:58.191968, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'samba4' [2014/12/24 11:53:58.191981, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:378(load_auth_module) load_auth_module: Attempting to find an auth method to match guest [2014/12/24 11:53:58.191999, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:403(load_auth_module) load_auth_module: auth method guest has a valid init [2014/12/24 11:53:58.192011, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:378(load_auth_module) load_auth_module: Attempting to find an auth method to match sam [2014/12/24 11:53:58.192019, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:403(load_auth_module) load_auth_module: auth method sam has a valid init [2014/12/24 11:53:58.192026, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:378(load_auth_module) load_auth_module: Attempting to find an auth method to match winbind:trustdomain [2014/12/24 11:53:58.192033, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:378(load_auth_module) load_auth_module: Attempting to find an auth method to match trustdomain [2014/12/24 11:53:58.192040, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:403(load_auth_module) load_auth_module: auth method trustdomain has a valid init [2014/12/24 11:53:58.192046, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:403(load_auth_module) load_auth_module: auth method winbind has a valid init [2014/12/24 11:53:58.193892, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'gssapi_spnego' registered [2014/12/24 11:53:58.193953, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'gssapi_krb5' registered [2014/12/24 11:53:58.193963, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'gssapi_krb5_sasl' registered [2014/12/24 11:53:58.219151, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'sasl-DIGEST-MD5' registered [2014/12/24 11:53:58.219195, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'spnego' registered [2014/12/24 11:53:58.219206, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'schannel' registered [2014/12/24 11:53:58.219216, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'naclrpc_as_system' registered [2014/12/24 11:53:58.219225, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'sasl-EXTERNAL' registered [2014/12/24 11:53:58.219233, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'ntlmssp' registered [2014/12/24 11:53:58.219241, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'http_basic' registered [2014/12/24 11:53:58.219249, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'http_ntlm' registered [2014/12/24 11:53:58.219259, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'krb5' registered [2014/12/24 11:53:58.219267, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:885(gensec_register) GENSEC backend 'fake_gssapi_krb5' registered [2014/12/24 11:53:58.219597, 5, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:664(gensec_start_mech) Starting GENSEC mechanism spnego [2014/12/24 11:53:58.219720, 5, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:664(gensec_start_mech) Starting GENSEC submechanism ntlmssp [2014/12/24 11:53:58.219929, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:395(reply_nt1) using SPNEGO [2014/12/24 11:53:58.219944, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:683(reply_negprot) Selected protocol NT LANMAN 1.0 [2014/12/24 11:53:58.219956, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/negprot.c:690(reply_negprot) negprot index=8 [2014/12/24 11:53:58.219971, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:168(show_msg) [2014/12/24 11:53:58.219977, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:178(show_msg) size=159 smb_com=0x72 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51267 smb_tid=0 smb_pid=65534 smb_uid=0 smb_mid=0 smt_wct=17 smb_vwv[ 0]= 8 (0x8) 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]= 27 (0x1B) smb_vwv[ 9]=64768 (0xFD00) smb_vwv[10]= 243 (0xF3) smb_vwv[11]=19072 (0x4A80) smb_vwv[12]=13417 (0x3469) smb_vwv[13]=26603 (0x67EB) smb_vwv[14]=53279 (0xD01F) smb_vwv[15]=50177 (0xC401) smb_vwv[16]= 255 (0xFF) smb_bcc=90 [2014/12/24 11:53:58.220030, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/util/util.c:559(dump_data) [0000] 73 61 6D 62 61 34 00 00 00 00 00 00 00 00 00 00 samba4.. ........ [0010] 60 48 06 06 2B 06 01 05 05 02 A0 3E 30 3C A0 0E `H..+... .. >0< . [0020] 30 0C 06 0A 2B 06 01 04 01 82 37 02 02 0A A3 2A 0...+... ..7...£* [0030] 30 28 A0 26 1B 24 6E 6F 74 5F 64 65 66 69 6E 65 0( &.$no t_define [0040] 64 5F 69 6E 5F 52 46 43 34 31 37 38 40 70 6C 65 d_in_RFC 4178@ple [0050] 61 73 65 5F 69 67 6E 6F 72 65 ase_igno re [2014/12/24 11:53:58.223544, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util_sock.c:369(read_smb_length_return_keepalive) got smb length of 156 [2014/12/24 11:53:58.223586, 6, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1877(process_smb) got message type 0x0 of len 0x9c [2014/12/24 11:53:58.223595, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1879(process_smb) Transaction 1 of length 160 (0 toread) [2014/12/24 11:53:58.223603, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:168(show_msg) [2014/12/24 11:53:58.223608, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:178(show_msg) size=156 smb_com=0x73 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=24 smb_flg2=51267 smb_tid=65535 smb_pid=6977 smb_uid=0 smb_mid=1 smt_wct=12 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]=65535 (0xFFFF) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 1 (0x1) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 74 (0x4A) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]=49236 (0xC054) smb_vwv[11]=32768 (0x8000) smb_bcc=97 [2014/12/24 11:53:58.223659, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/util/util.c:559(dump_data) [0000] 60 48 06 06 2B 06 01 05 05 02 A0 3E 30 3C A0 0E `H..+... .. >0< . [0010] 30 0C 06 0A 2B 06 01 04 01 82 37 02 02 0A A2 2A 0...+... ..7...¢* [0020] 04 28 4E 54 4C 4D 53 53 50 00 01 00 00 00 15 82 .(NTLMSS P....... [0030] 08 60 02 00 02 00 20 00 00 00 06 00 06 00 22 00 .`.... . ......". [0040] 00 00 53 34 53 41 4D 42 41 34 00 55 00 6E 00 69 ..S4SAMB A4.U.n.i [0050] 00 78 00 00 00 53 00 61 00 6D 00 62 00 61 00 00 .x...S.a .m.b.a.. [0060] 00 . [2014/12/24 11:53:58.223770, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1489(switch_message) switch message SMBsesssetupX (pid 6978) conn 0x0 [2014/12/24 11:53:58.223782, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2014/12/24 11:53:58.223791, 5, pid=6978, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2014/12/24 11:53:58.223809, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2014/12/24 11:53:58.223828, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2014/12/24 11:53:58.223842, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sesssetup.c:609(reply_sesssetup_and_X) wct=12 flg2=0xc843 [2014/12/24 11:53:58.223872, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sesssetup.c:142(reply_sesssetup_and_X_spnego) Doing spnego session setup [2014/12/24 11:53:58.223975, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sesssetup.c:183(reply_sesssetup_and_X_spnego) NativeOS=[Unix] NativeLanMan=[Samba] PrimaryDomain=[] [2014/12/24 11:53:58.224007, 5, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order) check lock order 1 for /var/lock/samba/smbXsrv_session_global.tdb [2014/12/24 11:53:58.224016, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order) lock order: 1:/var/lock/samba/smbXsrv_session_global.tdb 2: 3: [2014/12/24 11:53:58.224027, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key) Locking key 4CB91A11 [2014/12/24 11:53:58.224048, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal) Allocated locked data 0x0x7fdaeeab5170 [2014/12/24 11:53:58.224321, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:851(smbXsrv_session_global_store) [2014/12/24 11:53:58.224335, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:853(smbXsrv_session_global_store) smbXsrv_session_global_store: key '4CB91A11' stored [2014/12/24 11:53:58.224346, 1, pid=6978, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug) &global_blob: struct smbXsrv_session_globalB version : SMBXSRV_VERSION_0 (0) seqnum : 0x00000001 (1) info : union smbXsrv_session_globalU(case 0) info0 : * info0: struct smbXsrv_session_global0 db_rec : * session_global_id : 0x4cb91a11 (1287199249) session_wire_id : 0x0000000000009547 (38215) creation_time : Wed Dec 24 11:53:58 AM 2014 CET expiration_time : Thu Jan 1 01:00:00 AM 1970 CET auth_time : NTTIME(0) auth_session_info_seqnum : 0x00000000 (0) auth_session_info : NULL connection_dialect : 0x0000 (0) signing_required : 0x00 (0) encryption_required : 0x00 (0) num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000001b42 (6978) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x4fff040083677fdd (5764330448308633565) local_address : 'ipv4:127.0.0.1:445' remote_address : 'ipv4:127.0.0.1:40874' remote_name : '127.0.0.1' auth_session_info_seqnum : 0x00000000 (0) connection : * [2014/12/24 11:53:58.224545, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key) Unlocking key 4CB91A11 [2014/12/24 11:53:58.224561, 5, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor) release lock order 1 for /var/lock/samba/smbXsrv_session_global.tdb [2014/12/24 11:53:58.225209, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order) lock order: 1: 2: 3: [2014/12/24 11:53:58.225219, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1214(smbXsrv_session_create) [2014/12/24 11:53:58.225225, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1222(smbXsrv_session_create) smbXsrv_session_create: global_id (0x4cb91a11) stored [2014/12/24 11:53:58.225231, 1, pid=6978, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug) &session_blob: struct smbXsrv_sessionB version : SMBXSRV_VERSION_0 (0) reserved : 0x00000000 (0) info : union smbXsrv_sessionU(case 0) info0 : * info0: struct smbXsrv_session table : * db_rec : NULL client : * local_id : 0x00009547 (38215) global : * global: struct smbXsrv_session_global0 db_rec : NULL session_global_id : 0x4cb91a11 (1287199249) session_wire_id : 0x0000000000009547 (38215) creation_time : Wed Dec 24 11:53:58 AM 2014 CET expiration_time : Thu Jan 1 01:00:00 AM 1970 CET auth_time : NTTIME(0) auth_session_info_seqnum : 0x00000000 (0) auth_session_info : NULL connection_dialect : 0x0000 (0) signing_required : 0x00 (0) encryption_required : 0x00 (0) num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000001b42 (6978) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x4fff040083677fdd (5764330448308633565) local_address : 'ipv4:127.0.0.1:445' remote_address : 'ipv4:127.0.0.1:40874' remote_name : '127.0.0.1' auth_session_info_seqnum : 0x00000000 (0) connection : * status : NT_STATUS_MORE_PROCESSING_REQUIRED idle_time : Wed Dec 24 11:53:58 AM 2014 CET nonce_high : 0x0000000000000000 (0) nonce_low : 0x0000000000000000 (0) gensec : NULL compat : NULL tcon_table : NULL [2014/12/24 11:53:58.225422, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:484(make_auth_context_subsystem) Making default auth method list for DC [2014/12/24 11:53:58.225436, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:378(load_auth_module) load_auth_module: Attempting to find an auth method to match guest [2014/12/24 11:53:58.225457, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:403(load_auth_module) load_auth_module: auth method guest has a valid init [2014/12/24 11:53:58.225465, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:378(load_auth_module) load_auth_module: Attempting to find an auth method to match sam [2014/12/24 11:53:58.225474, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:403(load_auth_module) load_auth_module: auth method sam has a valid init [2014/12/24 11:53:58.225481, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:378(load_auth_module) load_auth_module: Attempting to find an auth method to match winbind:trustdomain [2014/12/24 11:53:58.225488, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:378(load_auth_module) load_auth_module: Attempting to find an auth method to match trustdomain [2014/12/24 11:53:58.225495, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:403(load_auth_module) load_auth_module: auth method trustdomain has a valid init [2014/12/24 11:53:58.225502, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:403(load_auth_module) load_auth_module: auth method winbind has a valid init [2014/12/24 11:53:58.225553, 5, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:664(gensec_start_mech) Starting GENSEC mechanism spnego [2014/12/24 11:53:58.225572, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2014/12/24 11:53:58.225585, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2014/12/24 11:53:58.225592, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2014/12/24 11:53:58.225599, 5, pid=6978, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2014/12/24 11:53:58.225606, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2014/12/24 11:53:58.225791, 5, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:664(gensec_start_mech) Starting GENSEC submechanism ntlmssp [2014/12/24 11:53:58.225837, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/ntlmssp/ntlmssp_util.c:34(debug_ntlmssp_flags) Got NTLMSSP neg_flags=0x60088215 NTLMSSP_NEGOTIATE_UNICODE NTLMSSP_REQUEST_TARGET NTLMSSP_NEGOTIATE_SIGN NTLMSSP_NEGOTIATE_NTLM NTLMSSP_NEGOTIATE_ALWAYS_SIGN NTLMSSP_NEGOTIATE_NTLM2 NTLMSSP_NEGOTIATE_128 NTLMSSP_NEGOTIATE_KEY_EXCH [2014/12/24 11:53:58.225980, 1, pid=6978, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug) negotiate: struct NEGOTIATE_MESSAGE Signature : 'NTLMSSP' MessageType : NtLmNegotiate (1) NegotiateFlags : 0x60088215 (1611170325) 1: NTLMSSP_NEGOTIATE_UNICODE 0: NTLMSSP_NEGOTIATE_OEM 1: NTLMSSP_REQUEST_TARGET 1: NTLMSSP_NEGOTIATE_SIGN 0: NTLMSSP_NEGOTIATE_SEAL 0: NTLMSSP_NEGOTIATE_DATAGRAM 0: NTLMSSP_NEGOTIATE_LM_KEY 0: NTLMSSP_NEGOTIATE_NETWARE 1: NTLMSSP_NEGOTIATE_NTLM 0: NTLMSSP_NEGOTIATE_NT_ONLY 0: NTLMSSP_ANONYMOUS 0: NTLMSSP_NEGOTIATE_OEM_DOMAIN_SUPPLIED 0: NTLMSSP_NEGOTIATE_OEM_WORKSTATION_SUPPLIED 0: NTLMSSP_NEGOTIATE_THIS_IS_LOCAL_CALL 1: NTLMSSP_NEGOTIATE_ALWAYS_SIGN 0: NTLMSSP_TARGET_TYPE_DOMAIN 0: NTLMSSP_TARGET_TYPE_SERVER 0: NTLMSSP_TARGET_TYPE_SHARE 1: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY 0: NTLMSSP_NEGOTIATE_IDENTIFY 0: NTLMSSP_REQUEST_NON_NT_SESSION_KEY 0: NTLMSSP_NEGOTIATE_TARGET_INFO 0: NTLMSSP_NEGOTIATE_VERSION 1: NTLMSSP_NEGOTIATE_128 1: NTLMSSP_NEGOTIATE_KEY_EXCH 0: NTLMSSP_NEGOTIATE_56 DomainNameLen : 0x0002 (2) DomainNameMaxLen : 0x0002 (2) DomainName : * DomainName : 'S4' WorkstationLen : 0x0006 (6) WorkstationMaxLen : 0x0006 (6) Workstation : * Workstation : 'SAMBA4' [2014/12/24 11:53:58.226196, 1, pid=6978, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug) challenge: struct CHALLENGE_MESSAGE Signature : 'NTLMSSP' MessageType : NtLmChallenge (0x2) TargetNameLen : 0x0004 (4) TargetNameMaxLen : 0x0004 (4) TargetName : * TargetName : 'S4' NegotiateFlags : 0x60898215 (1619624469) 1: NTLMSSP_NEGOTIATE_UNICODE 0: NTLMSSP_NEGOTIATE_OEM 1: NTLMSSP_REQUEST_TARGET 1: NTLMSSP_NEGOTIATE_SIGN 0: NTLMSSP_NEGOTIATE_SEAL 0: NTLMSSP_NEGOTIATE_DATAGRAM 0: NTLMSSP_NEGOTIATE_LM_KEY 0: NTLMSSP_NEGOTIATE_NETWARE 1: NTLMSSP_NEGOTIATE_NTLM 0: NTLMSSP_NEGOTIATE_NT_ONLY 0: NTLMSSP_ANONYMOUS 0: NTLMSSP_NEGOTIATE_OEM_DOMAIN_SUPPLIED 0: NTLMSSP_NEGOTIATE_OEM_WORKSTATION_SUPPLIED 0: NTLMSSP_NEGOTIATE_THIS_IS_LOCAL_CALL 1: NTLMSSP_NEGOTIATE_ALWAYS_SIGN 1: NTLMSSP_TARGET_TYPE_DOMAIN 0: NTLMSSP_TARGET_TYPE_SERVER 0: NTLMSSP_TARGET_TYPE_SHARE 1: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY 0: NTLMSSP_NEGOTIATE_IDENTIFY 0: NTLMSSP_REQUEST_NON_NT_SESSION_KEY 1: NTLMSSP_NEGOTIATE_TARGET_INFO 0: NTLMSSP_NEGOTIATE_VERSION 1: NTLMSSP_NEGOTIATE_128 1: NTLMSSP_NEGOTIATE_KEY_EXCH 0: NTLMSSP_NEGOTIATE_56 ServerChallenge : 9dec8f4efea524ae Reserved : 0000000000000000 TargetInfoLen : 0x0052 (82) TargetNameInfoMaxLen : 0x0052 (82) TargetInfo : * TargetInfo: struct AV_PAIR_LIST count : 0x00000005 (5) pair: ARRAY(5) pair: struct AV_PAIR AvId : MsvAvNbDomainName (0x2) AvLen : 0x0004 (4) Value : union ntlmssp_AvValue(case 0x2) AvNbDomainName : 'S4' pair: struct AV_PAIR AvId : MsvAvNbComputerName (0x1) AvLen : 0x000c (12) Value : union ntlmssp_AvValue(case 0x1) AvNbComputerName : 'SAMBA4' pair: struct AV_PAIR AvId : MsvAvDnsDomainName (0x4) AvLen : 0x0010 (16) Value : union ntlmssp_AvValue(case 0x4) AvDnsDomainName : 's4.local' pair: struct AV_PAIR AvId : MsvAvDnsComputerName (0x3) AvLen : 0x001e (30) Value : union ntlmssp_AvValue(case 0x3) AvDnsComputerName : 'samba4.s4.local' pair: struct AV_PAIR AvId : MsvAvEOL (0x0) AvLen : 0x0000 (0) Value : union ntlmssp_AvValue(case 0x0) [2014/12/24 11:53:58.226495, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2014/12/24 11:53:58.226546, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:168(show_msg) [2014/12/24 11:53:58.226554, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:178(show_msg) size=268 smb_com=0x73 smb_rcls=22 smb_reh=0 smb_err=49152 smb_flg=136 smb_flg2=51203 smb_tid=65535 smb_pid=6977 smb_uid=38215 smb_mid=1 smt_wct=4 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 165 (0xA5) smb_bcc=225 [2014/12/24 11:53:58.226584, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/util/util.c:559(dump_data) [0000] A1 81 A2 30 81 9F A0 03 0A 01 01 A1 0C 06 0A 2B ¡.¢0.. . ...¡...+ [0010] 06 01 04 01 82 37 02 02 0A A2 81 89 04 81 86 4E .....7.. .¢.....N [0020] 54 4C 4D 53 53 50 00 02 00 00 00 04 00 04 00 30 TLMSSP.. .......0 [0030] 00 00 00 15 82 89 60 9D EC 8F 4E FE A5 24 AE 00 ......`. ì.Nþ¥$®. [0040] 00 00 00 00 00 00 00 52 00 52 00 34 00 00 00 53 .......R .R.4...S [0050] 00 34 00 02 00 04 00 53 00 34 00 01 00 0C 00 53 .4.....S .4.....S [0060] 00 41 00 4D 00 42 00 41 00 34 00 04 00 10 00 73 .A.M.B.A .4.....s [0070] 00 34 00 2E 00 6C 00 6F 00 63 00 61 00 6C 00 03 .4...l.o .c.a.l.. [0080] 00 1E 00 73 00 61 00 6D 00 62 00 61 00 34 00 2E ...s.a.m .b.a.4.. [0090] 00 73 00 34 00 2E 00 6C 00 6F 00 63 00 61 00 6C .s.4...l .o.c.a.l [00A0] 00 00 00 00 00 57 00 69 00 6E 00 64 00 6F 00 77 .....W.i .n.d.o.w [00B0] 00 73 00 20 00 36 00 2E 00 31 00 00 00 53 00 61 .s. .6.. .1...S.a [00C0] 00 6D 00 62 00 61 00 20 00 34 00 2E 00 32 00 2E .m.b.a. .4...2.. [00D0] 00 30 00 72 00 63 00 33 00 00 00 53 00 34 00 00 .0.r.c.3 ...S.4.. [00E0] 00 . [2014/12/24 11:53:58.228798, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util_sock.c:369(read_smb_length_return_keepalive) got smb length of 346 [2014/12/24 11:53:58.228836, 6, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1877(process_smb) got message type 0x0 of len 0x15a [2014/12/24 11:53:58.228844, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1879(process_smb) Transaction 2 of length 350 (0 toread) [2014/12/24 11:53:58.228852, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:168(show_msg) [2014/12/24 11:53:58.228856, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:178(show_msg) size=346 smb_com=0x73 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=24 smb_flg2=51267 smb_tid=65535 smb_pid=6977 smb_uid=38215 smb_mid=2 smt_wct=12 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]=65535 (0xFFFF) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 1 (0x1) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 264 (0x108) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]=49236 (0xC054) smb_vwv[11]=32768 (0x8000) smb_bcc=287 [2014/12/24 11:53:58.228902, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/util/util.c:559(dump_data) [0000] A1 82 01 04 30 82 01 00 A2 81 FD 04 81 FA 4E 54 ¡...0... ¢.ý..úNT [0010] 4C 4D 53 53 50 00 03 00 00 00 18 00 18 00 40 00 LMSSP... ......@. [0020] 00 00 7E 00 7E 00 58 00 00 00 04 00 04 00 D6 00 ..~.~.X. ......Ö. [0030] 00 00 04 00 04 00 DA 00 00 00 0C 00 0C 00 DE 00 ......Ú. ......Þ. [0040] 00 00 10 00 10 00 EA 00 00 00 15 82 08 60 AF 5B ......ê. .....`¯[ [0050] 49 F1 A2 27 67 27 1C 97 46 0D 67 DF 3E DA 80 E0 Iñ¢'g'.. F.gß>Ú.à [0060] A1 CD 11 55 E2 D9 8B 8B 4E FB 4F 6E 13 04 EC 1F ¡Í.UâÙ.. NûOn..ì. [0070] 79 6E 28 73 C1 6D 01 01 00 00 00 00 00 00 00 27 yn(sÁm.. .......' [0080] 17 EB 67 1F D0 01 76 CE EF 0C B1 6C EE 2C 00 00 .ëg.Ð.vÎ ï.±lî,.. [0090] 00 00 02 00 04 00 53 00 34 00 01 00 0C 00 53 00 ......S. 4.....S. [00A0] 41 00 4D 00 42 00 41 00 34 00 04 00 10 00 73 00 A.M.B.A. 4.....s. [00B0] 34 00 2E 00 6C 00 6F 00 63 00 61 00 6C 00 03 00 4...l.o. c.a.l... [00C0] 1E 00 73 00 61 00 6D 00 62 00 61 00 34 00 2E 00 ..s.a.m. b.a.4... [00D0] 73 00 34 00 2E 00 6C 00 6F 00 63 00 61 00 6C 00 s.4...l. o.c.a.l. [00E0] 00 00 00 00 53 00 34 00 61 00 64 00 53 00 41 00 ....S.4. a.d.S.A. [00F0] 4D 00 42 00 41 00 34 00 1E D8 A6 0C FF B2 09 54 M.B.A.4. .ئ.ÿ².T [0100] 10 4E 78 73 94 B2 89 FD 00 55 00 6E 00 69 00 78 .Nxs.².ý .U.n.i.x [0110] 00 00 00 53 00 61 00 6D 00 62 00 61 00 00 00 ...S.a.m .b.a... [2014/12/24 11:53:58.229161, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1489(switch_message) switch message SMBsesssetupX (pid 6978) conn 0x0 [2014/12/24 11:53:58.229173, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2014/12/24 11:53:58.229181, 5, pid=6978, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2014/12/24 11:53:58.229188, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2014/12/24 11:53:58.229289, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2014/12/24 11:53:58.229299, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sesssetup.c:609(reply_sesssetup_and_X) wct=12 flg2=0xc843 [2014/12/24 11:53:58.229307, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sesssetup.c:142(reply_sesssetup_and_X_spnego) Doing spnego session setup [2014/12/24 11:53:58.229316, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sesssetup.c:183(reply_sesssetup_and_X_spnego) NativeOS=[Unix] NativeLanMan=[Samba] PrimaryDomain=[] [2014/12/24 11:53:58.229325, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2014/12/24 11:53:58.229332, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2014/12/24 11:53:58.229339, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2014/12/24 11:53:58.229346, 5, pid=6978, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2014/12/24 11:53:58.229353, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2014/12/24 11:53:58.229411, 1, pid=6978, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug) authenticate: struct AUTHENTICATE_MESSAGE Signature : 'NTLMSSP' MessageType : NtLmAuthenticate (3) LmChallengeResponseLen : 0x0018 (24) LmChallengeResponseMaxLen: 0x0018 (24) LmChallengeResponse : * LmChallengeResponse : union ntlmssp_LM_RESPONSE(case 24) v1: struct LM_RESPONSE Response : af5b49f1a22767271c97460d67df3eda80e0a1cd1155e2d9 NtChallengeResponseLen : 0x007e (126) NtChallengeResponseMaxLen: 0x007e (126) NtChallengeResponse : * NtChallengeResponse : union ntlmssp_NTLM_RESPONSE(case 126) v2: struct NTLMv2_RESPONSE Response : 8b8b4efb4f6e1304ec1f796e2873c16d Challenge: struct NTLMv2_CLIENT_CHALLENGE RespType : 0x01 (1) HiRespType : 0x01 (1) Reserved1 : 0x0000 (0) Reserved2 : 0x00000000 (0) TimeStamp : Wed Dec 24 11:53:58 AM 2014 CET ChallengeFromClient : 76ceef0cb16cee2c Reserved3 : 0x00000000 (0) AvPairs: struct AV_PAIR_LIST count : 0x00000005 (5) pair: ARRAY(5) pair: struct AV_PAIR AvId : MsvAvNbDomainName (0x2) AvLen : 0x0004 (4) Value : union ntlmssp_AvValue(case 0x2) AvNbDomainName : 'S4' pair: struct AV_PAIR AvId : MsvAvNbComputerName (0x1) AvLen : 0x000c (12) Value : union ntlmssp_AvValue(case 0x1) AvNbComputerName : 'SAMBA4' pair: struct AV_PAIR AvId : MsvAvDnsDomainName (0x4) AvLen : 0x0010 (16) Value : union ntlmssp_AvValue(case 0x4) AvDnsDomainName : 's4.local' pair: struct AV_PAIR AvId : MsvAvDnsComputerName (0x3) AvLen : 0x001e (30) Value : union ntlmssp_AvValue(case 0x3) AvDnsComputerName : 'samba4.s4.local' pair: struct AV_PAIR AvId : MsvAvEOL (0x0) AvLen : 0x0000 (0) Value : union ntlmssp_AvValue(case 0x0) DomainNameLen : 0x0004 (4) DomainNameMaxLen : 0x0004 (4) DomainName : * DomainName : 'S4' UserNameLen : 0x0004 (4) UserNameMaxLen : 0x0004 (4) UserName : * UserName : 'ad' WorkstationLen : 0x000c (12) WorkstationMaxLen : 0x000c (12) Workstation : * Workstation : 'SAMBA4' EncryptedRandomSessionKeyLen: 0x0010 (16) EncryptedRandomSessionKeyMaxLen: 0x0010 (16) EncryptedRandomSessionKey: * EncryptedRandomSessionKey: DATA_BLOB length=16 [0000] 1E D8 A6 0C FF B2 09 54 10 4E 78 73 94 B2 89 FD .ئ.ÿ².T .Nxs.².ý NegotiateFlags : 0x60088215 (1611170325) 1: NTLMSSP_NEGOTIATE_UNICODE 0: NTLMSSP_NEGOTIATE_OEM 1: NTLMSSP_REQUEST_TARGET 1: NTLMSSP_NEGOTIATE_SIGN 0: NTLMSSP_NEGOTIATE_SEAL 0: NTLMSSP_NEGOTIATE_DATAGRAM 0: NTLMSSP_NEGOTIATE_LM_KEY 0: NTLMSSP_NEGOTIATE_NETWARE 1: NTLMSSP_NEGOTIATE_NTLM 0: NTLMSSP_NEGOTIATE_NT_ONLY 0: NTLMSSP_ANONYMOUS 0: NTLMSSP_NEGOTIATE_OEM_DOMAIN_SUPPLIED 0: NTLMSSP_NEGOTIATE_OEM_WORKSTATION_SUPPLIED 0: NTLMSSP_NEGOTIATE_THIS_IS_LOCAL_CALL 1: NTLMSSP_NEGOTIATE_ALWAYS_SIGN 0: NTLMSSP_TARGET_TYPE_DOMAIN 0: NTLMSSP_TARGET_TYPE_SERVER 0: NTLMSSP_TARGET_TYPE_SHARE 1: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY 0: NTLMSSP_NEGOTIATE_IDENTIFY 0: NTLMSSP_REQUEST_NON_NT_SESSION_KEY 0: NTLMSSP_NEGOTIATE_TARGET_INFO 0: NTLMSSP_NEGOTIATE_VERSION 1: NTLMSSP_NEGOTIATE_128 1: NTLMSSP_NEGOTIATE_KEY_EXCH 0: NTLMSSP_NEGOTIATE_56 [2014/12/24 11:53:58.229761, 3, pid=6978, effective(0, 0), real(0, 0)] ../auth/ntlmssp/ntlmssp_server.c:359(ntlmssp_server_preauth) Got user=[ad] domain=[S4] workstation=[SAMBA4] len1=24 len2=126 [2014/12/24 11:53:58.229800, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3647(lp_load_ex) lp_load_ex: refreshing parameters [2014/12/24 11:53:58.229811, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1234(free_param_opts) Freeing parametrics: [2014/12/24 11:53:58.229866, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:564(init_globals) Initialising global parameters [2014/12/24 11:53:58.229883, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:353(max_open_files) rlimit_max: increasing rlimit_max (4040) to minimum Windows limit (16384) [2014/12/24 11:53:58.229957, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2597(lp_do_section) Processing section "[global]" doing parameter workgroup = S4 doing parameter netbios name = SAMBA4 doing parameter server string = samba4 doing parameter interfaces = 192.168.173.1/24 127.255.255.255/8 doing parameter bind interfaces only = Yes doing parameter hosts allow = 192.168.0.0/255.255.0.0 127.0.0.1 doing parameter max protocol = SMB2 doing parameter encrypt passwords = Yes doing parameter passwd program = /usr/local/webmanager/bin/samba_passwd_change.sh '%u' doing parameter passwd chat = *password* %n\n *changed* doing parameter passwd chat timeout = 3 doing parameter check password script = /usr/lib/samba/passcheck/passcheck.pl doing parameter username map = /etc/samba/smbusers doing parameter unix password sync = Yes doing parameter log level = 10 [2014/12/24 11:53:58.230041, 5, pid=6978, effective(0, 0), real(0, 0)] ../lib/util/debug.c:334(debug_dump_status) INFO: Current debug levels: all: 10 tdb: 10 printdrivers: 10 lanman: 10 smb: 10 rpc_parse: 10 rpc_srv: 10 rpc_cli: 10 passdb: 10 sam: 10 auth: 10 winbind: 10 vfs: 10 idmap: 10 quota: 10 acls: 10 locking: 10 msdfs: 10 dmapi: 10 registry: 10 scavenger: 10 dns: 10 ldb: 10 doing parameter log file = /var/log/samba/samba.log.%m doing parameter max log size = 1500 doing parameter max open files = 4000 doing parameter syslog = No doing parameter lanman auth = No doing parameter client lanman auth = No doing parameter client NTLMv2 auth = Yes doing parameter domain logons = Yes doing parameter logon script = %U.bat doing parameter logon path = doing parameter logon drive = H: doing parameter logon home = doing parameter add machine script = /usr/local/webmanager/bin/samba_2k.sh '%m' doing parameter os level = 254 doing parameter preferred master = Yes doing parameter domain master = Yes doing parameter local master = Yes doing parameter wins support = Yes doing parameter time server = Yes doing parameter name resolve order = host wins bcast doing parameter passdb backend = ldapsam:ldap://localhost doing parameter ldap suffix = dc=s4,dc=local doing parameter ldap machine suffix = ou=Computers doing parameter ldap user suffix = ou=Users doing parameter ldap group suffix = ou=Groups doing parameter ldap idmap suffix = ou=Idmap doing parameter ldap admin dn = cn=admin,dc=s4,dc=local doing parameter ldap ssl = No doing parameter idmap config * : backend = tdb doing parameter idmap config * : range = 1000000-1999999 doing parameter idmap config S4 : backend = rid doing parameter idmap config S4 : range = 10000-20000 doing parameter idmap config S4 : base_rid = 0 doing parameter printing = cups doing parameter min print space = 1000 doing parameter create mask = 0660 doing parameter force create mode = 0660 doing parameter directory mask = 0770 doing parameter force directory mode = 0770 doing parameter oplocks = Yes doing parameter veto oplock files = /*.mdb/*.MDB/*.mde/*.MDE/*.dbf/*.DBF/*.lck/*.LCK/*.cnv/*.CNV/*.stm/*.STM/*.dat/*.DAT/*.tbm/*.TBM/*.loc/*.LOC/*.fbk/*.FBK/*.fdb/*.FDB/*.spd/*.SPD/*.adb/*.ADB/*.adx/*.ADX/*.blb/*.BLB/*.ddb/*.DDB/*.ddf/*.DDF/*.ddx/*.DDX/*.edb/*.EDB/*.edx/*.EDX/*.gdb/*.GDB/*.gdx/*.GDX/*.hdb/*.HDB/*.hdx/*.HDX/*.hk4/*.HK4/*.mdx/*.MDX/*.rel/*.REL/*.rem/*.REM/*.rex/*.REX/*.sdb/*.SDB/*.sdx/*.SDX/*.tdb/*.TDB/*.tdx/*.TDX/*.fmt/*.FMT/*.bom/*.BOM/*.dbc/*.DBC/*.dbk/*.DBK/*.dpc/*.DPC/*.dra/*.DRA/*.drc/*.DRC/*.drt/*.DRT/*.dsn/*.DSN/*.lib/*.LIB/*.max/*.MAX/*.mnl/*.MNL/*.net/*.NET/*.obk/*.OBK/*.olb/*.OLB/*.opj/*.OPJ/*.sch/*.SCH/*.nsx/*.NSX/*.ndx/*.NDX/*.dbx/*.DBX/*.dbt/*.DBT/*.fpt/*.FPT/*.cdx/*.CDX/*.dwf/*.DWF/*.dwg/*.DWG/*.rvt/*.RVT/*.lock/ doing parameter level2 oplocks = No doing parameter unix extensions = No doing parameter wide links = Yes doing parameter include = /etc/samba/smb.conf.arch.%a [2014/12/24 11:53:58.230549, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2597(lp_do_section) Processing section "[global]" doing parameter create mask = 777 doing parameter force create mode = 000 doing parameter include = /usr/local/webmanager/var/etc/smb.conf.include [2014/12/24 11:53:58.230610, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[extranet]" doing parameter comment = doing parameter create mask = 0664 doing parameter directory mask = 0775 doing parameter force create mode = 0664 doing parameter force directory mode = 0775 doing parameter force group = www doing parameter path = /home/vol1/shares/extranet doing parameter readlist = doing parameter validusers = user1a ad doing parameter writelist = ad [2014/12/24 11:53:58.230684, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[intranet]" doing parameter comment = intranet doing parameter create mask = 0664 doing parameter directory mask = 0775 doing parameter force create mode = 0664 doing parameter force directory mode = 0775 doing parameter force group = www doing parameter path = /home/vol1/shares/intranet doing parameter readlist = doing parameter validusers = user1a ad doing parameter writelist = ad doing parameter include = /usr/local/webmanager/var/etc/archives.smb.conf.include [2014/12/24 11:53:58.230776, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2276(lp_include) Can't find include file /usr/local/webmanager/var/etc/archives.smb.conf.include doing parameter include = /usr/local/webmanager/var/etc/vmmedia.smb.conf.include [2014/12/24 11:53:58.230803, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2276(lp_include) Can't find include file /usr/local/webmanager/var/etc/vmmedia.smb.conf.include doing parameter include = /usr/local/webmanager/var/etc/vmhomes.smb.conf.include [2014/12/24 11:53:58.230826, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2276(lp_include) Can't find include file /usr/local/webmanager/var/etc/vmhomes.smb.conf.include [2014/12/24 11:53:58.230834, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[IPC$]" doing parameter admin users = @Administrators, user1a doing parameter path = /var/empty [2014/12/24 11:53:58.230856, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[homes]" doing parameter read only = No doing parameter browseable = No doing parameter invalid users = root doing parameter valid users = %S doing parameter force user = %S doing parameter create mask = 0601 doing parameter force create mode = 0600 doing parameter directory mask = 0700 doing parameter force directory mode = 0700 doing parameter map hidden = Yes doing parameter csc policy = disable [2014/12/24 11:53:58.230951, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[profile]" doing parameter path = /home/users/%U/.profileNT doing parameter read only = No doing parameter browseable = No doing parameter invalid users = root doing parameter create mask = 0645 doing parameter force create mode = 0644 doing parameter map hidden = Yes doing parameter csc policy = disable [2014/12/24 11:53:58.231022, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[netlogon]" doing parameter path = /usr/local/webmanager/var/etc/smb_netlogon/ doing parameter read only = Yes doing parameter browseable = No doing parameter invalid users = user1a doing parameter write list = @Administrators doing parameter locking = no [2014/12/24 11:53:58.231076, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[printers]" doing parameter comment = All Printers doing parameter path = /var/spool/print/tmp doing parameter create mask = 0700 doing parameter guest ok = Yes doing parameter printable = Yes doing parameter printing = cups doing parameter use client driver = No doing parameter min print space = 2000 [2014/12/24 11:53:58.231145, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[print$]" doing parameter comment = Printer Drivers doing parameter path = /var/spool/samba/drivers doing parameter guest ok = Yes doing parameter browsable = yes doing parameter readonly = yes doing parameter write list = root,@Administrators [2014/12/24 11:53:58.231201, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[pdf]" doing parameter comment = PDF printer doing parameter path = /var/spool/print/tmp doing parameter read only = No doing parameter create mask = 0700 doing parameter print ok = yes doing parameter browseable = Yes doing parameter printing = BSD doing parameter print command = /usr/local/bin/printpdf %s %U doing parameter lpq command = doing parameter lprm command = doing parameter lppause command = doing parameter lpresume command = doing parameter queuepause command = doing parameter queueresume command = doing parameter include = /etc/samba/smb.conf.local [2014/12/24 11:53:58.231341, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2276(lp_include) Can't find include file /etc/samba/smb.conf.local [2014/12/24 11:53:58.231356, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3688(lp_load_ex) pm_process() returned Yes [2014/12/24 11:53:58.231377, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1495(lp_add_ipc) adding IPC service [2014/12/24 11:53:58.231403, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/user_util.c:362(map_username) Scanning username map /etc/samba/smbusers [2014/12/24 11:53:58.231422, 8, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/user_util.c:435(map_username) The user 'ad' has no mapping. Skip it next time. [2014/12/24 11:53:58.231431, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_util.c:116(make_user_info_map) Mapping user [S4]\[ad] from workstation [SAMBA4] [2014/12/24 11:53:58.231471, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/user_info.c:62(make_user_info) attempting to make a user_info for ad (ad) [2014/12/24 11:53:58.231482, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/user_info.c:70(make_user_info) making strings for ad's user_info struct [2014/12/24 11:53:58.231501, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/user_info.c:108(make_user_info) making blobs for ad's user_info struct [2014/12/24 11:53:58.231509, 10, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/user_info.c:159(make_user_info) made a user_info for ad (ad) [2014/12/24 11:53:58.231519, 3, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:178(auth_check_ntlm_password) check_ntlm_password: Checking password for unmapped user [S4]\[ad]@[SAMBA4] with the new password interface [2014/12/24 11:53:58.231527, 3, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:181(auth_check_ntlm_password) check_ntlm_password: mapped user is: [S4]\[ad]@[SAMBA4] [2014/12/24 11:53:58.231535, 10, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:190(auth_check_ntlm_password) check_ntlm_password: auth_context challenge created by random [2014/12/24 11:53:58.231541, 10, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:192(auth_check_ntlm_password) challenge is: [2014/12/24 11:53:58.231549, 5, pid=6978, effective(0, 0), real(0, 0)] ../lib/util/util.c:559(dump_data) [0000] 9D EC 8F 4E FE A5 24 AE .ì.Nþ¥$® [2014/12/24 11:53:58.231570, 10, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_builtin.c:44(check_guest_security) Check auth for: [ad] [2014/12/24 11:53:58.231577, 10, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:233(auth_check_ntlm_password) check_ntlm_password: guest had nothing to say [2014/12/24 11:53:58.231585, 10, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_sam.c:75(auth_samstrict_auth) Check auth for: [ad] [2014/12/24 11:53:58.231596, 8, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:1203(is_myname) is_myname("S4") returns 0 [2014/12/24 11:53:58.231620, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2014/12/24 11:53:58.231628, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2014/12/24 11:53:58.231635, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2014/12/24 11:53:58.231642, 5, pid=6978, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2014/12/24 11:53:58.231649, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2014/12/24 11:53:58.231742, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:1249(smbldap_search_ext) smbldap_search_ext: base => [dc=s4,dc=local], filter => [(&(uid=ad)(objectclass=sambaSamAccount))], scope => [2] [2014/12/24 11:53:58.232024, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:1114(smbldap_close) The connection to the LDAP server was closed [2014/12/24 11:53:58.232049, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:595(smb_ldap_setup_conn) smb_ldap_setup_connection: ldap://localhost [2014/12/24 11:53:58.232106, 2, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:794(smbldap_open_connection) smbldap_open_connection: connection opened [2014/12/24 11:53:58.232121, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:954(smbldap_connect_system) ldap_connect_system: Binding to ldap server ldap://localhost as "cn=admin,dc=s4,dc=local" [2014/12/24 11:53:58.232571, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:1013(smbldap_connect_system) ldap_connect_system: successful connection to the LDAP server ldap_connect_system: LDAP server does support paged results [2014/12/24 11:53:58.232599, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:1092(smbldap_open) The LDAP server is successfully connected [2014/12/24 11:53:58.232917, 2, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_ldap.c:524(init_sam_from_ldap) init_sam_from_ldap: Entry found for user: ad [2014/12/24 11:53:58.232940, 10, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:570(pdb_set_username) pdb_set_username: setting username ad, was [2014/12/24 11:53:58.232960, 10, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:593(pdb_set_domain) pdb_set_domain: setting domain S4, was [2014/12/24 11:53:58.232971, 10, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:616(pdb_set_nt_username) pdb_set_nt_username: setting nt username ad, was [2014/12/24 11:53:58.232986, 10, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:508(pdb_set_user_sid_from_string) pdb_set_user_sid_from_string: setting user sid S-1-5-21-2548845908-4195694745-2934221645-1002 [2014/12/24 11:53:58.233002, 10, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:495(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-2548845908-4195694745-2934221645-1002 [2014/12/24 11:53:58.233052, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:90(smbldap_talloc_single_attribute) attribute displayName does not exist [2014/12/24 11:53:58.233065, 10, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:639(pdb_set_fullname) pdb_set_full_name: setting full name Ad Min, was [2014/12/24 11:53:58.233077, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:90(smbldap_talloc_single_attribute) attribute sambaHomeDrive does not exist [2014/12/24 11:53:58.233092, 10, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:708(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive H:, was NULL [2014/12/24 11:53:58.233122, 10, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:732(pdb_set_homedir) pdb_set_homedir: setting home dir \\SAMBA4\ad, was [2014/12/24 11:53:58.233134, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:90(smbldap_talloc_single_attribute) attribute sambaLogonScript does not exist [2014/12/24 11:53:58.233158, 10, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:662(pdb_set_logon_script) pdb_set_logon_script: setting logon script ad.bat, was [2014/12/24 11:53:58.233174, 10, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:685(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\SAMBA4\ad\.profileNT, was [2014/12/24 11:53:58.233185, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:90(smbldap_talloc_single_attribute) attribute description does not exist [2014/12/24 11:53:58.233196, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:90(smbldap_talloc_single_attribute) attribute sambaUserWorkstations does not exist [2014/12/24 11:53:58.233206, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:90(smbldap_talloc_single_attribute) attribute sambaMungedDial does not exist [2014/12/24 11:53:58.233243, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 3 [2014/12/24 11:53:58.233253, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 2 [2014/12/24 11:53:58.233260, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 3 [2014/12/24 11:53:58.233267, 5, pid=6978, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2014/12/24 11:53:58.233274, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2014/12/24 11:53:58.233355, 10, pid=6978, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:299(gencache_set_data_blob) Adding cache entry with key=[ACCT_POL/password history] and timeout=[Thu Jan 1 01:00:00 AM 1970 CET] (-1419418438 seconds in the past) [2014/12/24 11:53:58.273657, 10, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_ldap.c:3877(ldapsam_get_account_policy_from_ldap) ldapsam_get_account_policy_from_ldap [2014/12/24 11:53:58.273720, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:1249(smbldap_search_ext) smbldap_search_ext: base => [sambaDomainName=S4,dc=s4,dc=local], filter => [(objectClass=sambaDomain)], scope => [0] [2014/12/24 11:53:58.274335, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:425(cache_account_policy_set) cache_account_policy_set: updating account pol cache [2014/12/24 11:53:58.274427, 10, pid=6978, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:299(gencache_set_data_blob) Adding cache entry with key=[ACCT_POL/password history] and timeout=[Wed Dec 24 11:54:58 AM 2014 CET] (60 seconds ahead) [2014/12/24 11:53:58.274513, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 2 [2014/12/24 11:53:58.274595, 10, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:56(smbldap_get_single_attribute) smbldap_get_single_attribute: [sambaPasswordHistory] = [] [2014/12/24 11:53:58.274624, 0, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:881(pdb_set_pw_history) pdb_set_pw_history: data_blob_talloc() failed! [2014/12/24 11:53:58.274646, 1, pid=6978, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_ldap.c:1508(ldapsam_getsampwnam) ldapsam_getsampwnam: init_sam_from_ldap failed for user 'ad'! [2014/12/24 11:53:58.274673, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2014/12/24 11:53:58.274694, 3, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/check_samsec.c:400(check_sam_security) check_sam_security: Couldn't find user 'ad' in passdb. [2014/12/24 11:53:58.274717, 5, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:252(auth_check_ntlm_password) check_ntlm_password: sam authentication for user [ad] FAILED with error NT_STATUS_NO_SUCH_USER [2014/12/24 11:53:58.274751, 10, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_winbind.c:50(check_winbind_security) Check auth for: [ad] [2014/12/24 11:53:58.274773, 3, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_winbind.c:60(check_winbind_security) check_winbind_security: Not using winbind, requested domain [S4] was for this SAM. [2014/12/24 11:53:58.274791, 10, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:233(auth_check_ntlm_password) check_ntlm_password: winbind had nothing to say [2014/12/24 11:53:58.274808, 2, pid=6978, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:315(auth_check_ntlm_password) check_ntlm_password: Authentication for user [ad] -> [ad] FAILED with error NT_STATUS_NO_SUCH_USER [2014/12/24 11:53:58.274826, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/auth_ntlmssp.c:188(auth3_check_password) Checking NTLMSSP password for S4\ad failed: NT_STATUS_NO_SUCH_USER [2014/12/24 11:53:58.274860, 5, pid=6978, effective(0, 0), real(0, 0)] ../auth/ntlmssp/ntlmssp_server.c:455(ntlmssp_server_check_password) ../auth/ntlmssp/ntlmssp_server.c:455: Checking NTLMSSP password for S4\ad failed: NT_STATUS_NO_SUCH_USER [2014/12/24 11:53:58.274889, 2, pid=6978, effective(0, 0), real(0, 0)] ../auth/gensec/spnego.c:746(gensec_spnego_server_negTokenTarg) SPNEGO login failed: NT_STATUS_NO_SUCH_USER [2014/12/24 11:53:58.274945, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2014/12/24 11:53:58.274972, 5, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order) check lock order 1 for /var/lock/samba/smbXsrv_session_global.tdb [2014/12/24 11:53:58.274990, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order) lock order: 1:/var/lock/samba/smbXsrv_session_global.tdb 2: 3: [2014/12/24 11:53:58.275013, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key) Locking key 4CB91A11 [2014/12/24 11:53:58.275038, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal) Allocated locked data 0x0x7fdaeea62c30 [2014/12/24 11:53:58.275177, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key) Unlocking key 4CB91A11 [2014/12/24 11:53:58.275202, 5, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor) release lock order 1 for /var/lock/samba/smbXsrv_session_global.tdb [2014/12/24 11:53:58.275220, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order) lock order: 1: 2: 3: [2014/12/24 11:53:58.275271, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/error.c:82(error_packet_set) NT error packet at ../source3/smbd/sesssetup.c(267) cmd=115 (SMBsesssetupX) NT_STATUS_LOGON_FAILURE [2014/12/24 11:53:58.275302, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:168(show_msg) [2014/12/24 11:53:58.275314, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:178(show_msg) size=35 smb_com=0x73 smb_rcls=109 smb_reh=0 smb_err=49152 smb_flg=136 smb_flg2=51203 smb_tid=65535 smb_pid=6977 smb_uid=38215 smb_mid=2 smt_wct=0 smb_bcc=0 [2014/12/24 11:53:58.275366, 10, pid=6978, effective(0, 0), real(0, 0)] ../lib/util/util.c:559(dump_data) [2014/12/24 11:53:58.278150, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/lib/util_sock.c:132(read_fd_with_timeout) read_fd_with_timeout: blocking read. EOF from client. [2014/12/24 11:53:58.278199, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:553(receive_smb_talloc) receive_smb_raw_talloc failed for client ipv4:127.0.0.1:40874 read error = NT_STATUS_END_OF_FILE. [2014/12/24 11:53:58.278252, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2014/12/24 11:53:58.278479, 5, pid=6978, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2014/12/24 11:53:58.278500, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2014/12/24 11:53:58.278531, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2014/12/24 11:53:58.278551, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2014/12/24 11:53:58.278568, 5, pid=6978, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2014/12/24 11:53:58.278582, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2014/12/24 11:53:58.278606, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2014/12/24 11:53:58.278636, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2014/12/24 11:53:58.278672, 5, pid=6978, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2014/12/24 11:53:58.278688, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2014/12/24 11:53:58.278711, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2014/12/24 11:53:58.278758, 4, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2014/12/24 11:53:58.278776, 5, pid=6978, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2014/12/24 11:53:58.278791, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2014/12/24 11:53:58.278813, 5, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2014/12/24 11:53:58.279079, 3, pid=6978, effective(0, 0), real(0, 0)] ../source3/smbd/server_exit.c:246(exit_server_common) Server exit (failed to receive smb request)