Menu ▾ ▴

#633 dsi_stream_read: len:0, unexpected EOF

None
closed
Ralph Böhme
None
9
2016-12-20
2016-08-23
Ralph Böhme
No

A bug in the handling of client requests to list xattrs of files can lead to a session disconnect.

This will happens because in the function that implements this we keep a global state with the required buffer size for the names of all xattrs of a file (or directory of course).

This works as long as client request are strictly sequential, but newer OS X release seem to send async request where 2 or more AFP FPListExtAttr requests are in flight.

Discussion

  • Ralph Böhme

    Ralph Böhme - 2016-09-12
    • status: accepted --> closed
    • Group: -->
     

  • Ralph Böhme

    Ralph Böhme - 2016-09-12

    Fixed.

     

  • Vyacheslav Karpukhin

    Vyacheslav Karpukhin - 2016-09-23

    Does not seem to be fixed, consistently reproduces for me when accessing Photos.app's photo library located on an AFP share.

     

  • Alexander Chetyrbok

    Alexander Chetyrbok - 2016-09-26

    Ralph, it doesn't seem to be fixed. I get "dsi_stream_read: len:0, unexpected EOF" every time my TimeMachine tries to do a backup to a home server share with time machine support enabled. The problem started when I returned from vacation and amount of data to backup is bigger than usual. Somewhere in the middle of backup process TimeMachine reports about network problems and terminate backup and record "dsi_stream_read: len:0, unexpected EOF" exist in system log.

    I reproduce the problem with maxdebug log level, latest records from log is attached.

    It looks like second login attempt from TimeMachine during backup process. After it EOF is reported 2 times:
    Sep 26 18:01:08 microserver afpd[61471]: afp_dsi_transfer_session: got SIGURG, trying to receive session
    Sep 26 18:01:08 microserver afpd[61471]: afp_dsi_transfer_session: received socket fd: 17
    Sep 26 18:01:08 microserver afpd[61471]: dsi_cmdreply(DSI ID: 26536, len: 0): START
    Sep 26 18:01:08 microserver afpd[61471]: dsi_stream_send(0 bytes): START
    Sep 26 18:01:08 microserver afpd[61471]: dsi_stream_send(16 bytes): DSI header, no data
    Sep 26 18:01:08 microserver afpd[61471]: dsi_stream_write(send: 16 bytes): START
    Sep 26 18:01:08 microserver afpd[61471]: dsi_stream_write(send: 16 bytes): END
    Sep 26 18:01:08 microserver afpd[61471]: dsi_cmdreply(DSI ID: 26536, len: 0): END
    Sep 26 18:01:08 microserver afpd[61471]: afp_dsi_transfer_session: succesfull primary reconnect
    Sep 26 18:01:08 microserver afpd[61471]: dsi_stream_receive: START
    Sep 26 18:01:08 microserver afpd[61471]: dsi_buffered_stream_read: 16 bytes
    Sep 26 18:01:08 microserver afpd[61471]: from_buf: 16 bytes
    Sep 26 18:01:08 microserver afpd[61471]: from_buf(read: 0, unread:0 , space left: 12582912): returning 0
    Sep 26 18:01:08 microserver afpd[61471]: dsi_stream_read(16 bytes)
    Sep 26 18:01:08 microserver afpd[61471]: buf_read(16 bytes)
    Sep 26 18:01:08 microserver afpd[61471]: from_buf: 16 bytes
    Sep 26 18:01:08 microserver afpd[61471]: from_buf(read: 0, unread:0 , space left: 12582912): returning 0
    Sep 26 18:01:08 microserver afpd[61471]: buf_read(16 bytes): got: 0
    Sep 26 18:01:08 microserver afpd[61471]: dsi_stream_read: len:0, unexpected EOF
    Sep 26 18:01:08 microserver afpd[61471]: dsi_stream_receive: START
    Sep 26 18:01:08 microserver afpd[61471]: dsi_buffered_stream_read: 16 bytes
    Sep 26 18:01:08 microserver afpd[61471]: from_buf: 16 bytes
    Sep 26 18:01:08 microserver afpd[61471]: from_buf(read: 0, unread:0 , space left: 12582912): returning 0
    Sep 26 18:01:08 microserver afpd[61471]: dsi_stream_read(16 bytes)
    Sep 26 18:01:08 microserver afpd[61471]: buf_read(16 bytes)
    Sep 26 18:01:08 microserver afpd[61471]: from_buf: 16 bytes
    Sep 26 18:01:08 microserver afpd[61471]: from_buf(read: 0, unread:0 , space left: 12582912): returning 0
    Sep 26 18:01:08 microserver afpd[61471]: buf_read(16 bytes): got: 0
    Sep 26 18:01:08 microserver afpd[61471]: dsi_stream_read: len:0, unexpected EOF
    Sep 26 18:01:08 microserver afpd[61471]: dsi_disconnect: entering disconnected state

    OS: Debian
    Linux microserver 3.16.0-4-amd64 #1 SMP Debian 3.16.36-1+deb8u1 (2016-09-03) x86_64 GNU/Linux
    Distributor ID: Debian
    Description: Debian GNU/Linux 8.6 (jessie)
    Release: 8.6
    Codename: jessie

    Software:
    afpd 3.1.10 - Apple Filing Protocol (AFP) daemon of Netatalk

    This program is free software; you can redistribute it and/or modify it under
    the terms of the GNU General Public License as published by the Free Software
    Foundation; either version 2 of the License, or (at your option) any later
    version. Please see the file COPYING for further information and details.

    afpd has been compiled with support for these features:

          AFP versions: 2.2 3.0 3.1 3.2 3.3 3.4
     CNID backends: dbd last tdb
  Zeroconf support: Avahi

    TCP wrappers support: Yes
    Quota support: Yes
    Admin group support: Yes
    Valid shell checks: Yes
    cracklib support: No
    EA support: ad | sys
    ACL support: Yes
    LDAP support: No
    D-Bus support: Yes
    Spotlight support: No
    DTrace probes: No

              afp.conf: /opt/netatalk/etc/afp.conf
       extmap.conf: /opt/netatalk/etc/extmap.conf
   state directory: /opt/netatalk/var/netatalk/
afp_signature.conf: /opt/netatalk/var/netatalk/afp_signature.conf
  afp_voluuid.conf: /opt/netatalk/var/netatalk/afp_voluuid.conf
   UAM search path: /opt/netatalk/lib/netatalk//

    Server messages path: /opt/netatalk/var/netatalk/msg/

    Netatalk built from the latest source tarball.

     
    log2.txt.gz

  • masc

    masc - 2016-12-20
     

Log in to post a comment.