delete on close problem
Scott Moomaw
scott at bridgewater.edu
Mon Nov 12 15:23:28 GMT 2001
Several weeks ago, I noted a problem where applications were creating lots
of tmp files and unable to save data files when oplocks were on. I have
captured more useful data on this problem using a new CVS. Here's a
synopsis of the sequence of events.
open file (creating) new_page_2.htm
close file
set map_share_mode: FILE_SHARE_DELETE requested. open_mode = 8000
open file new_page_2.htm
close file
attempt to create file new_page_2.htm [FAILS because file already exists]
I have a huge level 10 log file that I can share; however, I'm going to
include a portion of that log file for review. How is FILE_SHARE_DELETE
supposed to function? Should the second close remove the file which would
allow the succeding open to occur? The log section that I'm including is
the 2nd open/close pair which is where I think the problem is.
After the application fails to create the file on the third open, it goes
into a cycle of open new tmp file(creating), close file, fail to create
same tmp file. I don't understand how delete_on_close semantics apply in
these cases since the map_share_mode stuff appears normal during these
iterations. If you want to see more debug info, just let me know. I have
a level 10 that shows the full process above along with the succeeding
creation of a bunch of tmp files.
[2001/11/08 13:48:38, 10] smbd/nttrans.c:map_create_disposition(400)
map_create_disposition: Mapped create_disposition 1 to 1
[2001/11/08 13:48:38, 10] smbd/nttrans.c:get_filename(261)
get_filename: data_offset = 87, data_len = 16, fname_len = 16
[2001/11/08 13:48:38, 10] smbd/nttrans.c:map_share_mode(487)
map_share_mode: FILE_SHARE_DELETE requested. open_mode = 8000
[2001/11/08 13:48:38, 10] smbd/nttrans.c:map_share_mode(527)
map_share_mode: Mapped desired access 20089, share access 7, file attributes 80 to open_mode 8040
[2001/11/08 13:48:38, 5] smbd/filename.c:unix_convert(145)
unix_convert called on file "\new_page_2.htm"
[2001/11/08 13:48:38, 3] lib/util.c:unix_clean_name(389)
unix_clean_name [/new_page_2.htm]
[2001/11/08 13:48:38, 5] smbd/mangle.c:is_8_3(337)
Checking new_page_2.htm for 8.3
[2001/11/08 13:48:38, 5] smbd/statcache.c:stat_cache_add(132)
stat_cache_add: Added entry NEW_PAGE_2.HTM -> new_page_2.htm
[2001/11/08 13:48:38, 5] smbd/filename.c:unix_convert(215)
conversion finished new_page_2.htm -> new_page_2.htm
[2001/11/08 13:48:38, 3] smbd/dosmode.c:unix_mode(111)
unix_mode(new_page_2.htm) returning 0755
[2001/11/08 13:48:38, 5] smbd/files.c:file_new(121)
allocated file structure 1812, fnum = 5908 (2 used)
[2001/11/08 13:48:38, 10] smbd/open.c:open_file_shared(653)
open_file_shared: fname = new_page_2.htm, share_mode = 8040, ofun = 1, mode = 755, oplock request = 3
[2001/11/08 13:48:38, 8] lib/util.c:is_in_path(1104)
is_in_path: new_page_2.htm
[2001/11/08 13:48:38, 8] lib/util.c:is_in_path(1109)
is_in_path: no name list.
[2001/11/08 13:48:38, 3] lib/util.c:unix_clean_name(389)
unix_clean_name [new_page_2.htm]
[2001/11/08 13:48:38, 4] smbd/open.c:open_file_shared(782)
calling open_file with flags=0x0 flags2=0x0 mode=0755
[2001/11/08 13:48:38, 10] smbd/open.c:fd_open(51)
fd_open: name new_page_2.htm, flags = 0200 mode = 0755, fd = 19.
[2001/11/08 13:48:38, 2] smbd/open.c:open_file(214)
joe opened file new_page_2.htm read=Yes write=No (numopen=1)
[2001/11/08 13:48:38, 10] smbd/open.c:open_file_shared(883)
open_file_shared : share_mode = 8040
[2001/11/08 13:48:38, 8] lib/util.c:is_in_path(1104)
is_in_path: new_page_2.htm
[2001/11/08 13:48:38, 8] lib/util.c:is_in_path(1109)
is_in_path: no name list.
[2001/11/08 13:48:38, 5] smbd/oplock.c:set_file_oplock(184)
set_file_oplock: granted oplock on file new_page_2.htm, dev = 800006, inode = 980948, file_id = 18, tv_sec = 3bead386, tv_usec = 4bdaf
[2001/11/08 13:48:38, 8] smbd/dosmode.c:dos_mode(123)
dos_mode: new_page_2.htm
[2001/11/08 13:48:38, 8] lib/util.c:is_in_path(1104)
is_in_path: new_page_2.htm
[2001/11/08 13:48:38, 8] lib/util.c:is_in_path(1109)
is_in_path: no name list.
[2001/11/08 13:48:38, 8] smbd/dosmode.c:dos_mode(167)
dos_mode returning a
[2001/11/08 13:48:38, 5] smbd/nttrans.c:reply_ntcreate_and_X(962)
reply_ntcreate_and_X: fnum = 5908, open name = new_page_2.htm
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(278)
size=103
smb_com=0xa2
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=1
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(284)
smb_tid=1
smb_pid=568
smb_uid=101
smb_mid=4675
smt_wct=34
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[0]=255 (0xFF)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[1]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[2]=5122 (0x1402)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[3]=279 (0x117)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[4]=128 (0x80)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[5]=32768 (0x8000)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[6]=36912 (0x9030)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[7]=34297 (0x85F9)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[8]=49512 (0xC168)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[9]=32769 (0x8001)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[10]=36912 (0x9030)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[11]=34297 (0x85F9)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[12]=49512 (0xC168)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[13]=32769 (0x8001)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[14]=36912 (0x9030)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[15]=34297 (0x85F9)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[16]=49512 (0xC168)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[17]=32769 (0x8001)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[18]=36912 (0x9030)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[19]=34297 (0x85F9)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[20]=49512 (0xC168)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[21]=8193 (0x2001)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[22]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[23]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[24]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[25]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[26]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[27]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[28]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[29]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[30]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[31]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[32]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[33]=0 (0x0)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(294)
smb_bcc=0
[2001/11/08 13:48:38, 6] lib/util_sock.c:write_socket(558)
write_socket(5,107)
[2001/11/08 13:48:38, 6] lib/util_sock.c:write_socket(561)
write_socket(5,107) wrote 107
[2001/11/08 13:48:38, 10] lib/util_sock.c:read_smb_length_return_keepalive(600)
got smb length of 41
[2001/11/08 13:48:38, 6] smbd/process.c:process_smb(854)
got message type 0x0 of len 0x29
[2001/11/08 13:48:38, 3] smbd/process.c:process_smb(855)
Transaction 79 of length 45
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(278)
size=41
smb_com=0x4
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=24
smb_flg2=2055
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(284)
smb_tid=1
smb_pid=65279
smb_uid=101
smb_mid=4739
smt_wct=3
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[0]=5908 (0x1714)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[1]=65535 (0xFFFF)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(289)
smb_vwv[2]=65535 (0xFFFF)
[2001/11/08 13:48:38, 5] lib/util.c:show_msg(294)
smb_bcc=0
[2001/11/08 13:48:38, 3] smbd/process.c:switch_message(662)
switch message SMBclose (pid 5288)
[2001/11/08 13:48:38, 4] smbd/uid.c:change_to_user(118)
change_to_user: Skipping user change - already user
[2001/11/08 13:48:38, 3] smbd/reply.c:reply_close(2998)
close fd=19 fnum=5908 (numopen=1)
[2001/11/08 13:48:38, 10] locking/locking.c:del_share_entry(511)
del_share_entry: num_share_modes = 1
[2001/11/08 13:48:38, 10] locking/locking.c:del_share_entry(522)
del_share_entry: deleting entry 0
[2001/11/08 13:48:38, 10] smbd/close.c:close_normal_file(155)
close_normal_file: share_entry_count = 0 for file new_page_2.htm
[2001/11/08 13:48:38, 10] locking/posix.c:posix_locking_close_file(1253)
posix_locking_close_file: file new_page_2.htm has no outstanding locks.
[2001/11/08 13:48:38, 2] smbd/close.c:close_normal_file(206)
joe closed file new_page_2.htm (numopen=0)
[2001/11/08 13:48:38, 5] smbd/files.c:file_free(339)
freed files structure 5908 (1 used)
------------------------------------------------------------------------
Scott Moomaw, Network Administrator Scott at Bridgewater.edu
Bridgewater College, IT Center
Bridgewater, VA 22812
Phone (540) 828 - 8000 x5437 FAX: (540) 828 - 5493
More information about the samba-technical
mailing list