Scott Bertilson
2004-Jan-09 16:15 UTC
[Samba] large file pre-allocation causing Windows error
I'm trying to copy a 400 MB file from a Windows 98 host to a FreeBSD 4.5 Samba server providing access to a FAT32 filesystem. I've got "strict allocate = no", but from what I can see with debug set to 10, it is doing a ftruncate which takes about 50 seconds to complete. It appears that Windows gets impatient and generates an error (while Samba is still waiting for the "ftruncate" to complete): Cannot create or replace DVm04-01: The specified network resource or device is no longer available. I've tested this with Samba 2.2.3a, 2.2.8a, and 3.0.0 with no difference in behavior. I'm including a debug snip that comes from 3.0.0. Is there another path through the code where "strict allocate" takes effect? Is it illegitimate or too hard to try to get Samba to trick Windows into believing that its pre-allocate has succeeded? Thanks, Scott -------------- [2004/01/09 10:04:17, 5] smbd/uid.c:change_to_root_user(218) change_to_root_user: now uid=(0,0) gid=(0,0) [2004/01/09 10:04:17, 2] smbd/server.c:exit_server(558) Closing connections [2004/01/09 10:04:17, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2004/01/09 10:04:17, 5] auth/auth_util.c:debug_nt_user_token(486) NT user token: (NULL) [2004/01/09 10:04:17, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2004/01/09 10:04:17, 5] smbd/uid.c:change_to_root_user(218) change_to_root_user: now uid=(0,0) gid=(0,0) [2004/01/09 10:04:17, 1] smbd/service.c:close_cnum(880) ssb-lap (192.168.1.35) closed connection to service prognew [2004/01/09 10:04:17, 3] smbd/connection.c:yield_connection(69) Yielding connection to prognew [2004/01/09 10:04:17, 10] locking/locking.c:del_share_entry(565) del_share_entry: num_share_modes = 1 [2004/01/09 10:04:17, 10] locking/locking.c:del_share_entry(570) del_share_entry: deleted share_mode_entry[0]: pid = 32286, share_mode = 0x11, desired_access = 0x2, port = 0x509, type= 0x3, file_id = 1, dev = 0x27406, inode = 788440731 [2004/01/09 10:04:17, 10] locking/locking.c:del_share_entry(578) del_share_entry: deleting entry 0 [2004/01/09 10:04:17, 10] locking/locking.c:del_share_entry(600) del_share_entry: Remaining table. [2004/01/09 10:04:17, 10] smbd/close.c:close_normal_file(167) close_normal_file: share_entry_count = 0 for file VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:04:17, 10] locking/posix.c:posix_locking_close_file(1241) posix_locking_close_file: file VIDEO/2003-1/DVm04-01.avi has no outstanding locks. [2004/01/09 10:04:17, 2] smbd/close.c:close_normal_file(228) play closed file VIDEO/2003-1/DVm04-01.avi (numopen=0) [2004/01/09 10:04:17, 5] smbd/files.c:file_free(385) freed files structure 6266 (0 used) [2004/01/09 10:04:17, 4] smbd/dir.c:dptr_close_internal(224) closing dptr key 256 [2004/01/09 10:04:17, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2004/01/09 10:04:17, 5] auth/auth_util.c:debug_nt_user_token(486) NT user token: (NULL) [2004/01/09 10:04:17, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2004/01/09 10:04:17, 5] smbd/uid.c:change_to_root_user(218) change_to_root_user: now uid=(0,0) gid=(0,0) [2004/01/09 10:04:17, 4] smbd/vfs.c:vfs_ChDir(611) vfs_ChDir to / [2004/01/09 10:04:17, 5] auth/auth_util.c:free_server_info(1210) attempting to free (and zero) a server_info structure [2004/01/09 10:04:17, 3] smbd/connection.c:yield_connection(69) Yielding connection to [2004/01/09 10:04:17, 5] smbd/oplock.c:receive_local_message(107) receive_local_message: doing select with timeout of 1 ms [2004/01/09 10:04:17, 3] smbd/server.c:exit_server(601) Server exit (normal exit) [2004/01/09 10:05:17, 5] smbd/uid.c:change_to_root_user(218) change_to_root_user: now uid=(0,0) gid=(0,0) [2004/01/09 10:05:49, 10] lib/util_sock.c:read_smb_length_return_keepalive(463) got smb length of 92 [2004/01/09 10:05:49, 6] smbd/process.c:process_smb(889) got message type 0x0 of len 0x5c [2004/01/09 10:05:49, 3] smbd/process.c:process_smb(890) Transaction 10 of length 96 [2004/01/09 10:05:49, 5] lib/util.c:show_msg(456) [2004/01/09 10:05:49, 5] lib/util.c:show_msg(466) size=92 smb_com=0x6 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=32768 smb_tid=1 smb_pid=5781 smb_uid=100 smb_mid=4610 smt_wct=1 smb_vwv[ 0]= 6 (0x6) smb_bcc=55 [2004/01/09 10:05:49, 10] lib/util.c:dump_data(1825) [000] 04 5C 00 56 00 49 00 44 00 45 00 4F 00 5C 00 32 .\.V.I.D .E.O.\.2 [010] 00 30 00 30 00 33 00 2D 00 31 00 5C 00 44 00 56 .0.0.3.- .1.\.D.V [020] 00 6D 00 30 00 34 00 2D 00 30 00 31 00 2E 00 61 .m.0.4.- .0.1...a [030] 00 76 00 69 00 00 00 .v.i... [2004/01/09 10:05:49, 3] smbd/process.c:switch_message(685) switch message SMBunlink (pid 32295) [2004/01/09 10:05:49, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (201, 31) - sec_ctx_stack_ndx = 0 [2004/01/09 10:05:49, 5] auth/auth_util.c:debug_nt_user_token(491) NT user token of user S-1-5-21-2409570546-2152095909-2247310219-1402 contains 5 SIDs SID[ 0]: S-1-5-21-2409570546-2152095909-2247310219-1402 SID[ 1]: S-1-5-21-2409570546-2152095909-2247310219-1063 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-11 [2004/01/09 10:05:49, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 201 Primary group is 31 and contains 2 supplementary groups Group[ 0]: 31 Group[ 1]: 31 [2004/01/09 10:05:49, 5] smbd/uid.c:change_to_user(203) change_to_user uid=(0,201) gid=(0,31) [2004/01/09 10:05:49, 3] smbd/reply.c:reply_unlink(1434) reply_unlink : \VIDEO\2003-1\DVm04-01.avi [2004/01/09 10:05:49, 5] smbd/filename.c:unix_convert(114) unix_convert called on file "\VIDEO\2003-1\DVm04-01.avi" [2004/01/09 10:05:49, 3] lib/util.c:unix_clean_name(580) unix_clean_name [/VIDEO/2003-1/DVm04-01.avi] [2004/01/09 10:05:49, 10] smbd/statcache.c:stat_cache_lookup(251) stat_cache_lookup: lookup failed for name [VIDEO/2003-1/DVM04-01.AVI] [2004/01/09 10:05:49, 10] smbd/statcache.c:stat_cache_lookup(281) stat_cache_lookup: lookup succeeded for name [VIDEO/2003-1] -> [VIDEO/2003-1] [2004/01/09 10:05:49, 5] smbd/statcache.c:stat_cache_add(178) stat_cache_add: Added entry VIDEO/2003-1/DVM04-01.AVI -> VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:05:49, 5] smbd/filename.c:unix_convert(183) conversion finished VIDEO/2003-1/DVm04-01.avi -> VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:05:49, 10] smbd/reply.c:can_delete(1257) can_delete: VIDEO/2003-1/DVm04-01.avi, dirtype = 6 [2004/01/09 10:05:49, 8] smbd/dosmode.c:dos_mode(122) dos_mode: VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:05:49, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:05:49, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:05:49, 8] smbd/dosmode.c:dos_mode(168) dos_mode returning a [2004/01/09 10:05:49, 5] smbd/files.c:file_new(122) allocated file structure 2384, fnum = 6480 (1 used) [2004/01/09 10:05:49, 10] smbd/open.c:open_file_shared1(848) open_file_shared: fname = VIDEO/2003-1/DVm04-01.avi, share_mode = 10, ofun = 1, mode = 0, oplock request = 0 [2004/01/09 10:05:49, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:05:49, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:05:49, 3] lib/util.c:unix_clean_name(580) unix_clean_name [VIDEO/2003-1/DVm04-01.avi] [2004/01/09 10:05:49, 4] smbd/open.c:open_file_shared1(1014) calling open_file with flags=0x0 flags2=0x0 mode=00 [2004/01/09 10:05:49, 2] smbd/open.c:open_file(250) PLAY opened file VIDEO/2003-1/DVm04-01.avi read=Yes write=No (numopen=1) [2004/01/09 10:05:49, 10] smbd/open.c:open_file_shared1(1126) open_file_shared : share_mode = 10 [2004/01/09 10:05:49, 10] locking/locking.c:set_share_mode(654) set_share_mode: creating entry for file VIDEO/2003-1/DVm04-01.avi. num_share_modes = 1 [2004/01/09 10:05:49, 10] locking/locking.c:print_share_mode_table(406) print_share_mode_table: share_mode_entry[0]: pid = 32295, share_mode = 0x10, desired_access = 0x10000, port = 0x0, type= 0x0, file_id = 1, dev = 0x27406, inode = 788440731 [2004/01/09 10:05:49, 10] locking/locking.c:del_share_entry(565) del_share_entry: num_share_modes = 1 [2004/01/09 10:05:49, 10] locking/locking.c:del_share_entry(570) del_share_entry: deleted share_mode_entry[0]: pid = 32295, share_mode = 0x10, desired_access = 0x10000, port = 0x0, type= 0x0, file_id = 1, dev = 0x27406, inode = 788440731 [2004/01/09 10:05:49, 10] locking/locking.c:del_share_entry(578) del_share_entry: deleting entry 0 [2004/01/09 10:05:49, 10] locking/locking.c:del_share_entry(600) del_share_entry: Remaining table. [2004/01/09 10:05:49, 10] smbd/close.c:close_normal_file(167) close_normal_file: share_entry_count = 0 for file VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:05:49, 10] locking/posix.c:posix_locking_close_file(1241) posix_locking_close_file: file VIDEO/2003-1/DVm04-01.avi has no outstanding locks. [2004/01/09 10:05:49, 2] smbd/close.c:close_normal_file(228) play closed file VIDEO/2003-1/DVm04-01.avi (numopen=0) [2004/01/09 10:05:49, 5] smbd/files.c:file_free(385) freed files structure 6480 (0 used) [2004/01/09 10:05:50, 5] lib/util.c:show_msg(456) [2004/01/09 10:05:50, 5] lib/util.c:show_msg(466) size=35 smb_com=0x6 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=51201 smb_tid=1 smb_pid=5781 smb_uid=100 smb_mid=4610 smt_wct=0 smb_bcc=0 [2004/01/09 10:05:50, 6] lib/util_sock.c:write_socket(407) write_socket(20,39) [2004/01/09 10:05:50, 6] lib/util_sock.c:write_socket(410) write_socket(20,39) wrote 39 [2004/01/09 10:06:26, 10] lib/util_sock.c:read_smb_length_return_keepalive(463) got smb length of 64 [2004/01/09 10:06:26, 6] smbd/process.c:process_smb(889) got message type 0x0 of len 0x40 [2004/01/09 10:06:26, 3] smbd/process.c:process_smb(890) Transaction 11 of length 68 [2004/01/09 10:06:26, 5] lib/util.c:show_msg(456) [2004/01/09 10:06:26, 5] lib/util.c:show_msg(466) size=64 smb_com=0x8 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=32768 smb_tid=1 smb_pid=5781 smb_uid=100 smb_mid=4738 smt_wct=0 smb_bcc=29 [2004/01/09 10:06:26, 10] lib/util.c:dump_data(1825) [000] 04 5C 00 56 00 49 00 44 00 45 00 4F 00 5C 00 32 .\.V.I.D .E.O.\.2 [010] 00 30 00 30 00 33 00 2D 00 31 00 00 00 .0.0.3.- .1... [2004/01/09 10:06:26, 3] smbd/process.c:switch_message(685) switch message SMBgetatr (pid 32295) [2004/01/09 10:06:26, 4] smbd/uid.c:change_to_user(122) change_to_user: Skipping user change - already user [2004/01/09 10:06:26, 5] smbd/filename.c:unix_convert(114) unix_convert called on file "\VIDEO\2003-1" [2004/01/09 10:06:26, 3] lib/util.c:unix_clean_name(580) unix_clean_name [/VIDEO/2003-1] [2004/01/09 10:06:26, 10] smbd/statcache.c:stat_cache_lookup(281) stat_cache_lookup: lookup succeeded for name [VIDEO/2003-1] -> [VIDEO/2003-1] [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1 [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 3] lib/util.c:unix_clean_name(580) unix_clean_name [VIDEO/2003-1] [2004/01/09 10:06:26, 8] smbd/dosmode.c:dos_mode(122) dos_mode: VIDEO/2003-1 [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1 [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] smbd/dosmode.c:dos_mode(168) dos_mode returning d [2004/01/09 10:06:26, 3] smbd/reply.c:reply_getatr(520) getatr name=VIDEO/2003-1 mode=16 size=0 [2004/01/09 10:06:26, 5] lib/util.c:show_msg(456) [2004/01/09 10:06:26, 5] lib/util.c:show_msg(466) size=55 smb_com=0x8 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=51265 smb_tid=1 smb_pid=5781 smb_uid=100 smb_mid=4738 smt_wct=10 smb_vwv[ 0]= 16 (0x10) smb_vwv[ 1]= 9258 (0x242A) smb_vwv[ 2]=16379 (0x3FFB) smb_vwv[ 3]= 0 (0x0) 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]= 0 (0x0) smb_bcc=0 [2004/01/09 10:06:26, 6] lib/util_sock.c:write_socket(407) write_socket(20,59) [2004/01/09 10:06:26, 6] lib/util_sock.c:write_socket(410) write_socket(20,59) wrote 59 [2004/01/09 10:06:26, 10] lib/util_sock.c:read_smb_length_return_keepalive(463) got smb length of 120 [2004/01/09 10:06:26, 6] smbd/process.c:process_smb(889) got message type 0x0 of len 0x78 [2004/01/09 10:06:26, 3] smbd/process.c:process_smb(890) Transaction 12 of length 124 [2004/01/09 10:06:26, 5] lib/util.c:show_msg(456) [2004/01/09 10:06:26, 5] lib/util.c:show_msg(466) size=120 smb_com=0x2d smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=32768 smb_tid=1 smb_pid=5781 smb_uid=100 smb_mid=4866 smt_wct=15 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 7 (0x7) smb_vwv[ 3]= 145 (0x91) smb_vwv[ 4]= 22 (0x16) smb_vwv[ 5]= 32 (0x20) smb_vwv[ 6]=32064 (0x7D40) smb_vwv[ 7]=16382 (0x3FFE) smb_vwv[ 8]= 16 (0x10) 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_bcc=55 [2004/01/09 10:06:26, 10] lib/util.c:dump_data(1825) [000] 00 5C 00 56 00 49 00 44 00 45 00 4F 00 5C 00 32 .\.V.I.D .E.O.\.2 [010] 00 30 00 30 00 33 00 2D 00 31 00 5C 00 44 00 56 .0.0.3.- .1.\.D.V [020] 00 6D 00 30 00 34 00 2D 00 30 00 31 00 2E 00 61 .m.0.4.- .0.1...a [030] 00 76 00 69 00 00 00 .v.i... [2004/01/09 10:06:26, 3] smbd/process.c:switch_message(685) switch message SMBopenX (pid 32295) [2004/01/09 10:06:26, 4] smbd/uid.c:change_to_user(122) change_to_user: Skipping user change - already user [2004/01/09 10:06:26, 5] smbd/filename.c:unix_convert(114) unix_convert called on file "\VIDEO\2003-1\DVm04-01.avi" [2004/01/09 10:06:26, 3] lib/util.c:unix_clean_name(580) unix_clean_name [/VIDEO/2003-1/DVm04-01.avi] [2004/01/09 10:06:26, 10] smbd/statcache.c:stat_cache_lookup(281) stat_cache_lookup: lookup succeeded for name [VIDEO/2003-1/DVM04-01.AVI] -> [VIDEO/2003-1/DVm04-01.avi] [2004/01/09 10:06:26, 5] smbd/filename.c:unix_convert(188) unix_convert begin: name = VIDEO/2003-1/DVm04-01.avi, dirpath = , start = VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:06:26, 10] smbd/mangle_hash2.c:is_mangled(269) is_mangled VIDEO/2003-1/DVm04-01.avi ? [2004/01/09 10:06:26, 10] smbd/mangle_hash2.c:is_mangled_component(208) is_mangled_component VIDEO/2003-1/DVm04-01.avi (len 5) ? [2004/01/09 10:06:26, 10] smbd/mangle_hash2.c:is_mangled_component(208) is_mangled_component 2003-1/DVm04-01.avi (len 6) ? [2004/01/09 10:06:26, 10] smbd/mangle_hash2.c:is_mangled_component(208) is_mangled_component DVm04-01.avi (len 12) ? [2004/01/09 10:06:26, 5] smbd/statcache.c:stat_cache_add(178) stat_cache_add: Added entry VIDEO -> VIDEO [2004/01/09 10:06:26, 10] smbd/mangle_hash2.c:is_mangled(269) is_mangled DVm04-01.avi ? [2004/01/09 10:06:26, 10] smbd/mangle_hash2.c:is_mangled_component(208) is_mangled_component DVm04-01.avi (len 12) ? [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: DVm01-01.avi [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: DVm02-01.avi [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: DVm03-01.avi [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: DVm07-01.avi [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: DVm05-01.avi [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: DVm06-01.avi [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: 2003-1.iod [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: DVm08-01.avi [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: DVm09-01.avi [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: DVm10-01.avi [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: DVm11-01.avi [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: DVm12-01.avi [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1473) is_in_path: DVm13-01.avi [2004/01/09 10:06:26, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:26, 10] smbd/mangle_hash2.c:is_mangled(269) is_mangled DVm04-01.avi ? [2004/01/09 10:06:26, 10] smbd/mangle_hash2.c:is_mangled_component(208) is_mangled_component DVm04-01.avi (len 12) ? [2004/01/09 10:06:26, 5] smbd/filename.c:unix_convert(323) New file DVm04-01.avi [2004/01/09 10:06:26, 3] smbd/dosmode.c:unix_mode(110) unix_mode(VIDEO/2003-1/DVm04-01.avi) returning 0744 [2004/01/09 10:06:26, 5] smbd/files.c:file_new(122) allocated file structure 2385, fnum = 6481 (1 used) [2004/01/09 10:06:27, 10] smbd/open.c:open_file_shared1(848) open_file_shared: fname = VIDEO/2003-1/DVm04-01.avi, share_mode = 91, ofun = 10, mode = 744, oplock request = 3 [2004/01/09 10:06:27, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:06:27, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:27, 3] lib/util.c:unix_clean_name(580) unix_clean_name [VIDEO/2003-1/DVm04-01.avi] [2004/01/09 10:06:27, 4] smbd/open.c:open_file_shared1(1014) calling open_file with flags=0x1 flags2=0xA00 mode=0744 [2004/01/09 10:06:27, 10] smbd/open.c:fd_open(52) fd_open: name VIDEO/2003-1/DVm04-01.avi, flags = 05001 mode = 0744, fd = 28. [2004/01/09 10:06:27, 2] smbd/open.c:open_file(250) PLAY opened file VIDEO/2003-1/DVm04-01.avi read=No write=Yes (numopen=1) [2004/01/09 10:06:27, 10] smbd/open.c:open_file_shared1(1126) open_file_shared : share_mode = 11 [2004/01/09 10:06:27, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:06:27, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:27, 5] smbd/oplock.c:set_file_oplock(218) set_file_oplock: granted oplock on file VIDEO/2003-1/DVm04-01.avi, dev = 27406, inode = 788440731, file_id = 2, tv_sec = 3ffed182, tv_usec = f40f3 [2004/01/09 10:06:27, 10] locking/locking.c:set_share_mode(654) set_share_mode: creating entry for file VIDEO/2003-1/DVm04-01.avi. num_share_modes = 1 [2004/01/09 10:06:27, 10] locking/locking.c:print_share_mode_table(406) print_share_mode_table: share_mode_entry[0]: pid = 32295, share_mode = 0x11, desired_access = 0x2, port = 0x50a, type= 0x3, file_id = 2, dev = 0x27406, inode = 788440731 [2004/01/09 10:06:27, 8] smbd/dosmode.c:dos_mode(122) dos_mode: VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:06:27, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:06:27, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:06:27, 8] smbd/dosmode.c:dos_mode(168) dos_mode returning a [2004/01/09 10:06:27, 5] lib/util.c:show_msg(456) [2004/01/09 10:06:27, 5] lib/util.c:show_msg(466) size=65 smb_com=0x2d smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=51201 smb_tid=1 smb_pid=5781 smb_uid=100 smb_mid=4866 smt_wct=15 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 6481 (0x1951) smb_vwv[ 3]= 32 (0x20) smb_vwv[ 4]=32034 (0x7D22) smb_vwv[ 5]=16382 (0x3FFE) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 1 (0x1) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]= 0 (0x0) smb_vwv[11]=32770 (0x8002) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 0 (0x0) smb_vwv[14]= 0 (0x0) smb_bcc=0 [2004/01/09 10:06:27, 6] lib/util_sock.c:write_socket(407) write_socket(20,69) [2004/01/09 10:06:27, 6] lib/util_sock.c:write_socket(410) write_socket(20,69) wrote 69 [2004/01/09 10:06:27, 10] lib/util_sock.c:read_smb_length_return_keepalive(463) got smb length of 48 [2004/01/09 10:06:27, 6] smbd/process.c:process_smb(889) got message type 0x0 of len 0x30 [2004/01/09 10:06:27, 3] smbd/process.c:process_smb(890) Transaction 13 of length 52 [2004/01/09 10:06:27, 5] lib/util.c:show_msg(456) [2004/01/09 10:06:27, 5] lib/util.c:show_msg(466) size=48 smb_com=0xb smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=32768 smb_tid=1 smb_pid=5781 smb_uid=100 smb_mid=4994 smt_wct=5 smb_vwv[ 0]= 6481 (0x1951) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]=26624 (0x6800) smb_vwv[ 3]= 6113 (0x17E1) smb_vwv[ 4]= 0 (0x0) smb_bcc=3 [2004/01/09 10:06:27, 10] lib/util.c:dump_data(1825) [000] 01 00 00 ... [2004/01/09 10:06:27, 3] smbd/process.c:switch_message(685) switch message SMBwrite (pid 32295) [2004/01/09 10:06:27, 4] smbd/uid.c:change_to_user(122) change_to_user: Skipping user change - already user [2004/01/09 10:06:27, 10] smbd/vfs.c:vfs_allocate_file_space(474) vfs_allocate_file_space: file VIDEO/2003-1/DVm04-01.avi, len 400648192 [2004/01/09 10:06:27, 10] smbd/vfs.c:vfs_set_filelen(532) vfs_set_filelen: ftruncate VIDEO/2003-1/DVm04-01.avi to len 400648192 [2004/01/09 10:07:37, 3] smbd/reply.c:reply_write(2186) write fnum=6481 num=0 wrote=0 [2004/01/09 10:07:37, 5] lib/util.c:show_msg(456) [2004/01/09 10:07:37, 5] lib/util.c:show_msg(466) size=37 smb_com=0xb smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=51201 smb_tid=1 smb_pid=5781 smb_uid=100 smb_mid=4994 smt_wct=1 smb_vwv[ 0]= 0 (0x0) smb_bcc=0 [2004/01/09 10:07:37, 6] lib/util_sock.c:write_socket(407) write_socket(20,41) [2004/01/09 10:07:37, 6] lib/util_sock.c:write_socket(410) write_socket(20,41) wrote 41 [2004/01/09 10:07:37, 10] lib/util_sock.c:read_smb_length_return_keepalive(463) got smb length of 110 [2004/01/09 10:07:37, 6] smbd/process.c:process_smb(889) got message type 0x0 of len 0x6e [2004/01/09 10:07:37, 3] smbd/process.c:process_smb(890) Transaction 14 of length 114 [2004/01/09 10:07:37, 5] lib/util.c:show_msg(456) [2004/01/09 10:07:37, 5] lib/util.c:show_msg(466) size=110 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=32769 smb_tid=1 smb_pid=5781 smb_uid=100 smb_mid=18689 smt_wct=15 smb_vwv[ 0]= 44 (0x2C) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 10 (0xA) smb_vwv[ 3]= 2432 (0x980) 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]= 44 (0x2C) smb_vwv[10]= 66 (0x42) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 1 (0x1) smb_bcc=45 [2004/01/09 10:07:37, 10] lib/util.c:dump_data(1825) [000] 00 16 00 04 00 00 00 04 01 00 00 00 00 5C 00 56 ........ .....\.V [010] 00 49 00 44 00 45 00 4F 00 5C 00 32 00 30 00 30 .I.D.E.O .\.2.0.0 [020] 00 33 00 2D 00 31 00 5C 00 2A 00 00 00 .3.-.1.\ .*... [2004/01/09 10:07:37, 3] smbd/process.c:switch_message(685) switch message SMBtrans2 (pid 32295) [2004/01/09 10:07:37, 4] smbd/uid.c:change_to_user(122) change_to_user: Skipping user change - already user [2004/01/09 10:07:37, 3] smbd/trans2.c:call_trans2findfirst(951) call_trans2findfirst: dirtype = 22, maxentries = 4, close_after_first=0, close_if_end = 0 requires_resume_key = 0 level = 260, max_data_bytes = 2432 [2004/01/09 10:07:37, 5] smbd/filename.c:unix_convert(114) unix_convert called on file "\VIDEO\2003-1\*" [2004/01/09 10:07:37, 3] lib/util.c:unix_clean_name(580) unix_clean_name [/VIDEO/2003-1/*] [2004/01/09 10:07:37, 10] smbd/statcache.c:stat_cache_lookup(251) stat_cache_lookup: lookup failed for name [VIDEO/2003-1/*] [2004/01/09 10:07:37, 10] smbd/statcache.c:stat_cache_lookup(281) stat_cache_lookup: lookup succeeded for name [VIDEO/2003-1] -> [VIDEO/2003-1] [2004/01/09 10:07:37, 5] smbd/filename.c:unix_convert(188) unix_convert begin: name = VIDEO/2003-1/*, dirpath = VIDEO/2003-1, start = * [2004/01/09 10:07:37, 10] smbd/mangle_hash2.c:is_mangled(269) is_mangled * ? [2004/01/09 10:07:37, 10] smbd/mangle_hash2.c:is_mangled_component(208) is_mangled_component * (len 1) ? [2004/01/09 10:07:37, 10] smbd/mangle_hash2.c:is_mangled(269) is_mangled * ? [2004/01/09 10:07:37, 10] smbd/mangle_hash2.c:is_mangled_component(208) is_mangled_component * (len 1) ? [2004/01/09 10:07:37, 5] smbd/filename.c:unix_convert(323) New file * [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1/* [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 3] lib/util.c:unix_clean_name(580) unix_clean_name [VIDEO/2003-1/*] [2004/01/09 10:07:37, 5] smbd/trans2.c:call_trans2findfirst(993) dir=VIDEO/2003-1, mask = * [2004/01/09 10:07:37, 5] smbd/dir.c:start_dir(334) start_dir dir=VIDEO/2003-1 [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1 [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 3] lib/util.c:unix_clean_name(580) unix_clean_name [VIDEO/2003-1] [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm01-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm02-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm03-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm07-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm05-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm06-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: 2003-1.iod [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm08-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm09-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm10-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm11-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm12-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm04-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: DVm13-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 3] smbd/dir.c:dptr_create(491) creating new dirptr 256 for path VIDEO/2003-1, expect_close = 1 [2004/01/09 10:07:37, 4] smbd/trans2.c:call_trans2findfirst(1023) dptr_num is 256, wcard = *, attr = 22 [2004/01/09 10:07:37, 8] smbd/trans2.c:call_trans2findfirst(1028) dirpath=<VIDEO/2003-1> dontdescend=<> [2004/01/09 10:07:37, 8] smbd/trans2.c:get_lanman2_dir_entry(521) get_lanman2_dir_entry:readdir on dirptr 0x82c8440 now at offset 1 [2004/01/09 10:07:37, 10] lib/ms_fnmatch.c:ms_fnmatch(240) ms_fnmatch(*,.) -> 0 [2004/01/09 10:07:37, 8] smbd/dosmode.c:dos_mode(122) dos_mode: VIDEO/2003-1/. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1/. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] smbd/dosmode.c:dos_mode(168) dos_mode returning d [2004/01/09 10:07:37, 5] smbd/trans2.c:get_lanman2_dir_entry(606) get_lanman2_dir_entry found VIDEO/2003-1/. fname=. [2004/01/09 10:07:37, 8] smbd/trans2.c:get_lanman2_dir_entry(521) get_lanman2_dir_entry:readdir on dirptr 0x82c8440 now at offset 2 [2004/01/09 10:07:37, 10] lib/ms_fnmatch.c:ms_fnmatch(240) ms_fnmatch(*,.) -> 0 [2004/01/09 10:07:37, 8] smbd/dosmode.c:dos_mode(122) dos_mode: VIDEO/2003-1/.. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1/.. [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] smbd/dosmode.c:dos_mode(168) dos_mode returning d [2004/01/09 10:07:37, 5] smbd/trans2.c:get_lanman2_dir_entry(606) get_lanman2_dir_entry found VIDEO/2003-1/.. fname=.. [2004/01/09 10:07:37, 8] smbd/trans2.c:get_lanman2_dir_entry(521) get_lanman2_dir_entry:readdir on dirptr 0x82c8440 now at offset 3 [2004/01/09 10:07:37, 10] lib/ms_fnmatch.c:ms_fnmatch(240) ms_fnmatch(*,DVm01-01.avi) -> 0 [2004/01/09 10:07:37, 8] smbd/dosmode.c:dos_mode(122) dos_mode: VIDEO/2003-1/DVm01-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1/DVm01-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] smbd/dosmode.c:dos_mode(168) dos_mode returning a [2004/01/09 10:07:37, 5] smbd/trans2.c:get_lanman2_dir_entry(606) get_lanman2_dir_entry found VIDEO/2003-1/DVm01-01.avi fname=DVm01-01.avi [2004/01/09 10:07:37, 8] smbd/trans2.c:get_lanman2_dir_entry(521) get_lanman2_dir_entry:readdir on dirptr 0x82c8440 now at offset 4 [2004/01/09 10:07:37, 10] lib/ms_fnmatch.c:ms_fnmatch(240) ms_fnmatch(*,DVm02-01.avi) -> 0 [2004/01/09 10:07:37, 8] smbd/dosmode.c:dos_mode(122) dos_mode: VIDEO/2003-1/DVm02-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1473) is_in_path: VIDEO/2003-1/DVm02-01.avi [2004/01/09 10:07:37, 8] lib/util.c:is_in_path(1477) is_in_path: no name list. [2004/01/09 10:07:37, 8] smbd/dosmode.c:dos_mode(168) dos_mode returning a [2004/01/09 10:07:37, 5] smbd/trans2.c:get_lanman2_dir_entry(606) get_lanman2_dir_entry found VIDEO/2003-1/DVm02-01.avi fname=DVm02-01.avi [2004/01/09 10:07:37, 9] smbd/trans2.c:send_trans2_replies(178) t2_rep: params_sent_thistime = 10, data_sent_thistime = 436, useable_space = 2858 [2004/01/09 10:07:37, 9] smbd/trans2.c:send_trans2_replies(180) t2_rep: params_to_send = 10, data_to_send = 436, paramsize = 10, datasize = 436 [2004/01/09 10:07:37, 6] lib/util_sock.c:write_socket(407) write_socket(20,508) [2004/01/09 10:07:37, 6] lib/util_sock.c:write_socket(410) write_socket(20,508) wrote 508 [2004/01/09 10:07:37, 4] smbd/trans2.c:call_trans2findfirst(1104) SMBtrans2 mask=* directory=VIDEO/2003-1 dirtype=22 numentries=4 [2004/01/09 10:07:37, 10] lib/util_sock.c:read_socket_data(336) read_socket_data: recv of 4 returned 0. Error = Undefined error: 0 [2004/01/09 10:07:37, 10] lib/util_sock.c:receive_smb(512) receive_smb: length < 0! [2004/01/09 10:07:37, 3] smbd/process.c:timeout_processing(1099) timeout_processing: End of file from client (client has disconnected). [2004/01/09 10:07:37, 5] lib/gencache.c:gencache_shutdown(88) Closing cache file [2004/01/09 10:07:37, 5] libsmb/namecache.c:namecache_shutdown(79) namecache_shutdown: netbios namecache closed successfully. [2004/01/09 10:07:37, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2004/01/09 10:07:37, 5] auth/auth_util.c:debug_nt_user_token(486) NT user token: (NULL) [2004/01/09 10:07:37, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2004/01/09 10:07:37, 5] smbd/uid.c:change_to_root_user(218) change_to_root_user: now uid=(0,0) gid=(0,0) [2004/01/09 10:07:37, 2] smbd/server.c:exit_server(558) Closing connections [2004/01/09 10:07:37, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2004/01/09 10:07:37, 5] auth/auth_util.c:debug_nt_user_token(486) NT user token: (NULL) [2004/01/09 10:07:37, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2004/01/09 10:07:37, 5] smbd/uid.c:change_to_root_user(218) change_to_root_user: now uid=(0,0) gid=(0,0) [2004/01/09 10:07:37, 1] smbd/service.c:close_cnum(880) ssb-lap (192.168.1.35) closed connection to service prognew [2004/01/09 10:07:37, 3] smbd/connection.c:yield_connection(69) Yielding connection to prognew [2004/01/09 10:07:37, 10] locking/locking.c:del_share_entry(565) del_share_entry: num_share_modes = 1 [2004/01/09 10:07:37, 10] locking/locking.c:del_share_entry(570) del_share_entry: deleted share_mode_entry[0]: pid = 32295, share_mode = 0x11, desired_access = 0x2, port = 0x50a, type= 0x3, file_id = 2, dev = 0x27406, inode = 788440731 [2004/01/09 10:07:37, 10] locking/locking.c:del_share_entry(578) del_share_entry: deleting entry 0 [2004/01/09 10:07:37, 10] locking/locking.c:del_share_entry(600) del_share_entry: Remaining table. [2004/01/09 10:07:37, 10] smbd/close.c:close_normal_file(167) close_normal_file: share_entry_count = 0 for file VIDEO/2003-1/DVm04-01.avi [2004/01/09 10:07:37, 10] locking/posix.c:posix_locking_close_file(1241) posix_locking_close_file: file VIDEO/2003-1/DVm04-01.avi has no outstanding locks. [2004/01/09 10:07:37, 2] smbd/close.c:close_normal_file(228) play closed file VIDEO/2003-1/DVm04-01.avi (numopen=0) [2004/01/09 10:07:37, 5] smbd/files.c:file_free(385) freed files structure 6481 (0 used) [2004/01/09 10:07:37, 4] smbd/dir.c:dptr_close_internal(224) closing dptr key 256 [2004/01/09 10:07:37, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2004/01/09 10:07:37, 5] auth/auth_util.c:debug_nt_user_token(486) NT user token: (NULL) [2004/01/09 10:07:37, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2004/01/09 10:07:37, 5] smbd/uid.c:change_to_root_user(218) change_to_root_user: now uid=(0,0) gid=(0,0) [2004/01/09 10:07:37, 4] smbd/vfs.c:vfs_ChDir(611) vfs_ChDir to / [2004/01/09 10:07:37, 5] auth/auth_util.c:free_server_info(1210) attempting to free (and zero) a server_info structure [2004/01/09 10:07:37, 3] smbd/connection.c:yield_connection(69) Yielding connection to [2004/01/09 10:07:37, 5] smbd/oplock.c:receive_local_message(107) receive_local_message: doing select with timeout of 1 ms [2004/01/09 10:07:37, 3] smbd/server.c:exit_server(601) Server exit (normal exit)