cifs backport is current

Steve French smfrench at gmail.com
Mon Jul 16 21:03:01 GMT 2007


More testing with SAMBA_3_2.

cthon basic subtests fail on cleaning up symlinks (posix unlink
problem, see previous note)
cthon "special" subtests fail on open/unlink test (have not debugged this yet)
cthon general tests work (yeah!)
cthon locking tests crash samba see below level 10 log

Locking key 06080000000000005D8B1D0000000000
Allocated locked data 0x0x805929c8
Unlocking key 06080000000000005D8B1D0000000000
parse_share_modes: delete_on_close: 0, num_share_modes: 2
parse_share_modes: share_mode_entry[0]:  pid = 23814, share_access =
0x7, private_options = 0x40, access_mask = 0x12019f, mid = 0x0, type=
0x0, gen_id = 43636, uid = 1000, flags = 2, file_id 806:1d8b5d
parse_share_modes: share_mode_entry[1]:  pid = 23814, share_access =
0x7, private_options = 0x40, access_mask = 0x12019f, mid = 0x0, type=
0x0, gen_id = 43638, uid = 1000, flags = 0, file_id 806:1d8b5d
call_trans2qfilepathinfo 1/lockfile31362 (fnum = 13714) level=520
call=7 total_data=24
dos_mode: 1/lockfile31362
dos_mode_from_sbuf returning
dos_mode returning
Locking key 06080000000000005D8B1D0000000000
Allocated locked data 0x0x80591ab8
Unlocking key 06080000000000005D8B1D0000000000
brl_get_locks_internal: 1 current locks on file_id 806:1d8b5d
[0]: smbpid = 31362, tid = 1, pid = 23814, start = 0, size =
9223372036854775808, fnum = 13712, WRITE POSIX_LOCK
t2_rep: params_sent_thistime = 2, data_sent_thistime = 24, useable_space = 16410
t2_rep: params_to_send = 2, data_to_send = 24, paramsize = 2, datasize = 24
size=84
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=128
smb_flg2=49217
smb_tid=1
smb_pid=31363
smb_uid=100
smb_mid=56430
smt_wct=10
smb_vwv[ 0]=    2 (0x2)
smb_vwv[ 1]=   24 (0x18)
smb_vwv[ 2]=    0 (0x0)
smb_vwv[ 3]=    2 (0x2)
smb_vwv[ 4]=   56 (0x38)
smb_vwv[ 5]=    0 (0x0)
smb_vwv[ 6]=   24 (0x18)
smb_vwv[ 7]=   60 (0x3C)
smb_vwv[ 8]=    0 (0x0)
smb_vwv[ 9]=    0 (0x0)
smb_bcc=29
[000] 00 00 00 00 00 01 00 00  00 82 7A 00 00 00 00 00  ........ ..z.....
[010] 00 00 00 00 00 00 00 00  00 00 00 00 80           ........ .....
got smb length of 98
got message type 0x0 of len 0x62
Transaction 56431 of length 102
size=98
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=0
smb_flg2=49153
smb_tid=1
smb_pid=31363
smb_uid=100
smb_mid=56431
smt_wct=15
smb_vwv[ 0]=    6 (0x6)
smb_vwv[ 1]=   24 (0x18)
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]=   24 (0x18)
smb_vwv[12]=   74 (0x4A)
smb_vwv[13]=    1 (0x1)
smb_vwv[14]=    8 (0x8)
smb_bcc=33
[000] 00 00 00 92 35 08 02 00  00 02 00 00 00 83 7A 00  ....5... ......z.
[010] 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ........ ........
[020] 80                                                .
switch message SMBtrans2 (pid 23814) conn 0x805907b8
change_to_user: Skipping user change - already user
call_trans2setfilepathinfo(8) 1/lockfile31362 (fnum 13714)
info_level=520 totdata=24
smb_set_posix_lock: file 1/lockfile31362, lock_type = 4,lock_pid =
31363, count = 9223372036854775808, offset = 0
do_unlock: unlock start=0 len=9223372036854775808 requested for fnum
13714 file 1/lockfile31362
Locking key 06080000000000005D8B1D0000000000
Allocated locked data 0x0x80596390
brl_get_locks_internal: 1 current locks on file_id 806:1d8b5d
[0]: smbpid = 31362, tid = 1, pid = 23814, start = 0, size =
9223372036854775808, fnum = 13712, WRITE POSIX_LOCK
brl_unlock_posix: No overlap - unlocked.
Unlocking key 06080000000000005D8B1D0000000000
PANIC: assert failed at locking/locking.c(282): fsp->current_lock_count > 0
smb_panic: clobber_region() last called from [call_trans2setfilepathinfo(5869)]
PANIC (pid 23814): assert failed: fsp->current_lock_count > 0
BACKTRACE: 11 stack frames:
 #0 bin/smbd(log_stack_trace+0x2d) [0x8025b150]
 #1 bin/smbd(smb_panic+0xe0) [0x8025b2e6]
 #2 bin/smbd(do_unlock+0x288) [0x801fec38]
 #3 bin/smbd [0x800b6be7]
 #4 bin/smbd [0x800c0da5]
 #5 bin/smbd(reply_trans2+0x6f1) [0x800c22a5]
 #6 bin/smbd [0x800de1b6]
 #7 bin/smbd(smbd_process+0x938) [0x800df377]
 #8 bin/smbd(main+0x16eb) [0x8044a4d3]
 #9 /lib/libc.so.6(__libc_start_main+0xdc) [0xb7b28f9c]
 #10 bin/smbd [0x800667e1]
smb_panic(): calling panic action [/bin/sleep 90000]


On 7/16/07, Steve French <smfrench at gmail.com> wrote:
> level 10 log of "rm /mnt/new-symlink-file"
>
> got smb length of 112
> got message type 0x0 of len 0x70
> Transaction 53226 of length 116
> size=112
> smb_com=0x32
> smb_rcls=0
> smb_reh=0
> smb_err=0
> smb_flg=0
> smb_flg2=49153
> smb_tid=1
> smb_pid=28784
> smb_uid=100
> smb_mid=53227
> smt_wct=15
> smb_vwv[ 0]=   42 (0x2A)
> smb_vwv[ 1]=    2 (0x2)
> smb_vwv[ 2]=    2 (0x2)
> 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]=   42 (0x2A)
> smb_vwv[10]=   68 (0x44)
> smb_vwv[11]=    2 (0x2)
> smb_vwv[12]=  110 (0x6E)
> smb_vwv[13]=    1 (0x1)
> smb_vwv[14]=    6 (0x6)
> smb_bcc=47
> [000] 00 00 00 0A 02 00 00 00  00 2F 00 6E 00 65 00 77  ........ ./.n.e.w
> [010] 00 2D 00 73 00 79 00 6D  00 6C 00 69 00 6E 00 6B  .-.s.y.m .l.i.n.k
> [020] 00 2D 00 66 00 69 00 6C  00 65 00 00 00 00 00     .-.f.i.l .e.....
> switch message SMBtrans2 (pid 23814) conn 0x805907b8
> change_to_user: Skipping user change - already user
> unix_convert called on file "new-symlink-file"
> conversion finished new-symlink-file -> new-symlink-file
> call_trans2setfilepathinfo(6) new-symlink-file (fnum -1)
> info_level=522 totdata=2
> smb_posix_unlink: file new-symlink-file
> open_file_ntcreate: fname=new-symlink-file, dos_attrs=0x0
> access_mask=0x10000 share_access=0x7 create_disposition = 0x1
> create_options=0x0 unix mode=0777 oplock_request=0
> open_file_ntcreate: fname=new-symlink-file, after mapping access_mask=0x10000
> allocated file structure 9148, fnum = 13244 (1 used)
> Locking key 0608000000000000D98D080000000000
> calling open_file with flags=0x0 flags2=0x0 mode=0777, access_mask =
> 0x10000, open_access_mask = 0x10000
> stevef opened file new-symlink-file read=No write=No (numopen=1)
> unparse_share_modes: del: 0, tok = 0, num: 1
> print_share_mode_table: share_mode_entry[0]:  pid = 23814,
> share_access = 0x7, private_options = 0x0, access_mask = 0x10000, mid
> = 0x0, type= 0x10, gen_id = 43168, uid = 1000, flags = 1, file_id
> 806:88dd9
> Unlocking key 0608000000000000D98D080000000000
> dos_mode: new-symlink-file
> dos_mode_from_sbuf returning a
> dos_mode returning a[sparse]
> smb_set_file_disposition_info: file new-symlink-file, dosmode = 544,
> delete_on_close = 1
> set_delete_on_close: Adding delete on close flag for fnum = 13244,
> file new-symlink-file
> Locking key 0608000000000000D98D080000000000
> Allocated locked data 0x0x80589c78
> parse_share_modes: delete_on_close: 0, num_share_modes: 1
> parse_share_modes: share_mode_entry[0]:  pid = 23814, share_access =
> 0x7, private_options = 0x0, access_mask = 0x10000, mid = 0x0, type=
> 0x10, gen_id = 43168, uid = 1000, flags = 1, file_id 806:88dd9
> unparse_share_modes: del: 1, tok = 20, num: 1
> print_share_mode_table: share_mode_entry[0]:  pid = 23814,
> share_access = 0x7, private_options = 0x0, access_mask = 0x10000, mid
> = 0x0, type= 0x10, gen_id = 43168, uid = 1000, flags = 1, file_id
> 806:88dd9
> Unlocking key 0608000000000000D98D080000000000
> Locking key 0608000000000000D98D080000000000
> Allocated locked data 0x0x80591018
> parse_share_modes: delete_on_close: 1, num_share_modes: 1
> parse_share_modes: share_mode_entry[0]:  pid = 23814, share_access =
> 0x7, private_options = 0x0, access_mask = 0x10000, mid = 0x0, type=
> 0x10, gen_id = 43168, uid = 1000, flags = 1, file_id 806:88dd9
> close_remove_share_mode: file new-symlink-file. Delete on close was
> set - deleting file.
> push_sec_ctx(1000, 100) : sec_ctx_stack_ndx = 1
> setting sec ctx (1000, 100) - sec_ctx_stack_ndx = 1
> NT user token: (NULL)
> UNIX token of user 1000
> Primary group is 100 and contains 3 supplementary groups
> Group[  0]: 100
> Group[  1]: 16
> Group[  2]: 33
> close_remove_share_mode: file new-symlink-file. Delete on close was
> set and dev and/or inode does not match
> close_remove_share_mode: file new-symlink-file. stored file_id
> 806:88dd9, stat file_id 806:88bf8
> pop_sec_ctx (1000, 100) - sec_ctx_stack_ndx = 0
> Unlocking key 0608000000000000D98D080000000000
> stevef closed file new-symlink-file (numopen=0) NT_STATUS_OK
> freed files structure 13244 (0 used)
> t2_rep: params_sent_thistime = 2, data_sent_thistime = 0, useable_space = 16412
> t2_rep: params_to_send = 2, data_to_send = 0, paramsize = 2, datasize = 0
> size=58
> smb_com=0x32
> smb_rcls=0
> smb_reh=0
> smb_err=0
> smb_flg=128
> smb_flg2=49217
> smb_tid=1
> smb_pid=28784
> smb_uid=100
> smb_mid=53227
> 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
> [000] 00 00 00                                          ...
> Running event "idle_evt(deadtime)" 8058d450
> Destroying timed event 8058d450 "idle_evt(deadtime)"
> Added timed event "idle_evt(deadtime)": 805923b8
>
>
> On 7/16/07, Steve French <smfrench at gmail.com> wrote:
> > Yes - that worked fine.  Now I can open a file again, and reproduce
> > the original problem "rm -r" fails (posix unlink leaves debris around
> > - in the cleanup phase of connectathon test 8 which is cleaning up 10
> > symlinks ).
> >
> > This is easy to reproduce - create a symlink somewhere within the
> > share - then try to remove it from a cifs mount with cifs 1.50 or
> > greater (which uses the new posix unlink). The posix unlink succeeds
> > (NT Status code is zero) but the symlink is left around.   Removing a
> > file works.
> >
> > On 7/16/07, Volker Lendecke <Volker.Lendecke at sernet.de> wrote:
> > > On Mon, Jul 16, 2007 at 02:51:23PM -0500, Steve French wrote:
> > > > gdb's backtrace was no more interesting than the one nicely dumped by
> > > > smb_panic.  The log level 10 info follows:
> > >
> > > Thanks :-)
> > >
> > > r23903 should do it I think.
> > >
> > > Volker
> > >
> > >
> >
> >
> > --
> > Thanks,
> >
> > Steve
> >
>
>
> --
> Thanks,
>
> Steve
>


-- 
Thanks,

Steve


More information about the samba-technical mailing list