Dear Maintainer,

*** Reporter, please consider answering these questions, where appropriate ***

   * What led up to the situation?
Two computers, both amd64 systems, running Jessie (testing), both dist-upgraded
24 Oct 2014.

Attempting to copy a substantial dataset from one machine to the other.
I have not tried to find the problem from the command line but can reproduce it
from either machine
using Gnome (Nautilus).

   * What exactly did you do (or not do) that was effective (or
     ineffective)?

On one machine, (the Server) enable file sharing (via ~/Public in Nautilus)

Then expose a substantial quantity of data (0.3TB is enough here) in the Public
folder.
For example
  cd ~/Public
  mount --bind ../Music Music
(I have a lot of FLAC-encoded CDs in Music : you may need to substitute a
similarly large lump of data.
The example dataset has 14000 large files in 600 folders.)

On the other machine, (the Client) in Nautilus, mount "users shared files on
<Server hostname>"
  display that folder
  perform operations on e.g. Music.
Right-click/Properties exhibits the problem
Copy/Paste (to a local folder on the Client - which DOES have enough space) -
also exhibits it, but it takes much longer to manifest.
This suggests to me that the problem is in handling directory or file stats
rather than simply the file sizes themselves.

   * What was the outcome of this action?

The operation runs for a while, then stops (e.g. the Properties window shows
file size increasing, but stops at 253GB
(or 63GB when the Client and Server machines are interchanged; but always at
the same size)

dmesg on the Client machine reports:
[  699.677988] pool[1873]: segfault at 0 ip 00007f5d88066a3a sp
00007f5d7d974cb8 error 4 in libc-2.19.so[7f5d87fe5000+19f000]
(on a subsequent run after a dist-upgrade and restart)
[  303.568248] pool[1941]: segfault at 0 ip 00007f84f52e6a3a sp
00007f84f299ccb8 error 4 in libc-2.19.so[7f84f5265000+19f000]

   * What outcome did you expect instead?

Successful operation without segfault...

I have not tried digging more info using gdb : given Gnome is in the way it's
not clear to me how one would go about it, e.g. which process to attach the
debugger to!

*** End of the template - remove these template lines ***

The "non serious data loss" may be a misnomer. It is my assessment
because, if one assumes that a copy finished correctly when it actually
terminated, the client machine is left with an incomplete data set.

Non-serious because the files are still there on the server, and it is
possible (tedious!) to identify the missing ones and copy them
separately.

If my assessment is wrong, feel free to classify the bug more
appropriately.

control: tag -1 + moreinfo

The crash happens because a NULL pointer is passed to strlen(), which is
definitely not allowed. It's therefore not a libc bug, but rather a bug
in "pool". Where does this binary come from? I haven't been able to find
it in the Debian archive (but I might have searched wrongly).

Good question.
 Google "pool : segfault" leads to among others
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=707681
which I believe is unrelated (cameras, USB) but (message #15) also
involves "pool" (pointing vaguely at dbus). Is "pool" related to thread
pools?

or https://bbs.archlinux.org/viewtopic.php?pid=1092046
which at least involves Nautilus so may be more closely related. This
points at Gnome bug https://bugzilla.gnome.org/show_bug.cgi?id=674659
which at least gives me some hints about running Nautilus under gdb.

If I can dig up anything this way I'll update.
- Brian

control: reassign -1 nautilus
control: tag -1 - moreinfo

It seems indeed to be related to glib thread pools, looks like they have
been created by nautilus. I am reassigning the bug there, don't hesitate
to reassign it to the correct package if needed.

"gdb nautilus" allows me to reproduce the segfault, but doesn't return
control to the debugger. So the "pool" (is it a process? I can't see it
in ps ax) containing the error must be elsewhere in the system.

Any suggestions how to move forward?

- Brian

Backtrace revealed missing debug info in glib, viz...
Thread 5 (Thread 0x7fffe5d4e700 (LWP 3843)):
#0  0x00007ffff3c760ed in poll () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#1  0x00007ffff4c52ee4 in ?? ()
from /lib/x86_64-linux-gnu/libglib-2.0.so.0
No symbol table info available.
... etc

So I thought I needed to install the debug version of libglib2.0-0
sudo apt-get -t testing install libglib2.0-0-dbg
(looks OK)

And try again...

gdb nautilus
GNU gdb (Debian 7.7.1+dfsg-3) 7.7.1
Copyright (C) 2014 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show
copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from nautilus...Reading symbols
from /usr/lib/debug//usr/bin/nautilus...done.
done.
(gdb) run
Starting program: /usr/bin/nautilus
BFD: /usr/lib/debug/.build-id/f4/bb3ff29b5a72f4c60cc4f76854a1bb47a3bc78.debug: unable to initialize decompress status for section .zdebug_aranges
warning: File
"/usr/lib/debug/.build-id/f4/bb3ff29b5a72f4c60cc4f76854a1bb47a3bc78.debug" has no build-id, file skipped
BFD: /usr/lib/debug/.build-id/c0/753208ea46400cd99ae9e1591b4767358d1679.debug: unable to initialize decompress status for section .zdebug_aranges
warning: File
"/usr/lib/debug/.build-id/c0/753208ea46400cd99ae9e1591b4767358d1679.debug" has no build-id, file skipped
(and several more)
[New Thread 0x7fffedaf2700 (LWP 3989)]

Am I missing something or is there a problem with the debug package?
Sorry about the noise on this bug report, I seem to be struggling.

- Brian

before starting one under gdb - nautilus probably has some "single
instance" logic going on.

The "pool" thread is not visible in ps, but it's visible in pstree: it's
probably the thread where miscellaneous background jobs that don't have
their own thread are scheduled. For instance:

% pstree -p
...
           ├─nautilus(9073)─┬─{dconf worker}(9079)
           │                ├─{gdbus}(9076)
           │                ├─{gmain}(9078)
           │                └─{pool}(9077)
...

Process 9073 represents the nautilus process as a whole, and 9073 is
also the thread ID of its main thread; the children in {} are other
threads inside process 9073.

    S

That's a bug in either libglib2.0-0-dbg, or gdb.

    S

Thanks, that's what I suspected.
Evidence that it's not just me seeing these messages :

https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=759361
"freerdp-x11: Segfaults on too-long command line with old-style options"
lists the same error multiple times, on an entirely different package,
suggesting this may be a gdb failure. (Or both packages are built
incorrectly)

- Brian

Thanks for these hints.
           |---gdb(4450)---nautilus(4670)-+-{dconf worker}(4674)
                                          |-{gdbus}(4671)
                                          |-{gmain}(4673)
                                          `-{pool}(4681)

but when I reproduce the segfault, dmesg reports
[24621.126174] pool[4704]: segfault at 0 ip 00007f95c1e6da3a sp
00007f95af7fdcb8 error 4 in libc-2.19.so[7f95c1dec000+19f000]

and gdb reports...
(nautilus:4670): Gtk-WARNING **: Refusing to add non-unique action
'TerminalNautilus:OpenFolderLocal' to action group 'ExtensionsMenuGroup'
[New Thread 0x7fffd082b700 (LWP 4688)]
[Thread 0x7fffd082b700 (LWP 4688) exited]
[Thread 0x7fffca980700 (LWP 4681) exited]
Gtk-Message: GtkDialog mapped without a transient parent.

So I believe the Nautilus thread pool closes and *something else* starts
another thread pool (4704) where the segfault occurs.

And ps ax shows...
 4450 pts/0    S      0:01 gdb nautilus
 4476 ?        Sl     0:00 /usr/lib/gvfs/gvfsd-smb-browse
                           --spawner :1.8 /org/gtk/gvfs/exec_spaw/4
 4482 ?        Sl     0:00 /usr/lib/gvfs/gvfsd-network
                           --spawner :1.8 /org/gtk/gvfs/exec_spaw/5
 4500 ?        Sl     0:00 /usr/lib/gvfs/gvfsd-dnssd
                           --spawner :1.8 /org/gtk/gvfs/exec_spaw/9
 4520 pts/1    Ss     0:00 /bin/bash
 4542 ?        Sl     0:35 /usr/bin/gedit --gapplication-service
 4547 ?        S      0:00 [kworker/1:2]
 4670 pts/0    Sl+    0:08 /usr/bin/nautilus
 4695 ?        S      0:01 [kworker/3:0]
 4752 pts/1    R+     0:00 ps ax

Quitting gdb confirms that 4670 is indeed the Nautilus spawned by gdb.
So I suspect that one of the gvfs services (4476,4482,4500 above) may be
creating this pool and failing.

Now, how would I go about closing those and restarting them under gdb
before starting Nautilus? Apologies if this is a ridiculously basic
question; it doesn't seem that way to me.

Incidentally this other "pool[]: segfault in libc-2.xx" bug also
appeared to be in or around gvfs.
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=707681
Didn't think it was related to mine, but it might be after all.

- Brian

gvfsd-smb-browse
gvfsd-network
gvfs/gvfsd-dnssd
I think I managed to get these running under gdb (they certainly produce
debugging output when I do things in Nautilus). However the segfault
doesn't appear (i.e. return control to gdb) under any of them.

So far I haven't managed to capture "pstree -p" containing a "pool" with
PID that later matches the PID in the segfault. If I could, at least I'd
know what created it.

- Brian

Hi,

Brian Drummond wrote (25 Oct 2014 12:32:42 GMT) :

Indeed, in my book this doesn't qualify as RC => downgrading severity.

(And: thanks for the detailed debugging!)

Cheers,
--
intrigeri

No problem.

I'm trying. Still haven't found a way to identify who owns the
segfaulting "pool" process, but I haven't given up.

Thanks,

- Brian

You might find it helpful to install something like corekeeper, then
look for core-dumps in /var/crash/(your numeric uid) which can be
inspected to find out more about the crash.

    S

By running the following script I have found who owns the errant "pool"
process, and it is gvfsd-dav.

Script (crude but it works!):
------------------------------------------------
#!/bin/bash

while true; do
   pstree -p | grep pool -B 5 >> pool.log
   sleep 0.5
done
------------------------------------------------

dmesg (after the segfault:

[12572.499279] pool[3175]: segfault at 0 ip 00007fe75d926aca sp
00007fe75afd9cb8 error 4 in libc-2.19.so[7fe75d8a5000+19f000]

------------------------------------------------

"pstree" excerpt from the log file (pool.log):
           |-gvfsd-dav(2970)-+-{dconf worker}(2974)
           |                 |-{gdbus}(2971)
           |                 |-{pool}(3175)
           |                 `-{pool}(3176)

Will update further if I succeed in getting a traceback from gvfsd-dav.

Backtrace from the relevant thread in gvfsd-dav...

I hope this is helpful. If any further info is required I will endeavour
to provide it, given adequate instructions. (In particular, how would I
make gdb display the "<optimized out>" bits?

- Brian

-----------------------------------------------------------------------------
Thread 4 (Thread 0x7f5926572700 (LWP 3882)):
#0  0x00007f592fa8daca in strlen () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#1  0x000000000040bb0c in path_equal (a=a@entry=0x7f5914051960
"/Music/Various Artists/100% Dance Hits/", b=<optimized out>, relax=1)
at gvfsbackenddav.c:244
        res = <optimized out>
        a_len = <optimized out>
        b_len = <optimized out>
        ua = 0x0
        ub = 0x7f5914054910 "/Music/Various Artists/"
#2  0x000000000040c4d9 in path_equal (relax=1, b=<optimized out>,
a=0x7f5914051960 "/Music/Various Artists/100% Dance Hits/") at
gvfsbackenddav.c:238
No locals.
#3  multistatus_get_response (resp_iter=resp_iter@entry=0x7f5926571d80,
response=response@entry=0x7f5926571d60) at gvfsbackenddav.c:829
        iter = <optimized out>
        href = <optimized out>
        propstat = 0x7f5914062790
        uri = 0x7f5914002e80
        path = 0x7f5914051960 "/Music/Various Artists/100% Dance Hits/"
#4  0x000000000040dc86 in do_enumerate (backend=<optimized out>,
job=0x2562990, filename=<optimized out>, matcher=<optimized out>,
flags=<optimized out>)
    at gvfsbackenddav.c:2185
        response = {multistatus = 0x7f5926571d40, path = 0x7f5914051960
"/Music/Various Artists/100% Dance Hits/", is_target = 0, first_propstat
= 0x7f5914061a30}
        info = <optimized out>
        msg = 0x7f592000a8d0
        ms = {doc = 0x7f5914286330, root = 0x7f5914269b00, target =
0x7f5914002c40, path = 0x7f5914286730 "/Music/Various Artists/"}
        iter = {cur_node = 0x7f59140624a0, next_node = 0x7f5914063200,
name = 0x412340 "response", ns_href = 0x412381 "DAV:", user_data =
0x7f5926571d40}
        res = <optimized out>
        error = 0x0
---Type <return> to continue, or q <return> to quit---
#5  0x00007f5931fe814a in g_vfs_job_run (job=0x2562990) at gvfsjob.c:197
        class = 0x25609a0
#6  0x00007f5931fe288f in job_handler_callback (data=<optimized out>,
user_data=<optimized out>) at gvfsdaemon.c:203
        job = 0x2562990
#7  0x00007f59302462b8 in ?? ()
from /lib/x86_64-linux-gnu/libglib-2.0.so.0
No symbol table info available.
#8  0x00007f5930245925 in ?? ()
from /lib/x86_64-linux-gnu/libglib-2.0.so.0
No symbol table info available.
#9  0x00007f592fdbd0a4 in start_thread ()
from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#10 0x00007f592faf1ccd in clone () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
-----------------------------------------------------------------------------

Control: reassign 766732 gvfs-backends

Reassigning to the package that owns gvfsd-dav.

You'd have to recompile gvfs without optimizations. But hopefully that
won't be necessary.

Looking at the source code, ua = g_uri_unescape_string (a, "/"). So that
function has failed, returning NULL, and the code does not make any
attempt to cope with that failure; so we call strlen(NULL) which crashes.

a is "/Music/Various Artists/100% Dance Hits/" which is not a valid URI
path: if your folder on disk is called "100% Dance Hits" then the URI
should end with "/100%25 Dance Hits/".

So there are probably two bugs here:

* whatever software you are using to serve your music over DAV (what is
  it?) is encoding paths incorrectly; and
* gvfs isn't coping gracefully with that.

Regards,
    S

Or indeed /100%25%20Dance%20Hits/, really, since spaces aren't URI
characters either.

    S

OK.

There's no actual music serving going on, just straight directory
access. All I did was right-click/Properties in Nautilus, having
selected the folder "Music" on the remote machine. (Copying the files
via Nautilus does the same, only slower)

Is '/home/brian/Music/Various Artists/100% Dance Hits' a legal path? If
so, what layer should encode it as an URI? I'm guessing also gvfsd-dav
(this time on the remote machine) in which case both bugs belong to
gvfs-backends.

Both ends run Debian Testing and I can reproduce the error from either
end.
Worth making it more robust, I'd think.

At least knowing paths containing '%' are significant should make it
easy to reproduce.

Thanks for the analysis,
- Brian

Well, machine A can't magically access paths on machine B without some
sort of network protocol - NFS, CIFS/SMB, WebDAV, whatever - and in this
case the network protocol seems to be WebDAV. How did you make these
files available?

Perhaps it's gnome-user-share at the "server" end?

It's a perfectly valid filesystem path, but not a valid URI path.
Whatever is taking the filesystem and turning it into DAV should do the
%-encoding.

    S

directory named '100% Silly'
(and allow it to be shared across the network)

On the local machine, "browse network" and select "simon's public files
on remote_host".

Display contents of that folder.

Here, that makes the newly mounted public partition unmount rather
sharply. I take it that's not expected behaviour.

But does this happen on anyone else's machine?

- Brian

Dear Maintainer,

FWIW, I just installed jessie and dist-upgraded to testing and I see this in my dmesg:

[24377.975079] pool[21459]: segfault at 7fadf6b50714 ip 00007fad1f99c72e sp 00007fad02b46298 error 4 in libc-2.19.so[7fad1f90c000+19f000]
[24380.967653] pool[21472]: segfault at 7fbc81084714 ip 00007fbbdde6072e sp 00007fbbc507a298 error 4 in libc-2.19.so[7fbbdddd0000+19f000]
[24384.128049] pool[21485]: segfault at 7f4460a24d04 ip 00007f444d8a272e sp 00007f4434a10298 error 4 in libc-2.19.so[7f444d812000+19f000]
[24387.297967] pool[21500]: segfault at 7f89e50b4d4b ip 00007f893b49272e sp 00007f892253e298 error 4 in libc-2.19.so[7f893b402000+19f000]
[24390.169803] pool[21520]: segfault at 7f4c99a6e824 ip 00007f4c6a88672e sp 00007f4c51a5a298 error 4 in libc-2.19.so[7f4c6a7f6000+19f000]
[24392.982515] pool[21535]: segfault at 7fa911efa714 ip 00007fa8a6ce572e sp 00007fa88def0298 error 4 in libc-2.19.so[7fa8a6c55000+19f000]
[24395.978641] pool[21548]: segfault at 7f2b79c77714 ip 00007f2b5aa0172e sp 00007f2b41c6d298 error 4 in libc-2.19.so[7f2b5a971000+19f000]
[24399.197621] pool[21564]: segfault at 7f44ecc82d4b ip 00007f444307672e sp 00007f442a10c298 error 4 in libc-2.19.so[7f4442fe6000+19f000]
[24401.982853] pool[21579]: segfault at 7febf4008714 ip 00007feb1d6ac72e sp 00007feaffffe298 error 4 in libc-2.19.so[7feb1d61c000+19f000]
[24404.977307] pool[21592]: segfault at 7f9474008714 ip 00007f945d33c72e sp 00007f943fffe298 error 4 in libc-2.19.so[7f945d2ac000+19f000]

and many, many, many more.
So, not sure what's going on, but it's continuously segfaulting here.

I think it started when I plugged in my USB camera. But I'm not sure, as unplugging it doesn't stop it...