Prev: [Samba] Problem After Upgrade - NT_STATUS_FILE_IS_A_DIRECTORY
Next: [Samba] samba entry in ldap
From: Leandro Tracchia on 9 Jul 2010 13:20
> Debug level 10 logs are needed at this point to see what
> the smbd is seeing when looking at the CIFS mounted files.

Here is level 10 log of log.smbd that is generated when I experience the problem first described.

[2010/07/09 12:48:25, 10] smbd/open.c:3365(create_file_default)
create_file: access_mask = 0x20089 file_attributes = 0x80, share_access = 0x7, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x3 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), create_file_flags = 0x1, fname = RSA/Tables
[2010/07/09 12:48:25, 5] smbd/filename.c:148(unix_convert)
unix_convert called on file "RSA/Tables"
[2010/07/09 12:48:25, 10] smbd/statcache.c:274(stat_cache_lookup)
stat_cache_lookup: lookup succeeded for name [RSA/Tables] -> [RSA/Tables]
[2010/07/09 12:48:25, 3] smbd/vfs.c:865(check_reduced_name)
reduce_name [RSA/Tables] [/media/server/RSA]
[2010/07/09 12:48:25, 10] smbd/vfs.c:937(check_reduced_name)
reduce_name realpath [RSA/Tables] -> [/media/server/RSA/Tables]
[2010/07/09 12:48:25, 3] smbd/vfs.c:974(check_reduced_name)
reduce_name: RSA/Tables reduced to /media/server/RSA/Tables
[2010/07/09 12:48:25, 10] smbd/open.c:2896(create_file_unixpath)
create_file_unixpath: access_mask = 0x20089 file_attributes = 0x80, share_access = 0x7, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x3 ea_list = 0x(nil), sd = 0x(nil), fname = RSA/Tables
[2010/07/09 12:48:25, 5] smbd/files.c:103(file_new)
allocated file structure 16108, fnum = 20204 (2 used)
[2010/07/09 12:48:25, 2] smbd/dosmode.c:97(unix_mode)
unix_mode(RSA/Tables) inheriting from RSA/Tables
[2010/07/09 12:48:25, 2] smbd/dosmode.c:106(unix_mode)
unix_mode(RSA/Tables) inherit mode 40770
[2010/07/09 12:48:25, 3] smbd/dosmode.c:149(unix_mode)
unix_mode(RSA/Tables) returning 0760
[2010/07/09 12:48:25, 10] smbd/open.c:1475(open_file_ntcreate)
open_file_ntcreate: fname=RSA/Tables, dos_attrs=0x80 access_mask=0x20089 share_access=0x7 create_disposition = 0x1 create_options=0x40 unix mode=0760 oplock_request=3
[2010/07/09 12:48:25, 3] smbd/vfs.c:865(check_reduced_name)
reduce_name [RSA/Tables] [/media/server/RSA]
[2010/07/09 12:48:25, 10] smbd/vfs.c:937(check_reduced_name)
reduce_name realpath [RSA/Tables] -> [/media/server/RSA/Tables]
[2010/07/09 12:48:25, 3] smbd/vfs.c:974(check_reduced_name)
reduce_name: RSA/Tables reduced to /media/server/RSA/Tables
[2010/07/09 12:48:25, 8] smbd/dosmode.c:494(dos_mode)
dos_mode: RSA/Tables
[2010/07/09 12:48:25, 8] smbd/dosmode.c:189(dos_mode_from_sbuf)
dos_mode_from_sbuf returning d
[2010/07/09 12:48:25, 8] smbd/dosmode.c:547(dos_mode)
dos_mode returning d
[2010/07/09 12:48:25, 10] smbd/open.c:1653(open_file_ntcreate)
open_file_ntcreate: fname=RSA/Tables, after mapping access_mask=0x20089
[2010/07/09 12:48:25, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
Locking key 15000000000000003909
[2010/07/09 12:48:25, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
Allocated locked data 0x0x7f8390299d50
[2010/07/09 12:48:25, 10] smbd/open.c:980(delay_for_oplocks)
delay_for_oplocks: oplock type 0x3 on file
[2010/07/09 12:48:25, 10] smbd/open.c:980(delay_for_oplocks)
delay_for_oplocks: oplock type 0x3 on file
[2010/07/09 12:48:25, 4] smbd/open.c:1913(open_file_ntcreate)
calling open_file with flags=0x0 flags2=0x0 mode=0760, access_mask = 0x20089, open_access_mask = 0x20089
[2010/07/09 12:48:25, 10] smbd/open.c:160(fd_open)
fd_open: name RSA/Tables, flags = 00 mode = 0760, fd = 31.
[2010/07/09 12:48:25, 10] locking/posix.c:495(get_windows_lock_ref_count)
get_windows_lock_count for file = 0
[2010/07/09 12:48:25, 10] locking/posix.c:521(delete_windows_lock_ref_count)
delete_windows_lock_ref_count for file
[2010/07/09 12:48:25, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
Unlocking key 15000000000000003909
[2010/07/09 12:48:25, 5] smbd/files.c:474(file_free)
freed files structure 20204 (1 used)
[2010/07/09 12:48:25, 10] smbd/open.c:3218(create_file_unixpath)
create_file_unixpath: NT_STATUS_FILE_IS_A_DIRECTORY
[2010/07/09 12:48:25, 10] smbd/open.c:3497(create_file_default)
create_file: NT_STATUS_FILE_IS_A_DIRECTORY
[2010/07/09 12:48:25, 3] smbd/error.c:60(error_packet_set)
error packet at smbd/nttrans.c(563) cmd=162 (SMBntcreateX) NT_STATUS_FILE_IS_A_DIRECTORY
[2010/07/09 12:48:25, 5] lib/util.c:632(show_msg)
[2010/07/09 12:48:25, 5] lib/util.c:642(show_msg)
size=35
smb_com=0xa2
smb_rcls=186
smb_reh=0
smb_err=49152
smb_flg=136
smb_flg2=51201
smb_tid=4
smb_pid=5696
smb_uid=100
smb_mid=62275
smt_wct=0
smb_bcc=0
[2010/07/09 12:48:25, 10] lib/util_sock.c:789(read_smb_length_return_keepalive)
got smb length of 176
[2010/07/09 12:48:25, 6] smbd/process.c:1456(process_smb)
got message type 0x0 of len 0xb0
[2010/07/09 12:48:25, 3] smbd/process.c:1459(process_smb)
Transaction 1680202 of length 180 (0 toread)
[2010/07/09 12:48:25, 5] lib/util.c:632(show_msg)
[2010/07/09 12:48:25, 5] lib/util.c:642(show_msg)
size=176
smb_com=0xa2
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=24
smb_flg2=51207
smb_tid=4
smb_pid=5696
smb_uid=100
smb_mid=62339
smt_wct=24
smb_vwv[ 0]= 255 (0xFF)
smb_vwv[ 1]=57054 (0xDEDE)
smb_vwv[ 2]=23040 (0x5A00)
smb_vwv[ 3]= 5632 (0x1600)
smb_vwv[ 4]= 0 (0x0)
smb_vwv[ 5]= 0 (0x0)
smb_vwv[ 6]= 0 (0x0)
smb_vwv[ 7]=35072 (0x8900)
smb_vwv[ 8]= 512 (0x200)
smb_vwv[ 9]= 0 (0x0)
smb_vwv[10]= 0 (0x0)
smb_vwv[11]= 0 (0x0)
smb_vwv[12]= 0 (0x0)
smb_vwv[13]= 0 (0x0)
smb_vwv[14]= 0 (0x0)
smb_vwv[15]= 1792 (0x700)
smb_vwv[16]= 0 (0x0)
smb_vwv[17]= 256 (0x100)
smb_vwv[18]= 0 (0x0)
smb_vwv[19]= 0 (0x0)
smb_vwv[20]= 0 (0x0)
smb_vwv[21]= 512 (0x200)
smb_vwv[22]= 0 (0x0)
smb_vwv[23]= 768 (0x300)
smb_bcc=93
[2010/07/09 12:48:25, 10] ../lib/util/util.c:304(_dump_data)
[0000] 00 5C 00 52 00 65 00 64 00 53 00 74 00 6F 00 6E .\.R.e.d .S.t.o.n
[0010] 00 65 00 20 00 41 00 72 00 73 00 65 00 6E 00 61 .e. .A.r .s.e.n.a
[0020] 00 6C 00 5C 00 4C 00 65 00 65 00 20 00 4D 00 61 .l.\.L.e .e. .M.a
[0030] 00 6E 00 73 00 69 00 6F 00 6E 00 20 00 50 00 68 .n.s.i.o .n. .P.h
[0040] 00 61 00 73 00 65 00 20 00 49 00 49 00 5C 00 54 .a.s.e. .I.I.\.T
[0050] 00 61 00 62 00 6C 00 65 00 73 00 00 00 .a.b.l.e .s...
[2010/07/09 12:48:25, 3] smbd/process.c:1273(switch_message)
switch message SMBntcreateX (pid 15334) conn 0x7f83902e6fe0
[2010/07/09 12:48:25, 4] smbd/uid.c:256(change_to_user)
change_to_user: Skipping user change - already user
[2010/07/09 12:48:25, 10] smbd/nttrans.c:484(reply_ntcreate_and_X)
reply_ntcreate_and_X: flags = 0x16, access_mask = 0x20089 file_attributes = 0x0, share_access = 0x7, create_disposition = 0x1 create_options = 0x0 root_dir_fid = 0x0, fname = RSA/Tables
[2010/07/09 12:48:25, 10] smbd/open.c:3365(create_file_default)
create_file: access_mask = 0x20089 file_attributes = 0x0, share_access = 0x7, create_disposition = 0x1 create_options = 0x0 oplock_request = 0x3 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), create_file_flags = 0x1, fname = RSA/Tables
[2010/07/09 12:48:25, 5] smbd/filename.c:148(unix_convert)
unix_convert called on file "RSA/Tables"
[2010/07/09 12:48:25, 10] smbd/statcache.c:274(stat_cache_lookup)
stat_cache_lookup: lookup succeeded for name [RSA/Tables] -> [RSA/Tables]
[2010/07/09 12:48:25, 3] smbd/vfs.c:865(check_reduced_name)
reduce_name [RSA/Tables] [/media/server/RSA]
[2010/07/09 12:48:25, 10] smbd/vfs.c:937(check_reduced_name)
reduce_name realpath [RSA/Tables] -> [/media/server/RSA/Tables]
[2010/07/09 12:48:25, 3] smbd/vfs.c:974(check_reduced_name)
reduce_name: RSA/Tables reduced to /media/server/RSA/Tables
[2010/07/09 12:48:25, 10] smbd/open.c:2896(create_file_unixpath)
create_file_unixpath: access_mask = 0x20089 file_attributes = 0x0, share_access = 0x7, create_disposition = 0x1 create_options = 0x0 oplock_request = 0x3 ea_list = 0x(nil), sd = 0x(nil), fname = RSA/Tables
[2010/07/09 12:48:25, 5] smbd/files.c:103(file_new)
allocated file structure 16109, fnum = 20205 (2 used)
[2010/07/09 12:48:25, 2] smbd/dosmode.c:97(unix_mode)
unix_mode(RSA/Tables) inheriting from RSA/Tables
[2010/07/09 12:48:25, 2] smbd/dosmode.c:106(unix_mode)
unix_mode(RSA/Tables) inherit mode 40770
[2010/07/09 12:48:25, 3] smbd/dosmode.c:149(unix_mode)
unix_mode(RSA/Tables) returning 0760
[2010/07/09 12:48:25, 10] smbd/open.c:1475(open_file_ntcreate)
open_file_ntcreate: fname=RSA/Tables, dos_attrs=0x0 access_mask=0x20089 share_access=0x7 create_disposition = 0x1 create_options=0x0 unix mode=0760 oplock_request=3
[2010/07/09 12:48:25, 3] smbd/vfs.c:865(check_reduced_name)
reduce_name [RSA/Tables] [/media/server/RSA]
[2010/07/09 12:48:25, 10] smbd/vfs.c:937(check_reduced_name)
reduce_name realpath [RSA/Tables] -> [/media/server/RSA/Tables]
[2010/07/09 12:48:25, 3] smbd/vfs.c:974(check_reduced_name)
reduce_name: RSA/Tables reduced to /media/server/RSA/Tables
[2010/07/09 12:48:25, 8] smbd/dosmode.c:494(dos_mode)
dos_mode: RSA/Tables
[2010/07/09 12:48:25, 8] smbd/dosmode.c:189(dos_mode_from_sbuf)
dos_mode_from_sbuf returning d
[2010/07/09 12:48:25, 8] smbd/dosmode.c:547(dos_mode)
dos_mode returning d
[2010/07/09 12:48:25, 10] smbd/open.c:1653(open_file_ntcreate)
open_file_ntcreate: fname=RSA/Tables, after mapping access_mask=0x20089
[2010/07/09 12:48:25, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
Locking key 15000000000000003909
[2010/07/09 12:48:25, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
Allocated locked data 0x0x7f8390299d50
[2010/07/09 12:48:25, 10] smbd/open.c:980(delay_for_oplocks)
delay_for_oplocks: oplock type 0x3 on file
[2010/07/09 12:48:25, 10] smbd/open.c:980(delay_for_oplocks)
delay_for_oplocks: oplock type 0x3 on file
[2010/07/09 12:48:25, 4] smbd/open.c:1913(open_file_ntcreate)
calling open_file with flags=0x0 flags2=0x0 mode=0760, access_mask = 0x20089, open_access_mask = 0x20089
[2010/07/09 12:48:25, 10] smbd/open.c:160(fd_open)
fd_open: name RSA/Tables, flags = 00 mode = 0760, fd = 31.
[2010/07/09 12:48:25, 10] locking/posix.c:495(get_windows_lock_ref_count)
get_windows_lock_count for file = 0
[2010/07/09 12:48:25, 10] locking/posix.c:521(delete_windows_lock_ref_count)
delete_windows_lock_ref_count for file
[2010/07/09 12:48:25, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
Unlocking key 15000000000000003909
[2010/07/09 12:48:25, 5] smbd/files.c:474(file_free)
freed files structure 20205 (1 used)
[2010/07/09 12:48:25, 5] smbd/open.c:2391(open_directory)
open_directory: opening directory RSA/Tables, access_mask = 0x20089, share_access = 0x7 create_options = 0x0, create_disposition = 0x1, file_attributes = 0x0
[2010/07/09 12:48:25, 10] smbd/posix_acls.c:3372(posix_get_nt_acl)
posix_get_nt_acl: called for file RSA/Tables
[2010/07/09 12:48:25, 10] smbd/posix_acls.c:2522(canonicalise_acl)
canonicalise_acl: Access ace entries before arrange :
[2010/07/09 12:48:25, 10] smbd/posix_acls.c:2535(canonicalise_acl)
canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms ---
[2010/07/09 12:48:25, 10] smbd/posix_acls.c:2535(canonicalise_acl)
canon_ace index 1. Type = allow SID = S-1-5-21-2665625993-2077132221-1624687091-3037 gid 1018 (editors) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
[2010/07/09 12:48:25, 10] smbd/posix_acls.c:2535(canonicalise_acl)
canon_ace index 2. Type = allow SID = S-1-5-21-2665625993-2077132221-1624687091-1000 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
[2010/07/09 12:48:25, 10] smbd/posix_acls.c:838(print_canon_ace_list)
print_canon_ace_list: canonicalise_acl: ace entries after arrange canon_ace index 0. Type = allow SID = S-1-5-21-2665625993-2077132221-1624687091-1000 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
canon_ace index 1. Type = allow SID = S-1-5-21-2665625993-2077132221-1624687091-3037 gid 1018 (editors) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms ---
[2010/07/09 12:48:25, 10] smbd/posix_acls.c:1116(map_canon_ace_perms)
map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff
[2010/07/09 12:48:25, 10] smbd/posix_acls.c:1116(map_canon_ace_perms)
map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff
[2010/07/09 12:48:25, 10] smbd/posix_acls.c:1116(map_canon_ace_perms)
map_canon_ace_perms: Mapped (UNIX) 0 to (NT) 0
[2010/07/09 12:48:25, 10] smbd/open.c:113(check_open_rights)
check_open_rights: file RSA/Tables requesting 0x20089 returning 0x20009 (NT_STATUS_OK)
[2010/07/09 12:48:25, 5] smbd/files.c:103(file_new)
allocated file structure 16110, fnum = 20206 (2 used)
[2010/07/09 12:48:25, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
Locking key 15000000000000003909
[2010/07/09 12:48:25, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
Allocated locked data 0x0x7f839029add0
[2010/07/09 12:48:25, 10] locking/locking.c:716(unparse_share_modes)
unparse_share_modes: del: 0, owrt: Fri May 1 10:32:46 2009 EDT cwrt: Wed Dec 31 19:00:00 1969 EST, tok: 0, num: 1
[2010/07/09 12:48:25, 10] locking/locking.c:518(print_share_mode_table)
print_share_mode_table: share_mode_entry[0]: pid = 15334, share_access = 0x7, private_options = 0x0, access_mask = 0x20089, mid = 0x0, type= 0x0, gen_id = 28771, uid = 1020, flags = 0, file_id 15:1000000000939:0
[2010/07/09 12:48:25, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
Unlocking key 15000000000000003909
[2010/07/09 12:48:25, 10] smbd/open.c:3201(create_file_unixpath)
create_file_unixpath: info=1
[2010/07/09 12:48:25, 10] smbd/open.c:3485(create_file_default)
create_file: info=1
[2010/07/09 12:48:25, 8] smbd/dosmode.c:494(dos_mode)
dos_mode: RSA/Tables
[2010/07/09 12:48:25, 8] smbd/dosmode.c:189(dos_mode_from_sbuf)
dos_mode_from_sbuf returning d
[2010/07/09 12:48:25, 8] smbd/dosmode.c:547(dos_mode)
dos_mode returning d
[2010/07/09 12:48:25, 5] smbd/nttrans.c:672(reply_ntcreate_and_X)
reply_ntcreate_and_X: fnum = 20206, open name = RSA/Tables
[2010/07/09 12:48:25, 10] lib/util_sock.c:789(read_smb_length_return_keepalive)
got smb length of 72
[2010/07/09 12:48:25, 6] smbd/process.c:1456(process_smb)
got message type 0x0 of len 0x48
[2010/07/09 12:48:25, 3] smbd/process.c:1459(process_smb)
Transaction 1680203 of length 76 (0 toread)
[2010/07/09 12:48:25, 5] lib/util.c:632(show_msg)
[2010/07/09 12:48:25, 5] lib/util.c:642(show_msg)
size=72
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=24
smb_flg2=51207
smb_tid=4
smb_pid=5696
smb_uid=100
smb_mid=62403
smt_wct=15
smb_vwv[ 0]= 4 (0x4)
smb_vwv[ 1]= 0 (0x0)
smb_vwv[ 2]= 2 (0x2)
smb_vwv[ 3]= 8 (0x8)
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]= 4 (0x4)
smb_vwv[10]= 68 (0x44)
smb_vwv[11]= 0 (0x0)
smb_vwv[12]= 0 (0x0)
smb_vwv[13]= 1 (0x1)
smb_vwv[14]= 7 (0x7)
smb_bcc=7





--
To unsubscribe from this list go to the following URL and read the
instructions: https://lists.samba.org/mailman/options/samba
First  |  Prev  | 
Pages: 1 2 3
Prev: [Samba] Problem After Upgrade - NT_STATUS_FILE_IS_A_DIRECTORY
Next: [Samba] samba entry in ldap