rdmark/netatalk-2.x

Netatalk server disappears upon connecting

tempestmac opened this issue · 2 comments

I get this error when connecting with OSX 11.6: "The operation can’t be completed because the original item for “appletalk” can’t be found" and the server window goes away, but I can try again with the same result. Trying to connect with an emulator running OS7 also fails with: "The connection to this server has been unexpectedly broken".

sudo journalctl /usr/local/sbin/afpd output:

Apr 07 20:55:27 SBCserver afpd[31180]: alarm: tickles: 30, flags: -|-|-|-|DSI_DISCONNECTED|-|-|-|-
Apr 07 20:55:30 SBCserver afpd[30992]: fdset_add_fd: adding fd 13 in slot 5
Apr 07 20:55:30 SBCserver afpd[30992]: main: polling 6 fds
Apr 07 20:55:30 SBCserver afpd[30992]: fdset_add_fd: adding fd 14 in slot 6
Apr 07 20:55:30 SBCserver afpd[30992]: main: polling 7 fds
Apr 07 20:55:30 SBCserver afpd[30992]: main: IPC request from child[32253]
Apr 07 20:55:30 SBCserver afpd[30992]: main: polling 6 fds
Apr 07 20:55:30 SBCserver afpd[32254]: dsi_stream_read(2 bytes)
Apr 07 20:55:30 SBCserver afpd[32254]: buf_read(2 bytes)
Apr 07 20:55:30 SBCserver afpd[32254]: buf_read(2 bytes): got: 2
Apr 07 20:55:30 SBCserver afpd[32254]: dsi_stream_read(2 bytes): got: 2
Apr 07 20:55:30 SBCserver afpd[32254]: dsi_stream_read(14 bytes)
Apr 07 20:55:30 SBCserver afpd[32254]: buf_read(14 bytes)
Apr 07 20:55:30 SBCserver afpd[32254]: buf_read(14 bytes): got: 14
Apr 07 20:55:30 SBCserver afpd[32254]: dsi_stream_read(14 bytes): got: 14
Apr 07 20:55:30 SBCserver afpd[32254]: dsi_stream_read(2 bytes)
Apr 07 20:55:30 SBCserver afpd[32254]: buf_read(2 bytes)
Apr 07 20:55:30 SBCserver afpd[32254]: buf_read(2 bytes): got: 2
Apr 07 20:55:30 SBCserver afpd[32254]: dsi_stream_read(2 bytes): got: 2
Apr 07 20:55:30 SBCserver afpd[32254]: AFP/TCP session from XXX.XXX.XX.241:56490
Apr 07 20:55:30 SBCserver afpd[32254]: dsi_stream_send(453 bytes): START
Apr 07 20:55:30 SBCserver afpd[32254]: dsi_stream_send(453 bytes): END
Apr 07 20:55:30 SBCserver afpd[30992]: child[32253]: exited 1
Apr 07 20:55:30 SBCserver afpd[30992]: main: polling 6 fds
Apr 07 20:55:30 SBCserver afpd[30992]: main: IPC request from child[32254]
Apr 07 20:55:30 SBCserver afpd[30992]: main: polling 5 fds
Apr 07 20:55:30 SBCserver afpd[30992]: child[32254]: done
Apr 07 20:55:30 SBCserver afpd[30992]: main: polling 5 fds
Apr 07 20:55:30 SBCserver afpd[30992]: fdset_add_fd: adding fd 13 in slot 5
Apr 07 20:55:30 SBCserver afpd[30992]: main: IPC request from child[32255]
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(2 bytes)
Apr 07 20:55:30 SBCserver afpd[30992]: main: polling 6 fds
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(2 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(2 bytes): got: 2
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(2 bytes): got: 2
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(14 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(14 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(14 bytes): got: 14
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(14 bytes): got: 14
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(6 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(6 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(6 bytes): got: 6
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(6 bytes): got: 6
Apr 07 20:55:30 SBCserver afpd[32255]: AFP/TCP session from XXX.XXX.XX.241:56491
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(12 bytes): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(12 bytes): END
Apr 07 20:55:30 SBCserver afpd[32255]: unload_volumes_and_extmap
Apr 07 20:55:30 SBCserver afpd[32255]: dircache_init: done. max dircache size: 8192
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_buffered_stream_read: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(24 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(24 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 24 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(24 bytes): got: 24
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(24 bytes): got: 24
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: DSI cmdlen: 24
Apr 07 20:55:30 SBCserver afpd[32255]: DSI request ID: 2
Apr 07 20:55:30 SBCserver afpd[32255]: <== Start AFP command: AFP_LOGIN
Apr 07 20:55:30 SBCserver afpd[32255]: login noauth
Apr 07 20:55:30 SBCserver afpd[32255]: AFP3.3 Login by nobody
Apr 07 20:55:30 SBCserver afpd[32255]: obj->options.admingid == 0
Apr 07 20:55:30 SBCserver afpd[32255]: login: supplementary groups:  65534
Apr 07 20:55:30 SBCserver afpd[32255]: ==> Finished AFP command: AFP_LOGIN -> AFP_OK
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 2, len: 0): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(0 bytes): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(16 bytes): DSI header, no data
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_write(send: 16 bytes): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_write(send: 16 bytes): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 2, len: 0): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_buffered_stream_read: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(8 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(8 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 8 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(8 bytes): got: 8
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(8 bytes): got: 8
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: DSI cmdlen: 8
Apr 07 20:55:30 SBCserver afpd[32255]: DSI request ID: 3
Apr 07 20:55:30 SBCserver afpd[32255]: <== Start AFP command: AFP_GETUSERINFO
Apr 07 20:55:30 SBCserver afpd[32255]: begin afp_getuserinfo:
Apr 07 20:55:30 SBCserver afpd[32255]: END afp_getuserinfo:
Apr 07 20:55:30 SBCserver afpd[32255]: ==> Finished AFP command: AFP_GETUSERINFO -> AFP_OK
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 3, len: 6): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(6 bytes): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(6 bytes): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 3, len: 6): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_buffered_stream_read: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(2 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(2 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 2 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(2 bytes): got: 2
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(2 bytes): got: 2
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: DSI cmdlen: 2
Apr 07 20:55:30 SBCserver afpd[32255]: DSI request ID: 4
Apr 07 20:55:30 SBCserver afpd[32255]: <== Start AFP command: AFP_GETSRVPARAM
Apr 07 20:55:30 SBCserver afpd[32255]: load_volumes: user: nobody
Apr 07 20:55:30 SBCserver afpd[32255]: login: supplementary groups:  65534
Apr 07 20:55:30 SBCserver afpd[32255]: readvolfile: seeding default umask: 0000
Apr 07 20:55:30 SBCserver afpd[32255]: readvolfile: "/etc/netatalk/AppleVolumes.system"
Apr 07 20:55:30 SBCserver afpd[32255]: readvolfile: seeding default umask: 0000
Apr 07 20:55:30 SBCserver afpd[32255]: readvolfile: "/etc/netatalk/AppleVolumes.default"
Apr 07 20:55:30 SBCserver afpd[32255]: Parsing volset :upriv,usedots
Apr 07 20:55:30 SBCserver afpd[32255]: createvol: Volume 'appletalk'
Apr 07 20:55:30 SBCserver afpd[32255]: createvol: Volume 'appletalk' -> UTF8-MAC Name: 'appletalk'
Apr 07 20:55:30 SBCserver afpd[32255]: createvol: Volume 'appletalk' ->  Longname: 'appletalk'
Apr 07 20:55:30 SBCserver afpd[32255]: initvol_vfs: enabling EA support with native EAs
Apr 07 20:55:30 SBCserver afpd[32255]: ==> Finished AFP command: AFP_GETSRVPARAM -> AFP_OK
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 4, len: 16): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(16 bytes): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(16 bytes): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 4, len: 16): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_buffered_stream_read: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(2 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(2 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 2 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(2 bytes): got: 2
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(2 bytes): got: 2
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: DSI cmdlen: 2
Apr 07 20:55:30 SBCserver afpd[32255]: DSI request ID: 5
Apr 07 20:55:30 SBCserver afpd[32255]: <== Start AFP command: AFP_GETSRVPARAM
Apr 07 20:55:30 SBCserver afpd[32255]: ==> Finished AFP command: AFP_GETSRVPARAM -> AFP_OK
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 5, len: 16): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(16 bytes): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(16 bytes): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 5, len: 16): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_buffered_stream_read: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(14 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(14 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 14 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(14 bytes): got: 14
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(14 bytes): got: 14
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: DSI cmdlen: 14
Apr 07 20:55:30 SBCserver afpd[32255]: DSI request ID: 6
Apr 07 20:55:30 SBCserver afpd[32255]: <== Start AFP command: AFP_OPENVOL
Apr 07 20:55:30 SBCserver afpd[32255]: Volume /home/appletalk/afpshare use CNID scheme dbd.
Apr 07 20:55:30 SBCserver afpd[32255]: CNID server: localhost:4700
Apr 07 20:55:30 SBCserver afpd[32255]: cnid_dbd_open: Finished initializing cnid dbd module for volume '/home
/appletalk/afpshare'
Apr 07 20:55:30 SBCserver afpd[32255]: getvolparams: Volume 'appletalk'
Apr 07 20:55:30 SBCserver afpd[32255]: ad_update: checking whether '/home/appletalk/afpshare/.AppleDouble/.Pa
rent' needs an upgrade.
Apr 07 20:55:30 SBCserver afpd[32255]: ad_update: checking whether '/home/appletalk/afpshare/Network Trash Fo
lder/.AppleDouble/.Parent' needs an upgrade.
Apr 07 20:55:30 SBCserver afpd[32255]: ad_update: checking whether '/home/appletalk/afpshare/Temporary Items/
.AppleDouble/.Parent' needs an upgrade.
Apr 07 20:55:30 SBCserver afpd[32255]: ==> Finished AFP command: AFP_OPENVOL -> AFP_OK
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 6, len: 4): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(4 bytes): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(4 bytes): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 6, len: 4): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_buffered_stream_read: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(15 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(15 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 15 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(15 bytes): got: 15
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(15 bytes): got: 15
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: DSI cmdlen: 15
Apr 07 20:55:30 SBCserver afpd[32255]: DSI request ID: 7
Apr 07 20:55:30 SBCserver afpd[32255]: <== Start AFP command: AFP_GETFLDRPARAM
Apr 07 20:55:30 SBCserver afpd[32255]: dirlookup(did: 2): START
Apr 07 20:55:30 SBCserver afpd[32255]: dirlookup(did: 2): RESULT: pdid: 1, path: "/home/appletalk/afpshare"

Apr 07 20:55:30 SBCserver afpd[32255]: came('/home/appletalk/afpshare'): {start}
Apr 07 20:55:30 SBCserver afpd[32255]: movecwd: from: curdir:"/home/appletalk/afpshare", cwd:"/home/appletalk
/afpshare"
Apr 07 20:55:30 SBCserver afpd[32255]: movecwd(to: did: 2, "/home/appletalk/afpshare")
Apr 07 20:55:30 SBCserver afpd[32255]: came('/home/appletalk/afpshare') {end: curdir:'/home/appletalk/afpshar
e', path:'.'}
Apr 07 20:55:30 SBCserver afpd[32255]: getfildirparams(vid:2, did:2, f/d:0000/1000) {cwdid:2, cwd: /home/appl
etalk/afpshare, name:'.'}
Apr 07 20:55:30 SBCserver afpd[32255]: of_statdir: stating: '../afpshare'
Apr 07 20:55:30 SBCserver afpd[32255]: ==> Finished AFP command: AFP_GETFLDRPARAM -> AFP_OK
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 7, len: 10): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(10 bytes): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(10 bytes): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 7, len: 10): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_buffered_stream_read: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes): got: 16
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(4 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(4 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 4 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(4 bytes): got: 4
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(4 bytes): got: 4
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: DSI cmdlen: 4
Apr 07 20:55:30 SBCserver afpd[32255]: DSI request ID: 8
Apr 07 20:55:30 SBCserver afpd[32255]: <== Start AFP command: AFP_CLOSEVOL
Apr 07 20:55:30 SBCserver afpd[32255]: closing database connection for volume '/home/appletalk/afpshare'
Apr 07 20:55:30 SBCserver afpd[32255]: ==> Finished AFP command: AFP_CLOSEVOL -> AFP_OK
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 8, len: 0): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(0 bytes): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_send(16 bytes): DSI header, no data
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_write(send: 16 bytes): START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_write(send: 16 bytes): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_cmdreply(DSI ID: 8, len: 0): END
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_receive: START
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_buffered_stream_read: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:30 SBCserver afpd[32255]: dsi_stream_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: buf_read(16 bytes)
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf: 16 bytes
Apr 07 20:55:30 SBCserver afpd[32255]: from_buf(read: 0, unread:0 , space left: 3646080): returning 0
Apr 07 20:55:31 SBCserver afpd[32255]: select timeout 1 s
Apr 07 20:55:31 SBCserver afpd[32255]: buf_read(16 bytes): got: -1
Apr 07 20:55:31 SBCserver afpd[32255]: dsi_stream_read: len:-1, No such file or directory
Apr 07 20:55:31 SBCserver afpd[32255]: dsi_disconnect: entering disconnected state
Apr 07 20:55:39 SBCserver afpd[31157]: alarm: tickles: 31, flags: -|-|-|-|DSI_DISCONNECTED|-|-|-|-

@tempestmac Thanks for reporting! Which version of the code are you using here? One of the stable releases, or bleeding edge branch-netatalk-2-x?

I think I found the reason. There was a refactored logging routine that for some reason caused this error when connecting over DSI in certain circumstances. I couldn't quite figure out why that is, so I reverted the refactoring for now. It gives us slightly lower quality logs, but that's an ok tradeoff I think. :)

Please try again with the latest branch-netatalk-2-x. I will cut a new release shortly after some testing.