On Samba servers running Samba 3.5.6 (also tested with 3.4.9) we get an error "There was an error accessing ...ppt" when trying to open certain Powerpoint files with MS Powerpoint 2010
- Tested with Office 2010 on a Windows 7 client
- happens with 3.4.9 and 3.5.6
- does not happen with 3.3.14 and 3.0.28
- not tested with other office, windows and samba versions
- does only happen with some ppt files (unclear, those that
cannot be opened from a share are immediately rewritten during
opening them from a non-Samba location)
- Samba (sernet-samba packages) on Debian/lenny (others untested)
- tried out multiple configurations, happens with a most basic
configuration (appended below) as well as with a sophisticated one
Running smbd with debug level 10 I have seen one interesting error in the log (see below) that does not appear when running 3.3.14. However, I am unsure if this is significant. The entire error log is available from http://tuallix.graeff.com/ppt_samba_err.txt.
Please let me know if I can do more testing for you, we have set up a test environment we can reproduce the error in. I can provide a .ppt triggering the problem on request.
========================= excerpt from smbd log ======================
smb_vwv= 8 (0x8)
[2011/01/28 16:48:28.600363, 10] ../lib/util/util.c:278(_dump_data)
 00 00 00 18 48 EC 03 00 00 00 00 00 00 00 00 00 ....H... ........
 00 00 00 00 00 00 00 00 00 00 00 60 9A 7F CE 02 ........ ...`....
 BF CB 01 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........
 00 00 00 ...
[2011/01/28 16:48:28.600421, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans2 (pid 5148) conn 0x809d52c0
[2011/01/28 16:48:28.600434, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/01/28 16:48:28.600449, 3] smbd/trans2.c:7722(call_trans2setfilepathinfo)
call_trans2setfilepathinfo(8) IBA/test2.ppt (fnum 18456) info_level=1004 totdata=40
[2011/01/28 16:48:28.600463, 3] smbd/trans2.c:7320(smbd_do_setfilepathinfo)
smbd_do_setfilepathinfo: IBA/test2.ppt (fnum 18456) info_level=1004 totdata=40
[2011/01/28 16:48:28.600477, 6] smbd/trans2.c:5518(smb_set_file_dosmode)
smb_set_file_dosmode: dosmode: 0x0
[2011/01/28 16:48:28.600490, 10] smbd/trans2.c:6303(smb_set_file_basic_info)
smb_set_file_basic_info: file IBA/test2.ppt
[2011/01/28 16:48:28.600502, 5] smbd/trans2.c:5436(smb_set_file_time)
smb_set_filetime: actime: Thu Jan 1 01:00:00 1970
smb_set_filetime: modtime: Fri Jan 28 16:48:29 2011
smb_set_filetime: ctime: Thu Jan 1 01:00:00 1970
smb_set_file_time: createtime: Thu Jan 1 01:00:00 1970
smb_set_file_time: setting pending modtime to Fri Jan 28 16:48:29 2011
[2011/01/28 16:48:28.600557, 5] locking/locking.c:1475(set_sticky_write_time)
set_sticky_write_time: Fri 28 Jan 2011 04:48:29 PM CET CET id=303:1e45fe:0
[2011/01/28 16:48:28.600588, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
Locking key 0303000000000000FE45
[2011/01/28 16:48:28.600605, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
Allocated locked data 0x0x809b3d08
[2011/01/28 16:48:28.600617, 10] locking/locking.c:552(parse_share_modes)
parse_share_modes: delete_on_close: 0, owrt: Fri 28 Jan 2011 04:24:08 PM CET CET, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 2
[2011/01/28 16:48:28.600650, 10] locking/locking.c:655(parse_share_modes)
parse_share_modes: share_mode_entry: pid = 5148, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x0, gen_id = 140, uid = 1006, flags = 0, file_id 303:1e45fe:0
[2011/01/28 16:48:28.600671, 10] locking/locking.c:655(parse_share_modes)
parse_share_modes: share_mode_entry: UNUSED pid = 5148, share_access = 0x3, private_options = 0x40, access_mask = 0x20089, mid = 0x0, type= 0x40, gen_id = 146, uid = 1006, flags = 0, file_id 303:1e45fe:0
[2011/01/28 16:48:28.600685, 10] locking/locking.c:726(unparse_share_modes)
unparse_share_modes: del: 0, owrt: Fri 28 Jan 2011 04:24:08 PM CET CET cwrt: Fri 28 Jan 2011 04:48:29 PM CET CET, tok: 0, num: 2
[2011/01/28 16:48:28.600716, 10] locking/locking.c:518(print_share_mode_table)
print_share_mode_table: share_mode_entry: pid = 5148, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x0, gen_id = 140, uid = 1006, flags = 0, file_id 303:1e45fe:0
[2011/01/28 16:48:28.600736, 10] locking/locking.c:518(print_share_mode_table)
print_share_mode_table: share_mode_entry: UNUSED pid = 5148, share_access = 0x3, private_options = 0x40, access_mask = 0x20089, mid = 0x0, type= 0x40, gen_id = 146, uid = 1006, flags = 0, file_id 303:1e45fe:0
[2011/01/28 16:48:28.600752, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
Unlocking key 0303000000000000FE45
[2011/01/28 16:48:28.600771, 10] smbd/trans2.c:5472(smb_set_file_time)
smb_set_file_time: setting utimes to modified values.
[2011/01/28 16:48:28.600783, 6] smbd/dosmode.c:861(file_ntimes)
file_ntime: actime: Thu Jan 1 01:00:00 1970
[2011/01/28 16:48:28.600799, 6] smbd/dosmode.c:863(file_ntimes)
file_ntime: modtime: Fri Jan 28 16:48:29 2011
[2011/01/28 16:48:28.600814, 6] smbd/dosmode.c:865(file_ntimes)
file_ntime: ctime: Thu Jan 1 01:00:00 1970
[2011/01/28 16:48:28.600830, 6] smbd/dosmode.c:867(file_ntimes)
file_ntime: createtime: Thu Jan 1 01:00:00 1970
[2011/01/28 16:48:28.600847, 3] smbd/error.c:80(error_packet_set)
error packet at smbd/trans2.c(7759) cmd=50 (SMBtrans2) NT_STATUS_NOT_SUPPORTED
[2011/01/28 16:48:28.600861, 5] lib/util.c:617(show_msg)
[2011/01/28 16:48:28.600869, 5] lib/util.c:627(show_msg)
====================== smb.conf ========================================
workgroup = MYGROUP
server string = Samba Server
passdb backend = smbpasswd
log file = /usr/local/samba/var/log.%m
max log size = 50
dns proxy = No
comment = Home Directories
read only = No
browseable = No
Can you upload a wireshark capture trace of this occurring please ? I'd like to see what is returning the NT_STATUS_NOT_SUPPORTED.
Created attachment 6233 [details]
tcpdump capture file ready for analyse with wireshark
captured with tcpdump -s 1600 -w ... ready for wireshark -r
Is it possible that you are using an older kernel than debian lenny? What file system are you sharing?
Created attachment 6234 [details]
The attached patch applies to both master and 3.6.
It seems that we try a utimes version that the kernel this system is running does not support. We do not do a proper fallback, which this patch implements.
I'm not pushing it right away because I could swear that we have talked about exactly this topic a couple of months ago. I can't find any reference to it, so I'm not sure this or a similar solution was turned down deliberately.
Björn, do you remember that discussion and the outcome? It might have been internal.
you are right, we are running 2.6.18 on this systems due to some dependencies, sorry for not having mentioned that before. The underlying file system is XFS.
Ok, the older kernel is the problem here. I'm very certain that the attached patch (or a similar one) will fix the problem.
We'll discuss soon how to proceed here.
the outcome was that this kernel/libc combination is unsupported/invalid and we want to refuse to start in case utimensat returns ENOSYS. Not yet done ...
Ok. I would still argue that we could do the workaround patch I proposed, but if the Samba Team decides that we should stop supporting configurations that we *could* support, I can provide a different patch.
Jeremy, do you have an opinion here?
Maybe this is redundant information: I confirm the problem is gone after upgrading to kernel 2.6.26.
If I may put my opinion in from the admins point of view: It is acceptable that Samba does not try to work around the problem (would be nice, anyway, especially since older Samba versions did work in this configuration), but should then at least log a meaningful error message.
yes, that is definetely the recommended thing to do.
Comment on attachment 6234 [details]
+1 on the patch from me. Anything that makes us fallback better works for me. Is there a reason we shouldn't fall back here ?
Oh wait a minute - just read the linked-to thread.
"Therefore I'd prefer the
> > attached short patch without any fallback code.
> +1 from me. Last thing we need are more obscure failure modes :-). "
Maybe we should just call smb_panic() on result == -1 && errno == ENOSYS with an appropriate error message.
(In reply to comment #15)
> Oh wait a minute - just read the linked-to thread.
> "Therefore I'd prefer the
> > > attached short patch without any fallback code.
> > +1 from me. Last thing we need are more obscure failure modes :-). "
> Maybe we should just call smb_panic() on result == -1 && errno == ENOSYS with
> an appropriate error message.
No, this would be wrong. We would need to add this test to the smbd startup routine. I still vote for the fallback, my 10ct...
Ok, after talking with Volker I'm happy with the patch. Re-assigning to Karolin for inclusion in 3.5.next.
Pushed to v3-5-test.
Will be included in the next bugfix release.
Closing out bug report.
this still looks wrong to me as we already discussed in the thread mentioned in comment 11.
The very least me miss now is the fix that Janek posted there for the vfswrap_fs_capabilities function because it returns the wrong result on broken/unsupported glibc/kernel combinations.
But Jeremy: in that mentioned thread you agreed that trying to support a broken setup and possibly waiting for other jet unknown other obcure erors is a bad idea - why do you want to do that now?
Re-assigning to Jeremy to comment.
This is a blocker for 3.5.7 now, because I am not sure whether I shall revert the patch or not.
Volkers fall back fix is the correct one. Don't revert - this is not a blocker.
and vfswrap_fs_capabilities() returning the wrong thing is okay?