[global] workgroup = GVCC.NET realm = GVCC.NET password server = pagh.klingons.gvcc.net kerberos method = system keytab client use spnego = yes domain logons = yes os level = 65 log level = 10 time server = yes printcap name = cups passdb backend = ldapsam:ldap://localhost/ ldapsam:trusted = yes ldapsam:editposix = yes ldap admin dn = cn=admin,dc=gvcc,dc=net ldap suffix = cn=accounts,dc=gvcc,dc=net ldap ssl = no guest ok = yes read only = No case sensitive = no create mode = 0770 directory mask = 0750 directory security mask = 0770 #force directory mode = 2000 inherit acls = no unix charset = utf8 display charset = utf8 acl group control = yes hide unreadable = yes unix extensions = yes [sys] path=/samba/sys readonly=no ======================================= [2012/01/04 16:04:20.370294, 5] lib/util_sock.c:304(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 = 50748 SO_RCVBUF = 87584 SO_SNDLOWAT = 1 SO_RCVLOWAT = 1 SO_SNDTIMEO = 0 SO_RCVTIMEO = 0 TCP_QUICKACK = 1 [2012/01/04 16:04:20.371099, 5] lib/util_sock.c:304(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 = 50748 SO_RCVBUF = 87584 SO_SNDLOWAT = 1 SO_RCVLOWAT = 1 SO_SNDTIMEO = 0 SO_RCVTIMEO = 0 TCP_QUICKACK = 1 [2012/01/04 16:04:20.372556, 6] param/loadparm.c:7132(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Jan 4 16:02:48 2012 [2012/01/04 16:04:20.373356, 3] smbd/oplock.c:894(init_oplocks) init_oplocks: initializing messages. [2012/01/04 16:04:20.373807, 3] smbd/oplock_linux.c:224(linux_init_kernel_oplocks) Linux kernel oplocks enabled [2012/01/04 16:04:20.373875, 5] lib/messages.c:329(messaging_deregister) Deregistering messaging pointer for type 1 - private_data=(nil) [2012/01/04 16:04:20.373979, 10] smbd/process.c:740(event_add_idle) event_add_idle: idle_evt(keepalive) 0x7fa55faa1650 [2012/01/04 16:04:20.374064, 10] smbd/process.c:740(event_add_idle) event_add_idle: idle_evt(deadtime) 0x7fa55fb08950 [2012/01/04 16:04:20.374134, 10] smbd/process.c:740(event_add_idle) event_add_idle: idle_evt(housekeeping) 0x7fa55faff570 [2012/01/04 16:04:20.375426, 5] lib/util_sock.c:462(read_fd_with_timeout) read_fd_with_timeout: blocking read. EOF from client. [2012/01/04 16:04:20.375549, 10] smbd/process.c:286(receive_smb_raw_talloc) receive_smb_raw: NT_STATUS_END_OF_FILE [2012/01/04 16:04:20.375681, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.375772, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.375858, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.375988, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.376107, 3] smbd/connection.c:31(yield_connection) Yielding connection to [2012/01/04 16:04:20.376313, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key DA220000FFFFFFFF0000 [2012/01/04 16:04:20.376443, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x7fa55fb172f0 [2012/01/04 16:04:20.376510, 3] smbd/connection.c:42(yield_connection) deleting connection record returned NT_STATUS_NOT_FOUND [2012/01/04 16:04:20.376583, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key DA220000FFFFFFFF0000 [2012/01/04 16:04:20.376923, 3] smbd/server.c:902(exit_server_common) Server exit (failed to receive smb request) [2012/01/04 16:04:20.388768, 5] lib/util_sock.c:304(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 = 50748 SO_RCVBUF = 87584 SO_SNDLOWAT = 1 SO_RCVLOWAT = 1 SO_SNDTIMEO = 0 SO_RCVTIMEO = 0 TCP_QUICKACK = 1 [2012/01/04 16:04:20.389527, 5] lib/util_sock.c:304(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 = 50748 SO_RCVBUF = 87584 SO_SNDLOWAT = 1 SO_RCVLOWAT = 1 SO_SNDTIMEO = 0 SO_RCVTIMEO = 0 TCP_QUICKACK = 1 [2012/01/04 16:04:20.390714, 6] param/loadparm.c:7132(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Jan 4 16:02:48 2012 [2012/01/04 16:04:20.391574, 3] smbd/oplock.c:894(init_oplocks) init_oplocks: initializing messages. [2012/01/04 16:04:20.391972, 3] smbd/oplock_linux.c:224(linux_init_kernel_oplocks) Linux kernel oplocks enabled [2012/01/04 16:04:20.392040, 5] lib/messages.c:329(messaging_deregister) Deregistering messaging pointer for type 1 - private_data=(nil) [2012/01/04 16:04:20.392143, 10] smbd/process.c:740(event_add_idle) event_add_idle: idle_evt(keepalive) 0x7fa55faa1650 [2012/01/04 16:04:20.392244, 10] smbd/process.c:740(event_add_idle) event_add_idle: idle_evt(deadtime) 0x7fa55fb08950 [2012/01/04 16:04:20.392314, 10] smbd/process.c:740(event_add_idle) event_add_idle: idle_evt(housekeeping) 0x7fa55faff570 [2012/01/04 16:04:20.392558, 10] lib/util_sock.c:726(read_smb_length_return_keepalive) got smb length of 68 [2012/01/04 16:04:20.392642, 6] smbd/process.c:1482(process_smb) got message type 0x81 of len 0x44 [2012/01/04 16:04:20.392692, 3] smbd/process.c:1485(process_smb) Transaction 0 of length 72 (0 toread) [2012/01/04 16:04:20.392793, 2] smbd/reply.c:536(reply_special) netbios connect: name1=PAGH.KLINGONS.G0x20 name2=PAGH 0x0 [2012/01/04 16:04:20.392953, 2] smbd/reply.c:547(reply_special) netbios connect: local=pagh.klingons.g remote=pagh, name type = 0 [2012/01/04 16:04:20.393016, 6] param/loadparm.c:7132(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Jan 4 16:02:48 2012 [2012/01/04 16:04:20.393105, 5] smbd/reply.c:587(reply_special) init msg_type=0x81 msg_flags=0x0 [2012/01/04 16:04:20.394391, 10] lib/util_sock.c:726(read_smb_length_return_keepalive) got smb length of 190 [2012/01/04 16:04:20.394497, 6] smbd/process.c:1482(process_smb) got message type 0x0 of len 0xbe [2012/01/04 16:04:20.394549, 3] smbd/process.c:1485(process_smb) Transaction 0 of length 194 (0 toread) [2012/01/04 16:04:20.394625, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.394666, 5] lib/util.c:627(show_msg) size=190 smb_com=0x72 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=8 smb_flg2=51201 smb_tid=0 smb_pid=8921 smb_uid=0 smb_mid=2 smt_wct=0 smb_bcc=155 [2012/01/04 16:04:20.394799, 10] ../lib/util/util.c:278(_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. [2012/01/04 16:04:20.395197, 3] smbd/process.c:1294(switch_message) switch message SMBnegprot (pid 8923) conn 0x0 [2012/01/04 16:04:20.395275, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.395362, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.395435, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.395600, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.395986, 3] smbd/negprot.c:586(reply_negprot) Requested protocol [PC NETWORK PROGRAM 1.0] [2012/01/04 16:04:20.396086, 3] smbd/negprot.c:586(reply_negprot) Requested protocol [MICROSOFT NETWORKS 1.03] [2012/01/04 16:04:20.396138, 3] smbd/negprot.c:586(reply_negprot) Requested protocol [MICROSOFT NETWORKS 3.0] [2012/01/04 16:04:20.396207, 3] smbd/negprot.c:586(reply_negprot) Requested protocol [LANMAN1.0] [2012/01/04 16:04:20.396278, 3] smbd/negprot.c:586(reply_negprot) Requested protocol [LM1.2X002] [2012/01/04 16:04:20.396327, 3] smbd/negprot.c:586(reply_negprot) Requested protocol [DOS LANMAN2.1] [2012/01/04 16:04:20.396377, 3] smbd/negprot.c:586(reply_negprot) Requested protocol [LANMAN2.1] [2012/01/04 16:04:20.396427, 3] smbd/negprot.c:586(reply_negprot) Requested protocol [Samba] [2012/01/04 16:04:20.396476, 3] smbd/negprot.c:586(reply_negprot) Requested protocol [NT LANMAN 1.0] [2012/01/04 16:04:20.396526, 3] smbd/negprot.c:586(reply_negprot) Requested protocol [NT LM 0.12] [2012/01/04 16:04:20.396592, 10] lib/util.c:1969(set_remote_arch) set_remote_arch: Client arch is 'Samba' [2012/01/04 16:04:20.396668, 6] param/loadparm.c:7132(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Jan 4 16:02:48 2012 [2012/01/04 16:04:20.396772, 5] smbd/connection.c:142(claim_connection) claiming [] [2012/01/04 16:04:20.396941, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key DB220000FFFFFFFF0000 [2012/01/04 16:04:20.397057, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x7fa55fb352a0 [2012/01/04 16:04:20.397242, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key DB220000FFFFFFFF0000 [2012/01/04 16:04:20.397418, 6] param/loadparm.c:7132(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Jan 4 16:02:48 2012 [2012/01/04 16:04:20.398210, 10] lib/util.c:2598(name_to_fqdn) name_to_fqdn: lookup for PAGH -> pagh.klingons.gvcc.net. [2012/01/04 16:04:20.398480, 3] smbd/negprot.c:404(reply_nt1) using SPNEGO [2012/01/04 16:04:20.398533, 3] smbd/negprot.c:691(reply_negprot) Selected protocol NT LANMAN 1.0 [2012/01/04 16:04:20.398582, 5] smbd/negprot.c:698(reply_negprot) negprot index=8 [2012/01/04 16:04:20.398635, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.398674, 5] lib/util.c:627(show_msg) size=181 smb_com=0x72 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51201 smb_tid=0 smb_pid=8921 smb_uid=0 smb_mid=2 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]=56064 (0xDB00) smb_vwv[ 8]= 34 (0x22) smb_vwv[ 9]=64768 (0xFD00) smb_vwv[10]=33011 (0x80F3) smb_vwv[11]= 128 (0x80) smb_vwv[12]=46002 (0xB3B2) smb_vwv[13]=61986 (0xF222) smb_vwv[14]=52426 (0xCCCA) smb_vwv[15]=50177 (0xC401) smb_vwv[16]= 255 (0xFF) smb_bcc=112 [2012/01/04 16:04:20.398951, 10] ../lib/util/util.c:278(_dump_data) [0000] 70 61 67 68 00 00 00 00 00 00 00 00 00 00 00 00 pagh.... ........ [0010] 60 5E 06 06 2B 06 01 05 05 02 A0 54 30 52 A0 24 `^..+... ...T0R.$ [0020] 30 22 06 09 2A 86 48 86 F7 12 01 02 02 06 09 2A 0"..*.H. .......* [0030] 86 48 82 F7 12 01 02 02 06 0A 2B 06 01 04 01 82 .H...... ..+..... [0040] 37 02 02 0A A3 2A 30 28 A0 26 1B 24 63 69 66 73 7....*0( .&.$cifs [0050] 2F 70 61 67 68 2E 6B 6C 69 6E 67 6F 6E 73 2E 67 /pagh.kl ingons.g [0060] 76 63 63 2E 6E 65 74 40 47 56 43 43 2E 4E 45 54 vcc.net@ GVCC.NET [2012/01/04 16:04:20.426506, 10] lib/util_sock.c:726(read_smb_length_return_keepalive) got smb length of 720 [2012/01/04 16:04:20.426622, 6] smbd/process.c:1482(process_smb) got message type 0x0 of len 0x2d0 [2012/01/04 16:04:20.426677, 3] smbd/process.c:1485(process_smb) Transaction 1 of length 724 (0 toread) [2012/01/04 16:04:20.426726, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.426765, 5] lib/util.c:627(show_msg) size=720 smb_com=0x73 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=8 smb_flg2=51201 smb_tid=0 smb_pid=8921 smb_uid=0 smb_mid=3 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]= 638 (0x27E) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]=53340 (0xD05C) smb_vwv[11]=32768 (0x8000) smb_bcc=661 [2012/01/04 16:04:20.427015, 10] ../lib/util/util.c:278(_dump_data) [0000] 60 82 02 7A 06 06 2B 06 01 05 05 02 A0 82 02 6E `..z..+. .......n [0010] 30 82 02 6A A0 24 30 22 06 09 2A 86 48 82 F7 12 0..j.$0" ..*.H... [0020] 01 02 02 06 09 2A 86 48 86 F7 12 01 02 02 06 0A .....*.H ........ [0030] 2B 06 01 04 01 82 37 02 02 0A A2 82 02 40 04 82 +.....7. .....@.. [0040] 02 3C 60 82 02 38 06 09 2A 86 48 86 F7 12 01 02 .<`..8.. *.H..... [0050] 02 01 00 6E 82 02 27 30 82 02 23 A0 03 02 01 05 ...n..'0 ..#..... [0060] A1 03 02 01 0E A2 07 03 05 00 00 00 00 00 A3 82 ........ ........ [0070] 01 60 61 82 01 5C 30 82 01 58 A0 03 02 01 05 A1 .`a..\0. .X...... [0080] 0A 1B 08 47 56 43 43 2E 4E 45 54 A2 29 30 27 A0 ...GVCC. NET.)0'. [0090] 03 02 01 01 A1 20 30 1E 1B 04 63 69 66 73 1B 16 ..... 0. ..cifs.. [00A0] 70 61 67 68 2E 6B 6C 69 6E 67 6F 6E 73 2E 67 76 pagh.kli ngons.gv [00B0] 63 63 2E 6E 65 74 A3 82 01 18 30 82 01 14 A0 03 cc.net.. ..0..... [00C0] 02 01 12 A1 03 02 01 04 A2 82 01 06 04 82 01 02 ........ ........ [00D0] 77 8B B5 39 A0 CA 3A 6D 5A 03 E1 5B 77 22 55 A3 w..9..:m Z..[w"U. [00E0] 93 F8 C6 3A 47 0E 3B B6 4F F8 CB 0E 4C 76 C6 2C ...:G.;. O...Lv., [00F0] 0B DF 40 81 28 42 4C 0F 3E D9 BB D9 DA AB 3C E0 ..@.(BL. >.....<. [0100] B5 BE 8E 9F B4 E9 E3 17 0E 74 57 CB 98 90 87 90 ........ .tW..... [0110] 60 BF 98 DB 76 37 66 7C 33 B0 B5 B1 95 E1 B1 0B `...v7f| 3....... [0120] E4 2E 02 4E DB 83 E1 2C 10 F9 CF E9 2A 03 A0 57 ...N..., ....*..W [0130] 3C 49 36 73 88 1F 3F 90 99 91 AC EE F7 08 AC C9 ...H. [01B0] 08 29 20 5F 8E 23 96 80 63 E5 5F 3F 22 E5 5D 00 .) _.#.. c._?".]. [01C0] 86 4B 07 22 AB DC 27 8B 74 8B AF 3A 8F 8E 2D BC .K."..'. t..:..-. [01D0] 94 21 A4 81 A9 30 81 A6 A0 03 02 01 17 A2 81 9E .!...0.. ........ [01E0] 04 81 9B EE 91 4E 22 46 A5 0F BE 18 79 5F 2E 2C .....N"F ....y_., [01F0] 13 64 CF 16 95 E6 B3 F4 7B 3D 06 E3 EC 80 34 0A .d...... {=....4. [2012/01/04 16:04:20.427820, 3] smbd/process.c:1294(switch_message) switch message SMBsesssetupX (pid 8923) conn 0x0 [2012/01/04 16:04:20.427873, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.427924, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.427974, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.428045, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.428122, 3] smbd/sesssetup.c:1435(reply_sesssetup_and_X) wct=12 flg2=0xc801 [2012/01/04 16:04:20.428187, 3] smbd/sesssetup.c:1189(reply_sesssetup_and_X_spnego) Doing spnego session setup [2012/01/04 16:04:20.428293, 3] smbd/sesssetup.c:1231(reply_sesssetup_and_X_spnego) NativeOS=[Unix] NativeLanMan=[Samba] PrimaryDomain=[] [2012/01/04 16:04:20.428372, 10] smbd/password.c:184(register_initial_vuid) register_initial_vuid: allocated vuid = 100 [2012/01/04 16:04:20.428454, 10] smbd/sesssetup.c:1134(check_spnego_blob_complete) check_spnego_blob_complete: needed_len = 638, pblob->length = 638 [2012/01/04 16:04:20.428572, 5] smbd/sesssetup.c:753(parse_spnego_mechanisms) parse_spnego_mechanisms: Got OID 1.2.840.48018.1.2.2 [2012/01/04 16:04:20.428637, 5] smbd/sesssetup.c:753(parse_spnego_mechanisms) parse_spnego_mechanisms: Got OID 1.2.840.113554.1.2.2 [2012/01/04 16:04:20.428686, 5] smbd/sesssetup.c:753(parse_spnego_mechanisms) parse_spnego_mechanisms: Got OID 1.3.6.1.4.1.311.2.2.10 [2012/01/04 16:04:20.428734, 3] smbd/sesssetup.c:805(reply_spnego_negotiate) reply_spnego_negotiate: Got secblob of size 572 [2012/01/04 16:04:20.433091, 10] lib/util.c:2598(name_to_fqdn) name_to_fqdn: lookup for PAGH -> pagh.klingons.gvcc.net. [2012/01/04 16:04:20.433911, 10] libads/kerberos_verify.c:221(ads_keytab_verify_ticket) ads_keytab_verify_ticket: krb5_rd_req_return_keyblock_from_keytab(host/pagh.klingons.gvcc.net@GVCC.NET) failed: Wrong principal in request [2012/01/04 16:04:20.434056, 10] libads/kerberos_verify.c:221(ads_keytab_verify_ticket) ads_keytab_verify_ticket: krb5_rd_req_return_keyblock_from_keytab(host/pagh.klingons.gvcc.net@GVCC.NET) failed: Wrong principal in request [2012/01/04 16:04:20.434151, 10] libads/kerberos_verify.c:221(ads_keytab_verify_ticket) ads_keytab_verify_ticket: krb5_rd_req_return_keyblock_from_keytab(host/pagh.klingons.gvcc.net@GVCC.NET) failed: Wrong principal in request [2012/01/04 16:04:20.434243, 10] libads/kerberos_verify.c:221(ads_keytab_verify_ticket) ads_keytab_verify_ticket: krb5_rd_req_return_keyblock_from_keytab(host/pagh.klingons.gvcc.net@GVCC.NET) failed: Wrong principal in request [2012/01/04 16:04:20.434335, 10] libads/kerberos_verify.c:221(ads_keytab_verify_ticket) ads_keytab_verify_ticket: krb5_rd_req_return_keyblock_from_keytab(host/pagh.klingons.gvcc.net@GVCC.NET) failed: Wrong principal in request [2012/01/04 16:04:20.782624, 10] libsmb/clikrb5.c:1110(get_key_from_keytab) get_key_from_keytab: will look for kvno 4, enctype 18 and name: cifs/pagh.klingons.gvcc.net@GVCC.NET [2012/01/04 16:04:20.782878, 3] libads/kerberos_verify.c:239(ads_keytab_verify_ticket) ads_keytab_verify_ticket: krb5_rd_req_return_keyblock_from_keytab succeeded for principal cifs/pagh.klingons.gvcc.net@GVCC.NET [2012/01/04 16:04:20.783430, 10] libsmb/clikrb5.c:915(get_krb5_smb_session_key) Got KRB5 session key of length 16 [2012/01/04 16:04:20.783507, 10] libsmb/clikrb5.c:384(unwrap_pac) authorization data is not a Windows PAC (type: 512) [2012/01/04 16:04:20.783558, 3] libads/kerberos_verify.c:610(ads_verify_ticket) ads_verify_ticket: did not retrieve auth data. continuing without PAC [2012/01/04 16:04:20.783696, 3] smbd/sesssetup.c:338(reply_spnego_kerberos) Ticket name is [heinz_sgv@GVCC.NET] [2012/01/04 16:04:20.783760, 10] smbd/sesssetup.c:396(reply_spnego_kerberos) Mapping [GVCC.NET] to short name [2012/01/04 16:04:20.784012, 3] smbd/sesssetup.c:410(reply_spnego_kerberos) Could not find short name: WBC_ERR_WINBIND_NOT_AVAILABLE [2012/01/04 16:04:20.784136, 5] lib/username.c:133(Get_Pwnam_alloc) Finding user GVCC.NET\heinz_sgv [2012/01/04 16:04:20.784212, 5] lib/username.c:77(Get_Pwnam_internals) Trying _Get_Pwnam(), username as lowercase is gvcc.net\heinz_sgv [2012/01/04 16:04:20.792449, 5] lib/username.c:85(Get_Pwnam_internals) Trying _Get_Pwnam(), username as given is GVCC.NET\heinz_sgv [2012/01/04 16:04:20.794603, 5] lib/username.c:95(Get_Pwnam_internals) Trying _Get_Pwnam(), username as uppercase is GVCC.NET\HEINZ_SGV [2012/01/04 16:04:20.796647, 5] lib/username.c:104(Get_Pwnam_internals) Checking combinations of 0 uppercase letters in gvcc.net\heinz_sgv [2012/01/04 16:04:20.796709, 5] lib/username.c:110(Get_Pwnam_internals) Get_Pwnam_internals didn't find user [GVCC.NET\heinz_sgv]! [2012/01/04 16:04:20.796762, 5] lib/username.c:133(Get_Pwnam_alloc) Finding user heinz_sgv [2012/01/04 16:04:20.796810, 5] lib/username.c:77(Get_Pwnam_internals) Trying _Get_Pwnam(), username as lowercase is heinz_sgv [2012/01/04 16:04:20.799005, 5] lib/username.c:110(Get_Pwnam_internals) Get_Pwnam_internals did find user [heinz_sgv]! [2012/01/04 16:04:20.799180, 6] param/loadparm.c:7132(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Jan 4 16:02:48 2012 [2012/01/04 16:04:20.799612, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(uid=heinz_sgv)(objectclass=sambaSamAccount))], scope => [2] [2012/01/04 16:04:20.800349, 5] lib/smbldap.c:1262(smbldap_close) The connection to the LDAP server was closed [2012/01/04 16:04:20.800420, 10] lib/smbldap.c:751(smb_ldap_setup_conn) smb_ldap_setup_connection: ldap://localhost/ [2012/01/04 16:04:20.800671, 2] lib/smbldap.c:950(smbldap_open_connection) smbldap_open_connection: connection opened [2012/01/04 16:04:20.800723, 10] lib/smbldap.c:1120(smbldap_connect_system) ldap_connect_system: Binding to ldap server ldap://localhost/ as "cn=admin,dc=gvcc,dc=net" [2012/01/04 16:04:20.802694, 3] lib/smbldap.c:1166(smbldap_connect_system) ldap_connect_system: successful connection to the LDAP server ldap_connect_system: LDAP server does support paged results [2012/01/04 16:04:20.802838, 4] lib/smbldap.c:1242(smbldap_open) The LDAP server is successfully connected [2012/01/04 16:04:20.805352, 2] passdb/pdb_ldap.c:572(init_sam_from_ldap) init_sam_from_ldap: Entry found for user: heinz_sgv [2012/01/04 16:04:20.805463, 10] passdb/pdb_get_set.c:608(pdb_set_username) pdb_set_username: setting username heinz_sgv, was [2012/01/04 16:04:20.805559, 10] passdb/pdb_get_set.c:631(pdb_set_domain) pdb_set_domain: setting domain GVCC.NET, was [2012/01/04 16:04:20.805609, 10] passdb/pdb_get_set.c:654(pdb_set_nt_username) pdb_set_nt_username: setting nt username heinz_sgv, was [2012/01/04 16:04:20.805668, 10] passdb/pdb_get_set.c:550(pdb_set_user_sid_from_string) pdb_set_user_sid_from_string: setting user sid S-1-5-21-3171465218-1814289097-3269728112-4696 [2012/01/04 16:04:20.805722, 10] passdb/pdb_get_set.c:537(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-3171465218-1814289097-3269728112-4696 [2012/01/04 16:04:20.805823, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaPwdLastSet does not exist [2012/01/04 16:04:20.805881, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaLogonTime does not exist [2012/01/04 16:04:20.805936, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaLogoffTime does not exist [2012/01/04 16:04:20.805990, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaKickoffTime does not exist [2012/01/04 16:04:20.806045, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaPwdCanChange does not exist [2012/01/04 16:04:20.806099, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaPwdMustChange does not exist [2012/01/04 16:04:20.806155, 10] passdb/pdb_get_set.c:677(pdb_set_fullname) pdb_set_full_name: setting full name Heinz Hölzl, was [2012/01/04 16:04:20.806208, 10] passdb/pdb_get_set.c:746(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive k:, was NULL [2012/01/04 16:04:20.806278, 10] passdb/pdb_get_set.c:770(pdb_set_homedir) pdb_set_homedir: setting home dir \\fs.bahnhof.sgv\heinz_sgv, was [2012/01/04 16:04:20.806335, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaLogonScript does not exist [2012/01/04 16:04:20.806392, 10] passdb/pdb_get_set.c:700(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2012/01/04 16:04:20.806446, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaProfilePath does not exist [2012/01/04 16:04:20.806497, 4] lib/substitute.c:504(automount_server) Home server: pagh.klingons.g [2012/01/04 16:04:20.806563, 10] passdb/pdb_get_set.c:723(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\pagh.klingons.g\heinz_sgv\profile, was [2012/01/04 16:04:20.806620, 10] lib/smbldap.c:316(smbldap_talloc_single_attribute) attribute description has 2 values, expected only one [2012/01/04 16:04:20.806676, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaUserWorkstations does not exist [2012/01/04 16:04:20.806751, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaMungedDial does not exist [2012/01/04 16:04:20.806805, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaLMPassword does not exist [2012/01/04 16:04:20.806859, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaNTPassword does not exist [2012/01/04 16:04:20.806912, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.806990, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.807040, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.807091, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.807140, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.807424, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = ACCT_POL/password history couldn't be found [2012/01/04 16:04:20.807478, 10] passdb/pdb_ldap.c:3983(ldapsam_get_account_policy_from_ldap) ldapsam_get_account_policy_from_ldap [2012/01/04 16:04:20.807560, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [sambaDomainName=GVCC.NET,cn=accounts,dc=gvcc,dc=net], filter => [(objectClass=sambaDomain)], scope => [0] [2012/01/04 16:04:20.808432, 10] lib/account_pol.c:396(cache_account_policy_set) cache_account_policy_set: updating account pol cache [2012/01/04 16:04:20.808530, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = ACCT_POL/password history and timeout = Wed Jan 4 16:05:20 2012 (60 seconds ahead) [2012/01/04 16:04:20.808835, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.808921, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaBadPasswordCount does not exist [2012/01/04 16:04:20.808978, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaBadPasswordTime does not exist [2012/01/04 16:04:20.809033, 10] lib/smbldap.c:310(smbldap_talloc_single_attribute) attribute sambaLogonHours does not exist [2012/01/04 16:04:20.809234, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = IDMAP/SID2UID/S-1-5-21-3171465218-1814289097-3269728112-4696 and timeout = Wed Jan 11 16:04:20 2012 (604800 seconds ahead) [2012/01/04 16:04:20.809394, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = IDMAP/UID2SID/1848 and timeout = Wed Jan 11 16:04:20 2012 (604800 seconds ahead) [2012/01/04 16:04:20.809548, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = IDMAP/GID2SID/100 couldn't be found [2012/01/04 16:04:20.809648, 5] passdb/lookup_sid.c:1387(gid_to_sid) gid_to_sid: winbind failed to find a sid for gid 100 [2012/01/04 16:04:20.809711, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.809763, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.809813, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.809862, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.809911, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.810026, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(gidNumber=100)(objectClass=sambaGroupMapping))], scope => [2] [2012/01/04 16:04:20.811843, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = IDMAP/SID2GID/S-1-5-21-3171465218-1814289097-3269728112-513 and timeout = Wed Jan 11 16:04:20 2012 (604800 seconds ahead) [2012/01/04 16:04:20.812048, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = IDMAP/GID2SID/100 and timeout = Wed Jan 11 16:04:20 2012 (604800 seconds ahead) [2012/01/04 16:04:20.812225, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.812276, 10] passdb/lookup_sid.c:1182(legacy_gid_to_sid) LEGACY: gid 100 -> sid S-1-5-21-3171465218-1814289097-3269728112-513 [2012/01/04 16:04:20.812389, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = IDMAP/SID2UID/S-1-5-21-3171465218-1814289097-3269728112-513 and timeout = Wed Jan 11 16:04:20 2012 (604800 seconds ahead) [2012/01/04 16:04:20.812541, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = IDMAP/UID2SID/100 and timeout = Wed Jan 11 16:04:20 2012 (604800 seconds ahead) [2012/01/04 16:04:20.812864, 5] passdb/login_cache.c:44(login_cache_init) Opening cache file at /var/cache/samba/login_cache.tdb [2012/01/04 16:04:20.813041, 7] passdb/login_cache.c:87(login_cache_read) Looking up login cache for user heinz_sgv [2012/01/04 16:04:20.813100, 7] passdb/login_cache.c:103(login_cache_read) No cache entry found [2012/01/04 16:04:20.813148, 9] passdb/pdb_ldap.c:1126(init_sam_from_ldap) No cache entry, bad count = 0, bad time = 0 [2012/01/04 16:04:20.813265, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.813316, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.813364, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.813413, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.813462, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.813537, 10] lib/gencache.c:345(gencache_get_data_blob) Returning valid cache entry: key = ACCT_POL/password history, value = 0 , timeout = Wed Jan 4 16:05:20 2012 [2012/01/04 16:04:20.813675, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.813776, 10] passdb/pdb_get_set.c:608(pdb_set_username) pdb_set_username: setting username heinz_sgv, was [2012/01/04 16:04:20.813828, 10] passdb/pdb_get_set.c:631(pdb_set_domain) pdb_set_domain: setting domain GVCC.NET, was [2012/01/04 16:04:20.813878, 10] passdb/pdb_get_set.c:654(pdb_set_nt_username) pdb_set_nt_username: setting nt username heinz_sgv, was [2012/01/04 16:04:20.813926, 10] passdb/pdb_get_set.c:677(pdb_set_fullname) pdb_set_full_name: setting full name Heinz Hölzl, was [2012/01/04 16:04:20.813977, 10] passdb/pdb_get_set.c:770(pdb_set_homedir) pdb_set_homedir: setting home dir \\fs.bahnhof.sgv\heinz_sgv, was [2012/01/04 16:04:20.814027, 10] passdb/pdb_get_set.c:746(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive k:, was NULL [2012/01/04 16:04:20.814078, 10] passdb/pdb_get_set.c:700(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2012/01/04 16:04:20.814131, 4] lib/substitute.c:504(automount_server) Home server: pagh.klingons.g [2012/01/04 16:04:20.814193, 10] passdb/pdb_get_set.c:723(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\pagh.klingons.g\heinz_sgv\profile, was [2012/01/04 16:04:20.814244, 10] passdb/pdb_get_set.c:813(pdb_set_workstations) pdb_set_workstations: setting workstations , was [2012/01/04 16:04:20.814294, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.814344, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.814392, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.814440, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.814487, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.814569, 10] lib/gencache.c:345(gencache_get_data_blob) Returning valid cache entry: key = ACCT_POL/password history, value = 0 , timeout = Wed Jan 4 16:05:20 2012 [2012/01/04 16:04:20.814679, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.814731, 10] passdb/pdb_get_set.c:537(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-3171465218-1814289097-3269728112-4696 [2012/01/04 16:04:20.814783, 10] passdb/pdb_compat.c:72(pdb_set_user_sid_from_rid) pdb_set_user_sid_from_rid: setting user sid S-1-5-21-3171465218-1814289097-3269728112-4696 from rid 4696 [2012/01/04 16:04:20.814852, 10] passdb/pdb_get_set.c:595(pdb_set_group_sid) pdb_set_group_sid: setting group sid S-1-5-21-3171465218-1814289097-3269728112-513 [2012/01/04 16:04:20.814955, 10] smbd/sesssetup.c:507(reply_spnego_kerberos) found user heinz_sgv in passdb, calling make_server_info_sam [2012/01/04 16:04:20.815058, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(objectClass=posixGroup)(|(memberUid=heinz_sgv)(gidNumber=100)))], scope => [2] [2012/01/04 16:04:20.816946, 5] auth/auth_util.c:649(make_server_info_sam) make_server_info_sam: made server info for user heinz_sgv -> heinz_sgv [2012/01/04 16:04:20.817056, 10] passdb/pdb_get_set.c:631(pdb_set_domain) pdb_set_domain: setting domain GVCC.NET, was GVCC.NET [2012/01/04 16:04:20.817152, 10] auth/token_util.c:356(create_local_nt_token) Create local NT token for S-1-5-21-3171465218-1814289097-3269728112-4696 [2012/01/04 16:04:20.817258, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = IDMAP/SID2GID/S-1-5-32-544 couldn't be found [2012/01/04 16:04:20.817391, 10] passdb/lookup_sid.c:1511(sid_to_gid) winbind failed to find a gid for sid S-1-5-32-544 [2012/01/04 16:04:20.817447, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.817500, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.817550, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.817600, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.817646, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.817772, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-544))], scope => [2] [2012/01/04 16:04:20.819091, 4] passdb/pdb_ldap.c:2562(ldapsam_getgroup) ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-544)) [2012/01/04 16:04:20.819176, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.819229, 10] passdb/lookup_sid.c:1256(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-5-32-544 [2012/01/04 16:04:20.819291, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.819339, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.819388, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.819436, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.819485, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.819695, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = IDMAP/SID2GID/S-1-5-32-544 couldn't be found [2012/01/04 16:04:20.819772, 10] passdb/lookup_sid.c:1511(sid_to_gid) winbind failed to find a gid for sid S-1-5-32-544 [2012/01/04 16:04:20.819826, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2012/01/04 16:04:20.819894, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2012/01/04 16:04:20.819943, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2012/01/04 16:04:20.819991, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.820037, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.820134, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-544))], scope => [2] [2012/01/04 16:04:20.821310, 4] passdb/pdb_ldap.c:2562(ldapsam_getgroup) ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-544)) [2012/01/04 16:04:20.821498, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.821549, 10] passdb/lookup_sid.c:1256(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-5-32-544 [2012/01/04 16:04:20.821610, 5] auth/token_util.c:306(create_builtin_administrators) create_builtin_administrators: Failed to create Administrators [2012/01/04 16:04:20.821664, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.821742, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = IDMAP/SID2GID/S-1-5-32-545 couldn't be found [2012/01/04 16:04:20.821803, 10] passdb/lookup_sid.c:1511(sid_to_gid) winbind failed to find a gid for sid S-1-5-32-545 [2012/01/04 16:04:20.821855, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.821904, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.821952, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.822000, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.822047, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.822142, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-545))], scope => [2] [2012/01/04 16:04:20.823239, 4] passdb/pdb_ldap.c:2562(ldapsam_getgroup) ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-545)) [2012/01/04 16:04:20.823305, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.823355, 10] passdb/lookup_sid.c:1256(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-5-32-545 [2012/01/04 16:04:20.823407, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.823460, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.823508, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.823556, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.823603, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.823695, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = IDMAP/SID2GID/S-1-5-32-545 couldn't be found [2012/01/04 16:04:20.823758, 10] passdb/lookup_sid.c:1511(sid_to_gid) winbind failed to find a gid for sid S-1-5-32-545 [2012/01/04 16:04:20.823809, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2012/01/04 16:04:20.823858, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2012/01/04 16:04:20.823906, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2012/01/04 16:04:20.823971, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.824020, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.824108, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-545))], scope => [2] [2012/01/04 16:04:20.825216, 4] passdb/pdb_ldap.c:2562(ldapsam_getgroup) ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-545)) [2012/01/04 16:04:20.825281, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.825332, 10] passdb/lookup_sid.c:1256(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-5-32-545 [2012/01/04 16:04:20.825390, 5] auth/token_util.c:277(create_builtin_users) create_builtin_users: Failed to create Users [2012/01/04 16:04:20.825441, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.825490, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.825539, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.825587, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.825635, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.825681, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.825859, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(objectclass=sambaGroupMapping)(sambaGroupType=4)(|(sambaSIDList=S-1-5-21-3171465218-1814289097-3269728112-4696)(sambaSIDList=S-1-5-21-3171465218-1814289097-3269728112-513)(sambaSIDList=S-1-1-0)(sambaSIDList=S-1-5-2)(sambaSIDList=S-1-5-11)(sambaSIDList=S-1-5-21-3171465218-1814289097-3269728112-1987)(sambaSIDList=S-1-5-21-3171465218-1814289097-3269728112-512)(sambaSIDList=S-1-5-21-3171465218-1814289097-3269728112-1999)(sambaSIDList=S-1-5-32-544)))], scope => [2] [2012/01/04 16:04:20.828547, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.828692, 3] lib/privileges.c:63(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-21-3171465218-1814289097-3269728112-4696] [2012/01/04 16:04:20.828756, 3] lib/privileges.c:63(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-21-3171465218-1814289097-3269728112-513] [2012/01/04 16:04:20.828816, 5] lib/privileges.c:128(get_privileges_for_sids) get_privileges_for_sids: sid = S-1-1-0 Privilege set: SE_PRIV 0x0 0x0 0x0 0x0 [2012/01/04 16:04:20.828892, 3] lib/privileges.c:63(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-2] [2012/01/04 16:04:20.828949, 3] lib/privileges.c:63(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-11] [2012/01/04 16:04:20.829007, 3] lib/privileges.c:63(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-21-3171465218-1814289097-3269728112-1987] [2012/01/04 16:04:20.829067, 3] lib/privileges.c:63(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-21-3171465218-1814289097-3269728112-512] [2012/01/04 16:04:20.829127, 3] lib/privileges.c:63(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-21-3171465218-1814289097-3269728112-1999] [2012/01/04 16:04:20.829186, 5] lib/privileges.c:128(get_privileges_for_sids) get_privileges_for_sids: sid = S-1-5-32-544 Privilege set: SE_PRIV 0xff0 0x0 0x0 0x0 [2012/01/04 16:04:20.829280, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = IDMAP/SID2GID/S-1-1-0 couldn't be found [2012/01/04 16:04:20.829344, 10] passdb/lookup_sid.c:1511(sid_to_gid) winbind failed to find a gid for sid S-1-1-0 [2012/01/04 16:04:20.829413, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.829463, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.829511, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.829559, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.829607, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.829701, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-1-0))], scope => [2] [2012/01/04 16:04:20.830902, 4] passdb/pdb_ldap.c:2562(ldapsam_getgroup) ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-1-0)) [2012/01/04 16:04:20.830978, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.831029, 10] passdb/lookup_sid.c:1256(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-1-0 [2012/01/04 16:04:20.831086, 10] auth/auth_util.c:753(create_local_token) Could not convert SID S-1-1-0 to gid, ignoring it [2012/01/04 16:04:20.831166, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = IDMAP/SID2GID/S-1-5-2 couldn't be found [2012/01/04 16:04:20.831231, 10] passdb/lookup_sid.c:1511(sid_to_gid) winbind failed to find a gid for sid S-1-5-2 [2012/01/04 16:04:20.831283, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.831332, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.831512, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.831562, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.831610, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.831705, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-2))], scope => [2] [2012/01/04 16:04:20.832835, 4] passdb/pdb_ldap.c:2562(ldapsam_getgroup) ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-2)) [2012/01/04 16:04:20.832901, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.832952, 10] passdb/lookup_sid.c:1256(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-5-2 [2012/01/04 16:04:20.833003, 10] auth/auth_util.c:753(create_local_token) Could not convert SID S-1-5-2 to gid, ignoring it [2012/01/04 16:04:20.833068, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = IDMAP/SID2GID/S-1-5-11 couldn't be found [2012/01/04 16:04:20.833131, 10] passdb/lookup_sid.c:1511(sid_to_gid) winbind failed to find a gid for sid S-1-5-11 [2012/01/04 16:04:20.833183, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.833232, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.833280, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.833328, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.833375, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.833462, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-11))], scope => [2] [2012/01/04 16:04:20.834727, 4] passdb/pdb_ldap.c:2562(ldapsam_getgroup) ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-11)) [2012/01/04 16:04:20.834828, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.834880, 10] passdb/lookup_sid.c:1256(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-5-11 [2012/01/04 16:04:20.834931, 10] auth/auth_util.c:753(create_local_token) Could not convert SID S-1-5-11 to gid, ignoring it [2012/01/04 16:04:20.835002, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = IDMAP/SID2GID/S-1-5-21-3171465218-1814289097-3269728112-1987 couldn't be found [2012/01/04 16:04:20.835073, 10] passdb/lookup_sid.c:1511(sid_to_gid) winbind failed to find a gid for sid S-1-5-21-3171465218-1814289097-3269728112-1987 [2012/01/04 16:04:20.835127, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.835176, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.835225, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.835272, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.835319, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.835410, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(sambaSid=S-1-5-21-3171465218-1814289097-3269728112-1987)(|(objectClass=sambaGroupMapping)(objectClass=sambaSamAccount)))], scope => [2] [2012/01/04 16:04:20.837839, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = IDMAP/SID2GID/S-1-5-21-3171465218-1814289097-3269728112-1987 and timeout = Wed Jan 11 16:04:20 2012 (604800 seconds ahead) [2012/01/04 16:04:20.838030, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = IDMAP/GID2SID/498 and timeout = Wed Jan 11 16:04:20 2012 (604800 seconds ahead) [2012/01/04 16:04:20.838183, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.838234, 10] passdb/lookup_sid.c:1288(legacy_sid_to_gid) LEGACY: sid S-1-5-21-3171465218-1814289097-3269728112-1987 -> gid 498 [2012/01/04 16:04:20.838306, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = IDMAP/SID2GID/S-1-5-21-3171465218-1814289097-3269728112-512 couldn't be found [2012/01/04 16:04:20.838376, 10] passdb/lookup_sid.c:1511(sid_to_gid) winbind failed to find a gid for sid S-1-5-21-3171465218-1814289097-3269728112-512 [2012/01/04 16:04:20.838430, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.838480, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.838528, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.838576, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.838623, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.838712, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(sambaSid=S-1-5-21-3171465218-1814289097-3269728112-512)(|(objectClass=sambaGroupMapping)(objectClass=sambaSamAccount)))], scope => [2] [2012/01/04 16:04:20.841087, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = IDMAP/SID2GID/S-1-5-21-3171465218-1814289097-3269728112-512 and timeout = Wed Jan 11 16:04:20 2012 (604800 seconds ahead) [2012/01/04 16:04:20.841260, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = IDMAP/GID2SID/500 and timeout = Wed Jan 11 16:04:20 2012 (604800 seconds ahead) [2012/01/04 16:04:20.841523, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.841577, 10] passdb/lookup_sid.c:1288(legacy_sid_to_gid) LEGACY: sid S-1-5-21-3171465218-1814289097-3269728112-512 -> gid 500 [2012/01/04 16:04:20.841666, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = IDMAP/SID2GID/S-1-5-21-3171465218-1814289097-3269728112-1999 couldn't be found [2012/01/04 16:04:20.841736, 10] passdb/lookup_sid.c:1511(sid_to_gid) winbind failed to find a gid for sid S-1-5-21-3171465218-1814289097-3269728112-1999 [2012/01/04 16:04:20.841790, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.841839, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.841887, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.841935, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.841982, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.842071, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(sambaSid=S-1-5-21-3171465218-1814289097-3269728112-1999)(|(objectClass=sambaGroupMapping)(objectClass=sambaSamAccount)))], scope => [2] [2012/01/04 16:04:20.844458, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = IDMAP/SID2GID/S-1-5-21-3171465218-1814289097-3269728112-1999 and timeout = Wed Jan 11 16:04:20 2012 (604800 seconds ahead) [2012/01/04 16:04:20.844630, 10] lib/gencache.c:180(gencache_set_data_blob) Adding cache entry with key = IDMAP/GID2SID/499 and timeout = Wed Jan 11 16:04:20 2012 (604800 seconds ahead) [2012/01/04 16:04:20.844783, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.844833, 10] passdb/lookup_sid.c:1288(legacy_sid_to_gid) LEGACY: sid S-1-5-21-3171465218-1814289097-3269728112-1999 -> gid 499 [2012/01/04 16:04:20.844902, 10] lib/gencache.c:334(gencache_get_data_blob) Cache entry with key = IDMAP/SID2GID/S-1-5-32-544 couldn't be found [2012/01/04 16:04:20.844966, 10] passdb/lookup_sid.c:1511(sid_to_gid) winbind failed to find a gid for sid S-1-5-32-544 [2012/01/04 16:04:20.845018, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.845067, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.845115, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.845163, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.845210, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.845299, 5] lib/smbldap.c:1360(smbldap_search_ext) smbldap_search_ext: base => [cn=accounts,dc=gvcc,dc=net], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-544))], scope => [2] [2012/01/04 16:04:20.846393, 4] passdb/pdb_ldap.c:2562(ldapsam_getgroup) ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-544)) [2012/01/04 16:04:20.846459, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.846510, 10] passdb/lookup_sid.c:1256(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-5-32-544 [2012/01/04 16:04:20.846560, 10] auth/auth_util.c:753(create_local_token) Could not convert SID S-1-5-32-544 to gid, ignoring it [2012/01/04 16:04:20.846615, 10] auth/token_util.c:531(debug_nt_user_token) NT user token of user S-1-5-21-3171465218-1814289097-3269728112-4696 contains 14 SIDs SID[ 0]: S-1-5-21-3171465218-1814289097-3269728112-4696 SID[ 1]: S-1-5-21-3171465218-1814289097-3269728112-513 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-11 SID[ 5]: S-1-5-21-3171465218-1814289097-3269728112-1987 SID[ 6]: S-1-5-21-3171465218-1814289097-3269728112-512 SID[ 7]: S-1-5-21-3171465218-1814289097-3269728112-1999 SID[ 8]: S-1-5-32-544 SID[ 9]: S-1-22-1-1848 SID[ 10]: S-1-22-2-100 SID[ 11]: S-1-22-2-498 SID[ 12]: S-1-22-2-500 SID[ 13]: S-1-22-2-499 SE_PRIV 0xff0 0x0 0x0 0x0 [2012/01/04 16:04:20.846850, 10] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 1848 Primary group is 100 and contains 4 supplementary groups Group[ 0]: 100 Group[ 1]: 498 Group[ 2]: 500 Group[ 3]: 499 [2012/01/04 16:04:20.846952, 10] smbd/password.c:184(register_initial_vuid) register_initial_vuid: allocated vuid = 101 [2012/01/04 16:04:20.847009, 10] smbd/password.c:278(register_existing_vuid) register_existing_vuid: (1848,100) heinz_sgv heinz_sgv GVCC.NET guest=0 [2012/01/04 16:04:20.847059, 3] smbd/password.c:282(register_existing_vuid) register_existing_vuid: User name: heinz_sgv Real name: Heinz Hölzl [2012/01/04 16:04:20.847108, 3] smbd/password.c:292(register_existing_vuid) register_existing_vuid: UNIX uid 1848 is UNIX user heinz_sgv, and will be vuid 101 [2012/01/04 16:04:20.847231, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 49442F383932332F3130 [2012/01/04 16:04:20.847317, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x7fa55fb3db60 [2012/01/04 16:04:20.847952, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 49442F383932332F3130 [2012/01/04 16:04:20.848090, 7] param/loadparm.c:9398(lp_servicenumber) lp_servicenumber: couldn't find heinz_sgv [2012/01/04 16:04:20.848155, 3] smbd/password.c:223(register_homes_share) Adding homes service for user 'heinz_sgv' using home directory: '/home/heinz_sgv' [2012/01/04 16:04:20.848377, 8] param/loadparm.c:6162(add_a_service) add_a_service: Creating snum = 9 for heinz_sgv [2012/01/04 16:04:20.848429, 10] param/loadparm.c:6209(hash_a_service) hash_a_service: hashing index 9 for service name heinz_sgv [2012/01/04 16:04:20.848492, 3] param/loadparm.c:6264(lp_add_home) adding home's share [heinz_sgv] for user 'heinz_sgv' at '/samba/sys/user/privat/%u/config' [2012/01/04 16:04:20.848588, 6] param/loadparm.c:7132(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Jan 4 16:02:48 2012 [2012/01/04 16:04:20.848763, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.848805, 5] lib/util.c:627(show_msg) size=248 smb_com=0x73 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51203 smb_tid=0 smb_pid=8921 smb_uid=101 smb_mid=3 smt_wct=4 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 153 (0x99) smb_bcc=205 [2012/01/04 16:04:20.848966, 10] ../lib/util/util.c:278(_dump_data) [0000] A1 81 96 30 81 93 A0 03 0A 01 00 A1 0B 06 09 2A ...0.... .......* [0010] 86 48 82 F7 12 01 02 02 A2 7F 04 7D 60 7B 06 09 .H...... ...}`{.. [0020] 2A 86 48 86 F7 12 01 02 02 02 00 6F 6C 30 6A A0 *.H..... ...ol0j. [0030] 03 02 01 05 A1 03 02 01 0F A2 5E 30 5C A0 03 02 ........ ..^0\... [0040] 01 17 A2 55 04 53 CA D4 E5 15 C5 6B CB 06 F2 89 ...U.S.. ...k.... [0050] B3 49 FD B1 27 DF D1 BF 53 34 55 B0 AC 78 D0 57 .I..'... S4U..x.W [0060] 95 67 55 25 D3 B4 51 A1 A3 BD 40 0C D9 87 45 1B .gU%..Q. ..@...E. [0070] 9B 0F 96 9E DD A9 9D C4 E6 9F E9 30 73 82 D0 04 ........ ...0s... [0080] 9B 78 A8 89 28 33 70 8F D9 11 B0 1A 78 33 E2 85 .x..(3p. ....x3.. [0090] FA 1E 7C 28 6A 01 A5 C8 18 55 00 6E 00 69 00 78 ..|(j... .U.n.i.x [00A0] 00 00 00 53 00 61 00 6D 00 62 00 61 00 20 00 33 ...S.a.m .b.a. .3 [00B0] 00 2E 00 35 00 2E 00 32 00 00 00 47 00 56 00 43 ...5...2 ...G.V.C [00C0] 00 43 00 2E 00 4E 00 45 00 54 00 00 00 .C...N.E .T... [2012/01/04 16:04:20.850612, 10] lib/util_sock.c:726(read_smb_length_return_keepalive) got smb length of 108 [2012/01/04 16:04:20.850700, 6] smbd/process.c:1482(process_smb) got message type 0x0 of len 0x6c [2012/01/04 16:04:20.850752, 3] smbd/process.c:1485(process_smb) Transaction 2 of length 112 (0 toread) [2012/01/04 16:04:20.850801, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.850860, 5] lib/util.c:627(show_msg) size=108 smb_com=0x75 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=8 smb_flg2=51201 smb_tid=65535 smb_pid=8921 smb_uid=101 smb_mid=4 smt_wct=4 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 8 (0x8) smb_vwv[ 3]= 1 (0x1) smb_bcc=65 [2012/01/04 16:04:20.851023, 10] ../lib/util/util.c:278(_dump_data) [0000] 00 5C 00 5C 00 50 00 41 00 47 00 48 00 2E 00 4B .\.\.P.A .G.H...K [0010] 00 4C 00 49 00 4E 00 47 00 4F 00 4E 00 53 00 2E .L.I.N.G .O.N.S.. [0020] 00 47 00 56 00 43 00 43 00 2E 00 4E 00 45 00 54 .G.V.C.C ...N.E.T [0030] 00 5C 00 49 00 50 00 43 00 24 00 00 00 49 50 43 .\.I.P.C .$...IPC [0040] 00 . [2012/01/04 16:04:20.851176, 3] smbd/process.c:1294(switch_message) switch message SMBtconX (pid 8923) conn 0x0 [2012/01/04 16:04:20.851242, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.851294, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.851466, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.851536, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.851635, 4] smbd/reply.c:767(reply_tcon_and_X) Client requested device type [IPC] for share [IPC$] [2012/01/04 16:04:20.851727, 5] smbd/service.c:1226(make_connection) making a connection to 'normal' service ipc$ [2012/01/04 16:04:20.851825, 10] smbd/share_access.c:238(user_ok_token) user_ok_token: share IPC$ is ok for unix user heinz_sgv [2012/01/04 16:04:20.851913, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.851964, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.852012, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.852058, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.852105, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.852211, 10] lib/gencache.c:345(gencache_get_data_blob) Returning valid cache entry: key = ACCT_POL/password history, value = 0 , timeout = Wed Jan 4 16:05:20 2012 [2012/01/04 16:04:20.852328, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.852397, 10] passdb/pdb_get_set.c:608(pdb_set_username) pdb_set_username: setting username heinz_sgv, was [2012/01/04 16:04:20.852448, 10] passdb/pdb_get_set.c:631(pdb_set_domain) pdb_set_domain: setting domain GVCC.NET, was [2012/01/04 16:04:20.852496, 10] passdb/pdb_get_set.c:654(pdb_set_nt_username) pdb_set_nt_username: setting nt username heinz_sgv, was [2012/01/04 16:04:20.852545, 10] passdb/pdb_get_set.c:677(pdb_set_fullname) pdb_set_full_name: setting full name Heinz Hölzl, was [2012/01/04 16:04:20.852594, 10] passdb/pdb_get_set.c:770(pdb_set_homedir) pdb_set_homedir: setting home dir \\fs.bahnhof.sgv\heinz_sgv, was [2012/01/04 16:04:20.852643, 10] passdb/pdb_get_set.c:746(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive k:, was NULL [2012/01/04 16:04:20.852694, 10] passdb/pdb_get_set.c:700(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2012/01/04 16:04:20.852743, 4] lib/substitute.c:504(automount_server) Home server: pagh.klingons.g [2012/01/04 16:04:20.852800, 10] passdb/pdb_get_set.c:723(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\pagh.klingons.g\heinz_sgv\profile, was [2012/01/04 16:04:20.852850, 10] passdb/pdb_get_set.c:813(pdb_set_workstations) pdb_set_workstations: setting workstations , was [2012/01/04 16:04:20.852900, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.852963, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.853011, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.853058, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.853105, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.853173, 10] lib/gencache.c:345(gencache_get_data_blob) Returning valid cache entry: key = ACCT_POL/password history, value = 0 , timeout = Wed Jan 4 16:05:20 2012 [2012/01/04 16:04:20.853282, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.853333, 10] passdb/pdb_get_set.c:537(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-3171465218-1814289097-3269728112-4696 [2012/01/04 16:04:20.853386, 10] passdb/pdb_compat.c:72(pdb_set_user_sid_from_rid) pdb_set_user_sid_from_rid: setting user sid S-1-5-21-3171465218-1814289097-3269728112-4696 from rid 4696 [2012/01/04 16:04:20.853455, 10] passdb/pdb_get_set.c:595(pdb_set_group_sid) pdb_set_group_sid: setting group sid S-1-5-21-3171465218-1814289097-3269728112-513 [2012/01/04 16:04:20.853522, 5] lib/username.c:133(Get_Pwnam_alloc) Finding user heinz_sgv [2012/01/04 16:04:20.853571, 5] lib/username.c:77(Get_Pwnam_internals) Trying _Get_Pwnam(), username as lowercase is heinz_sgv [2012/01/04 16:04:20.853622, 5] lib/username.c:110(Get_Pwnam_internals) Get_Pwnam_internals did find user [heinz_sgv]! [2012/01/04 16:04:20.853712, 10] smbd/service.c:163(set_conn_connectpath) set_conn_connectpath: service IPC$, connectpath = /tmp [2012/01/04 16:04:20.853763, 3] smbd/service.c:807(make_connection_snum) Connect path is '/tmp' for service [IPC$] [2012/01/04 16:04:20.853903, 10] lib/util_seaccess.c:58(se_map_generic) se_map_generic(): mapped mask 0x10000000 to 0x001f01ff [2012/01/04 16:04:20.853986, 3] smbd/vfs.c:97(vfs_init_default) Initialising default vfs hooks [2012/01/04 16:04:20.854049, 10] smbd/vfs.c:48(vfs_find_backend_entry) vfs_find_backend_entry called for /[Default VFS]/ [2012/01/04 16:04:20.854099, 5] smbd/vfs.c:87(smb_register_vfs) Successfully added vfs backend '/[Default VFS]/' [2012/01/04 16:04:20.854172, 10] smbd/vfs.c:48(vfs_find_backend_entry) vfs_find_backend_entry called for posixacl [2012/01/04 16:04:20.854221, 5] smbd/vfs.c:87(smb_register_vfs) Successfully added vfs backend 'posixacl' [2012/01/04 16:04:20.854269, 3] smbd/vfs.c:122(vfs_init_custom) Initialising custom vfs hooks from [/[Default VFS]/] [2012/01/04 16:04:20.854318, 10] smbd/vfs.c:48(vfs_find_backend_entry) vfs_find_backend_entry called for /[Default VFS]/ Successfully loaded vfs module [/[Default VFS]/] with the new modules system [2012/01/04 16:04:20.854379, 5] smbd/connection.c:142(claim_connection) claiming [IPC$] [2012/01/04 16:04:20.854502, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key DB220000010000004950 [2012/01/04 16:04:20.854563, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x7fa55fb172f0 [2012/01/04 16:04:20.854654, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key DB220000010000004950 [2012/01/04 16:04:20.854896, 10] smbd/service.c:163(set_conn_connectpath) set_conn_connectpath: service IPC$, connectpath = /tmp [2012/01/04 16:04:20.854952, 10] smbd/share_access.c:238(user_ok_token) user_ok_token: share IPC$ is ok for unix user heinz_sgv [2012/01/04 16:04:20.855002, 10] smbd/share_access.c:283(is_share_read_only_for_token) is_share_read_only_for_user: share IPC$ is read-only for unix user heinz_sgv [2012/01/04 16:04:20.855074, 10] lib/util_seaccess.c:58(se_map_generic) se_map_generic(): mapped mask 0x10000000 to 0x001f01ff [2012/01/04 16:04:20.855134, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.855182, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.855244, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.855291, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.855338, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.855406, 10] lib/gencache.c:345(gencache_get_data_blob) Returning valid cache entry: key = ACCT_POL/password history, value = 0 , timeout = Wed Jan 4 16:05:20 2012 [2012/01/04 16:04:20.855517, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.855573, 10] passdb/pdb_get_set.c:608(pdb_set_username) pdb_set_username: setting username heinz_sgv, was [2012/01/04 16:04:20.855623, 10] passdb/pdb_get_set.c:631(pdb_set_domain) pdb_set_domain: setting domain GVCC.NET, was [2012/01/04 16:04:20.855671, 10] passdb/pdb_get_set.c:654(pdb_set_nt_username) pdb_set_nt_username: setting nt username heinz_sgv, was [2012/01/04 16:04:20.855720, 10] passdb/pdb_get_set.c:677(pdb_set_fullname) pdb_set_full_name: setting full name Heinz Hölzl, was [2012/01/04 16:04:20.855770, 10] passdb/pdb_get_set.c:770(pdb_set_homedir) pdb_set_homedir: setting home dir \\fs.bahnhof.sgv\heinz_sgv, was [2012/01/04 16:04:20.855819, 10] passdb/pdb_get_set.c:746(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive k:, was NULL [2012/01/04 16:04:20.855869, 10] passdb/pdb_get_set.c:700(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2012/01/04 16:04:20.855920, 4] lib/substitute.c:504(automount_server) Home server: pagh.klingons.g [2012/01/04 16:04:20.855975, 10] passdb/pdb_get_set.c:723(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\pagh.klingons.g\heinz_sgv\profile, was [2012/01/04 16:04:20.856025, 10] passdb/pdb_get_set.c:813(pdb_set_workstations) pdb_set_workstations: setting workstations , was [2012/01/04 16:04:20.856074, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.856123, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.856171, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.856233, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.856280, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.856347, 10] lib/gencache.c:345(gencache_get_data_blob) Returning valid cache entry: key = ACCT_POL/password history, value = 0 , timeout = Wed Jan 4 16:05:20 2012 [2012/01/04 16:04:20.856455, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.856506, 10] passdb/pdb_get_set.c:537(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-3171465218-1814289097-3269728112-4696 [2012/01/04 16:04:20.856558, 10] passdb/pdb_compat.c:72(pdb_set_user_sid_from_rid) pdb_set_user_sid_from_rid: setting user sid S-1-5-21-3171465218-1814289097-3269728112-4696 from rid 4696 [2012/01/04 16:04:20.856623, 10] passdb/pdb_get_set.c:595(pdb_set_group_sid) pdb_set_group_sid: setting group sid S-1-5-21-3171465218-1814289097-3269728112-513 [2012/01/04 16:04:20.856683, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (1848, 100) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.856732, 5] auth/token_util.c:531(debug_nt_user_token) NT user token of user S-1-5-21-3171465218-1814289097-3269728112-4696 contains 14 SIDs SID[ 0]: S-1-5-21-3171465218-1814289097-3269728112-4696 SID[ 1]: S-1-5-21-3171465218-1814289097-3269728112-513 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-11 SID[ 5]: S-1-5-21-3171465218-1814289097-3269728112-1987 SID[ 6]: S-1-5-21-3171465218-1814289097-3269728112-512 SID[ 7]: S-1-5-21-3171465218-1814289097-3269728112-1999 SID[ 8]: S-1-5-32-544 SID[ 9]: S-1-22-1-1848 SID[ 10]: S-1-22-2-100 SID[ 11]: S-1-22-2-498 SID[ 12]: S-1-22-2-500 SID[ 13]: S-1-22-2-499 SE_PRIV 0xff0 0x0 0x0 0x0 [2012/01/04 16:04:20.856956, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 1848 Primary group is 100 and contains 4 supplementary groups Group[ 0]: 100 Group[ 1]: 498 Group[ 2]: 500 Group[ 3]: 499 [2012/01/04 16:04:20.857055, 5] smbd/uid.c:354(change_to_user) change_to_user uid=(0,1848) gid=(0,100) [2012/01/04 16:04:20.857112, 10] smbd/service.c:163(set_conn_connectpath) set_conn_connectpath: service IPC$, connectpath = /tmp [2012/01/04 16:04:20.857187, 3] smbd/service.c:1069(make_connection_snum) pagh (100.1.254.1) connect to service IPC$ initially as user heinz_sgv (uid=1848, gid=100) (pid 8923) [2012/01/04 16:04:20.857245, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.857293, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.857339, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.857401, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.857459, 3] smbd/reply.c:846(reply_tcon_and_X) tconX service=IPC$ [2012/01/04 16:04:20.858069, 10] lib/util_sock.c:726(read_smb_length_return_keepalive) got smb length of 126 [2012/01/04 16:04:20.858150, 6] smbd/process.c:1482(process_smb) got message type 0x0 of len 0x7e [2012/01/04 16:04:20.858201, 3] smbd/process.c:1485(process_smb) Transaction 3 of length 130 (0 toread) [2012/01/04 16:04:20.858250, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.858289, 5] lib/util.c:627(show_msg) size=126 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=8 smb_flg2=51201 smb_tid=1 smb_pid=8921 smb_uid=101 smb_mid=5 smt_wct=15 smb_vwv[ 0]= 58 (0x3A) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]=16644 (0x4104) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 58 (0x3A) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 126 (0x7E) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 16 (0x10) smb_bcc=61 [2012/01/04 16:04:20.858540, 10] ../lib/util/util.c:278(_dump_data) [0000] 00 44 20 03 00 5C 00 70 00 61 00 67 00 68 00 2E .D ..\.p .a.g.h.. [0010] 00 6B 00 6C 00 69 00 6E 00 67 00 6F 00 6E 00 73 .k.l.i.n .g.o.n.s [0020] 00 2E 00 67 00 76 00 63 00 63 00 2E 00 6E 00 65 ...g.v.c .c...n.e [0030] 00 74 00 5C 00 73 00 79 00 73 00 00 00 .t.\.s.y .s... [2012/01/04 16:04:20.858680, 3] smbd/process.c:1294(switch_message) switch message SMBtrans2 (pid 8923) conn 0x7fa55fb20bb0 [2012/01/04 16:04:20.858741, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (1848, 100) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.858792, 5] auth/token_util.c:531(debug_nt_user_token) NT user token of user S-1-5-21-3171465218-1814289097-3269728112-4696 contains 14 SIDs SID[ 0]: S-1-5-21-3171465218-1814289097-3269728112-4696 SID[ 1]: S-1-5-21-3171465218-1814289097-3269728112-513 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-11 SID[ 5]: S-1-5-21-3171465218-1814289097-3269728112-1987 SID[ 6]: S-1-5-21-3171465218-1814289097-3269728112-512 SID[ 7]: S-1-5-21-3171465218-1814289097-3269728112-1999 SID[ 8]: S-1-5-32-544 SID[ 9]: S-1-22-1-1848 SID[ 10]: S-1-22-2-100 SID[ 11]: S-1-22-2-498 SID[ 12]: S-1-22-2-500 SID[ 13]: S-1-22-2-499 SE_PRIV 0xff0 0x0 0x0 0x0 [2012/01/04 16:04:20.859004, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 1848 Primary group is 100 and contains 4 supplementary groups Group[ 0]: 100 Group[ 1]: 498 Group[ 2]: 500 Group[ 3]: 499 [2012/01/04 16:04:20.859103, 5] smbd/uid.c:354(change_to_user) change_to_user uid=(0,1848) gid=(0,100) [2012/01/04 16:04:20.859202, 4] smbd/vfs.c:721(vfs_ChDir) vfs_ChDir to /tmp [2012/01/04 16:04:20.859355, 10] smbd/trans2.c:7979(call_trans2getdfsreferral) call_trans2getdfsreferral [2012/01/04 16:04:20.859469, 10] smbd/msdfs.c:107(parse_dfs_path) parse_dfs_path: temp = |pagh.klingons.gvcc.net\sys| after trimming \'s [2012/01/04 16:04:20.859531, 10] smbd/msdfs.c:132(parse_dfs_path) parse_dfs_path: hostname: pagh.klingons.gvcc.net [2012/01/04 16:04:20.859579, 10] smbd/msdfs.c:174(parse_dfs_path) parse_dfs_path: servicename: sys [2012/01/04 16:04:20.859639, 3] smbd/msdfs.c:848(get_referred_path) get_referred_path: |sys| in dfs path \pagh.klingons.gvcc.net\sys is not a dfs root. [2012/01/04 16:04:20.859693, 3] smbd/error.c:80(error_packet_set) error packet at smbd/trans2.c(8001) cmd=50 (SMBtrans2) NT_STATUS_NOT_FOUND [2012/01/04 16:04:20.859798, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.859838, 5] lib/util.c:627(show_msg) size=35 smb_com=0x32 smb_rcls=37 smb_reh=2 smb_err=49152 smb_flg=136 smb_flg2=51203 smb_tid=1 smb_pid=8921 smb_uid=101 smb_mid=5 smt_wct=0 smb_bcc=0 [2012/01/04 16:04:20.860267, 10] lib/util_sock.c:726(read_smb_length_return_keepalive) got smb length of 35 [2012/01/04 16:04:20.860327, 6] smbd/process.c:1482(process_smb) got message type 0x0 of len 0x23 [2012/01/04 16:04:20.860376, 3] smbd/process.c:1485(process_smb) Transaction 4 of length 39 (0 toread) [2012/01/04 16:04:20.860424, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.860463, 5] lib/util.c:627(show_msg) size=35 smb_com=0x71 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=8 smb_flg2=51201 smb_tid=1 smb_pid=8921 smb_uid=101 smb_mid=6 smt_wct=0 smb_bcc=0 [2012/01/04 16:04:20.860597, 3] smbd/process.c:1294(switch_message) switch message SMBtdis (pid 8923) conn 0x7fa55fb20bb0 [2012/01/04 16:04:20.860649, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.860699, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.860746, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.860810, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.860903, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.860951, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.860998, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.861057, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.861106, 3] smbd/service.c:1250(close_cnum) pagh (100.1.254.1) closed connection to service IPC$ [2012/01/04 16:04:20.861161, 3] smbd/connection.c:31(yield_connection) Yielding connection to IPC$ [2012/01/04 16:04:20.861283, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key DB220000010000004950 [2012/01/04 16:04:20.861456, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x7fa55fb21080 [2012/01/04 16:04:20.861516, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key DB220000010000004950 [2012/01/04 16:04:20.861632, 4] smbd/vfs.c:721(vfs_ChDir) vfs_ChDir to / [2012/01/04 16:04:20.861687, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.861734, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.861781, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.861840, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.861905, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.861945, 5] lib/util.c:627(show_msg) size=35 smb_com=0x71 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51203 smb_tid=1 smb_pid=8921 smb_uid=101 smb_mid=6 smt_wct=0 smb_bcc=0 [2012/01/04 16:04:20.862481, 10] lib/util_sock.c:726(read_smb_length_return_keepalive) got smb length of 108 [2012/01/04 16:04:20.862539, 6] smbd/process.c:1482(process_smb) got message type 0x0 of len 0x6c [2012/01/04 16:04:20.862587, 3] smbd/process.c:1485(process_smb) Transaction 5 of length 112 (0 toread) [2012/01/04 16:04:20.862635, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.862673, 5] lib/util.c:627(show_msg) size=108 smb_com=0x75 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=8 smb_flg2=51201 smb_tid=65535 smb_pid=8921 smb_uid=101 smb_mid=7 smt_wct=4 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 8 (0x8) smb_vwv[ 3]= 1 (0x1) smb_bcc=65 [2012/01/04 16:04:20.862833, 10] ../lib/util/util.c:278(_dump_data) [0000] 00 5C 00 5C 00 50 00 41 00 47 00 48 00 2E 00 4B .\.\.P.A .G.H...K [0010] 00 4C 00 49 00 4E 00 47 00 4F 00 4E 00 53 00 2E .L.I.N.G .O.N.S.. [0020] 00 47 00 56 00 43 00 43 00 2E 00 4E 00 45 00 54 .G.V.C.C ...N.E.T [0030] 00 5C 00 53 00 59 00 53 00 00 00 3F 3F 3F 3F 3F .\.S.Y.S ...????? [0040] 00 . [2012/01/04 16:04:20.862985, 3] smbd/process.c:1294(switch_message) switch message SMBtconX (pid 8923) conn 0x0 [2012/01/04 16:04:20.863036, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.863084, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.863131, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.863192, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.863250, 4] smbd/reply.c:767(reply_tcon_and_X) Client requested device type [?????] for share [SYS] [2012/01/04 16:04:20.863323, 5] smbd/service.c:1226(make_connection) making a connection to 'normal' service sys [2012/01/04 16:04:20.863379, 10] smbd/share_access.c:238(user_ok_token) user_ok_token: share sys is ok for unix user heinz_sgv [2012/01/04 16:04:20.863447, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.863496, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.863544, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.863593, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.863639, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.863718, 10] lib/gencache.c:345(gencache_get_data_blob) Returning valid cache entry: key = ACCT_POL/password history, value = 0 , timeout = Wed Jan 4 16:05:20 2012 [2012/01/04 16:04:20.863831, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.863892, 10] passdb/pdb_get_set.c:608(pdb_set_username) pdb_set_username: setting username heinz_sgv, was [2012/01/04 16:04:20.863942, 10] passdb/pdb_get_set.c:631(pdb_set_domain) pdb_set_domain: setting domain GVCC.NET, was [2012/01/04 16:04:20.863990, 10] passdb/pdb_get_set.c:654(pdb_set_nt_username) pdb_set_nt_username: setting nt username heinz_sgv, was [2012/01/04 16:04:20.864038, 10] passdb/pdb_get_set.c:677(pdb_set_fullname) pdb_set_full_name: setting full name Heinz Hölzl, was [2012/01/04 16:04:20.864087, 10] passdb/pdb_get_set.c:770(pdb_set_homedir) pdb_set_homedir: setting home dir \\fs.bahnhof.sgv\heinz_sgv, was [2012/01/04 16:04:20.864136, 10] passdb/pdb_get_set.c:746(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive k:, was NULL [2012/01/04 16:04:20.864289, 10] passdb/pdb_get_set.c:700(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2012/01/04 16:04:20.864344, 4] lib/substitute.c:504(automount_server) Home server: pagh.klingons.g [2012/01/04 16:04:20.864416, 10] passdb/pdb_get_set.c:723(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\pagh.klingons.g\heinz_sgv\profile, was [2012/01/04 16:04:20.864467, 10] passdb/pdb_get_set.c:813(pdb_set_workstations) pdb_set_workstations: setting workstations , was [2012/01/04 16:04:20.864557, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.864610, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.864658, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.864705, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.864753, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.864821, 10] lib/gencache.c:345(gencache_get_data_blob) Returning valid cache entry: key = ACCT_POL/password history, value = 0 , timeout = Wed Jan 4 16:05:20 2012 [2012/01/04 16:04:20.864930, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.864980, 10] passdb/pdb_get_set.c:537(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-3171465218-1814289097-3269728112-4696 [2012/01/04 16:04:20.865032, 10] passdb/pdb_compat.c:72(pdb_set_user_sid_from_rid) pdb_set_user_sid_from_rid: setting user sid S-1-5-21-3171465218-1814289097-3269728112-4696 from rid 4696 [2012/01/04 16:04:20.865100, 10] passdb/pdb_get_set.c:595(pdb_set_group_sid) pdb_set_group_sid: setting group sid S-1-5-21-3171465218-1814289097-3269728112-513 [2012/01/04 16:04:20.865155, 5] lib/username.c:133(Get_Pwnam_alloc) Finding user heinz_sgv [2012/01/04 16:04:20.865202, 5] lib/username.c:77(Get_Pwnam_internals) Trying _Get_Pwnam(), username as lowercase is heinz_sgv [2012/01/04 16:04:20.865253, 5] lib/username.c:110(Get_Pwnam_internals) Get_Pwnam_internals did find user [heinz_sgv]! [2012/01/04 16:04:20.865339, 10] smbd/service.c:163(set_conn_connectpath) set_conn_connectpath: service sys, connectpath = /samba/sys [2012/01/04 16:04:20.865389, 3] smbd/service.c:807(make_connection_snum) Connect path is '/samba/sys' for service [sys] [2012/01/04 16:04:20.865453, 10] lib/util_seaccess.c:58(se_map_generic) se_map_generic(): mapped mask 0x10000000 to 0x001f01ff [2012/01/04 16:04:20.865510, 3] smbd/vfs.c:97(vfs_init_default) Initialising default vfs hooks [2012/01/04 16:04:20.865558, 3] smbd/vfs.c:122(vfs_init_custom) Initialising custom vfs hooks from [/[Default VFS]/] [2012/01/04 16:04:20.865607, 10] smbd/vfs.c:48(vfs_find_backend_entry) vfs_find_backend_entry called for /[Default VFS]/ Successfully loaded vfs module [/[Default VFS]/] with the new modules system [2012/01/04 16:04:20.865900, 5] smbd/connection.c:142(claim_connection) claiming [sys] [2012/01/04 16:04:20.866018, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key DB220000010000007379 [2012/01/04 16:04:20.866074, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x7fa55fb172f0 [2012/01/04 16:04:20.866162, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key DB220000010000007379 [2012/01/04 16:04:20.866301, 10] smbd/service.c:163(set_conn_connectpath) set_conn_connectpath: service sys, connectpath = /samba/sys [2012/01/04 16:04:20.866355, 10] smbd/share_access.c:238(user_ok_token) user_ok_token: share sys is ok for unix user heinz_sgv [2012/01/04 16:04:20.866404, 10] smbd/share_access.c:283(is_share_read_only_for_token) is_share_read_only_for_user: share sys is read-write for unix user heinz_sgv [2012/01/04 16:04:20.866463, 10] lib/util_seaccess.c:58(se_map_generic) se_map_generic(): mapped mask 0x10000000 to 0x001f01ff [2012/01/04 16:04:20.866522, 10] lib/util_seaccess.c:58(se_map_generic) se_map_generic(): mapped mask 0x10000000 to 0x001f01ff [2012/01/04 16:04:20.866581, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.866643, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.866691, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.866739, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.866786, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.866857, 10] lib/gencache.c:345(gencache_get_data_blob) Returning valid cache entry: key = ACCT_POL/password history, value = 0 , timeout = Wed Jan 4 16:05:20 2012 [2012/01/04 16:04:20.866967, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.867023, 10] passdb/pdb_get_set.c:608(pdb_set_username) pdb_set_username: setting username heinz_sgv, was [2012/01/04 16:04:20.867073, 10] passdb/pdb_get_set.c:631(pdb_set_domain) pdb_set_domain: setting domain GVCC.NET, was [2012/01/04 16:04:20.867122, 10] passdb/pdb_get_set.c:654(pdb_set_nt_username) pdb_set_nt_username: setting nt username heinz_sgv, was [2012/01/04 16:04:20.867171, 10] passdb/pdb_get_set.c:677(pdb_set_fullname) pdb_set_full_name: setting full name Heinz Hölzl, was [2012/01/04 16:04:20.867220, 10] passdb/pdb_get_set.c:770(pdb_set_homedir) pdb_set_homedir: setting home dir \\fs.bahnhof.sgv\heinz_sgv, was [2012/01/04 16:04:20.867269, 10] passdb/pdb_get_set.c:746(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive k:, was NULL [2012/01/04 16:04:20.867320, 10] passdb/pdb_get_set.c:700(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2012/01/04 16:04:20.867370, 4] lib/substitute.c:504(automount_server) Home server: pagh.klingons.g [2012/01/04 16:04:20.867426, 10] passdb/pdb_get_set.c:723(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\pagh.klingons.g\heinz_sgv\profile, was [2012/01/04 16:04:20.867476, 10] passdb/pdb_get_set.c:813(pdb_set_workstations) pdb_set_workstations: setting workstations , was [2012/01/04 16:04:20.867525, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.867574, 3] smbd/uid.c:429(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2012/01/04 16:04:20.867623, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2012/01/04 16:04:20.867671, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.867718, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.867785, 10] lib/gencache.c:345(gencache_get_data_blob) Returning valid cache entry: key = ACCT_POL/password history, value = 0 , timeout = Wed Jan 4 16:05:20 2012 [2012/01/04 16:04:20.867894, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.867944, 10] passdb/pdb_get_set.c:537(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-3171465218-1814289097-3269728112-4696 [2012/01/04 16:04:20.867996, 10] passdb/pdb_compat.c:72(pdb_set_user_sid_from_rid) pdb_set_user_sid_from_rid: setting user sid S-1-5-21-3171465218-1814289097-3269728112-4696 from rid 4696 [2012/01/04 16:04:20.868060, 10] passdb/pdb_get_set.c:595(pdb_set_group_sid) pdb_set_group_sid: setting group sid S-1-5-21-3171465218-1814289097-3269728112-513 [2012/01/04 16:04:20.868120, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (1848, 100) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.868169, 5] auth/token_util.c:531(debug_nt_user_token) NT user token of user S-1-5-21-3171465218-1814289097-3269728112-4696 contains 14 SIDs SID[ 0]: S-1-5-21-3171465218-1814289097-3269728112-4696 SID[ 1]: S-1-5-21-3171465218-1814289097-3269728112-513 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-11 SID[ 5]: S-1-5-21-3171465218-1814289097-3269728112-1987 SID[ 6]: S-1-5-21-3171465218-1814289097-3269728112-512 SID[ 7]: S-1-5-21-3171465218-1814289097-3269728112-1999 SID[ 8]: S-1-5-32-544 SID[ 9]: S-1-22-1-1848 SID[ 10]: S-1-22-2-100 SID[ 11]: S-1-22-2-498 SID[ 12]: S-1-22-2-500 SID[ 13]: S-1-22-2-499 SE_PRIV 0xff0 0x0 0x0 0x0 [2012/01/04 16:04:20.868409, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 1848 Primary group is 100 and contains 4 supplementary groups Group[ 0]: 100 Group[ 1]: 498 Group[ 2]: 500 Group[ 3]: 499 [2012/01/04 16:04:20.868508, 5] smbd/uid.c:354(change_to_user) change_to_user uid=(0,1848) gid=(0,100) [2012/01/04 16:04:20.868567, 10] smbd/service.c:163(set_conn_connectpath) set_conn_connectpath: service sys, connectpath = /samba/sys [2012/01/04 16:04:20.868634, 1] smbd/service.c:1069(make_connection_snum) pagh (100.1.254.1) connect to service sys initially as user heinz_sgv (uid=1848, gid=100) (pid 8923) [2012/01/04 16:04:20.868691, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.868739, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.868786, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.868848, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.868905, 3] smbd/reply.c:846(reply_tcon_and_X) tconX service=SYS [2012/01/04 16:04:20.869382, 10] lib/util_sock.c:726(read_smb_length_return_keepalive) got smb length of 94 [2012/01/04 16:04:20.869446, 6] smbd/process.c:1482(process_smb) got message type 0x0 of len 0x5e [2012/01/04 16:04:20.869494, 3] smbd/process.c:1485(process_smb) Transaction 6 of length 98 (0 toread) [2012/01/04 16:04:20.869543, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.869586, 5] lib/util.c:627(show_msg) size=94 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=8 smb_flg2=51201 smb_tid=1 smb_pid=8921 smb_uid=101 smb_mid=8 smt_wct=15 smb_vwv[ 0]= 26 (0x1A) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]=16644 (0x4104) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 26 (0x1A) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 94 (0x5E) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 5 (0x5) smb_bcc=29 [2012/01/04 16:04:20.869837, 10] ../lib/util/util.c:278(_dump_data) [0000] 00 44 20 01 01 00 00 00 00 5C 00 75 00 73 00 65 .D ..... .\.u.s.e [0010] 00 72 00 5C 00 61 00 70 00 6C 00 00 00 .r.\.a.p .l... [2012/01/04 16:04:20.869927, 3] smbd/process.c:1294(switch_message) switch message SMBtrans2 (pid 8923) conn 0x7fa55fb20bb0 [2012/01/04 16:04:20.869983, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (1848, 100) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.870032, 5] auth/token_util.c:531(debug_nt_user_token) NT user token of user S-1-5-21-3171465218-1814289097-3269728112-4696 contains 14 SIDs SID[ 0]: S-1-5-21-3171465218-1814289097-3269728112-4696 SID[ 1]: S-1-5-21-3171465218-1814289097-3269728112-513 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-11 SID[ 5]: S-1-5-21-3171465218-1814289097-3269728112-1987 SID[ 6]: S-1-5-21-3171465218-1814289097-3269728112-512 SID[ 7]: S-1-5-21-3171465218-1814289097-3269728112-1999 SID[ 8]: S-1-5-32-544 SID[ 9]: S-1-22-1-1848 SID[ 10]: S-1-22-2-100 SID[ 11]: S-1-22-2-498 SID[ 12]: S-1-22-2-500 SID[ 13]: S-1-22-2-499 SE_PRIV 0xff0 0x0 0x0 0x0 [2012/01/04 16:04:20.870247, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 1848 Primary group is 100 and contains 4 supplementary groups Group[ 0]: 100 Group[ 1]: 498 Group[ 2]: 500 Group[ 3]: 499 [2012/01/04 16:04:20.870344, 5] smbd/uid.c:354(change_to_user) change_to_user uid=(0,1848) gid=(0,100) [2012/01/04 16:04:20.870397, 4] smbd/vfs.c:721(vfs_ChDir) vfs_ChDir to /samba/sys [2012/01/04 16:04:20.870493, 3] smbd/trans2.c:5083(call_trans2qfilepathinfo) call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 257 [2012/01/04 16:04:20.870643, 5] smbd/filename.c:169(unix_convert) unix_convert called on file "user/apl" [2012/01/04 16:04:20.870723, 10] smbd/statcache.c:236(stat_cache_lookup) stat_cache_lookup: lookup failed for name [USER/APL] [2012/01/04 16:04:20.870786, 10] smbd/statcache.c:236(stat_cache_lookup) stat_cache_lookup: lookup failed for name [USER] [2012/01/04 16:04:20.870837, 5] smbd/filename.c:328(unix_convert) unix_convert begin: name = user/apl, dirpath = , start = user/apl [2012/01/04 16:04:20.870921, 5] smbd/statcache.c:138(stat_cache_add) stat_cache_add: Added entry (7fa55fb349c0:size 8) USER/APL -> user/apl [2012/01/04 16:04:20.870971, 5] smbd/filename.c:351(unix_convert) conversion of base_name finished user/apl -> user/apl [2012/01/04 16:04:20.871033, 3] smbd/vfs.c:851(check_reduced_name) check_reduced_name [user/apl] [/samba/sys] [2012/01/04 16:04:20.871094, 10] smbd/vfs.c:938(check_reduced_name) check_reduced_name realpath [user/apl] -> [/samba/sys/user/apl] [2012/01/04 16:04:20.871143, 3] smbd/vfs.c:1008(check_reduced_name) check_reduced_name: user/apl reduced to /samba/sys/user/apl [2012/01/04 16:04:20.871262, 10] locking/locking.c:926(fetch_share_mode_unlocked) fetch_share_mode_unlocked: no share_mode record around (file not open) [2012/01/04 16:04:20.871457, 3] smbd/trans2.c:5209(call_trans2qfilepathinfo) call_trans2qfilepathinfo user/apl (fnum = -1) level=257 call=5 total_data=0 [2012/01/04 16:04:20.871549, 5] smbd/trans2.c:4180(smbd_do_qfilepathinfo) smbd_do_qfilepathinfo: user/apl (fnum = -1) level=257 max_data=16644 [2012/01/04 16:04:20.871613, 8] smbd/dosmode.c:613(dos_mode) dos_mode: user/apl [2012/01/04 16:04:20.871676, 8] smbd/dosmode.c:207(dos_mode_from_sbuf) dos_mode_from_sbuf returning d [2012/01/04 16:04:20.871728, 8] smbd/dosmode.c:666(dos_mode) dos_mode returning d [2012/01/04 16:04:20.871841, 10] smbd/trans2.c:4412(smbd_do_qfilepathinfo) smbd_do_qfilepathinfo: SMB_QUERY_FILE_BASIC_INFO [2012/01/04 16:04:20.871891, 5] smbd/trans2.c:4425(smbd_do_qfilepathinfo) SMB_QFBI - create: Wed Jan 4 16:03:10 2012 access: Wed Jan 4 16:04:20 2012 write: Wed Jan 4 16:03:10 2012 change: Wed Jan 4 16:03:10 2012 mode: 10 [2012/01/04 16:04:20.872340, 9] smbd/trans2.c:910(send_trans2_replies) t2_rep: params_sent_thistime = 2, data_sent_thistime = 36, useable_space = 131010 [2012/01/04 16:04:20.872397, 9] smbd/trans2.c:912(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 36, paramsize = 2, datasize = 36 [2012/01/04 16:04:20.872447, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.872487, 5] lib/util.c:627(show_msg) size=96 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51203 smb_tid=1 smb_pid=8921 smb_uid=101 smb_mid=8 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 36 (0x24) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 36 (0x24) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=41 [2012/01/04 16:04:20.872696, 10] ../lib/util/util.c:278(_dump_data) [0000] 00 00 00 00 00 00 8B FA F8 F1 CA CC 01 00 B2 B3 ........ ........ [0010] 22 F2 CA CC 01 00 8B FA F8 F1 CA CC 01 00 8B FA "....... ........ [0020] F8 F1 CA CC 01 10 00 00 00 ........ . [2012/01/04 16:04:20.873429, 10] lib/util_sock.c:726(read_smb_length_return_keepalive) got smb length of 116 [2012/01/04 16:04:20.873491, 6] smbd/process.c:1482(process_smb) got message type 0x0 of len 0x74 [2012/01/04 16:04:20.873542, 3] smbd/process.c:1485(process_smb) Transaction 7 of length 120 (0 toread) [2012/01/04 16:04:20.873591, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.873629, 5] lib/util.c:627(show_msg) size=116 smb_com=0x7 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=8 smb_flg2=51201 smb_tid=1 smb_pid=8921 smb_uid=101 smb_mid=9 smt_wct=1 smb_vwv[ 0]= 22 (0x16) smb_bcc=79 [2012/01/04 16:04:20.873782, 10] ../lib/util/util.c:278(_dump_data) [0000] 04 5C 00 75 00 73 00 65 00 72 00 5C 00 61 00 70 .\.u.s.e .r.\.a.p [0010] 00 6C 00 5C 00 6E 00 65 00 77 00 64 00 69 00 72 .l.\.n.e .w.d.i.r [0020] 00 00 00 04 00 5C 00 75 00 73 00 65 00 72 00 5C .....\.u .s.e.r.\ [0030] 00 61 00 70 00 6C 00 5C 00 72 00 65 00 6E 00 61 .a.p.l.\ .r.e.n.a [0040] 00 6D 00 65 00 64 00 64 00 69 00 72 00 00 00 .m.e.d.d .i.r... [2012/01/04 16:04:20.873941, 3] smbd/process.c:1294(switch_message) switch message SMBmv (pid 8923) conn 0x7fa55fb20bb0 [2012/01/04 16:04:20.873992, 4] smbd/uid.c:257(change_to_user) change_to_user: Skipping user change - already user [2012/01/04 16:04:20.874090, 5] smbd/filename.c:169(unix_convert) unix_convert called on file "user/apl/newdir" [2012/01/04 16:04:20.874151, 10] smbd/statcache.c:236(stat_cache_lookup) stat_cache_lookup: lookup failed for name [USER/APL/NEWDIR] [2012/01/04 16:04:20.874202, 10] smbd/statcache.c:275(stat_cache_lookup) stat_cache_lookup: lookup succeeded for name [USER/APL] -> [user/apl] [2012/01/04 16:04:20.874262, 5] smbd/filename.c:328(unix_convert) unix_convert begin: name = user/apl/newdir, dirpath = user/apl, start = newdir [2012/01/04 16:04:20.874320, 5] smbd/statcache.c:138(stat_cache_add) stat_cache_add: Added entry (7fa55fb33fb0:size f) USER/APL/NEWDIR -> user/apl/newdir [2012/01/04 16:04:20.874369, 5] smbd/filename.c:351(unix_convert) conversion of base_name finished user/apl/newdir -> user/apl/newdir [2012/01/04 16:04:20.874420, 3] smbd/vfs.c:851(check_reduced_name) check_reduced_name [user/apl/newdir] [/samba/sys] [2012/01/04 16:04:20.874488, 10] smbd/vfs.c:938(check_reduced_name) check_reduced_name realpath [user/apl/newdir] -> [/samba/sys/user/apl/newdir] [2012/01/04 16:04:20.874538, 3] smbd/vfs.c:1008(check_reduced_name) check_reduced_name: user/apl/newdir reduced to /samba/sys/user/apl/newdir [2012/01/04 16:04:20.874586, 5] smbd/filename.c:169(unix_convert) unix_convert called on file "user/apl/renameddir" [2012/01/04 16:04:20.874636, 10] smbd/statcache.c:236(stat_cache_lookup) stat_cache_lookup: lookup failed for name [USER/APL/RENAMEDDIR] [2012/01/04 16:04:20.874684, 10] smbd/statcache.c:275(stat_cache_lookup) stat_cache_lookup: lookup succeeded for name [USER/APL] -> [user/apl] [2012/01/04 16:04:20.874736, 5] smbd/filename.c:328(unix_convert) unix_convert begin: name = user/apl/renameddir, dirpath = user/apl, start = renameddir [2012/01/04 16:04:20.874805, 10] smbd/mangle_hash2.c:239(is_mangled) is_mangled renameddir ? [2012/01/04 16:04:20.874867, 10] smbd/mangle_hash2.c:178(is_mangled_component) is_mangled_component renameddir (len 10) ? [2012/01/04 16:04:20.874922, 10] smbd/mangle_hash2.c:239(is_mangled) is_mangled renameddir ? [2012/01/04 16:04:20.874970, 10] smbd/mangle_hash2.c:178(is_mangled_component) is_mangled_component renameddir (len 10) ? [2012/01/04 16:04:20.875165, 10] smbd/mangle_hash2.c:239(is_mangled) is_mangled renameddir ? [2012/01/04 16:04:20.875215, 10] smbd/mangle_hash2.c:178(is_mangled_component) is_mangled_component renameddir (len 10) ? [2012/01/04 16:04:20.875263, 5] smbd/filename.c:650(unix_convert) New file renameddir [2012/01/04 16:04:20.875311, 3] smbd/vfs.c:851(check_reduced_name) check_reduced_name [user/apl/renameddir] [/samba/sys] [2012/01/04 16:04:20.875380, 10] smbd/vfs.c:938(check_reduced_name) check_reduced_name realpath [user/apl/renameddir] -> [/samba/sys/user/apl/renameddir] [2012/01/04 16:04:20.875429, 3] smbd/vfs.c:1008(check_reduced_name) check_reduced_name: user/apl/renameddir reduced to /samba/sys/user/apl/renameddir [2012/01/04 16:04:20.875491, 3] smbd/reply.c:6327(reply_mv) reply_mv : user/apl/newdir -> user/apl/renameddir [2012/01/04 16:04:20.875593, 3] smbd/reply.c:6012(rename_internals) rename_internals: case_sensitive = 0, case_preserve = 1, short case preserve = 1, directory = user/apl/newdir, newname = user/apl/renameddir, last_component_dest = renameddir [2012/01/04 16:04:20.875692, 10] smbd/open.c:3407(create_file_default) create_file: access_mask = 0x10000 file_attributes = 0x0, share_access = 0x3, create_disposition = 0x1 create_options = 0x1 oplock_request = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = user/apl/newdir [2012/01/04 16:04:20.875762, 3] smbd/vfs.c:851(check_reduced_name) check_reduced_name [user/apl/newdir] [/samba/sys] [2012/01/04 16:04:20.875822, 10] smbd/vfs.c:938(check_reduced_name) check_reduced_name realpath [user/apl/newdir] -> [/samba/sys/user/apl/newdir] [2012/01/04 16:04:20.875871, 3] smbd/vfs.c:1008(check_reduced_name) check_reduced_name: user/apl/newdir reduced to /samba/sys/user/apl/newdir [2012/01/04 16:04:20.875932, 10] smbd/open.c:2925(create_file_unixpath) create_file_unixpath: access_mask = 0x10000 file_attributes = 0x0, share_access = 0x3, create_disposition = 0x1 create_options = 0x1 oplock_request = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = user/apl/newdir [2012/01/04 16:04:20.876012, 5] smbd/open.c:2447(open_directory) open_directory: opening directory user/apl/newdir, access_mask = 0x10000, share_access = 0x3 create_options = 0x1, create_disposition = 0x1, file_attributes = 0x0 [2012/01/04 16:04:20.876096, 10] smbd/posix_acls.c:3479(posix_get_nt_acl) posix_get_nt_acl: called for file user/apl/newdir [2012/01/04 16:04:20.876553, 10] smbd/posix_acls.c:2605(canonicalise_acl) canonicalise_acl: Access ace entries before arrange : [2012/01/04 16:04:20.876628, 10] smbd/posix_acls.c:2618(canonicalise_acl) canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms --- [2012/01/04 16:04:20.876687, 10] smbd/posix_acls.c:2618(canonicalise_acl) canon_ace index 1. Type = allow SID = S-1-5-21-3171465218-1814289097-3269728112-513 gid 100 (users) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-x [2012/01/04 16:04:20.877125, 10] smbd/posix_acls.c:2618(canonicalise_acl) canon_ace index 2. Type = allow SID = S-1-5-21-3171465218-1814289097-3269728112-4696 uid 1848 (heinz_sgv) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx [2012/01/04 16:04:20.881571, 10] smbd/posix_acls.c:841(print_canon_ace_list) print_canon_ace_list: canonicalise_acl: ace entries after arrange canon_ace index 0. Type = allow SID = S-1-5-21-3171465218-1814289097-3269728112-4696 uid 1848 (heinz_sgv) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx canon_ace index 1. Type = allow SID = S-1-5-21-3171465218-1814289097-3269728112-513 gid 100 (users) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-x canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms --- [2012/01/04 16:04:20.883934, 10] smbd/posix_acls.c:1117(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff [2012/01/04 16:04:20.883988, 10] smbd/posix_acls.c:1117(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 140 to (NT) 1200a9 [2012/01/04 16:04:20.884036, 10] smbd/posix_acls.c:1117(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 0 to (NT) 0 [2012/01/04 16:04:20.884108, 10] smbd/open.c:110(smbd_check_open_rights) smbd_check_open_rights: file user/apl/newdir requesting 0x10000 returning 0x10000 (NT_STATUS_OK) [2012/01/04 16:04:20.884262, 5] smbd/files.c:119(file_new) allocated file structure 2223, fnum = 6319 (1 used) [2012/01/04 16:04:20.884349, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 05FE0000000000000660 [2012/01/04 16:04:20.884443, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x7fa55fb16990 [2012/01/04 16:04:20.884528, 10] locking/locking.c:726(unparse_share_modes) unparse_share_modes: del: 0, owrt: Mi 04 Jan 2012 11:20:38 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2012/01/04 16:04:20.884653, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 8923, share_access = 0x3, private_options = 0x1, access_mask = 0x10080, mid = 0x0, type= 0x0, gen_id = 1, uid = 1848, flags = 0, file_id fe05:6006:0 [2012/01/04 16:04:20.884941, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 05FE0000000000000660 [2012/01/04 16:04:20.885038, 10] smbd/open.c:3232(create_file_unixpath) create_file_unixpath: info=1 [2012/01/04 16:04:20.885089, 10] smbd/open.c:3478(create_file_default) create_file: info=1 [2012/01/04 16:04:20.885147, 3] smbd/vfs.c:851(check_reduced_name) check_reduced_name [user/apl/renameddir] [/samba/sys] [2012/01/04 16:04:20.885229, 10] smbd/vfs.c:938(check_reduced_name) check_reduced_name realpath [user/apl/renameddir] -> [/samba/sys/user/apl/renameddir] [2012/01/04 16:04:20.885280, 3] smbd/vfs.c:1008(check_reduced_name) check_reduced_name: user/apl/renameddir reduced to /samba/sys/user/apl/renameddir [2012/01/04 16:04:20.885349, 8] smbd/dosmode.c:613(dos_mode) dos_mode: user/apl/newdir [2012/01/04 16:04:20.885402, 8] smbd/dosmode.c:207(dos_mode_from_sbuf) dos_mode_from_sbuf returning d [2012/01/04 16:04:20.885455, 8] smbd/dosmode.c:666(dos_mode) dos_mode returning d [2012/01/04 16:04:20.885519, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 05FE0000000000000660 [2012/01/04 16:04:20.885574, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x7fa55fb216f0 [2012/01/04 16:04:20.885623, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Mi 04 Jan 2012 11:20:38 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2012/01/04 16:04:20.885711, 10] locking/locking.c:655(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 8923, share_access = 0x3, private_options = 0x1, access_mask = 0x10080, mid = 0x0, type= 0x0, gen_id = 1, uid = 1848, flags = 0, file_id fe05:6006:0 [2012/01/04 16:04:20.885888, 3] smbd/reply.c:5847(rename_internals_fsp) rename_internals_fsp: succeeded doing rename on user/apl/newdir -> user/apl/renameddir [2012/01/04 16:04:20.885947, 8] smbd/dosmode.c:613(dos_mode) dos_mode: user/apl/renameddir [2012/01/04 16:04:20.885997, 8] smbd/dosmode.c:207(dos_mode_from_sbuf) dos_mode_from_sbuf returning d [2012/01/04 16:04:20.886046, 8] smbd/dosmode.c:666(dos_mode) dos_mode returning d [2012/01/04 16:04:20.886095, 10] smbd/dosmode.c:701(file_set_dosmode) file_set_dosmode: setting dos mode 0x30 on file user/apl/renameddir [2012/01/04 16:04:20.886172, 8] smbd/dosmode.c:613(dos_mode) dos_mode: user/apl/renameddir [2012/01/04 16:04:20.886222, 8] smbd/dosmode.c:207(dos_mode_from_sbuf) dos_mode_from_sbuf returning d [2012/01/04 16:04:20.886271, 8] smbd/dosmode.c:666(dos_mode) dos_mode returning d [2012/01/04 16:04:20.886321, 3] smbd/dosmode.c:166(unix_mode) unix_mode(user/apl/renameddir) returning 0770 [2012/01/04 16:04:20.886456, 10] smbd/notify_internal.c:890(notify_trigger) notify_trigger called action=0x4, filter=0x2, path=/samba/sys/user/apl/newdir [2012/01/04 16:04:20.886518, 10] smbd/notify_internal.c:189(notify_load) notify_load: [2012/01/04 16:04:20.886580, 1] ../librpc/ndr/ndr.c:214(ndr_print_debug) notify->array: struct notify_array num_depths : 0x00000000 (0) depth: ARRAY(0) [2012/01/04 16:04:20.886759, 10] smbd/notify_internal.c:890(notify_trigger) notify_trigger called action=0x5, filter=0x2, path=/samba/sys/user/apl/renameddir [2012/01/04 16:04:20.886812, 10] smbd/reply.c:5539(rename_open_files) rename_open_files: renaming file fnum 6319 (file_id fe05:6006:0) from user/apl/newdir -> user/apl/renameddir [2012/01/04 16:04:20.886872, 10] locking/locking.c:956(rename_share_filename) rename_share_filename: servicepath /samba/sys newname user/apl/renameddir [2012/01/04 16:04:20.886923, 10] locking/locking.c:996(rename_share_filename) rename_share_filename: msg_len = 56 [2012/01/04 16:04:20.886975, 10] locking/locking.c:726(unparse_share_modes) unparse_share_modes: del: 0, owrt: Mi 04 Jan 2012 11:20:38 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2012/01/04 16:04:20.887060, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 8923, share_access = 0x3, private_options = 0x1, access_mask = 0x10080, mid = 0x0, type= 0x0, gen_id = 1, uid = 1848, flags = 0, file_id fe05:6006:0 [2012/01/04 16:04:20.887129, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 05FE0000000000000660 [2012/01/04 16:04:20.887213, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 05FE0000000000000660 [2012/01/04 16:04:20.887267, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x7fa55fb216f0 [2012/01/04 16:04:20.887316, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Mi 04 Jan 2012 11:20:38 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2012/01/04 16:04:20.887403, 10] locking/locking.c:655(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 8923, share_access = 0x3, private_options = 0x1, access_mask = 0x10080, mid = 0x0, type= 0x0, gen_id = 1, uid = 1848, flags = 0, file_id fe05:6006:0 [2012/01/04 16:04:20.887459, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 05FE0000000000000660 [2012/01/04 16:04:20.887547, 5] smbd/files.c:497(file_free) freed files structure 6319 (0 used) [2012/01/04 16:04:20.887600, 3] smbd/reply.c:6075(rename_internals) rename_internals: Error NT_STATUS_OK rename user/apl/newdir -> user/apl/renameddir [2012/01/04 16:04:20.887664, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.887704, 5] lib/util.c:627(show_msg) size=35 smb_com=0x7 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51203 smb_tid=1 smb_pid=8921 smb_uid=101 smb_mid=9 smt_wct=0 smb_bcc=0 [2012/01/04 16:04:20.888449, 10] lib/util_sock.c:726(read_smb_length_return_keepalive) got smb length of 35 [2012/01/04 16:04:20.888536, 6] smbd/process.c:1482(process_smb) got message type 0x0 of len 0x23 [2012/01/04 16:04:20.888588, 3] smbd/process.c:1485(process_smb) Transaction 8 of length 39 (0 toread) [2012/01/04 16:04:20.888638, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.888678, 5] lib/util.c:627(show_msg) size=35 smb_com=0x71 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=8 smb_flg2=51201 smb_tid=1 smb_pid=8921 smb_uid=101 smb_mid=10 smt_wct=0 smb_bcc=0 [2012/01/04 16:04:20.888816, 3] smbd/process.c:1294(switch_message) switch message SMBtdis (pid 8923) conn 0x7fa55fb20bb0 [2012/01/04 16:04:20.888869, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.888920, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.888970, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.889040, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.889103, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.889151, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.889197, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.889257, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.889305, 1] smbd/service.c:1250(close_cnum) pagh (100.1.254.1) closed connection to service sys [2012/01/04 16:04:20.889365, 3] smbd/connection.c:31(yield_connection) Yielding connection to sys [2012/01/04 16:04:20.889491, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key DB220000010000007379 [2012/01/04 16:04:20.889561, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x7fa55fb21080 [2012/01/04 16:04:20.889619, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key DB220000010000007379 [2012/01/04 16:04:20.889735, 4] smbd/vfs.c:721(vfs_ChDir) vfs_ChDir to / [2012/01/04 16:04:20.889792, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.889840, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.889901, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.889961, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.890028, 5] lib/messages.c:329(messaging_deregister) Deregistering messaging pointer for type 784 - private_data=0x7fa55fa8c670 [2012/01/04 16:04:20.890157, 5] lib/util.c:617(show_msg) [2012/01/04 16:04:20.890198, 5] lib/util.c:627(show_msg) size=35 smb_com=0x71 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51203 smb_tid=1 smb_pid=8921 smb_uid=101 smb_mid=10 smt_wct=0 smb_bcc=0 [2012/01/04 16:04:20.894546, 5] lib/util_sock.c:462(read_fd_with_timeout) read_fd_with_timeout: blocking read. EOF from client. [2012/01/04 16:04:20.894648, 10] smbd/process.c:286(receive_smb_raw_talloc) receive_smb_raw: NT_STATUS_END_OF_FILE [2012/01/04 16:04:20.894704, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2012/01/04 16:04:20.894753, 5] auth/token_util.c:525(debug_nt_user_token) NT user token: (NULL) [2012/01/04 16:04:20.894801, 5] auth/token_util.c:551(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2012/01/04 16:04:20.894866, 5] smbd/uid.c:369(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2012/01/04 16:04:20.894927, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 49442F383932332F3130 [2012/01/04 16:04:20.894997, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x7fa55fb1ff50 [2012/01/04 16:04:20.895059, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 49442F383932332F3130 [2012/01/04 16:04:20.895183, 3] smbd/connection.c:31(yield_connection) Yielding connection to [2012/01/04 16:04:20.895312, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key DB220000FFFFFFFF0000 [2012/01/04 16:04:20.895370, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x7fa55fb20bb0 [2012/01/04 16:04:20.895427, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key DB220000FFFFFFFF0000 [2012/01/04 16:04:20.895743, 3] smbd/server.c:902(exit_server_common) Server exit (failed to receive smb request)