Bug 12021 - smbd Crashing (Signal 4) on File Delete
smbd Crashing (Signal 4) on File Delete
Status: RESOLVED FIXED
Product: Samba 4.1 and newer
Classification: Unclassified
Component: File services
4.3.6
x64 FreeBSD
: P5 normal
: ---
Assigned To: Karolin Seeger
Samba QA Contact
https://forums.freenas.org/index.php?...
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2016-07-14 09:58 UTC by Mark Barbieri
Modified: 2016-08-05 10:22 UTC (History)
5 users (show)

See Also:


Attachments
log.smbd :You can see the posix_unlink and deletion starts at time-stamp 2016/07/13 05:21:03.532018 in the attached (4.58 MB, text/plain)
2016-07-14 09:58 UTC, Mark Barbieri
no flags Details
backtrace (331.54 KB, text/plain)
2016-07-17 10:32 UTC, Mark Barbieri
no flags Details
Test patch for 4.3.x. (936 bytes, patch)
2016-07-18 20:41 UTC, Jeremy Allison
no flags Details
log after patch (609.31 KB, text/plain)
2016-07-20 13:09 UTC, Mark Barbieri
no flags Details
Patch for 4.4.x, 4.3.x. (5.60 KB, patch)
2016-07-20 19:02 UTC, Jeremy Allison
slow: review+
jra: review? (obnox)
jra: review? (uri)
Details
log.smbd after patch (719.82 KB, text/plain)
2016-07-21 21:37 UTC, Mark Barbieri
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Mark Barbieri 2016-07-14 09:58:06 UTC
Created attachment 12270 [details]
log.smbd :You can see the posix_unlink and deletion starts at time-stamp 2016/07/13 05:21:03.532018 in the attached

smbd Crashing (Signal 4) on File Delete

I'm running a FreeNAS 9.10 system with smbd version 4.3.6

Shares have been created with windows based security.  By default, FreeNAS includes VFS module streams_xattr.

I have this share mounted on a Debian 8.5 system.

On this share there are files with Alternate Data Streams, (in this case they are zone identifier metadata streams).

If I execute 'rm' against the file to delete it, the 'rm' command hangs and eventually smbd crashes with a signal 4 error.

If I manually remove the alternate data stream from the file then I can delete it without problem.  I have confirmed it is not a permission problem.

This issue has been discussed on the FreeNAS forum and has been experienced by others.  My specific posts on this issue commence from here: https://forums.freenas.org/index.php?threads/smbd-crashing-signal-4-on-file-delete.34865/page-2#post-299818

It is also raised here : https://bugs.pcbsd.org/issues/15808  At this stage, the belief is that this is a samba bug.

Running strace on the rm command confirms that the command 'unlinkat(AT_FDCWD, "/shares/Temp/.....' hangs during removal.

With minimal debug logging, checking the log shows signal 4 crash messages about every 30 seconds until the rm command is killed

Manually removing the alternate data stream from the file resolves this issue.

Removing streams_xattr from the shares also resolves this problem.

A debug log file is attached.  You can see the posix_unlink and deletion starts at time-stamp 2016/07/13 05:21:03.532018 in the attached. 

The following is repeated in the debug log files until the service crashes.

[2016/07/13 04:54:21.821077, 10, pid=11240, effective(0, 0), real(0, 0)] ../source3/smbd/open.c:3866(open_streams_for_delete)
  open_streams_for_delete found 2 streams
[2016/07/13 04:54:21.821091, 10, pid=11240, effective(0, 0), real(0, 0)] ../source3/smbd/open.c:3897(open_streams_for_delete)
  Unable to stat stream: openvpn.zip:Zone.Identifier:$DATA
[2016/07/13 04:54:21.821103, 10, pid=11240, effective(0, 0), real(0, 0)] ../source3/smbd/open.c:4973(create_file_default)
  create_file: access_mask = 0x10000 file_attributes = 0x80, share_access = 0x7, create_disposition = 0x1 create_options = 0x0 oplock_request = 0x0 private_flags = 0x4 root_dir_fid = 0x0, ea_list = 0x0x0, sd = 0x0x0, fname = openvpn.zip:Zone.Identifier:$DATA
[2016/07/13 04:54:21.821117, 10, pid=11240, effective(0, 0), real(0, 0)] ../source3/smbd/open.c:4450(create_file_unixpath)
  create_file_unixpath: access_mask = 0x10000 file_attributes = 0x80, share_access = 0x7, create_disposition = 0x1 create_options = 0x0 oplock_request = 0x0 private_flags = 0x4 ea_list = 0x0x0, sd = 0x0x0, fname = openvpn.zip:Zone.Identifier:$DATA
[2016/07/13 04:54:21.821157, 10, pid=11240, effective(0, 0), real(0, 0)] ../source3/smbd/trans2.c:301(get_ea_names_from_file)
  get_ea_names_from_file: ea_namelist size = 52
[2016/07/13 04:54:21.821184, 10, pid=11240, effective(0, 0), real(0, 0)] ../source3/smbd/trans2.c:210(get_ea_value)
  get_ea_value: EA user.DosStream.Zone.Identifier:$DATA is of length 27
[2016/07/13 04:54:21.821197, 10, pid=11240, effective(0, 0), real(0, 0)] ../lib/util/util.c:559(dump_data)
  [0000] 5B 5A 6F 6E 65 54 72 61   6E 73 66 65 72 5D 0D 0A   [ZoneTra nsfer]..
  [0010] 5A 6F 6E 65 49 64 3D 33   0D 0A 00                  ZoneId=3 ...
Comment 1 Jeremy Allison 2016-07-14 16:32:52 UTC
Sig4 is an illegal instruction. Can you ensure smbd is built with symbols (-g) and then reproduce with the following in the [global] section of your smb.conf:

panic action = /bin/sleep 999999

This will keep the parent smbd around so you can attach to it with a debugger.

If it's gdb, type "bt" to get a full stack backtrace so we can see what might be going wrong.

Thanks !
Comment 2 Mark Barbieri 2016-07-17 10:32:16 UTC
Created attachment 12273 [details]
backtrace

First few hundred lines from the backtrace.  The backtrace is huge, but it is the same lines repeated until segmentation fault (out of memory?)
Comment 3 Mark Barbieri 2016-07-17 10:44:24 UTC
There were no debug symbols built with the module, but I've installed the FreeNAS nightlies build and located the additional .debug modules.

I'm not sure if the backtrace is really helpful, but I was looking at smbd/open.c in open_streams_for_delete().

This line caught my eye:

		if (strequal(stream_info[i].name, "::$DATA")) {
			streams[i] = NULL;
			continue;
		}

However, as per the log, the stream format is like this:

[2016/07/13 05:21:03.532231, 10, pid=18124, effective(0, 0), real(0, 0)] ../source3/smbd/open.c:3897(open_streams_for_delete)
  Unable to stat stream: openvpn.zip:Zone.Identifier:$DATA

Should the above snippet be checking for ":$DATA" instead of "::$DATA"
Comment 4 Jeremy Allison 2016-07-18 19:42:01 UTC
OK, I know what is causing this. Give me a little while and I'll give you a fix to test.
Comment 5 Jeremy Allison 2016-07-18 20:41:44 UTC
Created attachment 12274 [details]
Test patch for 4.3.x.

Can you try this change to see if it addresses the problem ?
Comment 6 Jeremy Allison 2016-07-19 16:02:06 UTC
John (iXSystems) - I have a proper fix for this for master including regression test. I also know how to back-port to 4.4.x, 4.3.x. Ping me directly if you have any customers affected by this and I can give you the details directly.
Comment 7 Mark Barbieri 2016-07-20 13:09:37 UTC
Created attachment 12281 [details]
log after patch

OK, this doesn't crash, but it also does not delete the file.

rm: cannot remove ‘openvpn.zip’: No such file or directory

File remains after the 'rm'

See log attached.
Comment 8 Jeremy Allison 2016-07-20 15:37:56 UTC
Yes, I expected that. Just needed to confirm the issue. A real patch (that allows the file to be deleted) has been pushed to master, so I'll do a back-port for 4.4.x, 4.3.x once that lands.
Comment 9 Josh Paetzel 2016-07-20 16:37:21 UTC
Alright, perfect.

I'll put that patch for 4.3 into FreeNAS nightlies as soon as you have it.
Comment 10 Jeremy Allison 2016-07-20 19:02:50 UTC
Created attachment 12282 [details]
Patch for 4.4.x, 4.3.x.

OK, here is a back-port of the concepts behind the patch that went into master.

Due to the fact that 4.4.x and below don't have the flags field in struct smb_filename, this is much more of a hack but is relatively self contained and works (was tested using the POSIX-STREAM-DELETE smbtorture test from master).

I haven't back-ported the regression test as that also requires infrastructure 4.4.x doesn't have.

Josh, you should test this on FreeNAS but I'm pretty sure it'll fix the problem for you. Once Ralph as +1'ed it it'll go into the next release of 4.4.x and 4.3.x.
Comment 11 Mark Barbieri 2016-07-21 21:37:33 UTC
Created attachment 12284 [details]
log.smbd after patch

Tested and works.

I've attached a debug log for the session in case you want to verify that it works as you expected.


Many thanks.
Comment 12 Ralph Böhme 2016-07-22 05:00:54 UTC
Comment on attachment 12282 [details]
Patch for 4.4.x, 4.3.x.

Oh, this is ugly, but what can we do...
Comment 13 Ralph Böhme 2016-07-22 05:01:33 UTC
Reassigning to Karolin for inclusion in 4.3 and 4.4.
Comment 14 Karolin Seeger 2016-08-02 07:34:40 UTC
(In reply to Ralph Böhme from comment #13)
Pushed to autobuild-v4-[4|3]-test.
Comment 15 Karolin Seeger 2016-08-05 07:41:19 UTC
(In reply to Karolin Seeger from comment #14)
Pushed to both branches.
Closing out bug report.

Thanks!
Comment 16 Mark Barbieri 2016-08-05 10:22:25 UTC
Many thanks