Created attachment 6701 [details] Logs for opening files inside of winzip showing successful and unsucessful attempts Winzip occasionally fails to read files (or transfer files out) out of an open winzip dialog box. It appears two different paths are followed for authentication. Files attached from the server log with a successful attempt and an unsuccessful attempt. Server is Enterprise Linux using ACL's. Client is Windows 7 use SMB2 Patches applied from Bug 8219 6643 and 6650 Using SMB2 Signing
Created attachment 6702 [details] Log attached for a failed delete attempt This also seems to cause delete to fail occasionally in the explorer window looking at the log the problems seem related. Delete provides no error message but the file is still present when refreshing. File deletes with no error under same user in Linux.
Possible Dup of Bug 7891
Bug still exists in RC3
Your log files are from winbind. We need the smbd log files.
Created attachment 6725 [details] SMB Logs for Bug Here are two errors in the logs that are likely related. [2011/07/28 09:19:03.948894, 5] smbd/smb2_signing.c:73(smb2_signing_sign_pdu) signed SMB2 message smbd_smb2_request_reply: sending... req->in.vector[0].iov_len = 4 req->in.vector[1].iov_len = 64 req->in.vector[2].iov_len = 40 req->in.vector[3].iov_len = 0 req->out.vector[0].iov_len = 4 req->out.vector[1].iov_len = 64 req->out.vector[2].iov_len = 8 req->out.vector[3].iov_len = 4 [2011/07/28 09:19:03.949992, 10] smbd/smb2_server.c:2361(smbd_smb2_request_incoming) smbd_smb2_request_incoming: idx[1] of 4 vectors [2011/07/28 09:19:03.950049, 10] smbd/smb2_server.c:345(smb2_validate_message_id) smb2_validate_message_id: clearing id 461 (position 205) from bitmap [2011/07/28 09:19:03.950099, 10] smbd/smb2_server.c:1095(smbd_smb2_request_dispatch) smbd_smb2_request_dispatch: opcode[SMB2_IOCTL] mid = 461 [2011/07/28 09:19:03.950163, 4] smbd/uid.c:351(change_to_user) Skipping user change - already user [2011/07/28 09:19:03.950213, 10] smbd/smb2_ioctl.c:249(smbd_smb2_ioctl_send) smbd_smb2_ioctl: file_id[0x0000000000003E19] [2011/07/28 09:19:03.950277, 10] smbd/smb2_ioctl.c:138(smbd_smb2_request_ioctl_done) smbd_smb2_request_ioctl_done: smbd_smb2_ioctl_recv returned 0 status NT_STATUS_INVALID_DEVICE_REQUEST [2011/07/28 09:19:03.950329, 10] smbd/smb2_server.c:1799(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_INVALID_DEVICE_REQUEST] || at smbd/smb2_ioctl.c:144 [2011/07/28 09:19:03.950379, 10] smbd/smb2_server.c:1702(smbd_smb2_request_done_ex) smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_INVALID_DEVICE_REQUEST] body[8] dyn[yes:1] at smbd/smb2_server.c:1830 [2011/07/28 09:19:03.950429, 10] smbd/smb2_server.c:472(smb2_set_operation_credit) smb2_set_operation_credit: requested 1, granted 1, total granted 31 [2011/07/28 09:19:05.762155, 5] smbd/smb2_signing.c:73(smb2_signing_sign_pdu) signed SMB2 message smbd_smb2_request_reply: sending... req->in.vector[0].iov_len = 4 req->in.vector[1].iov_len = 64 req->in.vector[2].iov_len = 24 req->in.vector[3].iov_len = 0 req->out.vector[0].iov_len = 4 req->out.vector[1].iov_len = 64 req->out.vector[2].iov_len = 60 req->out.vector[3].iov_len = 0 [2011/07/28 09:19:05.763560, 10] smbd/smb2_server.c:2361(smbd_smb2_request_incoming) smbd_smb2_request_incoming: idx[1] of 4 vectors [2011/07/28 09:19:05.763615, 10] smbd/smb2_server.c:345(smb2_validate_message_id) smb2_validate_message_id: clearing id 517 (position 5) from bitmap [2011/07/28 09:19:05.763666, 10] smbd/smb2_server.c:1095(smbd_smb2_request_dispatch) smbd_smb2_request_dispatch: opcode[SMB2_CREATE] mid = 517 [2011/07/28 09:19:05.763738, 4] smbd/uid.c:351(change_to_user) Skipping user change - already user [2011/07/28 09:19:05.763796, 10] smbd/smb2_create.c:455(smbd_smb2_create_send) smbd_smb2_create: name[SambaTestCase\testcase.zip:Zone.Identifier] [2011/07/28 09:19:05.763851, 5] smbd/filename.c:257(unix_convert) unix_convert called on file "SambaTestCase/testcase.zip:Zone.Identifier" [2011/07/28 09:19:05.763904, 10] smbd/statcache.c:280(stat_cache_lookup) stat_cache_lookup: lookup succeeded for name [SAMBATESTCASE/TESTCASE.ZIP] -> [SambaTestCase/testcase.zip] [2011/07/28 09:19:05.763975, 10] smbd/filename.c:1203(build_stream_path) comparing [:Zone.Identifier] and [::$DATA]: not equal [2011/07/28 09:19:05.764028, 3] smbd/vfs.c:905(check_reduced_name) check_reduced_name [SambaTestCase/testcase.zip] [/data/erb] [2011/07/28 09:19:05.764102, 10] smbd/vfs.c:969(check_reduced_name) check_reduced_name realpath [SambaTestCase/testcase.zip] -> [/data/erb/SambaTestCase/testcase.zip] [2011/07/28 09:19:05.764151, 3] smbd/vfs.c:1039(check_reduced_name) check_reduced_name: SambaTestCase/testcase.zip reduced to /data/erb/SambaTestCase/testcase.zip [2011/07/28 09:19:05.764201, 10] smbd/open.c:3760(create_file_default) create_file: access_mask = 0x80 file_attributes = 0x0, share_access = 0x7, create_disposition = 0x1 create_options = 0x200000 oplock_request = 0x0 private_flags = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = SambaTestCase/testcase.zip:Zone.Identifier [2011/07/28 09:19:05.764261, 10] smbd/open.c:3864(create_file_default) create_file: NT_STATUS_OBJECT_NAME_NOT_FOUND [2011/07/28 09:19:05.764322, 4] smbd/sec_ctx.c:314(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2011/07/28 09:19:05.764370, 5] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2011/07/28 09:19:05.764417, 5] auth/token_util.c:527(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2011/07/28 09:19:05.764512, 5] smbd/uid.c:400(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2011/07/28 09:19:05.764574, 10] smbd/smb2_server.c:1799(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at smbd/smb2_create.c:308 [2011/07/28 09:19:05.764626, 10] smbd/smb2_server.c:1702(smbd_smb2_request_done_ex) smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] body[8] dyn[yes:1] at smbd/smb2_server.c:1830 [2011/07/28 09:19:05.764679, 10] smbd/smb2_server.c:472(smb2_set_operation_credit)
Created attachment 6730 [details] Install Instructions and smb.conf file Volker, I have added the smb.conf file and install instructions to be more complete can you tell from the logs if I should reclassify the component as SMB2? Also let me know if there is anything I can provide that would help track this down. Thanks, Eric
Maybe the problem is that smb2_ioctl.c doesn't handle the same fsctl opcodes as nttrans.c.
Still exists in 3.6.4 were you able to replicate the bug?
Created attachment 7602 [details] Untested patch for 3.6 Can you apply and test this patches?
Comment on attachment 7602 [details] Untested patch for 3.6 Jeremy, David, Richard, would this be fine for 3.6? Can someone test this?
(In reply to comment #9) > Created attachment 7602 [details] > Untested patch for 3.6 > > Can you apply and test this patches? Sorry will post later today.
Will try and get to this tomorrow. Jeremy.
I like the patch, I just *hate* the SMB_VFS_FSCTL() name. As it isn't really a vfs function we should just call it smb_fsctl() (IMHO) so we don't confuse people into thinking this is vectored. Jeremy.
(In reply to comment #11) > (In reply to comment #9) > > Created attachment 7602 [details] [details] > > Untested patch for 3.6 > > > > Can you apply and test this patches? > > Sorry will post later today. Sorry for the delay code works fine, so far no evidence of bug.
Comment on attachment 7602 [details] Untested patch for 3.6 I hate the SMB_VFS_FSCTL() function name as it's really confusing for VFS users. I have a version of this patch that calls this function smb_fsctl() instead which I'll upload. Jeremy.
Created attachment 7625 [details] git-am fix for 3.6.next. Here's the modified version. It's the same code that the reporter just reported as working, with the change of SMB_VFS_FSCTL() -> smb_fsctl() Jeremy.
Comment on attachment 7625 [details] git-am fix for 3.6.next. Looks ok
Karolin, please pick for the release
Pushed to v3-6-test. Closing out bug report. Thanks!