homepage

FreeBSD slaves are running into this:
======================================================================
ERROR: test_copy2_symlinks (test.test_shutil.TestShutil)
----------------------------------------------------------------------
Traceback (most recent call last):
 File "/home/buildslave/cpython/3.x.snakebite-freebsd91-amd64/build/Lib/test/test_shutil.py", line 490, in test_copy2_symlinks
 shutil.copy2(src_link, dst, follow_symlinks=False)
 File "/home/buildslave/cpython/3.x.snakebite-freebsd91-amd64/build/Lib/shutil.py", line 237, in copy2
 copyfile(src, dst, follow_symlinks=follow_symlinks)
 File "/home/buildslave/cpython/3.x.snakebite-freebsd91-amd64/build/Lib/shutil.py", line 107, in copyfile
 os.symlink(os.readlink(src), dst)
TypeError: embedded NUL character
======================================================================
ERROR: test_copy_symlinks (test.test_shutil.TestShutil)
----------------------------------------------------------------------
Traceback (most recent call last):
 File "/home/buildslave/cpython/3.x.snakebite-freebsd91-amd64/build/Lib/test/test_shutil.py", line 463, in test_copy_symlinks
 shutil.copy(src_link, dst, follow_symlinks=False)
 File "/home/buildslave/cpython/3.x.snakebite-freebsd91-amd64/build/Lib/shutil.py", line 221, in copy
 copyfile(src, dst, follow_symlinks=follow_symlinks)
 File "/home/buildslave/cpython/3.x.snakebite-freebsd91-amd64/build/Lib/shutil.py", line 107, in copyfile
 os.symlink(os.readlink(src), dst)
TypeError: embedded NUL character
======================================================================
FAIL: test_copytree_symlinks (test.test_shutil.TestShutil)
----------------------------------------------------------------------
Traceback (most recent call last):
 File "/home/buildslave/cpython/3.x.snakebite-freebsd91-amd64/build/Lib/test/test_shutil.py", line 606, in test_copytree_symlinks
 os.path.join(src_dir, 'file.txt'))
AssertionError: '/tmp/tmpqlihz5/src/file.' != '/tmp/tmpqlihz5/src/file.txt'
- /tmp/tmpqlihz5/src/file.
+ /tmp/tmpqlihz5/src/file.txt
? +++
Haven't had time to debug it any further yet. Have no clue what's going on either just from a cursory look at the error messages. Not sure if it's ZFS related like the other FreeBSD issues.

Looks like os.readlink() is busted:
> /home/trent/src/cpython/Lib/shutil.py(107)copyfile()
-> os.symlink(os.readlink(src), dst)
(Pdb) s
TypeError: embedded NUL character
> /home/trent/src/cpython/Lib/shutil.py(107)copyfile()
-> os.symlink(os.readlink(src), dst)
(Pdb) os.readlink(src)
'/tmp/tmpr3obfj/foo\x00\x00\x00\x00\x00\x00'
(Pdb) p src
'/tmp/tmpr3obfj/baz'
(Pdb) l
102 	 # XXX What about other special files? (sockets, devices...)
103 	 if stat.S_ISFIFO(st.st_mode):
104 	 raise SpecialFileError("`%s` is a named pipe" % fn)
105 	
106 	 if not follow_symlinks and os.path.islink(src):
107 ->	 os.symlink(os.readlink(src), dst)
108 	 else:
109 	 with open(src, 'rb') as fsrc:
110 	 with open(dst, 'wb') as fdst:
111 	 copyfileobj(fsrc, fdst)
112 	 return dst
> /home/trent/src/cpython/Lib/shutil.py(107)copyfile()
-> os.symlink(os.readlink(src), dst)
(Pdb) s
TypeError: embedded NUL character
> /home/trent/src/cpython/Lib/shutil.py(107)copyfile()
-> os.symlink(os.readlink(src), dst)
(Pdb) os.readlink(src)
'/tmp/tmpr3obfj/foo\x00\x00\x00\x00\x00\x00'
(Pdb) p src
'/tmp/tmpr3obfj/baz'
(Pdb) l
102 	 # XXX What about other special files? (sockets, devices...)
103 	 if stat.S_ISFIFO(st.st_mode):
104 	 raise SpecialFileError("`%s` is a named pipe" % fn)
105 	
106 	 if not follow_symlinks and os.path.islink(src):
107 ->	 os.symlink(os.readlink(src), dst)
108 	 else:
109 	 with open(src, 'rb') as fsrc:
110 	 with open(dst, 'wb') as fdst:
111 	 copyfileobj(fsrc, fdst)
112 	 return dst
i.e.:
(Pdb) os.readlink(src)
'/tmp/tmpr3obfj/foo\x00\x00\x00\x00\x00\x00'
Started another session with gdb, set a breakpoint at posix_readlink:
Breakpoint 1, posix_readlink (self=0x800909858, args=0x805ec2840, kwargs=0x0)
 at ./Modules/posixmodule.c:7007
7007	 int dir_fd = DEFAULT_DIR_FD;
(gdb) l
7002	
7003	static PyObject *
7004	posix_readlink(PyObject *self, PyObject *args, PyObject *kwargs)
7005	{
7006	 path_t path;
7007	 int dir_fd = DEFAULT_DIR_FD;
7008	 char buffer[MAXPATHLEN];
7009	 ssize_t length;
7010	 PyObject *return_value = NULL;
7011	 static char *keywords[] = {"path", "dir_fd", NULL};
(gdb) n
7013	 memset(&path, 0, sizeof(path));
(gdb) 
7014	 if (!PyArg_ParseTupleAndKeywords(args, kwargs, "O&|$O&:readlink", keywords,
(gdb) 
7024	 Py_BEGIN_ALLOW_THREADS
(gdb) 
7026	 if (dir_fd != DEFAULT_DIR_FD)
(gdb) p path
1ドル = {function_name = 0x0, argument_name = 0x0, nullable = 0, allow_fd = 0, 
 wide = 0x0, narrow = 0x805ec0f10 "/tmp/tmpko8vo_/baz", fd = -1, length = 18, 
 object = 0x805e30d60, cleanup = 0x805ec0ee0}
path.narrow and length are correct at that point.
(gdb) p dir_fd
2ドル = -100
(gdb) n
7024	 Py_BEGIN_ALLOW_THREADS
(gdb) n
7026	 if (dir_fd != DEFAULT_DIR_FD)
(gdb) n
7030	 length = readlink(path.narrow, buffer, sizeof(buffer));
(gdb) n
7031	 Py_END_ALLOW_THREADS
(gdb) p length
3ドル = 24
(gdb) p sizeof(buffer)
7ドル = 1024
(gdb) p buffer
9ドル = "/tmp/tmpko8vo_/foo000円000円000円000円000円000円ͤ\r001円\b000円000円000円000円000円000円000円??????A", '0円' <repeats 77 times>, "??203円000円\b000円000円000円?v???177円000円000円??A", '0円' <repeats 13 times>, "f023円J", '0円' <repeats 13 times>, "??A000円000円000円000円000円001円000円000円000円000円000円000円000円030円u???177円000円000円 u???177円000円000円RCJ000円000円000円000円000円000円001円000円000円000円000円000円000円??A000円000円000円000円000円?v???177円000円000円?(?005円\b000円000円0000円?L002円\b000円000円000円210円N?005円\b000円000円000円001円000円000円000円000円000円000円000円??A000円000円000円000円000円?"...
No idea why readlink is returning 24. Need to look into it more.

I'll ask the obvious: was that an optimized build? Not that that explains the bug--but that might explain why "length" appeared to contain 24.
It's hard to believe this is really an OS bug...

Hi Larry,
Funnily enough, I just tried to step through a heavily hacked version of posix_readlink again, only to get gdb telling me I couldn't 'print' the variables I had added in.
Turns out, `./configure --with-pydebug` on FreeBSD ends up with '-O2' being appended to CFLAGS some how. I've raised a separate issue for this: http://bugs.python.org/issue15748.

Well, bugger me, check this out:
import os
import stat
import tempfile
d = tempfile.mkdtemp()
src = os.path.join(d, 'foo')
dst = os.path.join(d, 'bar')
src_link = os.path.join(d, 'baz')
dst_link = os.path.join(d, 'qux')
sf = open(dst, 'w')
sf.write('foo')
sf.flush()
sf.close()
df = open(dst, 'w')
df.write('bar')
df.flush()
df.close()
os.symlink(src, src_link)
os.symlink(dst, dst_link)
os.lchmod(src_link, stat.S_IRWXU | stat.S_IRWXO)
os.readlink(dst_link)
os.readlink(src_link)
Results of the last two calls:
>>> os.readlink(dst_link)
path 1: /tmp/tmpfz5v6h/qux, length 1: 18, buf 1: /tmp/tmpfz5v6h/bar
path 2: /tmp/tmpfz5v6h/qux, length 2: 18, buf 2: /tmp/tmpfz5v6h/bar
'/tmp/tmpfz5v6h/bar'
[73299 refs]
>>> os.readlink(src_link)
path 1: /tmp/tmpfz5v6h/baz, length 1: 24, buf 1: /tmp/tmpfz5v6h/foo
path 2: /tmp/tmpfz5v6h/baz, length 2: 24, buf 2: /tmp/tmpfz5v6h/foo
'/tmp/tmpfz5v6h/foo\x00\x00\x00\x00\x00\x00'
[73299 refs]
So, without the os.lchmod() call, the length is returned correctly. With it, it gets returned as 24. Looks like an OS bug.

Hmmmmm... tested against other types of file systems and didn't see any issues. Tested manually against ZFS again:
% ~/src/cpython/python /tmp/test_readlink.py 
temp dir: /mnt/t-zfs/trent/d_6i51
path 1: /mnt/t-zfs/trent/d_6i51/qux, length 1: 27, buf 1: /mnt/t-zfs/trent/d_6i51/bar
path 2: /mnt/t-zfs/trent/d_6i51/qux, length 2: 27, buf 2: /mnt/t-zfs/trent/d_6i51/bar
dst: /mnt/t-zfs/trent/d_6i51/bar
path 1: /mnt/t-zfs/trent/d_6i51/baz, length 1: 24, buf 1: /mnt/t-zfs/trent/d_6i51/
path 2: /mnt/t-zfs/trent/d_6i51/baz, length 2: 24, buf 2: /mnt/t-zfs/trent/d_6i51/
src: /mnt/t-zfs/trent/d_6i51/
[47136 refs]
This time, src got truncated by 3 characters back down to 24. (Instead of getting rounded up by 6 from 18->24 in the previous example.)
Next step: replicate with a C snippet and ping the FreeBSD developers, I guess.

I don't understand if the issue comes from symlink() or readlink(). Can you reproduce the issue using commands on the command line?
$ ln -s setup.py link
`link' -> `setup.py'
$ readlink link
setup.py
(You may need to test different length for filenames.)
Do you only have the issue with ZFS, or with other file systems?

haypo: If a series of shell commands duplicated the problem, then okay, but I suspect the problem has to do with persistent state in the process and will only be reproducible with a C program.

Reproduced behaviour with test_readlink.sh. Sending an e-mail to freebsd-fs to see what they think.

Link to my freebsd-fs e-mail: http://lists.freebsd.org/pipermail/freebsd-fs/2012-August/014964.html 

Turns out our unit test uncovered a very subtle corner-case bug in ZFS, requiring the following patch to FreeBSD:
a/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/sa.c
b/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/sa.c
index 69374fb..7f61517 100644
--- a/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/sa.c
+++ b/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/sa.c
@@ -1695,6 +1695,7 @@ sa_modify_attrs(sa_handle_t *hdl, sa_attr_type_t newattr,
 ASSERT(action == SA_REPLACE);
 SA_ADD_BULK_ATTR(attr_desc, j, attr,
 locator, datastart, buflen);
+ length_idx++;
 } else {
 length = SA_REGISTERED_LEN(sa, attr);
 if (length == 0) {
I guess the unit test should probably be patched to to skip the test IFF the underlying filesystem is ZFS and it exhibits the "length 24" problem. (Actually, detecting if the underlying filesystem is ZFS is non-trivial -- just testing for the "length 24" bug is probably sufficient.) I'll look into this later.
(According to Andriy Gapon (FreeBSD developer that came up with the patch), the bug is likely to affect all ZFS implementations since the beginning of time.)

Could we work around it? Ignore the length we get back from readlink() and just measure the buffer ourselves? Or, if we wanted to be *really* paranoid, write a 0円 at the length they give us back and *then* strlen it.

Not really... the problem is that the chmod 0007 actually corrupts the ZFS metadata regarding the symlink by always setting the length to 24.
Andriy did some debugging here: http://lists.freebsd.org/pipermail/freebsd-fs/2012-August/015005.html
So, the link basically becomes invalid once the bug hits.
Here's another option I just thought of: change the tests to use something other than 0007, then add another test specifically for this issue.

Link to discussion (initiated by Andriy) on zfs@lists.illumos.org: http://thread.gmane.org/gmane.os.illumos.zfs/69 

Is any action needed here to take this forward, can it be closed as "out of date" or what?