maindavfs2 - Support: sr #107637, davfs2 closes connection after a...

 
 

sr #107637: davfs2 closes connection after a few seconds

Submitter:  None
Submitted:  Sat 26 Mar 2011 07:38:17 PM UTC
   
 
Category:  None Priority:  5 - Normal
Severity:  3 - Normal Status:  Done
Privacy:  Public Assigned to:  _71007
Originator Email:  -email is unavailable- Open/Closed:  Closed
Operating System:  GNU/Linux
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Mon 28 Mar 2011 07:43:27 PM UTC, comment #7: 

Hi Werner,

the work around solved my problem!
(Only that after unmounting the entry in /etc/mtab remains, but I simply remove it in the start/stop script after unmounting)

You guessed right, this is a chrooted environment (Fonz fun plug - ffp).

Many thanks for your excellent software and the great support!

Ulrich

Anonymous
Mon 28 Mar 2011 07:17:14 PM UTC, comment #6: 

What's confusing is /proc/mounts:

https://sd2dav.1und1.de/ /e-data/ab500074-7832-4b9b-bd6f-974b6df3b666/ffproot/ffp/media/smartdrive

There is an extra prefix '/e-data/ab500074-7832-4b9b-bd6f-974b6df3b666/ffproot' before the mount point. davfs2 can't recognize this entry and thinks it is no longer mounted and terminates. It also does not call unmount; that's the reason for the stale entries in /etc/mtab.

What is your kernel doing. Some kind of virtual machine or chroot environment?

To work around this you have to force davfs2 to use /etc/mtab (it defaults to /proc/mounts).

In file src/defaults.h, around line 51, replace

#define DAV_MOUNTS "/proc/mounts"

with

#define DAV_MOUNTS "/etc/mtab"

Now davfs2 should be able to recognize the mounted file system in /etc/mtab (please remove the stale entries if not done at boot time).

Cheers
Werner

- <_71007>
Sun 27 Mar 2011 07:59:18 PM UTC, comment #5: 

Both /proc/mounts and /etc/mtab exist and are accessible.

/proc/mounts contains:

[..]
https://sd2dav.1und1.de/ /e-data/ab500074-7832-4b9b-bd6f-974b6df3b666/ffproot/ffp/media/smartdrive fuse rw,nosuid,nodev,user_id=0,group_id=0,allow_other,max_read=16384 0 0

mount returns:

[..]
https://sd2dav.1und1.de/ on /e-data/ab500074-7832-4b9b-bd6f-974b6df3b666/ffproot/ffp/media/smartdrive type fuse (rw,nosuid,nodev,user_id=0,group_id=0,allow_other,max_read=16384)

What strikes me unusual, is, that /etc/mtab contains MANY lines such as:
https://sd2dav.1und1.de/ /ffp/media/smartdrive davfs rw,nosuid,nodev,_netdev 0 0

It seems, that my syslogd arbitrarily misses some lines. I was able to capture one log, though, that seems quite complete (also containing 'mounts in'). I attached it to this message, maybe it helps. It also contains the lines from a successful 'ls' command issued right after mounting.

Regards

Ulrich

(file #23028)

Anonymous
Sun 27 Mar 2011 03:39:57 PM UTC, comment #4: 

It must be

  • for /etc/mtab (just 'mount' without any options or parameters)


and
but it should be there and name either /proc/mounts or /etc/mtab.

- <_71007>
Sun 27 Mar 2011 03:36:22 PM UTC, comment #3: 

"Transport endpoint is not connected" refers to the connection between the Fuse kernel-module and the mount.davfs daemon in userspace (via the fuse device).

Locking at the end of your log:
davfs2 uses the select call to watch the fuse device. The timeout is equal to delay_upload. When select returns 0 (no message from the kernel) davfs2 will check whether the file system is still mounted. The reason for this is that the kernel sends no notice when the file system is unmounted so davfs2 has to regulary check itself.
At this point in your log davfs2 decides to shut down, just as if it had been unmounted.

I see two possible reasons:

  • someone unmounted the file system (not very likely)
  • the check fails because neither /etc/mtab nor /proc/mounts is available. Without one of these davfs2 can't check whether it is still mounted.


After mounting the file system please check:

  • for /proc/mounts ('cat /proc/mounts')
  • for /etc/fstab (just 'mount' without any options or parameters)


At the beginning of the log, just after listing all the options, there should be a message beginning with 'mounts in:  '. It is missing in your log but it should be there and name either /proc/mounts or /etc/fstab.

Cheers
Werner

- <_71007>
Sun 27 Mar 2011 01:22:07 PM UTC, comment #2: 

Werner,

thanks for your comments.

if_match_bug already is set to 1, as I had davfs2 running on a similar box.

I checked the syslogd, it is the version included in busybox, nothing was configured or deleted. If you are missing information, can you please let me know what, so I can investigate?

But first of all, I probably should have stated the problem more precisely. Right after mounting the webdav drive I can read from and write to the server. I also checked that the files really are transferred to the server. So the basic setup seems correct.
But after the time specified for delay_upload (presently 5 seconds), all attempts to access the webdav drive result in messages like "ls: cannot access /ffp/media/smartdrive/music: Transport endpoint is not connected".
While the successful access to the server is logged, there are no log entries for the error message.

Have you ever seen this behavior?

Regards

Ulrich

Anonymous
Sun 27 Mar 2011 10:30:05 AM UTC, comment #1: 

1und1 uses an older version of Apache. This is not necessarily a bad thing but they also don't care to fix a WebDAV related bug that has been fixed in Apache about two years ago.

You need to set option "if_match_bug 1" for 1und1.

Closing the connection is not an error. In HTTP connections are closed a short time after the last request.

The debug output is quite incomplete. A lot of lines are arbitrarily skipped. If it wasn't you, you might look what is wrong with your logging system.

Cheers
Werner

- <_71007>
Sat 26 Mar 2011 07:38:17 PM UTC, original submission:  

Hi,

I have built davfs2 1.4.6 with neon 0.25.5 and fuse 2.8.5 under Linux 2.6.22.18 on my NAS box (Zyxel NSA-320).
When I mount the webdav server, I can read and write files. But after the time specified for delay_upload in davfs2.conf the connection is closed, again. In /var/log/messages I cannot see anything unusual. In the excerpt below you can see that the connection is closed exactly 5 seconds after being opened, which is my delay_upload value for testing.

Any idea what could cause the disconnect?

Thanks

Ulrich

Mar 26 19:20:14 NSA320 mark.debug syslog: davfs2 1.4.6
Mar 26 19:20:14 NSA320 mark.debug syslog: mount.davfs https://sd2dav.1und1.de/ /ffp/media/smartdrive/
Mar 26 19:20:14 NSA320 mark.debug syslog: Configuration:
Mar 26 19:20:14 NSA320 mark.debug syslog:   url: https://sd2dav.1und1.de/
Mar 26 19:20:14 NSA320 mark.debug syslog:   mount point: /ffp/media/smartdrive
Mar 26 19:20:14 NSA320 mark.debug syslog:   dav_user: davfs2
Mar 26 19:20:14 NSA320 mark.debug syslog:   dav_group: davfs2
Mar 26 19:20:14 NSA320 mark.debug syslog:   ignore_home: (null)
Mar 26 19:20:14 NSA320 mark.debug syslog:   conf: (null)
Mar 26 19:20:14 NSA320 mark.debug syslog:   user: 0
Mar 26 19:20:14 NSA320 mark.debug syslog:   netdev: 1
Mar 26 19:20:14 NSA320 mark.debug syslog: HTTP session to
Mar 26 19:20:14 NSA320 mark.debug syslog: https
Mar 26 19:20:14 NSA320 mark.debug syslog: ://
Mar 26 19:20:14 NSA320 mark.debug syslog: sd2dav.1und1.de
Mar 26 19:20:14 NSA320 mark.debug syslog: :
Mar 26 19:20:14 NSA320 mark.debug syslog: 443
Mar 26 19:20:14 NSA320 mark.debug syslog:  begins.
Mar 26 19:20:14 NSA320 mark.debug syslog: Initializing cache
Mar 26 19:20:14 NSA320 mark.debug syslog: Alignment of dav_node: 8
Mar 26 19:20:14 NSA320 mark.debug syslog: Checking cache directory
Mar 26 19:20:14 NSA320 mark.debug syslog:   /i-data/md1/system/davfs2/sd2dav.1und1.de+ffp-media-smartdrive+root
Mar 26 19:20:14 NSA320 mark.debug syslog: new node: (nil)->0x39140
Mar 26 19:20:14 NSA320 mark.debug syslog: Reading stored cache data
Mar 26 19:20:14 NSA320 mark.debug syslog: new node: 0x39140->0x41b18
Mar 26 19:20:14 NSA320 mark.debug syslog: new node: 0x39140->0x41c00
Mar 26 19:20:14 NSA320 mark.debug syslog: Doing DNS lookup on
Mar 26 19:20:14 NSA320 mark.debug syslog: sd2dav.1und1.de
Mar 26 19:20:14 NSA320 mark.debug syslog: ...
Mar 26 19:20:14 NSA320 mark.debug syslog: Running pre_send hooks
Mar 26 19:20:14 NSA320 mark.debug syslog: Sending request headers:
Mar 26 19:20:14 NSA320 mark.debug syslog: OPTIONS / HTTP/1.1^M Host: sd2dav.1und1.de^M User-Agent: davfs2/1.4.6 neon/0.25.5^M Keep-Alive: ^M Connection: TE, Keep-Alive^M TE: trailers^M ^M
Mar 26 19:20:14 NSA320 mark.debug syslog: Sending request-line and headers:
Mar 26 19:20:14 NSA320 mark.debug syslog: Connecting to
Mar 26 19:20:14 NSA320 mark.debug syslog: 213.165.67.38
Mar 26 19:20:14 NSA320 mark.debug syslog:
Mar 26 19:20:14 NSA320 mark.debug syslog: Request sent; retry is
Mar 26 19:20:14 NSA320 mark.debug syslog: 0
Mar 26 19:20:14 NSA320 mark.debug syslog: .
Mar 26 19:20:15 NSA320 mark.debug syslog: [status-line] <
Mar 26 19:20:15 NSA320 mark.debug syslog: HTTP/1.1 401 Authorization Required^M
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Date: Sat, 26 Mar 2011 19:20:15 GMT^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: date
Mar 26 19:20:15 NSA320 mark.debug syslog: ], Value: [
Mar 26 19:20:15 NSA320 mark.debug syslog: Sat, 26 Mar 2011 19:20:15 GMT
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Server: Apache/2.0.63 (Unix) mod_ssl/2.0.63 OpenSSL/0.9.7d^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: server
Mar 26 19:20:15 NSA320 mark.debug syslog: ], Value: [
Mar 26 19:20:15 NSA320 mark.debug syslog: Apache/2.0.63 (Unix) mod_ssl/2.0.63 OpenSSL/0.9.7d
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: WWW-Authenticate: Basic realm="1&1 Homenet"^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: www-authenticate
Mar 26 19:20:15 NSA320 mark.debug syslog: ], Value: [
Mar 26 19:20:15 NSA320 mark.debug syslog: Basic realm="1&1 Homenet"
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Content-Length: 511^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: content-length
Mar 26 19:20:15 NSA320 mark.debug syslog: ], Value: [
Mar 26 19:20:15 NSA320 mark.debug syslog: 511
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Keep-Alive: timeout=1, max=100^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: keep-alive
Mar 26 19:20:15 NSA320 mark.debug syslog: ], Value: [
Mar 26 19:20:15 NSA320 mark.debug syslog: timeout=1, max=100
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Connection: Keep-Alive^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: connection
Mar 26 19:20:15 NSA320 mark.debug syslog: ], Value: [
Mar 26 19:20:15 NSA320 mark.debug syslog: Keep-Alive
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Content-Type: text/html; charset=iso-8859-1^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: content-type
Mar 26 19:20:15 NSA320 mark.debug syslog: ], Value: [
Mar 26 19:20:15 NSA320 mark.debug syslog: text/html; charset=iso-8859-1
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: ^M
Mar 26 19:20:15 NSA320 mark.debug syslog: End of headers.
Mar 26 19:20:15 NSA320 mark.debug syslog: Reading
Mar 26 19:20:15 NSA320 mark.debug syslog: 511
Mar 26 19:20:15 NSA320 mark.debug syslog:  bytes of response body.
Mar 26 19:20:15 NSA320 mark.debug syslog: Got
Mar 26 19:20:15 NSA320 mark.debug syslog: 511
Mar 26 19:20:15 NSA320 mark.debug syslog:  bytes.
Mar 26 19:20:15 NSA320 mark.debug syslog: Running post_send hooks
Mar 26 19:20:15 NSA320 mark.debug syslog: Running pre_send hooks
Mar 26 19:20:15 NSA320 mark.debug syslog: Sending request headers:
Mar 26 19:20:15 NSA320 mark.debug syslog: OPTIONS / HTTP/1.1^M Host: sd2dav.1und1.de^M User-Agent: davfs2/1.4.6 neon/0.25.5^M Keep-Alive: ^M Connection: TE, Keep-Alive^M TE: trailers^M Authorization: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx^M ^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Sending request-line and headers:
Mar 26 19:20:15 NSA320 mark.debug syslog: Request sent; retry is
Mar 26 19:20:15 NSA320 mark.debug syslog: 1
Mar 26 19:20:15 NSA320 mark.debug syslog: .
Mar 26 19:20:15 NSA320 mark.debug syslog: [status-line] <
Mar 26 19:20:15 NSA320 mark.debug syslog: HTTP/1.1 200 OK^M
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Date: Sat, 26 Mar 2011 19:20:15 GMT^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: date
Mar 26 19:20:15 NSA320 mark.debug syslog: ], Value: [
Mar 26 19:20:15 NSA320 mark.debug syslog: Sat, 26 Mar 2011 19:20:15 GMT
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Server: Apache/2.0.63 (Unix) mod_ssl/2.0.63 OpenSSL/0.9.7d DAV/2 Catacomb/static^M
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: DASL: <DAV:basicsearch>^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: dasl
Mar 26 19:20:15 NSA320 mark.debug syslog: ], Value: [
Mar 26 19:20:15 NSA320 mark.debug syslog: <DAV:basicsearch>
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Content-Length: 0^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: [status-line] <
Mar 26 19:20:15 NSA320 mark.debug syslog: HTTP/1.1 207 Multi-Status^M
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Date: Sat, 26 Mar 2011 19:20:15 GMT^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: date
Mar 26 19:20:15 NSA320 mark.debug syslog: ], Value: [
Mar 26 19:20:15 NSA320 mark.debug syslog: Sat, 26 Mar 2011 19:20:15 GMT
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Server: Apache/2.0.63 (Unix) mod_ssl/2.0.63 OpenSSL/0.9.7d DAV/2 Catacomb/static^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Got
Mar 26 19:20:15 NSA320 mark.debug syslog: 3750
Mar 26 19:20:15 NSA320 mark.debug syslog:  bytes.
Mar 26 19:20:15 NSA320 mark.debug syslog: Running post_send hooks
Mar 26 19:20:15 NSA320 mark.debug syslog: Request ends, status
Mar 26 19:20:15 NSA320 mark.debug syslog: 207
Mar 26 19:20:15 NSA320 mark.debug syslog:  class
Mar 26 19:20:15 NSA320 mark.debug syslog: 2
Mar 26 19:20:15 NSA320 mark.debug syslog: xx, error line:
Mar 26 19:20:15 NSA320 mark.debug syslog: 207 Multi-Status
Mar 26 19:20:15 NSA320 mark.debug syslog:
Mar 26 19:20:15 NSA320 mark.debug syslog: [status-line] <
Mar 26 19:20:15 NSA320 mark.debug syslog: HTTP/1.1 207 Multi-Status^M
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Date: Sat, 26 Mar 2011 19:20:15 GMT^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: date
Mar 26 19:20:15 NSA320 mark.debug syslog: ], Value: [
Mar 26 19:20:15 NSA320 mark.debug syslog: Sat, 26 Mar 2011 19:20:15 GMT
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Server: Apache/2.0.63 (Unix) mod_ssl/2.0.63 OpenSSL/0.9.7d DAV/2 Catacomb/static^M
Mar 26 19:20:15 NSA320 mark.debug syslog: [status-line] <
Mar 26 19:20:15 NSA320 mark.debug syslog: HTTP/1.1 200 OK^M
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Date: Sat, 26 Mar 2011 19:20:15 GMT^M
Mar 26 19:20:15 NSA320 mark.debug syslog: Header Name: [
Mar 26 19:20:15 NSA320 mark.debug syslog: date
Mar 26 19:20:15 NSA320 mark.debug syslog: ], Value: [
Mar 26 19:20:15 NSA320 mark.debug syslog: Sat, 26 Mar 2011 19:20:15 GMT
Mar 26 19:20:15 NSA320 mark.debug syslog: ]
Mar 26 19:20:15 NSA320 mark.debug syslog: [hdr]
Mar 26 19:20:15 NSA320 mark.debug syslog: Server: Apache/2.0.63 (Unix) mod_ssl/2.0.63 OpenSSL/0.9.7d DAV/2 Catacomb/static^M
Mar 26 19:20:20 NSA320 mark.debug syslog: SELECT: 0
Mar 26 19:20:20 NSA320 mark.debug syslog: Closing
Mar 26 19:20:20 NSA320 mark.debug syslog: Closing cache
Mar 26 19:20:20 NSA320 mark.debug syslog: deleting node 0x3d9a8
Mar 26 19:20:20 NSA320 mark.debug syslog: deleting node 0x3d940
Mar 26 19:20:20 NSA320 mark.debug syslog: deleting node 0x3d828
Mar 26 19:20:20 NSA320 mark.debug syslog: deleting node 0x41de8
Mar 26 19:20:20 NSA320 mark.debug syslog: Creating index /i-data/md1/system/davfs2/sd2dav.1und1.de+ffp-media-smartdrive+root/index.new.
Mar 26 19:20:20 NSA320 mark.debug syslog: writing root 0x39140
Mar 26 19:20:20 NSA320 mark.debug syslog: writing file 0x41c00
Mar 26 19:20:20 NSA320 mark.debug syslog: writing backup 0x41b18

Anonymous

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach Files:
   
   
Comment:
   

Attached Files
file #23028:  messages added by None (30KiB - application/octet-stream - System log)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by _71007 (Posted a comment)
  • -email is unavailable- added by None (Submitted the item)
  •  

    There are 0 votes so far. Votes easily highlight which items people would like to see resolved in priority, independently of the priority of the item set by tracker managers.

    Only logged-in users can vote.

     

    Follow 5 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2012-07-19 _71007 Open/ClosedOpen Closed
    2012-03-11 _71007 StatusIn Progress Done
    2011-03-27 None Attached File- Added messages, #23028
    2011-03-27 _71007 StatusNone In Progress
        Assigned toNone _71007

    Back to the top

    Powered by Savane 3.13-758e.
    Corresponding source code