[2015/04/22 17:09:32.648326, 1, pid=6862] 172.21.1.210 (172.21.1.210) closed connection to service test4 [2015/04/22 17:09:35.670466, 6, pid=8470] lp_file_list_changed() file /etc/samba/smb.conf.%m -> /etc/samba/smb.conf.172.21.1.210 last mod_time: Thu Jan 1 00:00:00 1970 file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Apr 22 17:09:22 2015 [2015/04/22 17:09:35.670559, 3, pid=8470] Allowed connection from bb64-7.eng.local (172.21.1.210) [2015/04/22 17:09:35.670584, 10, pid=8470] Connection allowed from ipv4:172.21.1.210:41966 to ipv4:172.21.10.70:445 [2015/04/22 17:09:35.670622, 3, pid=8470] init_oplocks: initializing messages. [2015/04/22 17:09:35.670681, 3, pid=8470] Linux kernel oplocks enabled [2015/04/22 17:09:35.670714, 5, pid=8470] Deregistering messaging pointer for type 1 - private_data=(nil) [2015/04/22 17:09:35.670752, 10, pid=8470] event_add_idle: idle_evt(keepalive) 0x7fd08dcd4290 [2015/04/22 17:09:35.670782, 10, pid=8470] event_add_idle: idle_evt(deadtime) 0x7fd08dce4c90 [2015/04/22 17:09:35.670814, 10, pid=8470] event_add_idle: idle_evt(housekeeping) 0x7fd08dce84c0 [2015/04/22 17:09:51.114269, 10, pid=8470] got smb length of 78 [2015/04/22 17:09:51.114376, 6, pid=8470] got message type 0x0 of len 0x4e [2015/04/22 17:09:51.114404, 3, pid=8470] Transaction 0 of length 82 (0 toread) [2015/04/22 17:09:51.114428, 5, pid=8470] [2015/04/22 17:09:51.114441, 5, pid=8470] size=78 smb_com=0x72 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=0 smb_pid=7783 smb_uid=0 smb_mid=24 smt_wct=0 smb_bcc=43 [2015/04/22 17:09:51.114561, 10, pid=8470] [0000] 02 4C 4D 31 2E 32 58 30 30 32 00 02 4C 41 4E 4D .LM1.2X0 02..LANM [0010] 41 4E 32 2E 31 00 02 4E 54 20 4C 4D 20 30 2E 31 AN2.1..N T LM 0.1 [0020] 32 00 02 50 4F 53 49 58 20 32 00 2..POSIX 2. [2015/04/22 17:09:51.114640, 3, pid=8470] switch message SMBnegprot (pid 8470) conn 0x0 [2015/04/22 17:09:51.114666, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.114692, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.114717, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.114763, 5, pid=8470] change_to_root_user: now uid=(0,0) gid=(0,0) [2015/04/22 17:09:51.115037, 3, pid=8470] Requested protocol [LM1.2X002] [2015/04/22 17:09:51.115074, 3, pid=8470] Requested protocol [LANMAN2.1] [2015/04/22 17:09:51.115100, 3, pid=8470] Requested protocol [NT LM 0.12] [2015/04/22 17:09:51.115125, 3, pid=8470] Requested protocol [POSIX 2] [2015/04/22 17:09:51.115150, 10, pid=8470] set_remote_arch: Client arch is 'CIFSFS' [2015/04/22 17:09:51.115186, 6, pid=8470] lp_file_list_changed() file /etc/samba/smb.conf.%m -> /etc/samba/smb.conf.172.21.1.210 last mod_time: Thu Jan 1 00:00:00 1970 file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Apr 22 17:09:22 2015 [2015/04/22 17:09:51.115267, 10, pid=8470] Locking key 16210000FFFFFFFF [2015/04/22 17:09:51.115297, 10, pid=8470] Allocated locked data 0x0x7fd08dcf8180 [2015/04/22 17:09:51.115327, 10, pid=8470] Unlocking key 16210000FFFFFFFF [2015/04/22 17:09:51.115369, 6, pid=8470] lp_file_list_changed() file /etc/samba/smb.conf.%m -> /etc/samba/smb.conf.172.21.1.210 last mod_time: Thu Jan 1 00:00:00 1970 file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Apr 22 17:09:22 2015 [2015/04/22 17:09:51.115455, 10, pid=8470] get challenge: creating negprot_global_auth_context [2015/04/22 17:09:51.115482, 5, pid=8470] Making default auth method list for standalone security=user, encrypt passwords = yes [2015/04/22 17:09:51.115510, 5, pid=8470] Attempting to register auth backend sam [2015/04/22 17:09:51.115534, 5, pid=8470] Successfully added auth method 'sam' [2015/04/22 17:09:51.115556, 5, pid=8470] Attempting to register auth backend sam_ignoredomain [2015/04/22 17:09:51.115580, 5, pid=8470] Successfully added auth method 'sam_ignoredomain' [2015/04/22 17:09:51.115612, 5, pid=8470] Attempting to register auth backend unix [2015/04/22 17:09:51.115636, 5, pid=8470] Successfully added auth method 'unix' [2015/04/22 17:09:51.115659, 5, pid=8470] Attempting to register auth backend winbind [2015/04/22 17:09:51.115681, 5, pid=8470] Successfully added auth method 'winbind' [2015/04/22 17:09:51.115703, 5, pid=8470] Attempting to register auth backend wbc [2015/04/22 17:09:51.115726, 5, pid=8470] Successfully added auth method 'wbc' [2015/04/22 17:09:51.115748, 5, pid=8470] Attempting to register auth backend smbserver [2015/04/22 17:09:51.115770, 5, pid=8470] Successfully added auth method 'smbserver' [2015/04/22 17:09:51.115793, 5, pid=8470] Attempting to register auth backend trustdomain [2015/04/22 17:09:51.115822, 5, pid=8470] Successfully added auth method 'trustdomain' [2015/04/22 17:09:51.115844, 5, pid=8470] Attempting to register auth backend ntdomain [2015/04/22 17:09:51.115867, 5, pid=8470] Successfully added auth method 'ntdomain' [2015/04/22 17:09:51.115890, 5, pid=8470] Attempting to register auth backend guest [2015/04/22 17:09:51.115913, 5, pid=8470] Successfully added auth method 'guest' [2015/04/22 17:09:51.115935, 5, pid=8470] load_auth_module: Attempting to find an auth method to match guest [2015/04/22 17:09:51.115958, 5, pid=8470] load_auth_module: auth method guest has a valid init [2015/04/22 17:09:51.115981, 5, pid=8470] load_auth_module: Attempting to find an auth method to match sam [2015/04/22 17:09:51.116004, 5, pid=8470] load_auth_module: auth method sam has a valid init [2015/04/22 17:09:51.116027, 10, pid=8470] get challenge: getting challenge [2015/04/22 17:09:51.116049, 5, pid=8470] auth_get_challenge: module guest did not want to specify a challenge [2015/04/22 17:09:51.116072, 5, pid=8470] auth_get_challenge: module sam did not want to specify a challenge [2015/04/22 17:09:51.116099, 5, pid=8470] auth_context challenge created by random [2015/04/22 17:09:51.116123, 5, pid=8470] challenge is: [2015/04/22 17:09:51.116146, 5, pid=8470] [0000] 32 AF 02 6E B0 D3 A1 9C 2..n.... [2015/04/22 17:09:51.116180, 3, pid=8470] not using SPNEGO [2015/04/22 17:09:51.116202, 3, pid=8470] Selected protocol NT LM 0.12 [2015/04/22 17:09:51.116224, 5, pid=8470] negprot index=2 [2015/04/22 17:09:51.116246, 5, pid=8470] [2015/04/22 17:09:51.116259, 5, pid=8470] size=93 smb_com=0x72 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49155 smb_tid=0 smb_pid=7783 smb_uid=0 smb_mid=24 smt_wct=17 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]=12803 (0x3203) smb_vwv[ 2]= 256 (0x100) smb_vwv[ 3]= 1024 (0x400) smb_vwv[ 4]= 65 (0x41) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 256 (0x100) smb_vwv[ 7]= 5632 (0x1600) smb_vwv[ 8]= 33 (0x21) smb_vwv[ 9]=64768 (0xFD00) smb_vwv[10]= 243 (0xF3) smb_vwv[11]=16384 (0x4000) smb_vwv[12]=62391 (0xF3B7) smb_vwv[13]= 7972 (0x1F24) smb_vwv[14]=53373 (0xD07D) smb_vwv[15]= 1 (0x1) smb_vwv[16]= 2048 (0x800) smb_bcc=24 [2015/04/22 17:09:51.116531, 10, pid=8470] [0000] 32 AF 02 6E B0 D3 A1 9C 45 00 58 00 41 00 47 00 2..n.... E.X.A.G. [0010] 52 00 49 00 44 00 00 00 R.I.D... [2015/04/22 17:09:51.117031, 10, pid=8470] got smb length of 246 [2015/04/22 17:09:51.117118, 6, pid=8470] got message type 0x0 of len 0xf6 [2015/04/22 17:09:51.117165, 3, pid=8470] Transaction 1 of length 250 (0 toread) [2015/04/22 17:09:51.117188, 5, pid=8470] [2015/04/22 17:09:51.117201, 5, pid=8470] size=246 smb_com=0x73 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=53249 smb_tid=0 smb_pid=7783 smb_uid=0 smb_mid=25 smt_wct=13 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]=16472 (0x4058) smb_vwv[ 3]= 50 (0x32) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 24 (0x18) smb_vwv[ 8]= 24 (0x18) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]= 0 (0x0) smb_vwv[11]=53468 (0xD0DC) smb_vwv[12]= 0 (0x0) smb_bcc=185 [2015/04/22 17:09:51.117450, 10, pid=8470] [0000] 78 43 63 B0 F5 64 DF 35 51 87 FA FB BE F8 BA 62 xCc..d.5 Q......b [0010] 07 73 0A 84 C7 EB BF 9C 78 43 63 B0 F5 64 DF 35 .s...... xCc..d.5 [0020] 51 87 FA FB BE F8 BA 62 07 73 0A 84 C7 EB BF 9C Q......b .s...... [0030] 00 70 00 77 00 61 00 74 00 6B 00 69 00 6E 00 73 .p.w.a.t .k.i.n.s [0040] 00 00 00 00 00 4C 00 69 00 6E 00 75 00 78 00 20 .....L.i .n.u.x. [0050] 00 76 00 65 00 72 00 73 00 69 00 6F 00 6E 00 20 .v.e.r.s .i.o.n. [0060] 00 32 00 2E 00 36 00 2E 00 33 00 32 00 2D 00 36 .2...6.. .3.2.-.6 [0070] 00 30 00 2D 00 67 00 65 00 6E 00 65 00 72 00 69 .0.-.g.e .n.e.r.i [0080] 00 63 00 00 00 43 00 49 00 46 00 53 00 20 00 56 .c...C.I .F.S. .V [0090] 00 46 00 53 00 20 00 43 00 6C 00 69 00 65 00 6E .F.S. .C .l.i.e.n [00A0] 00 74 00 20 00 66 00 6F 00 72 00 20 00 4C 00 69 .t. .f.o .r. .L.i [00B0] 00 6E 00 75 00 78 00 00 00 .n.u.x.. . [2015/04/22 17:09:51.117700, 3, pid=8470] switch message SMBsesssetupX (pid 8470) conn 0x0 [2015/04/22 17:09:51.117723, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.117746, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.117768, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.117810, 5, pid=8470] change_to_root_user: now uid=(0,0) gid=(0,0) [2015/04/22 17:09:51.117841, 3, pid=8470] wct=13 flg2=0xd001 [2015/04/22 17:09:51.117869, 3, pid=8470] Domain=[] NativeOS=[Linux version 2.6.32-60-generic] NativeLanMan=[CIFS VFS Client for Linux] PrimaryDomain=[null] [2015/04/22 17:09:51.117895, 2, pid=8470] setup_new_vc_session: New VC == 0, if NT4.x compatible we would close all old resources. [2015/04/22 17:09:51.117918, 3, pid=8470] sesssetupX:name=[]\[pwatkins]@[172.21.1.210] [2015/04/22 17:09:51.117953, 6, pid=8470] lp_file_list_changed() file /etc/samba/smb.conf.%m -> /etc/samba/smb.conf.172.21.1.210 last mod_time: Thu Jan 1 00:00:00 1970 file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Apr 22 17:09:22 2015 [2015/04/22 17:09:51.118032, 5, pid=8470] Mapping user []\[pwatkins] from workstation [172.21.1.210] [2015/04/22 17:09:51.118057, 5, pid=8470] Mapped domain from [] to [EX-LM00016] for user [pwatkins] from workstation [172.21.1.210] [2015/04/22 17:09:51.118082, 5, pid=8470] attempting to make a user_info for pwatkins (pwatkins) [2015/04/22 17:09:51.118105, 5, pid=8470] making strings for pwatkins's user_info struct [2015/04/22 17:09:51.118128, 5, pid=8470] making blobs for pwatkins's user_info struct [2015/04/22 17:09:51.118151, 10, pid=8470] made a user_info for pwatkins (pwatkins) [2015/04/22 17:09:51.118174, 3, pid=8470] check_ntlm_password: Checking password for unmapped user []\[pwatkins]@[172.21.1.210] with the new password interface [2015/04/22 17:09:51.118197, 3, pid=8470] check_ntlm_password: mapped user is: [EX-LM00016]\[pwatkins]@[172.21.1.210] [2015/04/22 17:09:51.118220, 10, pid=8470] check_ntlm_password: auth_context challenge created by random [2015/04/22 17:09:51.118242, 10, pid=8470] challenge is: [2015/04/22 17:09:51.118264, 5, pid=8470] [0000] 32 AF 02 6E B0 D3 A1 9C 2..n.... [2015/04/22 17:09:51.118297, 10, pid=8470] Check auth for: [pwatkins] [2015/04/22 17:09:51.118319, 10, pid=8470] check_ntlm_password: guest had nothing to say [2015/04/22 17:09:51.118342, 10, pid=8470] Check auth for: [pwatkins] [2015/04/22 17:09:51.118365, 8, pid=8470] is_myname("EX-LM00016") returns 1 [2015/04/22 17:09:51.118391, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.118416, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.118438, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.118461, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.118483, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.118541, 5, pid=8470] pdb_getsampwnam (TDB): error fetching database. Key: USER_pwatkins [2015/04/22 17:09:51.118580, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.118604, 3, pid=8470] check_sam_security: Couldn't find user 'pwatkins' in passdb. [2015/04/22 17:09:51.118627, 5, pid=8470] check_ntlm_password: sam authentication for user [pwatkins] FAILED with error NT_STATUS_NO_SUCH_USER [2015/04/22 17:09:51.118654, 2, pid=8470] check_ntlm_password: Authentication for user [pwatkins] -> [pwatkins] FAILED with error NT_STATUS_NO_SUCH_USER [2015/04/22 17:09:51.118679, 3, pid=8470] No such user pwatkins [] - using guest account [2015/04/22 17:09:51.118715, 10, pid=8470] register_initial_vuid: allocated vuid = 100 [2015/04/22 17:09:51.118742, 10, pid=8470] register_existing_vuid: (65534,65534) nfsnobody pwatkins EX-LM00016 guest=1 [2015/04/22 17:09:51.118765, 3, pid=8470] register_existing_vuid: User name: nfsnobody Real name: [2015/04/22 17:09:51.118787, 3, pid=8470] register_existing_vuid: UNIX uid 65534 is UNIX user nfsnobody, and will be vuid 100 [2015/04/22 17:09:51.118828, 6, pid=8470] lp_file_list_changed() file /etc/samba/smb.conf.%m -> /etc/samba/smb.conf.172.21.1.210 last mod_time: Thu Jan 1 00:00:00 1970 file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Apr 22 17:09:22 2015 [2015/04/22 17:09:51.119417, 10, pid=8470] got smb length of 108 [2015/04/22 17:09:51.119499, 6, pid=8470] got message type 0x0 of len 0x6c [2015/04/22 17:09:51.119552, 3, pid=8470] Transaction 2 of length 112 (0 toread) [2015/04/22 17:09:51.119580, 5, pid=8470] [2015/04/22 17:09:51.119593, 5, pid=8470] size=108 smb_com=0x75 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=53249 smb_tid=0 smb_pid=7783 smb_uid=100 smb_mid=26 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 [2015/04/22 17:09:51.119749, 10, pid=8470] [0000] 00 5C 00 5C 00 65 00 78 00 2D 00 6C 00 6D 00 30 .\.\.e.x .-.l.m.0 [0010] 00 30 00 30 00 31 00 36 00 2E 00 65 00 6E 00 67 .0.0.1.6 ...e.n.g [0020] 00 2E 00 6C 00 6F 00 63 00 61 00 6C 00 5C 00 74 ...l.o.c .a.l.\.t [0030] 00 65 00 73 00 74 00 34 00 00 00 3F 3F 3F 3F 3F .e.s.t.4 ...????? [0040] 00 . [2015/04/22 17:09:51.119864, 3, pid=8470] switch message SMBtconX (pid 8470) conn 0x0 [2015/04/22 17:09:51.119890, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.119913, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.119935, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.119969, 5, pid=8470] change_to_root_user: now uid=(0,0) gid=(0,0) [2015/04/22 17:09:51.119998, 4, pid=8470] Client requested device type [?????] for share [test4] [2015/04/22 17:09:51.120032, 5, pid=8470] making a connection to 'normal' service test4 [2015/04/22 17:09:51.120115, 3, pid=8470] Allowed connection from bb64-7.eng.local (172.21.1.210) [2015/04/22 17:09:51.120152, 5, pid=8470] Finding user nfsnobody [2015/04/22 17:09:51.120177, 5, pid=8470] Trying _Get_Pwnam(), username as lowercase is nfsnobody [2015/04/22 17:09:51.120203, 5, pid=8470] Get_Pwnam_internals did find user [nfsnobody]! [2015/04/22 17:09:51.120231, 5, pid=8470] Finding user nfsnobody [2015/04/22 17:09:51.120255, 5, pid=8470] Trying _Get_Pwnam(), username as lowercase is nfsnobody [2015/04/22 17:09:51.120278, 5, pid=8470] Get_Pwnam_internals did find user [nfsnobody]! [2015/04/22 17:09:51.120307, 10, pid=8470] lookup_name: EX-LM00016\nfsnobody => domain=[EX-LM00016], name=[nfsnobody] [2015/04/22 17:09:51.120331, 10, pid=8470] lookup_name: flags = 0x073 [2015/04/22 17:09:51.120357, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.120380, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.120410, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.120434, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.120456, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.120498, 5, pid=8470] pdb_getsampwnam (TDB): error fetching database. Key: USER_nfsnobody [2015/04/22 17:09:51.120534, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.120559, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.120582, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.120604, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.120627, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.120648, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.120694, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.120722, 10, pid=8470] lookup_name: Unix User\nfsnobody => domain=[Unix User], name=[nfsnobody] [2015/04/22 17:09:51.120746, 10, pid=8470] lookup_name: flags = 0x073 [2015/04/22 17:09:51.120794, 5, pid=8470] Finding user nfsnobody [2015/04/22 17:09:51.120826, 5, pid=8470] Trying _Get_Pwnam(), username as lowercase is nfsnobody [2015/04/22 17:09:51.120851, 5, pid=8470] Get_Pwnam_internals did find user [nfsnobody]! [2015/04/22 17:09:51.120904, 5, pid=8470] gid_to_sid: winbind failed to find a sid for gid 65534 [2015/04/22 17:09:51.120930, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.120953, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.120976, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.120998, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.121020, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.121061, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.121086, 10, pid=8470] LEGACY: gid 65534 -> sid S-1-22-2-65534 [2015/04/22 17:09:51.121120, 10, pid=8470] lookup_name: EX-LM00016\nfsnobody => domain=[EX-LM00016], name=[nfsnobody] [2015/04/22 17:09:51.121144, 10, pid=8470] lookup_name: flags = 0x073 [2015/04/22 17:09:51.121169, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.121192, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.121214, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.121236, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.121257, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.121296, 5, pid=8470] pdb_getsampwnam (TDB): error fetching database. Key: USER_nfsnobody [2015/04/22 17:09:51.121331, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.121356, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.121378, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.121401, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.121423, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.121444, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.121485, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.121511, 10, pid=8470] lookup_name: Unix User\nfsnobody => domain=[Unix User], name=[nfsnobody] [2015/04/22 17:09:51.121534, 10, pid=8470] lookup_name: flags = 0x073 [2015/04/22 17:09:51.121561, 5, pid=8470] Finding user nfsnobody [2015/04/22 17:09:51.121584, 5, pid=8470] Trying _Get_Pwnam(), username as lowercase is nfsnobody [2015/04/22 17:09:51.121607, 5, pid=8470] Get_Pwnam_internals did find user [nfsnobody]! [2015/04/22 17:09:51.121641, 10, pid=8470] sid S-1-22-1-65534 -> uid 65534 [2015/04/22 17:09:51.121707, 10, pid=8470] sys_getgrouplist: user [nfsnobody] [2015/04/22 17:09:51.121767, 10, pid=8470] Create local NT token for S-1-22-1-65534 [2015/04/22 17:09:51.121816, 10, pid=8470] winbind failed to find a gid for sid S-1-5-32-544 [2015/04/22 17:09:51.121845, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.121869, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.121891, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.121914, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.121935, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.121981, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.122007, 10, pid=8470] LEGACY: mapping failed for sid S-1-5-32-544 [2015/04/22 17:09:51.122031, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.122054, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.122076, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.122098, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.122120, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.122164, 3, pid=8470] Failed to fetch domain sid for EXAGRID [2015/04/22 17:09:51.122191, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.122226, 10, pid=8470] winbind failed to find a gid for sid S-1-5-32-545 [2015/04/22 17:09:51.122251, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.122275, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.122297, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.122319, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.122341, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.122383, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.122408, 10, pid=8470] LEGACY: mapping failed for sid S-1-5-32-545 [2015/04/22 17:09:51.122432, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.122454, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.122477, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.122499, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.122520, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.122558, 3, pid=8470] Failed to fetch domain sid for EXAGRID [2015/04/22 17:09:51.122585, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.122608, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.122631, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.122654, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.122676, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.122697, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.122759, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.122793, 4, pid=8470] get_privileges: No privileges assigned to SID [S-1-22-1-65534] [2015/04/22 17:09:51.122828, 4, pid=8470] get_privileges: No privileges assigned to SID [S-1-22-2-65534] [2015/04/22 17:09:51.122858, 5, pid=8470] get_privileges_for_sids: sid = S-1-1-0 Privilege set: 0x0 [2015/04/22 17:09:51.122894, 4, pid=8470] get_privileges: No privileges assigned to SID [S-1-5-2] [2015/04/22 17:09:51.122922, 4, pid=8470] get_privileges: No privileges assigned to SID [S-1-5-32-546] [2015/04/22 17:09:51.122979, 10, pid=8470] wbcSidsToUnixIds returned WBC_ERR_WINBIND_NOT_AVAILABLE [2015/04/22 17:09:51.123013, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.123037, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.123059, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.123082, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.123104, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.123146, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.123172, 10, pid=8470] LEGACY: mapping failed for sid S-1-1-0 [2015/04/22 17:09:51.123196, 10, pid=8470] LEGACY: mapping failed for sid S-1-1-0 [2015/04/22 17:09:51.123219, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.123242, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.123265, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.123287, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.123309, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.123349, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.123374, 10, pid=8470] LEGACY: mapping failed for sid S-1-5-2 [2015/04/22 17:09:51.123398, 10, pid=8470] LEGACY: mapping failed for sid S-1-5-2 [2015/04/22 17:09:51.123421, 4, pid=8470] push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.123444, 4, pid=8470] push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2015/04/22 17:09:51.123466, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2015/04/22 17:09:51.123489, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.123510, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.123552, 4, pid=8470] pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.123576, 10, pid=8470] LEGACY: mapping failed for sid S-1-5-32-546 [2015/04/22 17:09:51.123600, 10, pid=8470] LEGACY: mapping failed for sid S-1-5-32-546 [2015/04/22 17:09:51.123625, 10, pid=8470] Could not convert SID S-1-1-0 to gid, ignoring it [2015/04/22 17:09:51.123648, 10, pid=8470] Could not convert SID S-1-5-2 to gid, ignoring it [2015/04/22 17:09:51.123671, 10, pid=8470] Could not convert SID S-1-5-32-546 to gid, ignoring it [2015/04/22 17:09:51.123696, 10, pid=8470] Security token SIDs (5): SID[ 0]: S-1-22-1-65534 SID[ 1]: S-1-22-2-65534 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-32-546 Privileges (0x 0): Rights (0x 0): [2015/04/22 17:09:51.123789, 10, pid=8470] UNIX token of user 65534 Primary group is 65534 and contains 1 supplementary groups Group[ 0]: 65534 [2015/04/22 17:09:51.123839, 3, pid=8470] Forced user nfsnobody [2015/04/22 17:09:51.123866, 10, pid=8470] set_conn_connectpath: service test4, connectpath = /home1/shares/test4 [2015/04/22 17:09:51.123891, 3, pid=8470] Connect path is '/home1/shares/test4' for service [test4] [2015/04/22 17:09:51.123925, 10, pid=8470] se_map_generic(): mapped mask 0x10000000 to 0x001f01ff [2015/04/22 17:09:51.123953, 10, pid=8470] se_access_check: MAX desired = 0x2000000, granted = 0x101f01ff, remaining = 0x101f01ff [2015/04/22 17:09:51.123979, 3, pid=8470] Initialising default vfs hooks [2015/04/22 17:09:51.124005, 10, pid=8470] vfs_find_backend_entry called for /[Default VFS]/ [2015/04/22 17:09:51.124028, 5, pid=8470] Successfully added vfs backend '/[Default VFS]/' [2015/04/22 17:09:51.124051, 10, pid=8470] vfs_find_backend_entry called for posixacl [2015/04/22 17:09:51.124074, 5, pid=8470] Successfully added vfs backend 'posixacl' [2015/04/22 17:09:51.124096, 3, pid=8470] Initialising custom vfs hooks from [/[Default VFS]/] [2015/04/22 17:09:51.124118, 10, pid=8470] vfs_find_backend_entry called for /[Default VFS]/ Successfully loaded vfs module [/[Default VFS]/] with the new modules system [2015/04/22 17:09:51.124161, 5, pid=8470] claiming [test4] [2015/04/22 17:09:51.124223, 10, pid=8470] Locking key 16210000FFFFFFFF9344 [2015/04/22 17:09:51.124251, 10, pid=8470] Allocated locked data 0x0x7fd08dcd9ed0 [2015/04/22 17:09:51.124299, 10, pid=8470] Unlocking key 16210000FFFFFFFF9344 [2015/04/22 17:09:51.124403, 10, pid=8470] set_conn_connectpath: service test4, connectpath = /home1/shares/test4 [2015/04/22 17:09:51.124438, 10, pid=8470] user_ok_token: share test4 is ok for unix user nfsnobody [2015/04/22 17:09:51.124465, 10, pid=8470] is_share_read_only_for_user: share test4 is read-write for unix user nfsnobody [2015/04/22 17:09:51.124495, 10, pid=8470] se_map_generic(): mapped mask 0x10000000 to 0x001f01ff [2015/04/22 17:09:51.124527, 10, pid=8470] se_map_generic(): mapped mask 0x10000000 to 0x001f01ff [2015/04/22 17:09:51.124557, 4, pid=8470] setting sec ctx (65534, 65534) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.124582, 5, pid=8470] Security token SIDs (5): SID[ 0]: S-1-22-1-65534 SID[ 1]: S-1-22-2-65534 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-32-546 Privileges (0x 0): Rights (0x 0): [2015/04/22 17:09:51.124675, 5, pid=8470] UNIX token of user 65534 Primary group is 65534 and contains 1 supplementary groups Group[ 0]: 65534 [2015/04/22 17:09:51.124725, 5, pid=8470] Impersonated user: uid=(0,65534), gid=(0,65534) [2015/04/22 17:09:51.124753, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.124777, 5, pid=8470] Security token: (NULL) [2015/04/22 17:09:51.124799, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:09:51.124844, 5, pid=8470] change_to_root_user: now uid=(0,0) gid=(0,0) [2015/04/22 17:09:51.124878, 10, pid=8470] set_conn_connectpath: service test4, connectpath = /home1/shares/test4 [2015/04/22 17:09:51.124913, 10, pid=8470] vfswrap_fs_capabilities: timestamp resolution of sec available on share test4, directory /home1/shares/test4 [2015/04/22 17:09:51.124941, 1, pid=8470] 172.21.1.210 (172.21.1.210) connect to service test4 initially as user nfsnobody (uid=65534, gid=65534) (pid 8470) [2015/04/22 17:09:51.124973, 3, pid=8470] tconX service=test4 [2015/04/22 17:09:51.125382, 10, pid=8470] got smb length of 84 [2015/04/22 17:09:51.125465, 6, pid=8470] got message type 0x0 of len 0x54 [2015/04/22 17:09:51.125517, 3, pid=8470] Transaction 3 of length 88 (0 toread) [2015/04/22 17:09:51.125567, 5, pid=8470] [2015/04/22 17:09:51.125580, 5, pid=8470] size=84 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7783 smb_uid=100 smb_mid=27 smt_wct=15 smb_vwv[ 0]= 18 (0x12) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 4000 (0xFA0) 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]= 18 (0x12) smb_vwv[10]= 66 (0x42) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 5 (0x5) smb_bcc=19 [2015/04/22 17:09:51.125853, 10, pid=8470] [0000] 00 07 01 00 00 00 00 5C 00 44 00 49 00 52 00 31 .......\ .D.I.R.1 [0010] 00 00 00 ... [2015/04/22 17:09:51.125904, 3, pid=8470] switch message SMBtrans2 (pid 8470) conn 0x7fd08dce6d70 [2015/04/22 17:09:51.125929, 4, pid=8470] setting sec ctx (65534, 65534) - sec_ctx_stack_ndx = 0 [2015/04/22 17:09:51.125953, 5, pid=8470] Security token SIDs (5): SID[ 0]: S-1-22-1-65534 SID[ 1]: S-1-22-2-65534 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-32-546 Privileges (0x 0): Rights (0x 0): [2015/04/22 17:09:51.126043, 5, pid=8470] UNIX token of user 65534 Primary group is 65534 and contains 1 supplementary groups Group[ 0]: 65534 [2015/04/22 17:09:51.126099, 5, pid=8470] Impersonated user: uid=(0,65534), gid=(0,65534) [2015/04/22 17:09:51.126129, 4, pid=8470] vfs_ChDir to /home1/shares/test4 [2015/04/22 17:09:51.126166, 3, pid=8470] call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 263 [2015/04/22 17:09:51.126201, 5, pid=8470] unix_convert called on file "DIR1" [2015/04/22 17:09:51.126227, 5, pid=8470] unix_convert begin: name = DIR1, dirpath = , start = DIR1 [2015/04/22 17:09:51.126255, 5, pid=8470] conversion of base_name finished DIR1 -> DIR1 [2015/04/22 17:09:51.126280, 3, pid=8470] check_reduced_name [DIR1] [/home1/shares/test4] [2015/04/22 17:09:51.126308, 10, pid=8470] check_reduced_name realpath [DIR1] -> [/home1/shares/test4/DIR1] [2015/04/22 17:09:51.126331, 3, pid=8470] check_reduced_name: DIR1 reduced to /home1/shares/test4/DIR1 [2015/04/22 17:09:51.126364, 10, pid=8470] file_name_hash: /home1/shares/test4/DIR1 hash 0x3c804577 [2015/04/22 17:09:51.126396, 10, pid=8470] fetch_share_mode_unlocked: no share_mode record around (file not open) [2015/04/22 17:09:51.126421, 3, pid=8470] call_trans2qfilepathinfo DIR1 (fnum = -1) level=263 call=5 total_data=0 [2015/04/22 17:09:51.126448, 5, pid=8470] smbd_do_qfilepathinfo: DIR1 (fnum = -1) level=263 max_data=4000 [2015/04/22 17:09:51.126474, 8, pid=8470] dos_mode: DIR1 [2015/04/22 17:09:51.126498, 8, pid=8470] dos_mode_from_sbuf returning d [2015/04/22 17:09:51.126523, 8, pid=8470] dos_mode returning d [2015/04/22 17:09:51.126553, 10, pid=8470] smbd_do_qfilepathinfo: SMB_FILE_ALL_INFORMATION [2015/04/22 17:09:51.126580, 9, pid=8470] t2_rep: params_sent_thistime = 2, data_sent_thistime = 82, useable_space = 16410 [2015/04/22 17:09:51.126604, 9, pid=8470] t2_rep: params_to_send = 2, data_to_send = 82, paramsize = 2, datasize = 82 [2015/04/22 17:09:51.126627, 5, pid=8470] [2015/04/22 17:09:51.126640, 5, pid=8470] size=142 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49155 smb_tid=1 smb_pid=7783 smb_uid=100 smb_mid=27 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 82 (0x52) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 82 (0x52) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=87 [2015/04/22 17:09:51.126856, 10, pid=8470] [0000] 00 00 00 00 00 EA 11 27 BD 77 7C D0 01 EA 11 27 .......' .w|....' [0010] BD 77 7C D0 01 24 50 11 B5 1E 7D D0 01 24 50 11 .w|..$P. ..}..$P. [0020] B5 1E 7D D0 01 10 00 00 00 00 00 00 00 00 00 00 ..}..... ........ [0030] 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 ........ ........ [0040] 00 00 01 00 00 00 00 00 00 0A 00 00 00 5C 00 44 ........ .....\.D [0050] 00 49 00 52 00 31 00 .I.R.1. [2015/04/22 17:09:51.127488, 10, pid=8470] got smb length of 92 [2015/04/22 17:09:51.127570, 6, pid=8470] got message type 0x0 of len 0x5c [2015/04/22 17:09:51.127604, 3, pid=8470] Transaction 4 of length 96 (0 toread) [2015/04/22 17:09:51.127626, 5, pid=8470] [2015/04/22 17:09:51.127639, 5, pid=8470] size=92 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7783 smb_uid=100 smb_mid=28 smt_wct=15 smb_vwv[ 0]= 26 (0x1A) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 4000 (0xFA0) 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]= 66 (0x42) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 5 (0x5) smb_bcc=27 [2015/04/22 17:09:51.127901, 10, pid=8470] [0000] 00 07 01 00 00 00 00 5C 00 44 00 49 00 52 00 31 .......\ .D.I.R.1 [0010] 00 5C 00 46 00 4F 00 4F 00 00 00 .\.F.O.O ... [2015/04/22 17:09:51.127954, 3, pid=8470] switch message SMBtrans2 (pid 8470) conn 0x7fd08dce6d70 [2015/04/22 17:09:51.127977, 4, pid=8470] Skipping user change - already user [2015/04/22 17:09:51.128009, 3, pid=8470] call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 263 [2015/04/22 17:09:51.128035, 5, pid=8470] unix_convert called on file "DIR1/FOO" [2015/04/22 17:09:51.128059, 5, pid=8470] unix_convert begin: name = DIR1/FOO, dirpath = , start = DIR1/FOO [2015/04/22 17:09:51.128093, 5, pid=8470] check_parent_exists: name = DIR1/FOO, dirpath = DIR1, start = FOO [2015/04/22 17:09:51.128120, 10, pid=8470] is_mangled DIR1/FOO ? [2015/04/22 17:09:51.128144, 10, pid=8470] is_mangled_component DIR1/FOO (len 4) ? [2015/04/22 17:09:51.128167, 10, pid=8470] is_mangled_component FOO (len 3) ? [2015/04/22 17:09:51.128192, 3, pid=8470] check_reduced_name [DIR1/FOO] [/home1/shares/test4] [2015/04/22 17:09:51.128226, 10, pid=8470] check_reduced_name realpath [DIR1/FOO] -> [/home1/shares/test4/DIR1/FOO] [2015/04/22 17:09:51.128250, 3, pid=8470] check_reduced_name: DIR1/FOO reduced to /home1/shares/test4/DIR1/FOO [2015/04/22 17:09:51.128275, 3, pid=8470] call_trans2qfilepathinfo: SMB_VFS_STAT of DIR1/FOO failed (No such file or directory) [2015/04/22 17:09:51.128315, 3, pid=8470] error packet at smbd/trans2.c(5369) cmd=50 (SMBtrans2) NT_STATUS_OBJECT_NAME_NOT_FOUND [2015/04/22 17:09:51.128342, 5, pid=8470] [2015/04/22 17:09:51.128355, 5, pid=8470] size=35 smb_com=0x32 smb_rcls=52 smb_reh=0 smb_err=49152 smb_flg=128 smb_flg2=49155 smb_tid=1 smb_pid=7783 smb_uid=100 smb_mid=28 smt_wct=0 smb_bcc=0 [2015/04/22 17:09:51.128474, 10, pid=8470] [2015/04/22 17:09:51.128777, 10, pid=8470] got smb length of 104 [2015/04/22 17:09:51.128836, 6, pid=8470] got message type 0x0 of len 0x68 [2015/04/22 17:09:51.128861, 3, pid=8470] Transaction 5 of length 108 (0 toread) [2015/04/22 17:09:51.128883, 5, pid=8470] [2015/04/22 17:09:51.128896, 5, pid=8470] size=104 smb_com=0xa2 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7783 smb_uid=100 smb_mid=29 smt_wct=24 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 5120 (0x1400) smb_vwv[ 3]= 512 (0x200) 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]= 64 (0x40) smb_vwv[10]= 0 (0x0) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]=32768 (0x8000) smb_vwv[14]= 0 (0x0) smb_vwv[15]= 1792 (0x700) smb_vwv[16]= 0 (0x0) smb_vwv[17]= 768 (0x300) smb_vwv[18]= 0 (0x0) smb_vwv[19]=16384 (0x4000) smb_vwv[20]= 0 (0x0) smb_vwv[21]= 512 (0x200) smb_vwv[22]= 0 (0x0) smb_vwv[23]= 768 (0x300) smb_bcc=21 [2015/04/22 17:09:51.129229, 10, pid=8470] [0000] 00 5C 00 44 00 49 00 52 00 31 00 5C 00 46 00 4F .\.D.I.R .1.\.F.O [0010] 00 4F 00 00 00 .O... [2015/04/22 17:09:51.129280, 3, pid=8470] switch message SMBntcreateX (pid 8470) conn 0x7fd08dce6d70 [2015/04/22 17:09:51.129304, 4, pid=8470] Skipping user change - already user [2015/04/22 17:09:51.129331, 10, pid=8470] reply_ntcreate_and_X: flags = 0x2, access_mask = 0x40000000 file_attributes = 0x80, share_access = 0x7, create_disposition = 0x3 create_options = 0x40 root_dir_fid = 0x0, fname = DIR1/FOO [2015/04/22 17:09:51.129359, 5, pid=8470] unix_convert called on file "DIR1/FOO" [2015/04/22 17:09:51.129382, 5, pid=8470] unix_convert begin: name = DIR1/FOO, dirpath = , start = DIR1/FOO [2015/04/22 17:09:51.129408, 5, pid=8470] check_parent_exists: name = DIR1/FOO, dirpath = DIR1, start = FOO [2015/04/22 17:09:51.129432, 10, pid=8470] is_mangled DIR1/FOO ? [2015/04/22 17:09:51.129454, 10, pid=8470] is_mangled_component DIR1/FOO (len 4) ? [2015/04/22 17:09:51.129477, 10, pid=8470] is_mangled_component FOO (len 3) ? [2015/04/22 17:09:51.129502, 3, pid=8470] check_reduced_name [DIR1/FOO] [/home1/shares/test4] [2015/04/22 17:09:51.129535, 10, pid=8470] check_reduced_name realpath [DIR1/FOO] -> [/home1/shares/test4/DIR1/FOO] [2015/04/22 17:09:51.129559, 3, pid=8470] check_reduced_name: DIR1/FOO reduced to /home1/shares/test4/DIR1/FOO [2015/04/22 17:09:51.129594, 10, pid=8470] create_file: access_mask = 0x40000000 file_attributes = 0x80, share_access = 0x7, create_disposition = 0x3 create_options = 0x40 oplock_request = 0x1 private_flags = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = DIR1/FOO [2015/04/22 17:09:51.129623, 10, pid=8470] create_file_unixpath: access_mask = 0x40000000 file_attributes = 0x80, share_access = 0x7, create_disposition = 0x3 create_options = 0x40 oplock_request = 0x1 private_flags = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = DIR1/FOO [2015/04/22 17:09:51.129658, 5, pid=8470] allocated file structure 29897, fnum = 33993 (1 used) [2015/04/22 17:09:51.129685, 10, pid=8470] file_name_hash: /home1/shares/test4/DIR1/FOO hash 0x2de3a41d [2015/04/22 17:09:51.129712, 3, pid=8470] unix_mode(DIR1/FOO) returning 0744 [2015/04/22 17:09:51.129737, 10, pid=8470] open_file_ntcreate: fname=DIR1/FOO, dos_attrs=0x80 access_mask=0x40000000 share_access=0x7 create_disposition = 0x3 create_options=0x40 unix mode=0744 oplock_request=1 private_flags = 0x0 [2015/04/22 17:09:51.129764, 10, pid=8470] se_map_generic(): mapped mask 0x40000000 to 0x00120116 [2015/04/22 17:09:51.129788, 10, pid=8470] open_file_ntcreate: fname=DIR1/FOO, after mapping access_mask=0x120116 [2015/04/22 17:09:51.129816, 4, pid=8470] calling open_file with flags=0x1 flags2=0x40 mode=0744, access_mask = 0x120116, open_access_mask = 0x120116 [2015/04/22 17:09:51.129896, 10, pid=8470] fd_open: name DIR1/FOO, flags = 0101 mode = 0744, fd = 31. [2015/04/22 17:09:51.129951, 10, pid=8470] notify_trigger called action=0x1, filter=0x1, path=/home1/shares/test4/DIR1/FOO [2015/04/22 17:09:51.129985, 2, pid=8470] nfsnobody opened file DIR1/FOO read=No write=Yes (numopen=1) [2015/04/22 17:09:51.130015, 10, pid=8470] Locking key 17000000000000001150 [2015/04/22 17:09:51.130043, 10, pid=8470] Allocated locked data 0x0x7fd08dcf88d0 [2015/04/22 17:09:51.130070, 10, pid=8470] grant_fsp_oplock_type: oplock type 0x10 on file DIR1/FOO [2015/04/22 17:09:51.130096, 5, pid=8470] set_file_oplock: granted oplock on file DIR1/FOO, 17:3013e5011:0/2196584162, tv_sec = 5537d5df, tv_usec = 1fa76 [2015/04/22 17:09:51.130126, 10, pid=8470] file_set_dosmode: setting dos mode 0x20 on file DIR1/FOO [2015/04/22 17:09:51.130198, 8, pid=8470] dos_mode: DIR1/FOO [2015/04/22 17:09:51.130227, 8, pid=8470] dos_mode_from_sbuf returning a [2015/04/22 17:09:51.130251, 8, pid=8470] dos_mode returning a [2015/04/22 17:09:51.130274, 3, pid=8470] unix_mode(DIR1/FOO) returning 0744 [2015/04/22 17:09:51.130329, 10, pid=8470] unparse_share_modes: owrt: Wed Apr 22 05:09:51 PM 2015 UTC cwrt: Thu Jan 1 12:00:00 AM 1970 UTC, ntok: 0, num: 1 [2015/04/22 17:09:51.130376, 10, pid=8470] print_share_mode_table: share_mode_entry[0]: pid = 8470, share_access = 0x7, private_options = 0x0, access_mask = 0x120196, mid = 0x1d, type= 0x10, gen_id = 2196584162, uid = 65534, flags = 0, file_id 17:3013e5011:0, name_hash = 0x2de3a41d [2015/04/22 17:09:51.130425, 10, pid=8470] Unlocking key 17000000000000001150 [2015/04/22 17:09:51.130460, 10, pid=8470] create_file_unixpath: info=2 [2015/04/22 17:09:51.130484, 10, pid=8470] create_file: info=2 [2015/04/22 17:09:51.130507, 8, pid=8470] dos_mode: DIR1/FOO [2015/04/22 17:09:51.130531, 8, pid=8470] dos_mode_from_sbuf returning a [2015/04/22 17:09:51.130553, 8, pid=8470] dos_mode returning a [2015/04/22 17:09:51.130594, 10, pid=8470] parse_share_modes: owrt: Wed Apr 22 05:09:51 PM 2015 UTC, cwrt: Thu Jan 1 12:00:00 AM 1970 UTC, ntok: 0, num_share_modes: 1 [2015/04/22 17:09:51.130637, 10, pid=8470] parse_share_modes: share_mode_entry[0]: pid = 8470, share_access = 0x7, private_options = 0x0, access_mask = 0x120196, mid = 0x1d, type= 0x10, gen_id = 2196584162, uid = 65534, flags = 0, file_id 17:3013e5011:0, name_hash = 0x2de3a41d [2015/04/22 17:09:51.130664, 5, pid=8470] reply_ntcreate_and_X: fnum = 33993, open name = DIR1/FOO [2015/04/22 17:09:51.131068, 10, pid=8470] got smb length of 92 [2015/04/22 17:09:51.131152, 6, pid=8470] got message type 0x0 of len 0x5c [2015/04/22 17:09:51.131207, 3, pid=8470] Transaction 6 of length 96 (0 toread) [2015/04/22 17:09:51.131231, 5, pid=8470] [2015/04/22 17:09:51.131244, 5, pid=8470] size=92 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7783 smb_uid=100 smb_mid=30 smt_wct=15 smb_vwv[ 0]= 26 (0x1A) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 4000 (0xFA0) 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]= 66 (0x42) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 5 (0x5) smb_bcc=27 [2015/04/22 17:09:51.131498, 10, pid=8470] [0000] 00 EE 03 00 00 00 00 5C 00 44 00 49 00 52 00 31 .......\ .D.I.R.1 [0010] 00 5C 00 46 00 4F 00 4F 00 00 00 .\.F.O.O ... [2015/04/22 17:09:51.131551, 3, pid=8470] switch message SMBtrans2 (pid 8470) conn 0x7fd08dce6d70 [2015/04/22 17:09:51.131575, 4, pid=8470] Skipping user change - already user [2015/04/22 17:09:51.131599, 3, pid=8470] call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1006 [2015/04/22 17:09:51.131624, 5, pid=8470] unix_convert called on file "DIR1/FOO" [2015/04/22 17:09:51.131648, 5, pid=8470] unix_convert begin: name = DIR1/FOO, dirpath = , start = DIR1/FOO [2015/04/22 17:09:51.131674, 5, pid=8470] conversion of base_name finished DIR1/FOO -> DIR1/FOO [2015/04/22 17:09:51.131697, 3, pid=8470] check_reduced_name [DIR1/FOO] [/home1/shares/test4] [2015/04/22 17:09:51.131726, 10, pid=8470] check_reduced_name realpath [DIR1/FOO] -> [/home1/shares/test4/DIR1/FOO] [2015/04/22 17:09:51.131751, 3, pid=8470] check_reduced_name: DIR1/FOO reduced to /home1/shares/test4/DIR1/FOO [2015/04/22 17:09:51.131778, 10, pid=8470] file_name_hash: /home1/shares/test4/DIR1/FOO hash 0x2de3a41d [2015/04/22 17:09:51.131810, 10, pid=8470] parse_share_modes: owrt: Wed Apr 22 05:09:51 PM 2015 UTC, cwrt: Thu Jan 1 12:00:00 AM 1970 UTC, ntok: 0, num_share_modes: 1 [2015/04/22 17:09:51.131851, 10, pid=8470] parse_share_modes: share_mode_entry[0]: pid = 8470, share_access = 0x7, private_options = 0x0, access_mask = 0x120196, mid = 0x1d, type= 0x10, gen_id = 2196584162, uid = 65534, flags = 0, file_id 17:3013e5011:0, name_hash = 0x2de3a41d [2015/04/22 17:09:51.131875, 10, pid=8470] get_delete_on_close_token: name_hash = 0x2de3a41d [2015/04/22 17:09:51.131898, 3, pid=8470] call_trans2qfilepathinfo DIR1/FOO (fnum = -1) level=1006 call=5 total_data=0 [2015/04/22 17:09:51.131922, 5, pid=8470] smbd_do_qfilepathinfo: DIR1/FOO (fnum = -1) level=1006 max_data=4000 [2015/04/22 17:09:51.131945, 8, pid=8470] dos_mode: DIR1/FOO [2015/04/22 17:09:51.131968, 8, pid=8470] dos_mode_from_sbuf returning a [2015/04/22 17:09:51.131991, 8, pid=8470] dos_mode returning a [2015/04/22 17:09:51.132016, 10, pid=8470] smbd_do_qfilepathinfo: SMB_FILE_INTERNAL_INFORMATION [2015/04/22 17:09:51.132040, 9, pid=8470] t2_rep: params_sent_thistime = 2, data_sent_thistime = 8, useable_space = 16410 [2015/04/22 17:09:51.132063, 9, pid=8470] t2_rep: params_to_send = 2, data_to_send = 8, paramsize = 2, datasize = 8 [2015/04/22 17:09:51.132085, 5, pid=8470] [2015/04/22 17:09:51.132098, 5, pid=8470] size=68 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49155 smb_tid=1 smb_pid=7783 smb_uid=100 smb_mid=30 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 8 (0x8) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 8 (0x8) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=13 [2015/04/22 17:09:51.132305, 10, pid=8470] [0000] 00 00 00 00 00 11 50 3E 01 03 00 00 00 ......P> ..... [2015/04/22 17:09:51.132724, 10, pid=8470] got smb length of 114 [2015/04/22 17:09:51.132838, 6, pid=8470] got message type 0x0 of len 0x72 [2015/04/22 17:09:51.132891, 3, pid=8470] Transaction 7 of length 118 (0 toread) [2015/04/22 17:09:51.132914, 5, pid=8470] [2015/04/22 17:09:51.132927, 5, pid=8470] size=114 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7783 smb_uid=100 smb_mid=31 smt_wct=15 smb_vwv[ 0]= 6 (0x6) smb_vwv[ 1]= 40 (0x28) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 1000 (0x3E8) 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]= 6 (0x6) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 40 (0x28) smb_vwv[12]= 74 (0x4A) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 8 (0x8) smb_bcc=49 [2015/04/22 17:09:51.133182, 10, pid=8470] [0000] 00 00 00 C9 84 EC 03 00 00 00 00 00 00 00 00 00 ........ ........ [0010] 00 5E 7F F2 24 1F 7D D0 01 5E 7F F2 24 1F 7D D0 .^..$.}. .^..$.}. [0020] 01 5E 7F F2 24 1F 7D D0 01 00 00 00 00 00 00 00 .^..$.}. ........ [0030] 00 . [2015/04/22 17:09:51.133271, 3, pid=8470] switch message SMBtrans2 (pid 8470) conn 0x7fd08dce6d70 [2015/04/22 17:09:51.133294, 4, pid=8470] Skipping user change - already user [2015/04/22 17:09:51.133325, 3, pid=8470] call_trans2setfilepathinfo(8) DIR1/FOO (fnum 33993) info_level=1004 totdata=40 [2015/04/22 17:09:51.133352, 3, pid=8470] smbd_do_setfilepathinfo: DIR1/FOO (fnum 33993) info_level=1004 totdata=40 [2015/04/22 17:09:51.133378, 6, pid=8470] smb_set_file_dosmode: dosmode: 0x0 [2015/04/22 17:09:51.133402, 10, pid=8470] smb_set_file_basic_info: file DIR1/FOO [2015/04/22 17:09:51.133426, 5, pid=8470] smb_set_filetime: actime: Wed Apr 22 17:09:51 2015 smb_set_filetime: modtime: Wed Apr 22 17:09:51 2015 smb_set_filetime: ctime: Wed Apr 22 17:09:51 2015 smb_set_file_time: createtime: Thu Jan 1 00:00:00 1970 smb_set_file_time: setting pending modtime to Wed Apr 22 17:09:51 2015 [2015/04/22 17:09:51.133548, 5, pid=8470] set_sticky_write_time: Wed Apr 22 05:09:51 PM 2015 UTC id=17:3013e5011:0 [2015/04/22 17:09:51.133581, 10, pid=8470] Locking key 17000000000000001150 [2015/04/22 17:09:51.133608, 10, pid=8470] Allocated locked data 0x0x7fd08dce7eb0 [2015/04/22 17:09:51.133632, 10, pid=8470] parse_share_modes: owrt: Wed Apr 22 05:09:51 PM 2015 UTC, cwrt: Thu Jan 1 12:00:00 AM 1970 UTC, ntok: 0, num_share_modes: 1 [2015/04/22 17:09:51.133669, 10, pid=8470] parse_share_modes: share_mode_entry[0]: pid = 8470, share_access = 0x7, private_options = 0x0, access_mask = 0x120196, mid = 0x1d, type= 0x10, gen_id = 2196584162, uid = 65534, flags = 0, file_id 17:3013e5011:0, name_hash = 0x2de3a41d [2015/04/22 17:09:51.133694, 10, pid=8470] unparse_share_modes: owrt: Wed Apr 22 05:09:51 PM 2015 UTC cwrt: Wed Apr 22 05:09:51 PM 2015 UTC, ntok: 0, num: 1 [2015/04/22 17:09:51.133730, 10, pid=8470] print_share_mode_table: share_mode_entry[0]: pid = 8470, share_access = 0x7, private_options = 0x0, access_mask = 0x120196, mid = 0x1d, type= 0x10, gen_id = 2196584162, uid = 65534, flags = 0, file_id 17:3013e5011:0, name_hash = 0x2de3a41d [2015/04/22 17:09:51.133756, 10, pid=8470] Unlocking key 17000000000000001150 [2015/04/22 17:09:51.133786, 10, pid=8470] smb_set_file_time: setting utimes to modified values. [2015/04/22 17:09:51.133825, 6, pid=8470] file_ntime: actime: Wed Apr 22 17:09:51 2015 [2015/04/22 17:09:51.133855, 6, pid=8470] file_ntime: modtime: Wed Apr 22 17:09:51 2015 [2015/04/22 17:09:51.133881, 6, pid=8470] file_ntime: ctime: Wed Apr 22 17:09:51 2015 [2015/04/22 17:09:51.133906, 6, pid=8470] file_ntime: createtime: Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:51.133957, 10, pid=8470] notify_trigger called action=0x3, filter=0x30, path=/home1/shares/test4/DIR1/FOO [2015/04/22 17:09:51.133986, 9, pid=8470] t2_rep: params_sent_thistime = 2, data_sent_thistime = 0, useable_space = 16412 [2015/04/22 17:09:51.134017, 9, pid=8470] t2_rep: params_to_send = 2, data_to_send = 0, paramsize = 2, datasize = 0 [2015/04/22 17:09:51.134042, 5, pid=8470] [2015/04/22 17:09:51.134055, 5, pid=8470] size=58 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49155 smb_tid=1 smb_pid=7783 smb_uid=100 smb_mid=31 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=3 [2015/04/22 17:09:51.134264, 10, pid=8470] [0000] 00 00 00 ... [2015/04/22 17:09:51.134644, 10, pid=8470] got smb length of 41 [2015/04/22 17:09:51.134726, 6, pid=8470] got message type 0x0 of len 0x29 [2015/04/22 17:09:51.134779, 3, pid=8470] Transaction 8 of length 45 (0 toread) [2015/04/22 17:09:51.134811, 5, pid=8470] [2015/04/22 17:09:51.134825, 5, pid=8470] size=41 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7783 smb_uid=100 smb_mid=32 smt_wct=3 smb_vwv[ 0]=33993 (0x84C9) smb_vwv[ 1]=65535 (0xFFFF) smb_vwv[ 2]=65535 (0xFFFF) smb_bcc=0 [2015/04/22 17:09:51.134971, 10, pid=8470] [2015/04/22 17:09:51.134985, 3, pid=8470] switch message SMBclose (pid 8470) conn 0x7fd08dce6d70 [2015/04/22 17:09:51.135009, 4, pid=8470] Skipping user change - already user [2015/04/22 17:09:51.135033, 3, pid=8470] close fd=31 fnum=33993 (numopen=1) [2015/04/22 17:09:51.135058, 6, pid=8470] close_write_time: Sun Feb 7 06:28:15 2106 [2015/04/22 17:09:51.135095, 10, pid=8470] Locking key 17000000000000001150 [2015/04/22 17:09:51.135122, 10, pid=8470] Allocated locked data 0x0x7fd08dcf7f10 [2015/04/22 17:09:51.135146, 10, pid=8470] parse_share_modes: owrt: Wed Apr 22 05:09:51 PM 2015 UTC, cwrt: Wed Apr 22 05:09:51 PM 2015 UTC, ntok: 0, num_share_modes: 1 [2015/04/22 17:09:51.135183, 10, pid=8470] parse_share_modes: share_mode_entry[0]: pid = 8470, share_access = 0x7, private_options = 0x0, access_mask = 0x120196, mid = 0x1d, type= 0x10, gen_id = 2196584162, uid = 65534, flags = 0, file_id 17:3013e5011:0, name_hash = 0x2de3a41d [2015/04/22 17:09:51.135208, 10, pid=8470] close_remove_share_mode: write time forced for file DIR1/FOO [2015/04/22 17:09:51.135232, 6, pid=8470] close_write_time: Wed Apr 22 17:09:51 2015 [2015/04/22 17:09:51.135260, 10, pid=8470] get_delete_on_close_token: name_hash = 0x2de3a41d [2015/04/22 17:09:51.135284, 10, pid=8470] Unlocking key 17000000000000001150 [2015/04/22 17:09:51.135323, 5, pid=8470] set_write_time: Wed Apr 22 05:09:51 PM 2015 UTC id=17:3013e5011:0 [2015/04/22 17:09:51.135358, 10, pid=8470] Locking key 17000000000000001150 [2015/04/22 17:09:51.135384, 10, pid=8470] Allocated locked data 0x0x7fd08dcf1600 [2015/04/22 17:09:51.135407, 3, pid=8470] fill_share_mode_lock failed [2015/04/22 17:09:51.135430, 10, pid=8470] Unlocking key 17000000000000001150 [2015/04/22 17:09:51.135462, 10, pid=8470] Locking key 17000000000000001150 [2015/04/22 17:09:51.135488, 10, pid=8470] Allocated locked data 0x0x7fd08dcf85d0 [2015/04/22 17:09:51.135511, 3, pid=8470] fill_share_mode_lock failed [2015/04/22 17:09:51.135533, 10, pid=8470] Unlocking key 17000000000000001150 [2015/04/22 17:09:51.135561, 5, pid=8470] smb_set_filetime: actime: Thu Jan 1 00:00:00 1970 smb_set_filetime: modtime: Wed Apr 22 17:09:51 2015 smb_set_filetime: ctime: Thu Jan 1 00:00:00 1970 smb_set_file_time: createtime: Thu Jan 1 00:00:00 1970 smb_set_file_time: setting utimes to modified values. [2015/04/22 17:09:51.135667, 6, pid=8470] file_ntime: actime: Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:51.135693, 6, pid=8470] file_ntime: modtime: Wed Apr 22 17:09:51 2015 [2015/04/22 17:09:51.135719, 6, pid=8470] file_ntime: ctime: Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:51.135745, 6, pid=8470] file_ntime: createtime: Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:51.135790, 10, pid=8470] notify_trigger called action=0x3, filter=0x0, path=/home1/shares/test4/DIR1/FOO [2015/04/22 17:09:51.135824, 2, pid=8470] nfsnobody closed file DIR1/FOO (numopen=0) NT_STATUS_OK [2015/04/22 17:09:51.135851, 5, pid=8470] freed files structure 33993 (0 used) [2015/04/22 17:09:51.135875, 5, pid=8470] [2015/04/22 17:09:51.135889, 5, pid=8470] size=35 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49155 smb_tid=1 smb_pid=7783 smb_uid=100 smb_mid=32 smt_wct=0 smb_bcc=0 [2015/04/22 17:09:51.136007, 10, pid=8470] [2015/04/22 17:09:57.603856, 10, pid=8470] got smb length of 84 [2015/04/22 17:09:57.603977, 6, pid=8470] got message type 0x0 of len 0x54 [2015/04/22 17:09:57.604004, 3, pid=8470] Transaction 9 of length 88 (0 toread) [2015/04/22 17:09:57.604027, 5, pid=8470] [2015/04/22 17:09:57.604040, 5, pid=8470] size=84 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7786 smb_uid=100 smb_mid=33 smt_wct=15 smb_vwv[ 0]= 18 (0x12) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 4000 (0xFA0) 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]= 18 (0x12) smb_vwv[10]= 66 (0x42) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 5 (0x5) smb_bcc=19 [2015/04/22 17:09:57.604299, 10, pid=8470] [0000] 00 07 01 00 00 00 00 5C 00 44 00 49 00 52 00 31 .......\ .D.I.R.1 [0010] 00 00 00 ... [2015/04/22 17:09:57.604352, 3, pid=8470] switch message SMBtrans2 (pid 8470) conn 0x7fd08dce6d70 [2015/04/22 17:09:57.604377, 4, pid=8470] Skipping user change - already user [2015/04/22 17:09:57.604404, 3, pid=8470] call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 263 [2015/04/22 17:09:57.604433, 5, pid=8470] unix_convert called on file "DIR1" [2015/04/22 17:09:57.604458, 5, pid=8470] unix_convert begin: name = DIR1, dirpath = , start = DIR1 [2015/04/22 17:09:57.604488, 5, pid=8470] conversion of base_name finished DIR1 -> DIR1 [2015/04/22 17:09:57.604513, 3, pid=8470] check_reduced_name [DIR1] [/home1/shares/test4] [2015/04/22 17:09:57.604543, 10, pid=8470] check_reduced_name realpath [DIR1] -> [/home1/shares/test4/DIR1] [2015/04/22 17:09:57.604568, 3, pid=8470] check_reduced_name: DIR1 reduced to /home1/shares/test4/DIR1 [2015/04/22 17:09:57.604595, 10, pid=8470] file_name_hash: /home1/shares/test4/DIR1 hash 0x3c804577 [2015/04/22 17:09:57.604630, 10, pid=8470] fetch_share_mode_unlocked: no share_mode record around (file not open) [2015/04/22 17:09:57.604655, 3, pid=8470] call_trans2qfilepathinfo DIR1 (fnum = -1) level=263 call=5 total_data=0 [2015/04/22 17:09:57.604679, 5, pid=8470] smbd_do_qfilepathinfo: DIR1 (fnum = -1) level=263 max_data=4000 [2015/04/22 17:09:57.604703, 8, pid=8470] dos_mode: DIR1 [2015/04/22 17:09:57.604727, 8, pid=8470] dos_mode_from_sbuf returning d [2015/04/22 17:09:57.604751, 8, pid=8470] dos_mode returning d [2015/04/22 17:09:57.604777, 10, pid=8470] smbd_do_qfilepathinfo: SMB_FILE_ALL_INFORMATION [2015/04/22 17:09:57.604815, 9, pid=8470] t2_rep: params_sent_thistime = 2, data_sent_thistime = 82, useable_space = 16410 [2015/04/22 17:09:57.604842, 9, pid=8470] t2_rep: params_to_send = 2, data_to_send = 82, paramsize = 2, datasize = 82 [2015/04/22 17:09:57.604865, 5, pid=8470] [2015/04/22 17:09:57.604878, 5, pid=8470] size=142 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49155 smb_tid=1 smb_pid=7786 smb_uid=100 smb_mid=33 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 82 (0x52) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 82 (0x52) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=87 [2015/04/22 17:09:57.605090, 10, pid=8470] [0000] 00 00 00 00 00 EA 11 27 BD 77 7C D0 01 EA 11 27 .......' .w|....' [0010] BD 77 7C D0 01 72 C6 F5 24 1F 7D D0 01 72 C6 F5 .w|..r.. $.}..r.. [0020] 24 1F 7D D0 01 10 00 00 00 00 00 00 00 00 00 00 $.}..... ........ [0030] 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 ........ ........ [0040] 00 00 01 00 00 00 00 00 00 0A 00 00 00 5C 00 44 ........ .....\.D [0050] 00 49 00 52 00 31 00 .I.R.1. [2015/04/22 17:09:57.605619, 10, pid=8470] got smb length of 92 [2015/04/22 17:09:57.605706, 6, pid=8470] got message type 0x0 of len 0x5c [2015/04/22 17:09:57.605755, 3, pid=8470] Transaction 10 of length 96 (0 toread) [2015/04/22 17:09:57.605778, 5, pid=8470] [2015/04/22 17:09:57.605792, 5, pid=8470] size=92 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7786 smb_uid=100 smb_mid=34 smt_wct=15 smb_vwv[ 0]= 26 (0x1A) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 4000 (0xFA0) 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]= 66 (0x42) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 5 (0x5) smb_bcc=27 [2015/04/22 17:09:57.606056, 10, pid=8470] [0000] 00 07 01 00 00 00 00 5C 00 44 00 49 00 52 00 31 .......\ .D.I.R.1 [0010] 00 5C 00 46 00 4F 00 4F 00 00 00 .\.F.O.O ... [2015/04/22 17:09:57.606110, 3, pid=8470] switch message SMBtrans2 (pid 8470) conn 0x7fd08dce6d70 [2015/04/22 17:09:57.606135, 4, pid=8470] Skipping user change - already user [2015/04/22 17:09:57.606159, 3, pid=8470] call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 263 [2015/04/22 17:09:57.606185, 5, pid=8470] unix_convert called on file "DIR1/FOO" [2015/04/22 17:09:57.606209, 5, pid=8470] unix_convert begin: name = DIR1/FOO, dirpath = , start = DIR1/FOO [2015/04/22 17:09:57.606236, 5, pid=8470] conversion of base_name finished DIR1/FOO -> DIR1/FOO [2015/04/22 17:09:57.606260, 3, pid=8470] check_reduced_name [DIR1/FOO] [/home1/shares/test4] [2015/04/22 17:09:57.606291, 10, pid=8470] check_reduced_name realpath [DIR1/FOO] -> [/home1/shares/test4/DIR1/FOO] [2015/04/22 17:09:57.606315, 3, pid=8470] check_reduced_name: DIR1/FOO reduced to /home1/shares/test4/DIR1/FOO [2015/04/22 17:09:57.606342, 10, pid=8470] file_name_hash: /home1/shares/test4/DIR1/FOO hash 0x2de3a41d [2015/04/22 17:09:57.606370, 10, pid=8470] fetch_share_mode_unlocked: no share_mode record around (file not open) [2015/04/22 17:09:57.606394, 3, pid=8470] call_trans2qfilepathinfo DIR1/FOO (fnum = -1) level=263 call=5 total_data=0 [2015/04/22 17:09:57.606418, 5, pid=8470] smbd_do_qfilepathinfo: DIR1/FOO (fnum = -1) level=263 max_data=4000 [2015/04/22 17:09:57.606441, 8, pid=8470] dos_mode: DIR1/FOO [2015/04/22 17:09:57.606464, 8, pid=8470] dos_mode_from_sbuf returning a [2015/04/22 17:09:57.606487, 8, pid=8470] dos_mode returning a [2015/04/22 17:09:57.606513, 10, pid=8470] smbd_do_qfilepathinfo: SMB_FILE_ALL_INFORMATION [2015/04/22 17:09:57.606537, 9, pid=8470] t2_rep: params_sent_thistime = 2, data_sent_thistime = 90, useable_space = 16410 [2015/04/22 17:09:57.606560, 9, pid=8470] t2_rep: params_to_send = 2, data_to_send = 90, paramsize = 2, datasize = 90 [2015/04/22 17:09:57.606583, 5, pid=8470] [2015/04/22 17:09:57.606596, 5, pid=8470] size=150 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49155 smb_tid=1 smb_pid=7786 smb_uid=100 smb_mid=34 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 90 (0x5A) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 90 (0x5A) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=95 [2015/04/22 17:09:57.606810, 10, pid=8470] [0000] 00 00 00 00 00 80 19 E2 24 1F 7D D0 01 5E 7F F2 ........ $.}..^.. [0010] 24 1F 7D D0 01 5E 7F F2 24 1F 7D D0 01 5E 7F F2 $.}..^.. $.}..^.. [0020] 24 1F 7D D0 01 20 00 00 00 00 00 00 00 00 00 00 $.}.. .. ........ [0030] 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 ........ ........ [0040] 00 00 00 00 00 00 00 00 00 12 00 00 00 5C 00 44 ........ .....\.D [0050] 00 49 00 52 00 31 00 5C 00 46 00 4F 00 4F 00 .I.R.1.\ .F.O.O. [2015/04/22 17:09:57.607335, 10, pid=8470] got smb length of 58 [2015/04/22 17:09:57.607422, 6, pid=8470] got message type 0x0 of len 0x3a [2015/04/22 17:09:57.607473, 3, pid=8470] Transaction 11 of length 62 (0 toread) [2015/04/22 17:09:57.607496, 5, pid=8470] [2015/04/22 17:09:57.607510, 5, pid=8470] size=58 smb_com=0x6 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7786 smb_uid=100 smb_mid=35 smt_wct=1 smb_vwv[ 0]= 7 (0x7) smb_bcc=21 [2015/04/22 17:09:57.607639, 10, pid=8470] [0000] 04 5C 00 44 00 49 00 52 00 31 00 5C 00 46 00 4F .\.D.I.R .1.\.F.O [0010] 00 4F 00 00 00 .O... [2015/04/22 17:09:57.607691, 3, pid=8470] switch message SMBunlink (pid 8470) conn 0x7fd08dce6d70 [2015/04/22 17:09:57.607715, 4, pid=8470] Skipping user change - already user [2015/04/22 17:09:57.607741, 5, pid=8470] unix_convert called on file "DIR1/FOO" [2015/04/22 17:09:57.607766, 5, pid=8470] unix_convert begin: name = DIR1/FOO, dirpath = , start = DIR1/FOO [2015/04/22 17:09:57.607792, 5, pid=8470] conversion of base_name finished DIR1/FOO -> DIR1/FOO [2015/04/22 17:09:57.607823, 3, pid=8470] check_reduced_name [DIR1/FOO] [/home1/shares/test4] [2015/04/22 17:09:57.607855, 10, pid=8470] check_reduced_name realpath [DIR1/FOO] -> [/home1/shares/test4/DIR1/FOO] [2015/04/22 17:09:57.607879, 3, pid=8470] check_reduced_name: DIR1/FOO reduced to /home1/shares/test4/DIR1/FOO [2015/04/22 17:09:57.607903, 3, pid=8470] reply_unlink : DIR1/FOO [2015/04/22 17:09:57.607931, 3, pid=8470] check_reduced_name [DIR1/FOO] [/home1/shares/test4] [2015/04/22 17:09:57.607960, 10, pid=8470] check_reduced_name realpath [DIR1/FOO] -> [/home1/shares/test4/DIR1/FOO] [2015/04/22 17:09:57.607984, 3, pid=8470] check_reduced_name: DIR1/FOO reduced to /home1/shares/test4/DIR1/FOO [2015/04/22 17:09:57.608007, 10, pid=8470] do_unlink: DIR1/FOO, dirtype = 7 [2015/04/22 17:09:57.608032, 8, pid=8470] dos_mode: DIR1/FOO [2015/04/22 17:09:57.608055, 8, pid=8470] dos_mode_from_sbuf returning a [2015/04/22 17:09:57.608079, 8, pid=8470] dos_mode returning a [2015/04/22 17:09:57.608103, 10, pid=8470] create_file: access_mask = 0x10000 file_attributes = 0x80, share_access = 0x0, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 private_flags = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = DIR1/FOO [2015/04/22 17:09:57.608132, 10, pid=8470] create_file_unixpath: access_mask = 0x10000 file_attributes = 0x80, share_access = 0x0, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 private_flags = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = DIR1/FOO [2015/04/22 17:09:57.608163, 10, pid=8470] posix_get_nt_acl: called for file DIR1 [2015/04/22 17:09:57.608214, 10, pid=8470] canonicalise_acl: Access ace entries before arrange : [2015/04/22 17:09:57.608241, 10, pid=8470] canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-x [2015/04/22 17:09:57.608269, 10, pid=8470] canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nfsnobody) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-x [2015/04/22 17:09:57.608338, 10, pid=8470] canon_ace index 2. Type = allow SID = S-1-5-21-1728798723-2110846055-115949566-501 uid 65534 (nfsnobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx [2015/04/22 17:09:57.608389, 10, pid=8470] print_canon_ace_list: canonicalise_acl: ace entries after arrange canon_ace index 0. Type = allow SID = S-1-5-21-1728798723-2110846055-115949566-501 uid 65534 (nfsnobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nfsnobody) 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 r-x [2015/04/22 17:09:57.608498, 10, pid=8470] map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff [2015/04/22 17:09:57.608523, 10, pid=8470] map_canon_ace_perms: Mapped (UNIX) 140 to (NT) 1200a9 [2015/04/22 17:09:57.608546, 10, pid=8470] map_canon_ace_perms: Mapped (UNIX) 140 to (NT) 1200a9 [2015/04/22 17:09:57.608574, 10, pid=8470] can_access_file_acl for file DIR1 access_mask 0x40, access_granted 0x40 access DENIED [2015/04/22 17:09:57.608602, 1, pid=8470] secdesc: struct security_descriptor revision : SECURITY_DESCRIPTOR_REVISION_1 (1) type : 0x9004 (36868) 0: SEC_DESC_OWNER_DEFAULTED 0: SEC_DESC_GROUP_DEFAULTED 1: SEC_DESC_DACL_PRESENT 0: SEC_DESC_DACL_DEFAULTED 0: SEC_DESC_SACL_PRESENT 0: SEC_DESC_SACL_DEFAULTED 0: SEC_DESC_DACL_TRUSTED 0: SEC_DESC_SERVER_SECURITY 0: SEC_DESC_DACL_AUTO_INHERIT_REQ 0: SEC_DESC_SACL_AUTO_INHERIT_REQ 0: SEC_DESC_DACL_AUTO_INHERITED 0: SEC_DESC_SACL_AUTO_INHERITED 1: SEC_DESC_DACL_PROTECTED 0: SEC_DESC_SACL_PROTECTED 0: SEC_DESC_RM_CONTROL_VALID 1: SEC_DESC_SELF_RELATIVE owner_sid : * owner_sid : S-1-5-21-1728798723-2110846055-115949566-501 group_sid : * group_sid : S-1-22-2-65534 sacl : NULL dacl : * dacl: struct security_acl revision : SECURITY_ACL_REVISION_NT4 (2) size : 0x0058 (88) num_aces : 0x00000003 (3) aces: ARRAY(3) aces: struct security_ace type : SEC_ACE_TYPE_ACCESS_ALLOWED (0) flags : 0x00 (0) 0: SEC_ACE_FLAG_OBJECT_INHERIT 0: SEC_ACE_FLAG_CONTAINER_INHERIT 0: SEC_ACE_FLAG_NO_PROPAGATE_INHERIT 0: SEC_ACE_FLAG_INHERIT_ONLY 0: SEC_ACE_FLAG_INHERITED_ACE 0x00: SEC_ACE_FLAG_VALID_INHERIT (0) 0: SEC_ACE_FLAG_SUCCESSFUL_ACCESS 0: SEC_ACE_FLAG_FAILED_ACCESS size : 0x0024 (36) access_mask : 0x001f01ff (2032127) object : union security_ace_object_ctr(case 0) trustee : S-1-5-21-1728798723-2110846055-115949566-501 aces: struct security_ace type : SEC_ACE_TYPE_ACCESS_ALLOWED (0) flags : 0x00 (0) 0: SEC_ACE_FLAG_OBJECT_INHERIT 0: SEC_ACE_FLAG_CONTAINER_INHERIT 0: SEC_ACE_FLAG_NO_PROPAGATE_INHERIT 0: SEC_ACE_FLAG_INHERIT_ONLY 0: SEC_ACE_FLAG_INHERITED_ACE 0x00: SEC_ACE_FLAG_VALID_INHERIT (0) 0: SEC_ACE_FLAG_SUCCESSFUL_ACCESS 0: SEC_ACE_FLAG_FAILED_ACCESS size : 0x0018 (24) access_mask : 0x001200a9 (1179817) object : union security_ace_object_ctr(case 0) trustee : S-1-22-2-65534 aces: struct security_ace type : SEC_ACE_TYPE_ACCESS_ALLOWED (0) flags : 0x00 (0) 0: SEC_ACE_FLAG_OBJECT_INHERIT 0: SEC_ACE_FLAG_CONTAINER_INHERIT 0: SEC_ACE_FLAG_NO_PROPAGATE_INHERIT 0: SEC_ACE_FLAG_INHERIT_ONLY 0: SEC_ACE_FLAG_INHERITED_ACE 0x00: SEC_ACE_FLAG_VALID_INHERIT (0) 0: SEC_ACE_FLAG_SUCCESSFUL_ACCESS 0: SEC_ACE_FLAG_FAILED_ACCESS size : 0x0014 (20) access_mask : 0x001200a9 (1179817) object : union security_ace_object_ctr(case 0) trustee : S-1-1-0 [2015/04/22 17:09:57.609449, 10, pid=8470] posix_get_nt_acl: called for file DIR1/FOO [2015/04/22 17:09:57.609484, 10, pid=8470] canonicalise_acl: Access ace entries before arrange : [2015/04/22 17:09:57.609509, 10, pid=8470] canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-- [2015/04/22 17:09:57.609535, 10, pid=8470] canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nfsnobody) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-- [2015/04/22 17:09:57.609581, 10, pid=8470] canon_ace index 2. Type = allow SID = S-1-5-21-1728798723-2110846055-115949566-501 uid 65534 (nfsnobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx [2015/04/22 17:09:57.609626, 10, pid=8470] print_canon_ace_list: canonicalise_acl: ace entries after arrange canon_ace index 0. Type = allow SID = S-1-5-21-1728798723-2110846055-115949566-501 uid 65534 (nfsnobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nfsnobody) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-- canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-- [2015/04/22 17:09:57.609724, 10, pid=8470] map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1e01ff [2015/04/22 17:09:57.609748, 10, pid=8470] map_canon_ace_perms: Mapped (UNIX) 100 to (NT) 120089 [2015/04/22 17:09:57.609771, 10, pid=8470] map_canon_ace_perms: Mapped (UNIX) 100 to (NT) 120089 [2015/04/22 17:09:57.609798, 10, pid=8470] can_access_file_acl for file DIR1/FOO access_mask 0x10000, access_granted 0x10000 access DENIED [2015/04/22 17:09:57.609830, 1, pid=8470] secdesc: struct security_descriptor revision : SECURITY_DESCRIPTOR_REVISION_1 (1) type : 0x9004 (36868) 0: SEC_DESC_OWNER_DEFAULTED 0: SEC_DESC_GROUP_DEFAULTED 1: SEC_DESC_DACL_PRESENT 0: SEC_DESC_DACL_DEFAULTED 0: SEC_DESC_SACL_PRESENT 0: SEC_DESC_SACL_DEFAULTED 0: SEC_DESC_DACL_TRUSTED 0: SEC_DESC_SERVER_SECURITY 0: SEC_DESC_DACL_AUTO_INHERIT_REQ 0: SEC_DESC_SACL_AUTO_INHERIT_REQ 0: SEC_DESC_DACL_AUTO_INHERITED 0: SEC_DESC_SACL_AUTO_INHERITED 1: SEC_DESC_DACL_PROTECTED 0: SEC_DESC_SACL_PROTECTED 0: SEC_DESC_RM_CONTROL_VALID 1: SEC_DESC_SELF_RELATIVE owner_sid : * owner_sid : S-1-5-21-1728798723-2110846055-115949566-501 group_sid : * group_sid : S-1-22-2-65534 sacl : NULL dacl : * dacl: struct security_acl revision : SECURITY_ACL_REVISION_NT4 (2) size : 0x0058 (88) num_aces : 0x00000003 (3) aces: ARRAY(3) aces: struct security_ace type : SEC_ACE_TYPE_ACCESS_ALLOWED (0) flags : 0x00 (0) 0: SEC_ACE_FLAG_OBJECT_INHERIT 0: SEC_ACE_FLAG_CONTAINER_INHERIT 0: SEC_ACE_FLAG_NO_PROPAGATE_INHERIT 0: SEC_ACE_FLAG_INHERIT_ONLY 0: SEC_ACE_FLAG_INHERITED_ACE 0x00: SEC_ACE_FLAG_VALID_INHERIT (0) 0: SEC_ACE_FLAG_SUCCESSFUL_ACCESS 0: SEC_ACE_FLAG_FAILED_ACCESS size : 0x0024 (36) access_mask : 0x001e01ff (1966591) object : union security_ace_object_ctr(case 0) trustee : S-1-5-21-1728798723-2110846055-115949566-501 aces: struct security_ace type : SEC_ACE_TYPE_ACCESS_ALLOWED (0) flags : 0x00 (0) 0: SEC_ACE_FLAG_OBJECT_INHERIT 0: SEC_ACE_FLAG_CONTAINER_INHERIT 0: SEC_ACE_FLAG_NO_PROPAGATE_INHERIT 0: SEC_ACE_FLAG_INHERIT_ONLY 0: SEC_ACE_FLAG_INHERITED_ACE 0x00: SEC_ACE_FLAG_VALID_INHERIT (0) 0: SEC_ACE_FLAG_SUCCESSFUL_ACCESS 0: SEC_ACE_FLAG_FAILED_ACCESS size : 0x0018 (24) access_mask : 0x00120089 (1179785) object : union security_ace_object_ctr(case 0) trustee : S-1-22-2-65534 aces: struct security_ace type : SEC_ACE_TYPE_ACCESS_ALLOWED (0) flags : 0x00 (0) 0: SEC_ACE_FLAG_OBJECT_INHERIT 0: SEC_ACE_FLAG_CONTAINER_INHERIT 0: SEC_ACE_FLAG_NO_PROPAGATE_INHERIT 0: SEC_ACE_FLAG_INHERIT_ONLY 0: SEC_ACE_FLAG_INHERITED_ACE 0x00: SEC_ACE_FLAG_VALID_INHERIT (0) 0: SEC_ACE_FLAG_SUCCESSFUL_ACCESS 0: SEC_ACE_FLAG_FAILED_ACCESS size : 0x0014 (20) access_mask : 0x00120089 (1179785) object : union security_ace_object_ctr(case 0) trustee : S-1-1-0 [2015/04/22 17:09:57.610645, 10, pid=8470] create_file_unixpath: open file DIR1/FOO for delete ACCESS_DENIED [2015/04/22 17:09:57.610670, 10, pid=8470] create_file_unixpath: NT_STATUS_ACCESS_DENIED [2015/04/22 17:09:57.610693, 10, pid=8470] create_file: NT_STATUS_ACCESS_DENIED [2015/04/22 17:09:57.610716, 10, pid=8470] SMB_VFS_CREATEFILE failed: NT_STATUS_ACCESS_DENIED [2015/04/22 17:09:57.610740, 3, pid=8470] error packet at smbd/reply.c(2820) cmd=6 (SMBunlink) NT_STATUS_ACCESS_DENIED [2015/04/22 17:09:57.610765, 5, pid=8470] [2015/04/22 17:09:57.610779, 5, pid=8470] size=35 smb_com=0x6 smb_rcls=34 smb_reh=0 smb_err=49152 smb_flg=128 smb_flg2=49155 smb_tid=1 smb_pid=7786 smb_uid=100 smb_mid=35 smt_wct=0 smb_bcc=0 [2015/04/22 17:09:57.610905, 10, pid=8470] [2015/04/22 17:09:57.611252, 10, pid=8470] got smb length of 134 [2015/04/22 17:09:57.611353, 6, pid=8470] got message type 0x0 of len 0x86 [2015/04/22 17:09:57.611400, 3, pid=8470] Transaction 12 of length 138 (0 toread) [2015/04/22 17:09:57.611423, 5, pid=8470] [2015/04/22 17:09:57.611436, 5, pid=8470] size=134 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7786 smb_uid=100 smb_mid=36 smt_wct=15 smb_vwv[ 0]= 26 (0x1A) smb_vwv[ 1]= 40 (0x28) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 1000 (0x3E8) 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]= 40 (0x28) smb_vwv[12]= 94 (0x5E) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 6 (0x6) smb_bcc=69 [2015/04/22 17:09:57.611690, 10, pid=8470] [0000] 00 00 00 EC 03 00 00 00 00 5C 00 44 00 49 00 52 ........ .\.D.I.R [0010] 00 31 00 5C 00 46 00 4F 00 4F 00 00 00 00 00 00 .1.\.F.O .O...... [0020] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0030] 00 00 00 00 00 00 00 00 00 00 00 00 00 22 00 00 ........ .....".. [0040] 00 00 88 FF FF ..... [2015/04/22 17:09:57.611800, 3, pid=8470] switch message SMBtrans2 (pid 8470) conn 0x7fd08dce6d70 [2015/04/22 17:09:57.611833, 4, pid=8470] Skipping user change - already user [2015/04/22 17:09:57.611860, 5, pid=8470] unix_convert called on file "DIR1/FOO" [2015/04/22 17:09:57.611885, 5, pid=8470] unix_convert begin: name = DIR1/FOO, dirpath = , start = DIR1/FOO [2015/04/22 17:09:57.611911, 5, pid=8470] conversion of base_name finished DIR1/FOO -> DIR1/FOO [2015/04/22 17:09:57.611935, 3, pid=8470] check_reduced_name [DIR1/FOO] [/home1/shares/test4] [2015/04/22 17:09:57.611965, 10, pid=8470] check_reduced_name realpath [DIR1/FOO] -> [/home1/shares/test4/DIR1/FOO] [2015/04/22 17:09:57.611989, 3, pid=8470] check_reduced_name: DIR1/FOO reduced to /home1/shares/test4/DIR1/FOO [2015/04/22 17:09:57.612012, 3, pid=8470] call_trans2setfilepathinfo(6) DIR1/FOO (fnum -1) info_level=1004 totdata=40 [2015/04/22 17:09:57.612036, 3, pid=8470] smbd_do_setfilepathinfo: DIR1/FOO (fnum -1) info_level=1004 totdata=40 [2015/04/22 17:09:57.612060, 6, pid=8470] smb_set_file_dosmode: dosmode: 0x22 [2015/04/22 17:09:57.612082, 8, pid=8470] dos_mode: DIR1/FOO [2015/04/22 17:09:57.612105, 8, pid=8470] dos_mode_from_sbuf returning a [2015/04/22 17:09:57.612128, 8, pid=8470] dos_mode returning a [2015/04/22 17:09:57.612150, 10, pid=8470] smb_set_file_dosmode: file DIR1/FOO : setting dos mode 0x22 [2015/04/22 17:09:57.612173, 10, pid=8470] file_set_dosmode: setting dos mode 0x22 on file DIR1/FOO [2015/04/22 17:09:57.612202, 8, pid=8470] dos_mode: DIR1/FOO [2015/04/22 17:09:57.612227, 8, pid=8470] dos_mode_from_sbuf returning a [2015/04/22 17:09:57.612250, 8, pid=8470] dos_mode returning a [2015/04/22 17:09:57.612273, 3, pid=8470] unix_mode(DIR1/FOO) returning 0744 [2015/04/22 17:09:57.612334, 10, pid=8470] notify_trigger called action=0x3, filter=0x4, path=/home1/shares/test4/DIR1/FOO [2015/04/22 17:09:57.612364, 10, pid=8470] smb_set_file_basic_info: file DIR1/FOO [2015/04/22 17:09:57.612388, 5, pid=8470] smb_set_filetime: actime: Thu Jan 1 00:00:00 1970 smb_set_filetime: modtime: Thu Jan 1 00:00:00 1970 smb_set_filetime: ctime: Thu Jan 1 00:00:00 1970 smb_set_file_time: createtime: Thu Jan 1 00:00:00 1970 smb_set_file_time: setting pending modtime to Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:57.612507, 10, pid=8470] smb_set_file_time: setting utimes to modified values. [2015/04/22 17:09:57.612529, 6, pid=8470] file_ntime: actime: Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:57.612555, 6, pid=8470] file_ntime: modtime: Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:57.612581, 6, pid=8470] file_ntime: ctime: Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:57.612607, 6, pid=8470] file_ntime: createtime: Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:57.612653, 10, pid=8470] notify_trigger called action=0x3, filter=0x0, path=/home1/shares/test4/DIR1/FOO [2015/04/22 17:09:57.612681, 9, pid=8470] t2_rep: params_sent_thistime = 2, data_sent_thistime = 0, useable_space = 16412 [2015/04/22 17:09:57.612705, 9, pid=8470] t2_rep: params_to_send = 2, data_to_send = 0, paramsize = 2, datasize = 0 [2015/04/22 17:09:57.612727, 5, pid=8470] [2015/04/22 17:09:57.612741, 5, pid=8470] size=58 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49155 smb_tid=1 smb_pid=7786 smb_uid=100 smb_mid=36 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=3 [2015/04/22 17:09:57.612957, 10, pid=8470] [0000] 00 00 00 ... [2015/04/22 17:09:57.613320, 10, pid=8470] got smb length of 58 [2015/04/22 17:09:57.613403, 6, pid=8470] got message type 0x0 of len 0x3a [2015/04/22 17:09:57.613456, 3, pid=8470] Transaction 13 of length 62 (0 toread) [2015/04/22 17:09:57.613482, 5, pid=8470] [2015/04/22 17:09:57.613495, 5, pid=8470] size=58 smb_com=0x6 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7786 smb_uid=100 smb_mid=37 smt_wct=1 smb_vwv[ 0]= 7 (0x7) smb_bcc=21 [2015/04/22 17:09:57.613624, 10, pid=8470] [0000] 04 5C 00 44 00 49 00 52 00 31 00 5C 00 46 00 4F .\.D.I.R .1.\.F.O [0010] 00 4F 00 00 00 .O... [2015/04/22 17:09:57.613674, 3, pid=8470] switch message SMBunlink (pid 8470) conn 0x7fd08dce6d70 [2015/04/22 17:09:57.613698, 4, pid=8470] Skipping user change - already user [2015/04/22 17:09:57.613723, 5, pid=8470] unix_convert called on file "DIR1/FOO" [2015/04/22 17:09:57.613747, 5, pid=8470] unix_convert begin: name = DIR1/FOO, dirpath = , start = DIR1/FOO [2015/04/22 17:09:57.613773, 5, pid=8470] conversion of base_name finished DIR1/FOO -> DIR1/FOO [2015/04/22 17:09:57.613797, 3, pid=8470] check_reduced_name [DIR1/FOO] [/home1/shares/test4] [2015/04/22 17:09:57.613833, 10, pid=8470] check_reduced_name realpath [DIR1/FOO] -> [/home1/shares/test4/DIR1/FOO] [2015/04/22 17:09:57.613857, 3, pid=8470] check_reduced_name: DIR1/FOO reduced to /home1/shares/test4/DIR1/FOO [2015/04/22 17:09:57.613880, 3, pid=8470] reply_unlink : DIR1/FOO [2015/04/22 17:09:57.613905, 3, pid=8470] check_reduced_name [DIR1/FOO] [/home1/shares/test4] [2015/04/22 17:09:57.613933, 10, pid=8470] check_reduced_name realpath [DIR1/FOO] -> [/home1/shares/test4/DIR1/FOO] [2015/04/22 17:09:57.613957, 3, pid=8470] check_reduced_name: DIR1/FOO reduced to /home1/shares/test4/DIR1/FOO [2015/04/22 17:09:57.613980, 10, pid=8470] do_unlink: DIR1/FOO, dirtype = 7 [2015/04/22 17:09:57.614005, 8, pid=8470] dos_mode: DIR1/FOO [2015/04/22 17:09:57.614028, 8, pid=8470] dos_mode_from_sbuf returning a [2015/04/22 17:09:57.614051, 8, pid=8470] dos_mode returning a [2015/04/22 17:09:57.614074, 10, pid=8470] create_file: access_mask = 0x10000 file_attributes = 0x80, share_access = 0x0, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 private_flags = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = DIR1/FOO [2015/04/22 17:09:57.614100, 10, pid=8470] create_file_unixpath: access_mask = 0x10000 file_attributes = 0x80, share_access = 0x0, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 private_flags = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = DIR1/FOO [2015/04/22 17:09:57.614129, 10, pid=8470] posix_get_nt_acl: called for file DIR1 [2015/04/22 17:09:57.614162, 10, pid=8470] canonicalise_acl: Access ace entries before arrange : [2015/04/22 17:09:57.614187, 10, pid=8470] canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-x [2015/04/22 17:09:57.614213, 10, pid=8470] canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nfsnobody) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-x [2015/04/22 17:09:57.614268, 10, pid=8470] canon_ace index 2. Type = allow SID = S-1-5-21-1728798723-2110846055-115949566-501 uid 65534 (nfsnobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx [2015/04/22 17:09:57.614316, 10, pid=8470] print_canon_ace_list: canonicalise_acl: ace entries after arrange canon_ace index 0. Type = allow SID = S-1-5-21-1728798723-2110846055-115949566-501 uid 65534 (nfsnobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nfsnobody) 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 r-x [2015/04/22 17:09:57.614413, 10, pid=8470] map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff [2015/04/22 17:09:57.614437, 10, pid=8470] map_canon_ace_perms: Mapped (UNIX) 140 to (NT) 1200a9 [2015/04/22 17:09:57.614460, 10, pid=8470] map_canon_ace_perms: Mapped (UNIX) 140 to (NT) 1200a9 [2015/04/22 17:09:57.614485, 10, pid=8470] can_access_file_acl for file DIR1 access_mask 0x40, access_granted 0x40 access DENIED [2015/04/22 17:09:57.614510, 1, pid=8470] secdesc: struct security_descriptor revision : SECURITY_DESCRIPTOR_REVISION_1 (1) type : 0x9004 (36868) 0: SEC_DESC_OWNER_DEFAULTED 0: SEC_DESC_GROUP_DEFAULTED 1: SEC_DESC_DACL_PRESENT 0: SEC_DESC_DACL_DEFAULTED 0: SEC_DESC_SACL_PRESENT 0: SEC_DESC_SACL_DEFAULTED 0: SEC_DESC_DACL_TRUSTED 0: SEC_DESC_SERVER_SECURITY 0: SEC_DESC_DACL_AUTO_INHERIT_REQ 0: SEC_DESC_SACL_AUTO_INHERIT_REQ 0: SEC_DESC_DACL_AUTO_INHERITED 0: SEC_DESC_SACL_AUTO_INHERITED 1: SEC_DESC_DACL_PROTECTED 0: SEC_DESC_SACL_PROTECTED 0: SEC_DESC_RM_CONTROL_VALID 1: SEC_DESC_SELF_RELATIVE owner_sid : * owner_sid : S-1-5-21-1728798723-2110846055-115949566-501 group_sid : * group_sid : S-1-22-2-65534 sacl : NULL dacl : * dacl: struct security_acl revision : SECURITY_ACL_REVISION_NT4 (2) size : 0x0058 (88) num_aces : 0x00000003 (3) aces: ARRAY(3) aces: struct security_ace type : SEC_ACE_TYPE_ACCESS_ALLOWED (0) flags : 0x00 (0) 0: SEC_ACE_FLAG_OBJECT_INHERIT 0: SEC_ACE_FLAG_CONTAINER_INHERIT 0: SEC_ACE_FLAG_NO_PROPAGATE_INHERIT 0: SEC_ACE_FLAG_INHERIT_ONLY 0: SEC_ACE_FLAG_INHERITED_ACE 0x00: SEC_ACE_FLAG_VALID_INHERIT (0) 0: SEC_ACE_FLAG_SUCCESSFUL_ACCESS 0: SEC_ACE_FLAG_FAILED_ACCESS size : 0x0024 (36) access_mask : 0x001f01ff (2032127) object : union security_ace_object_ctr(case 0) trustee : S-1-5-21-1728798723-2110846055-115949566-501 aces: struct security_ace type : SEC_ACE_TYPE_ACCESS_ALLOWED (0) flags : 0x00 (0) 0: SEC_ACE_FLAG_OBJECT_INHERIT 0: SEC_ACE_FLAG_CONTAINER_INHERIT 0: SEC_ACE_FLAG_NO_PROPAGATE_INHERIT 0: SEC_ACE_FLAG_INHERIT_ONLY 0: SEC_ACE_FLAG_INHERITED_ACE 0x00: SEC_ACE_FLAG_VALID_INHERIT (0) 0: SEC_ACE_FLAG_SUCCESSFUL_ACCESS 0: SEC_ACE_FLAG_FAILED_ACCESS size : 0x0018 (24) access_mask : 0x001200a9 (1179817) object : union security_ace_object_ctr(case 0) trustee : S-1-22-2-65534 aces: struct security_ace type : SEC_ACE_TYPE_ACCESS_ALLOWED (0) flags : 0x00 (0) 0: SEC_ACE_FLAG_OBJECT_INHERIT 0: SEC_ACE_FLAG_CONTAINER_INHERIT 0: SEC_ACE_FLAG_NO_PROPAGATE_INHERIT 0: SEC_ACE_FLAG_INHERIT_ONLY 0: SEC_ACE_FLAG_INHERITED_ACE 0x00: SEC_ACE_FLAG_VALID_INHERIT (0) 0: SEC_ACE_FLAG_SUCCESSFUL_ACCESS 0: SEC_ACE_FLAG_FAILED_ACCESS size : 0x0014 (20) access_mask : 0x001200a9 (1179817) object : union security_ace_object_ctr(case 0) trustee : S-1-1-0 [2015/04/22 17:09:57.615333, 10, pid=8470] posix_get_nt_acl: called for file DIR1/FOO [2015/04/22 17:09:57.615367, 10, pid=8470] canonicalise_acl: Access ace entries before arrange : [2015/04/22 17:09:57.615392, 10, pid=8470] canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-- [2015/04/22 17:09:57.615418, 10, pid=8470] canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nfsnobody) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-- [2015/04/22 17:09:57.615463, 10, pid=8470] canon_ace index 2. Type = allow SID = S-1-5-21-1728798723-2110846055-115949566-501 uid 65534 (nfsnobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx [2015/04/22 17:09:57.615509, 10, pid=8470] print_canon_ace_list: canonicalise_acl: ace entries after arrange canon_ace index 0. Type = allow SID = S-1-5-21-1728798723-2110846055-115949566-501 uid 65534 (nfsnobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nfsnobody) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-- canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-- [2015/04/22 17:09:57.615607, 10, pid=8470] map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1e01ff [2015/04/22 17:09:57.615630, 10, pid=8470] map_canon_ace_perms: Mapped (UNIX) 100 to (NT) 120089 [2015/04/22 17:09:57.615653, 10, pid=8470] map_canon_ace_perms: Mapped (UNIX) 100 to (NT) 120089 [2015/04/22 17:09:57.615679, 10, pid=8470] can_access_file_acl for file DIR1/FOO access_mask 0x10000, access_granted 0x10000 access DENIED [2015/04/22 17:09:57.615704, 1, pid=8470] secdesc: struct security_descriptor revision : SECURITY_DESCRIPTOR_REVISION_1 (1) type : 0x9004 (36868) 0: SEC_DESC_OWNER_DEFAULTED 0: SEC_DESC_GROUP_DEFAULTED 1: SEC_DESC_DACL_PRESENT 0: SEC_DESC_DACL_DEFAULTED 0: SEC_DESC_SACL_PRESENT 0: SEC_DESC_SACL_DEFAULTED 0: SEC_DESC_DACL_TRUSTED 0: SEC_DESC_SERVER_SECURITY 0: SEC_DESC_DACL_AUTO_INHERIT_REQ 0: SEC_DESC_SACL_AUTO_INHERIT_REQ 0: SEC_DESC_DACL_AUTO_INHERITED 0: SEC_DESC_SACL_AUTO_INHERITED 1: SEC_DESC_DACL_PROTECTED 0: SEC_DESC_SACL_PROTECTED 0: SEC_DESC_RM_CONTROL_VALID 1: SEC_DESC_SELF_RELATIVE owner_sid : * owner_sid : S-1-5-21-1728798723-2110846055-115949566-501 group_sid : * group_sid : S-1-22-2-65534 sacl : NULL dacl : * dacl: struct security_acl revision : SECURITY_ACL_REVISION_NT4 (2) size : 0x0058 (88) num_aces : 0x00000003 (3) aces: ARRAY(3) aces: struct security_ace type : SEC_ACE_TYPE_ACCESS_ALLOWED (0) flags : 0x00 (0) 0: SEC_ACE_FLAG_OBJECT_INHERIT 0: SEC_ACE_FLAG_CONTAINER_INHERIT 0: SEC_ACE_FLAG_NO_PROPAGATE_INHERIT 0: SEC_ACE_FLAG_INHERIT_ONLY 0: SEC_ACE_FLAG_INHERITED_ACE 0x00: SEC_ACE_FLAG_VALID_INHERIT (0) 0: SEC_ACE_FLAG_SUCCESSFUL_ACCESS 0: SEC_ACE_FLAG_FAILED_ACCESS size : 0x0024 (36) access_mask : 0x001e01ff (1966591) object : union security_ace_object_ctr(case 0) trustee : S-1-5-21-1728798723-2110846055-115949566-501 aces: struct security_ace type : SEC_ACE_TYPE_ACCESS_ALLOWED (0) flags : 0x00 (0) 0: SEC_ACE_FLAG_OBJECT_INHERIT 0: SEC_ACE_FLAG_CONTAINER_INHERIT 0: SEC_ACE_FLAG_NO_PROPAGATE_INHERIT 0: SEC_ACE_FLAG_INHERIT_ONLY 0: SEC_ACE_FLAG_INHERITED_ACE 0x00: SEC_ACE_FLAG_VALID_INHERIT (0) 0: SEC_ACE_FLAG_SUCCESSFUL_ACCESS 0: SEC_ACE_FLAG_FAILED_ACCESS size : 0x0018 (24) access_mask : 0x00120089 (1179785) object : union security_ace_object_ctr(case 0) trustee : S-1-22-2-65534 aces: struct security_ace type : SEC_ACE_TYPE_ACCESS_ALLOWED (0) flags : 0x00 (0) 0: SEC_ACE_FLAG_OBJECT_INHERIT 0: SEC_ACE_FLAG_CONTAINER_INHERIT 0: SEC_ACE_FLAG_NO_PROPAGATE_INHERIT 0: SEC_ACE_FLAG_INHERIT_ONLY 0: SEC_ACE_FLAG_INHERITED_ACE 0x00: SEC_ACE_FLAG_VALID_INHERIT (0) 0: SEC_ACE_FLAG_SUCCESSFUL_ACCESS 0: SEC_ACE_FLAG_FAILED_ACCESS size : 0x0014 (20) access_mask : 0x00120089 (1179785) object : union security_ace_object_ctr(case 0) trustee : S-1-1-0 [2015/04/22 17:09:57.616531, 10, pid=8470] create_file_unixpath: open file DIR1/FOO for delete ACCESS_DENIED [2015/04/22 17:09:57.616556, 10, pid=8470] create_file_unixpath: NT_STATUS_ACCESS_DENIED [2015/04/22 17:09:57.616579, 10, pid=8470] create_file: NT_STATUS_ACCESS_DENIED [2015/04/22 17:09:57.616608, 10, pid=8470] SMB_VFS_CREATEFILE failed: NT_STATUS_ACCESS_DENIED [2015/04/22 17:09:57.616633, 3, pid=8470] error packet at smbd/reply.c(2820) cmd=6 (SMBunlink) NT_STATUS_ACCESS_DENIED [2015/04/22 17:09:57.616658, 5, pid=8470] [2015/04/22 17:09:57.616671, 5, pid=8470] size=35 smb_com=0x6 smb_rcls=34 smb_reh=0 smb_err=49152 smb_flg=128 smb_flg2=49155 smb_tid=1 smb_pid=7786 smb_uid=100 smb_mid=37 smt_wct=0 smb_bcc=0 [2015/04/22 17:09:57.616790, 10, pid=8470] [2015/04/22 17:09:57.617138, 10, pid=8470] got smb length of 134 [2015/04/22 17:09:57.617222, 6, pid=8470] got message type 0x0 of len 0x86 [2015/04/22 17:09:57.617276, 3, pid=8470] Transaction 14 of length 138 (0 toread) [2015/04/22 17:09:57.617300, 5, pid=8470] [2015/04/22 17:09:57.617313, 5, pid=8470] size=134 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7786 smb_uid=100 smb_mid=38 smt_wct=15 smb_vwv[ 0]= 26 (0x1A) smb_vwv[ 1]= 40 (0x28) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 1000 (0x3E8) 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]= 40 (0x28) smb_vwv[12]= 94 (0x5E) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 6 (0x6) smb_bcc=69 [2015/04/22 17:09:57.617567, 10, pid=8470] [0000] 00 00 00 EC 03 00 00 00 00 5C 00 44 00 49 00 52 ........ .\.D.I.R [0010] 00 31 00 5C 00 46 00 4F 00 4F 00 00 00 00 00 00 .1.\.F.O .O...... [0020] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0030] 00 00 00 00 00 00 00 00 00 00 00 00 00 20 00 00 ........ ..... .. [0040] 00 00 88 FF FF ..... [2015/04/22 17:09:57.617677, 3, pid=8470] switch message SMBtrans2 (pid 8470) conn 0x7fd08dce6d70 [2015/04/22 17:09:57.617700, 4, pid=8470] Skipping user change - already user [2015/04/22 17:09:57.617727, 5, pid=8470] unix_convert called on file "DIR1/FOO" [2015/04/22 17:09:57.617751, 5, pid=8470] unix_convert begin: name = DIR1/FOO, dirpath = , start = DIR1/FOO [2015/04/22 17:09:57.617777, 5, pid=8470] conversion of base_name finished DIR1/FOO -> DIR1/FOO [2015/04/22 17:09:57.617801, 3, pid=8470] check_reduced_name [DIR1/FOO] [/home1/shares/test4] [2015/04/22 17:09:57.617837, 10, pid=8470] check_reduced_name realpath [DIR1/FOO] -> [/home1/shares/test4/DIR1/FOO] [2015/04/22 17:09:57.617861, 3, pid=8470] check_reduced_name: DIR1/FOO reduced to /home1/shares/test4/DIR1/FOO [2015/04/22 17:09:57.617884, 3, pid=8470] call_trans2setfilepathinfo(6) DIR1/FOO (fnum -1) info_level=1004 totdata=40 [2015/04/22 17:09:57.617908, 3, pid=8470] smbd_do_setfilepathinfo: DIR1/FOO (fnum -1) info_level=1004 totdata=40 [2015/04/22 17:09:57.617932, 6, pid=8470] smb_set_file_dosmode: dosmode: 0x20 [2015/04/22 17:09:57.617954, 8, pid=8470] dos_mode: DIR1/FOO [2015/04/22 17:09:57.617977, 8, pid=8470] dos_mode_from_sbuf returning a [2015/04/22 17:09:57.618000, 8, pid=8470] dos_mode returning a [2015/04/22 17:09:57.618023, 10, pid=8470] smb_set_file_basic_info: file DIR1/FOO [2015/04/22 17:09:57.618045, 5, pid=8470] smb_set_filetime: actime: Thu Jan 1 00:00:00 1970 smb_set_filetime: modtime: Thu Jan 1 00:00:00 1970 smb_set_filetime: ctime: Thu Jan 1 00:00:00 1970 smb_set_file_time: createtime: Thu Jan 1 00:00:00 1970 smb_set_file_time: setting pending modtime to Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:57.618161, 10, pid=8470] smb_set_file_time: setting utimes to modified values. [2015/04/22 17:09:57.618183, 6, pid=8470] file_ntime: actime: Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:57.618209, 6, pid=8470] file_ntime: modtime: Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:57.618235, 6, pid=8470] file_ntime: ctime: Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:57.618260, 6, pid=8470] file_ntime: createtime: Thu Jan 1 00:00:00 1970 [2015/04/22 17:09:57.618298, 10, pid=8470] notify_trigger called action=0x3, filter=0x0, path=/home1/shares/test4/DIR1/FOO [2015/04/22 17:09:57.618335, 9, pid=8470] t2_rep: params_sent_thistime = 2, data_sent_thistime = 0, useable_space = 16412 [2015/04/22 17:09:57.618359, 9, pid=8470] t2_rep: params_to_send = 2, data_to_send = 0, paramsize = 2, datasize = 0 [2015/04/22 17:09:57.618382, 5, pid=8470] [2015/04/22 17:09:57.618395, 5, pid=8470] size=58 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49155 smb_tid=1 smb_pid=7786 smb_uid=100 smb_mid=38 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=3 [2015/04/22 17:09:57.618606, 10, pid=8470] [0000] 00 00 00 ... [2015/04/22 17:10:15.381607, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:10:15.381647, 5, pid=8470] Security token: (NULL) [2015/04/22 17:10:15.381671, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:10:15.381715, 5, pid=8470] change_to_root_user: now uid=(0,0) gid=(0,0) [2015/04/22 17:10:15.381746, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:10:15.381771, 5, pid=8470] Security token: (NULL) [2015/04/22 17:10:15.381793, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:10:15.381836, 5, pid=8470] change_to_root_user: now uid=(0,0) gid=(0,0) [2015/04/22 17:10:15.381861, 1, pid=8470] 172.21.1.210 (172.21.1.210) closed connection to service test4 [2015/04/22 17:10:15.381890, 3, pid=8470] Yielding connection to test4 [2015/04/22 17:10:15.381949, 10, pid=8470] Locking key 16210000FFFFFFFF9344 [2015/04/22 17:10:15.381979, 10, pid=8470] Allocated locked data 0x0x7fd08dcf7d90 [2015/04/22 17:10:15.382013, 10, pid=8470] Unlocking key 16210000FFFFFFFF9344 [2015/04/22 17:10:15.382076, 4, pid=8470] vfs_ChDir to / [2015/04/22 17:10:15.382102, 4, pid=8470] setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2015/04/22 17:10:15.382125, 5, pid=8470] Security token: (NULL) [2015/04/22 17:10:15.382147, 5, pid=8470] UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2015/04/22 17:10:15.382182, 5, pid=8470] change_to_root_user: now uid=(0,0) gid=(0,0) [2015/04/22 17:10:15.382210, 5, pid=8470] Deregistering messaging pointer for type 784 - private_data=0x7fd08dcf3240 [2015/04/22 17:10:15.382297, 3, pid=8470] Server exit (termination signal) [2015/04/22 17:11:18.394965, 2, pid=8605] Closing idle connection [2015/04/22 17:12:18.435940, 2, pid=8988] Closing idle connection [2015/04/22 17:13:18.481742, 2, pid=9374] Closing idle connection [2015/04/22 17:14:18.527342, 2, pid=9757] Closing idle connection [2015/04/22 17:15:18.589731, 2, pid=10193] Closing idle connection [2015/04/22 17:16:18.652045, 2, pid=10641] Closing idle connection [2015/04/22 17:17:18.714358, 2, pid=11077] Closing idle connection [2015/04/22 17:18:18.776747, 2, pid=11498] Closing idle connection [2015/04/22 17:19:18.839193, 2, pid=11887] Closing idle connection [2015/04/22 17:20:18.901490, 2, pid=12288] Closing idle connection [2015/04/22 17:21:18.963966, 2, pid=12725] Closing idle connection [2015/04/22 17:22:19.026253, 2, pid=13150] Closing idle connection [2015/04/22 17:23:19.088561, 2, pid=13529] Closing idle connection [2015/04/22 17:24:19.094043, 2, pid=13914] Closing idle connection [2015/04/22 17:25:17.139269, 2, pid=14314] setup_new_vc_session: New VC == 0, if NT4.x compatible we would close all old resources. [2015/04/22 17:25:17.139428, 2, pid=14314] check_ntlm_password: Authentication for user [pwatkins] -> [pwatkins] FAILED with error NT_STATUS_NO_SUCH_USER [2015/04/22 17:25:17.140418, 1, pid=14314] 172.21.1.210 (172.21.1.210) connect to service test4 initially as user nfsnobody (uid=65534, gid=65534) (pid 14314) [2015/04/22 17:25:17.141749, 1, pid=14314] 172.21.1.210 (172.21.1.210) closed connection to service test4