#445 Unexpected disconnection

None
open
nobody
5
2014-04-26
2012-07-10
Miëtek Bak
No

Today, I attempted a fresh Time Machine backup to my Solaris 11 Express machine, running Netatalk 2.2.3, with the target directory on a ZFS volume.

The backup failed during the indexing phase.

Relevant portions of server dmesg:

Jul 9 21:53:04 zyx afpd[4259]: [ID 702911 daemon.notice] AFP/TCP started, advertising 192.168.144.2:548 (2.2.3)
Jul 9 21:54:50 zyx afpd[4265]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
Jul 9 21:54:51 zyx afpd[4265]: [ID 702911 daemon.notice] AFP logout by mietek
Jul 9 21:54:51 zyx afpd[4265]: [ID 702911 daemon.notice] AFP statistics: 1.33 KB read, 1.26 KB written
Jul 9 21:54:51 zyx afpd[4265]: [ID 702911 daemon.notice] done
Jul 9 21:56:59 zyx afpd[4275]: [ID 702911 daemon.notice] AFP3.3 Login by mietek

Jul 10 05:31:14 zyx afpd[4275]: [ID 702911 daemon.error] dsi_peek: EOF
Jul 10 05:31:14 zyx last message repeated 1 time
Jul 10 05:31:15 zyx afpd[4275]: [ID 702911 daemon.error] dsi_stream_send: Resource temporarily unavailable
Jul 10 05:31:15 zyx afpd[4275]: [ID 702911 daemon.error] afp_read(4274): Resource temporarily unavailable
Jul 10 05:31:15 zyx afpd[4275]: [ID 702911 daemon.error] dsi_stream_write: Broken pipe
Jul 10 05:31:15 zyx afpd[4275]: [ID 702911 daemon.notice] AFP statistics: 144241268.03 KB read, 1892871.14 KB written
Jul 10 05:31:15 zyx afpd[4275]: [ID 702911 daemon.error] dsi_stream_write: Broken pipe
Jul 10 05:31:26 zyx afpd[4365]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
Jul 10 05:31:26 zyx afpd[4365]: [ID 702911 daemon.notice] afp_disconnect: trying primary reconnect
Jul 10 05:31:26 zyx afpd[4259]: [ID 702911 daemon.notice] Reconnect: no child[4275]
Jul 10 05:31:31 zyx afpd[4365]: [ID 702911 daemon.error] afp_disconnect: primary reconnect failed
Jul 10 05:31:32 zyx afpd[4365]: [ID 702911 daemon.error] dsi_stream_read: len:0, unexpected EOF
Jul 10 05:31:32 zyx afpd[4365]: [ID 702911 daemon.notice] afp_over_dsi: failed reconnect
Jul 10 05:31:32 zyx afpd[4365]: [ID 702911 daemon.notice] AFP statistics: 0.55 KB read, 0.38 KB written
Jul 10 05:31:37 zyx afpd[4366]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
Jul 10 05:31:37 zyx afpd[4366]: [ID 702911 daemon.notice] afp_disconnect: trying primary reconnect
Jul 10 05:31:37 zyx afpd[4259]: [ID 702911 daemon.notice] Reconnect: no child[4275]
Jul 10 05:31:42 zyx afpd[4366]: [ID 702911 daemon.error] afp_disconnect: primary reconnect failed
Jul 10 05:31:44 zyx afpd[4366]: [ID 702911 daemon.error] dsi_stream_read: len:0, unexpected EOF
Jul 10 05:31:44 zyx afpd[4366]: [ID 702911 daemon.notice] afp_over_dsi: failed reconnect
Jul 10 05:31:44 zyx afpd[4366]: [ID 702911 daemon.notice] AFP statistics: 0.55 KB read, 0.38 KB written
Jul 10 05:31:49 zyx afpd[4367]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
Jul 10 05:31:49 zyx afpd[4367]: [ID 702911 daemon.notice] afp_disconnect: trying primary reconnect
Jul 10 05:31:49 zyx afpd[4259]: [ID 702911 daemon.notice] Reconnect: no child[4275]
Jul 10 05:31:54 zyx afpd[4367]: [ID 702911 daemon.error] afp_disconnect: primary reconnect failed
Jul 10 05:31:54 zyx afpd[4367]: [ID 702911 daemon.error] dsi_stream_read: len:0, unexpected EOF
Jul 10 05:31:54 zyx afpd[4367]: [ID 702911 daemon.notice] afp_over_dsi: failed reconnect
Jul 10 05:31:54 zyx afpd[4367]: [ID 702911 daemon.notice] AFP statistics: 0.55 KB read, 0.38 KB written

Jul 10 05:32:26 zyx afpd[4371]: [ID 702911 daemon.notice] AFP3.3 Login by mietek

Discussion

  • Miëtek Bak
    Miëtek Bak
    2012-07-18

    Today, I attempted a very large Finder copy to the same machine.

    The copy failed after 5 hours.

    Relevant portions of server dmesg:

    Jul 18 12:16:29 zyx afpd[8009]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
    Jul 18 12:21:09 zyx afpd[8009]: [ID 702911 daemon.notice] AFP logout by mietek
    Jul 18 12:21:09 zyx afpd[8009]: [ID 702911 daemon.notice] AFP statistics: 190136.78 KB read, 218929.63 KB written
    Jul 18 12:21:09 zyx afpd[8009]: [ID 702911 daemon.notice] done
    Jul 18 13:16:27 zyx afpd[8060]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
    Jul 18 13:19:39 zyx afpd[8060]: [ID 702911 daemon.notice] AFP logout by mietek
    Jul 18 13:19:39 zyx afpd[8060]: [ID 702911 daemon.notice] AFP statistics: 142325.51 KB read, 150911.91 KB written
    Jul 18 13:19:39 zyx afpd[8060]: [ID 702911 daemon.notice] done
    Jul 18 14:16:39 zyx afpd[8104]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
    Jul 18 14:32:43 zyx afpd[8104]: [ID 702911 daemon.notice] AFP logout by mietek
    Jul 18 14:32:43 zyx afpd[8104]: [ID 702911 daemon.notice] AFP statistics: 330325.31 KB read, 283394.73 KB written
    Jul 18 14:32:43 zyx afpd[8104]: [ID 702911 daemon.notice] done
    Jul 18 15:16:33 zyx afpd[8148]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
    Jul 18 15:24:44 zyx afpd[8148]: [ID 702911 daemon.notice] AFP logout by mietek
    Jul 18 15:24:44 zyx afpd[8148]: [ID 702911 daemon.notice] AFP statistics: 167161.09 KB read, 190883.60 KB written
    Jul 18 15:24:44 zyx afpd[8148]: [ID 702911 daemon.notice] done
    Jul 18 16:16:35 zyx afpd[8192]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
    Jul 18 16:35:27 zyx afpd[8192]: [ID 702911 daemon.notice] AFP logout by mietek
    Jul 18 16:35:27 zyx afpd[8192]: [ID 702911 daemon.notice] AFP statistics: 183006.19 KB read, 638989.13 KB written
    Jul 18 16:35:27 zyx afpd[8192]: [ID 702911 daemon.notice] done
    Jul 18 17:16:35 zyx afpd[8236]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
    Jul 18 17:27:32 zyx afpd[8236]: [ID 702911 daemon.notice] AFP logout by mietek
    Jul 18 17:27:32 zyx afpd[8236]: [ID 702911 daemon.notice] AFP statistics: 163294.16 KB read, 197891.62 KB written
    Jul 18 17:27:32 zyx afpd[8236]: [ID 702911 daemon.notice] done
    Jul 18 18:16:37 zyx afpd[8280]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
    Jul 18 18:31:54 zyx afpd[8280]: [ID 702911 daemon.notice] AFP logout by mietek
    Jul 18 18:31:54 zyx afpd[8280]: [ID 702911 daemon.notice] AFP statistics: 261512.85 KB read, 290632.85 KB written
    Jul 18 18:31:54 zyx afpd[8280]: [ID 702911 daemon.notice] done
    Jul 18 19:16:36 zyx afpd[8331]: [ID 702911 daemon.notice] AFP3.3 Login by mietek

    Jul 18 19:18:58 zyx afpd[8331]: [ID 702911 daemon.error] dsi_peek: EOF
    Jul 18 19:18:59 zyx afpd[8331]: [ID 702911 daemon.error] dsi_stream_send: Resource temporarily unavailable
    Jul 18 19:18:59 zyx afpd[8331]: [ID 702911 daemon.error] afp_read(3f01): Resource temporarily unavailable
    Jul 18 19:18:59 zyx afpd[8331]: [ID 702911 daemon.error] dsi_stream_write: Broken pipe
    Jul 18 19:18:59 zyx afpd[8331]: [ID 702911 daemon.notice] AFP statistics: 1003.00 KB read, 44800.92 KB written
    Jul 18 19:18:59 zyx afpd[8331]: [ID 702911 daemon.error] dsi_stream_write: Broken pipe
    Jul 18 19:19:04 zyx afpd[8349]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
    Jul 18 19:19:04 zyx afpd[8349]: [ID 702911 daemon.notice] afp_disconnect: trying primary reconnect
    Jul 18 19:19:04 zyx afpd[7799]: [ID 702911 daemon.notice] Reconnect: no child[8331]
    Jul 18 19:19:09 zyx afpd[8349]: [ID 702911 daemon.error] afp_disconnect: primary reconnect failed
    Jul 18 19:19:10 zyx afpd[8349]: [ID 702911 daemon.error] dsi_stream_read: len:0, unexpected EOF
    Jul 18 19:19:10 zyx afpd[8349]: [ID 702911 daemon.notice] afp_over_dsi: failed reconnect
    Jul 18 19:19:10 zyx afpd[8349]: [ID 702911 daemon.notice] AFP statistics: 0.55 KB read, 0.38 KB written
    Jul 18 19:19:16 zyx afpd[8350]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
    Jul 18 19:19:16 zyx afpd[8350]: [ID 702911 daemon.notice] afp_disconnect: trying primary reconnect
    Jul 18 19:19:16 zyx afpd[7799]: [ID 702911 daemon.notice] Reconnect: no child[8331]
    Jul 18 19:19:21 zyx afpd[8350]: [ID 702911 daemon.error] afp_disconnect: primary reconnect failed
    Jul 18 19:19:23 zyx afpd[8350]: [ID 702911 daemon.error] dsi_stream_read: len:0, unexpected EOF
    Jul 18 19:19:23 zyx afpd[8350]: [ID 702911 daemon.notice] afp_over_dsi: failed reconnect
    Jul 18 19:19:23 zyx afpd[8350]: [ID 702911 daemon.notice] AFP statistics: 0.55 KB read, 0.38 KB written
    Jul 18 19:19:30 zyx afpd[8351]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
    Jul 18 19:19:30 zyx afpd[8351]: [ID 702911 daemon.notice] afp_disconnect: trying primary reconnect
    Jul 18 19:19:30 zyx afpd[7799]: [ID 702911 daemon.notice] Reconnect: no child[8331]
    Jul 18 19:19:35 zyx afpd[8351]: [ID 702911 daemon.error] afp_disconnect: primary reconnect failed
    Jul 18 19:19:35 zyx afpd[8351]: [ID 702911 daemon.error] dsi_stream_read: len:0, unexpected EOF
    Jul 18 19:19:35 zyx afpd[8351]: [ID 702911 daemon.notice] afp_over_dsi: failed reconnect
    Jul 18 19:19:35 zyx afpd[8351]: [ID 702911 daemon.notice] AFP statistics: 0.55 KB read, 0.38 KB written
    Jul 18 19:19:47 zyx afpd[8362]: [ID 702911 daemon.notice] AFP3.3 Login by mietek
    Jul 18 19:19:49 zyx afpd[7799]: [ID 702911 daemon.warning] Terminated disconnected child[7804], client rebooted.
    Jul 18 19:19:49 zyx afpd[7804]: [ID 702911 daemon.notice] AFP statistics: 177816161.56 KB read, 66298.70 KB written

    Jul 18 19:20:08 zyx afpd[8365]: [ID 702911 daemon.notice] AFP3.3 Login by mietek

     
  • franklahm
    franklahm
    2012-11-01

    Closed due to inactivity.

     
  • franklahm
    franklahm
    2012-11-01

    • status: open --> closed
    • milestone: -->
     
  • Miëtek Bak
    Miëtek Bak
    2012-11-01

    Please reopen this ticket and respond to the bug report. The issue has not been fixed, or even acknowledged.

     
    Last edit: Miëtek Bak 2012-11-01
  • franklahm
    franklahm
    2012-11-01

    Reopened as requested.
    Please note that Netatalk is Opensource software provided as is without support.

     
  • franklahm
    franklahm
    2012-11-01

    • status: closed --> open