Feb 27 05:35:54.250379 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.250555 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.250594 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.250653 afpd[22811] {dsi_tcp.c:241} (I:DSI): AFP/TCP session from 10.11.2.10:50091
Feb 27 05:35:54.250767 afpd[22811] {netatalk_conf.c:1451} (D5:AFPDaemon): unload_volumes: BEGIN
Feb 27 05:35:54.250803 afpd[22811] {netatalk_conf.c:1462} (D5:AFPDaemon): unload_volumes: END
Feb 27 05:35:54.251062 afpd[22811] {dircache.c:575} (D5:AFPDaemon): dircache_init: done. max dircache size: 8192
Feb 27 05:35:54.251124 afpd[22811] {server_ipc.c:299} (D5:AFPDaemon): ipc_child_write(IPC_STATE)
Feb 27 05:35:54.251155 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.251173 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 16, unread:30 , space left: 12582866): returning 16
Feb 27 05:35:54.251187 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 30
Feb 27 05:35:54.251200 afpd[22811] {dsi_stream.c:628} (D5:DSI): dsi_stream_receive: DSI cmdlen: 30
Feb 27 05:35:54.251223 afpd[22811] {afp_dsi.c:590} (D5:DSI): DSI request ID: 2
Feb 27 05:35:54.251242 afpd[22811] {afp_dsi.c:605} (D5:AFPDaemon): <== Start AFP command: AFP_LOGIN_EXT
Feb 27 05:35:54.251455 afpd[22811] {uams_dhx2_pam.c:329} (I:UAMS): DHX2 login: szaydel
Feb 27 05:35:54.255622 afpd[22811] {afp_dsi.c:614} (D5:AFPDaemon): ==> Finished AFP command: AFP_LOGIN_EXT -> AFPERR_AUTHCONT
Feb 27 05:35:54.256058 afpd[22811] {dsi_cmdreply.c:24} (D5:DSI): dsi_cmdreply(DSI ID: 2, len: 264): START
Feb 27 05:35:54.256298 afpd[22811] {dsi_cmdreply.c:33} (D5:DSI): dsi_cmdreply(DSI ID: 2, len: 264): END
Feb 27 05:35:54.256341 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.256361 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.256546 afpd[22047] {socket.c:537} (D5:Default): fdset_add_fd: adding fd 9 in slot 1
Feb 27 05:35:54.256588 afpd[22047] {main.c:415} (D5:AFPDaemon): main: IPC request from child[22811]
Feb 27 05:35:54.256609 afpd[22047] {server_ipc.c:217} (D5:AFPDaemon): ipc_server_read(IPC_STATE): pid: 22811
Feb 27 05:35:54.266308 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.266347 afpd[22811] {dsi_stream.c:628} (D5:DSI): dsi_stream_receive: DSI cmdlen: 148
Feb 27 05:35:54.266361 afpd[22811] {afp_dsi.c:590} (D5:DSI): DSI request ID: 3
Feb 27 05:35:54.266374 afpd[22811] {afp_dsi.c:605} (D5:AFPDaemon): <== Start AFP command: AFP_LOGINCONT
Feb 27 05:35:54.272156 afpd[22811] {afp_dsi.c:614} (D5:AFPDaemon): ==> Finished AFP command: AFP_LOGINCONT -> AFPERR_AUTHCONT
Feb 27 05:35:54.272892 afpd[22811] {dsi_cmdreply.c:24} (D5:DSI): dsi_cmdreply(DSI ID: 3, len: 34): START
Feb 27 05:35:54.273110 afpd[22811] {dsi_cmdreply.c:33} (D5:DSI): dsi_cmdreply(DSI ID: 3, len: 34): END
Feb 27 05:35:54.273266 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.273291 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 16, unread:276 , space left: 12582620): returning 16
Feb 27 05:35:54.273308 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 276
Feb 27 05:35:54.273322 afpd[22811] {dsi_stream.c:628} (D5:DSI): dsi_stream_receive: DSI cmdlen: 276
Feb 27 05:35:54.273335 afpd[22811] {afp_dsi.c:590} (D5:DSI): DSI request ID: 4
Feb 27 05:35:54.273347 afpd[22811] {afp_dsi.c:605} (D5:AFPDaemon): <== Start AFP command: AFP_LOGINCONT
Feb 27 05:35:54.274515 afpd[22811] {uams_dhx2_pam.c:214} (I:UAMS): PAM DHX2: PAM Success
Feb 27 05:35:54.282926 afpd[22811] {uams_dhx2_pam.c:709} (I:UAMS): DHX2: PAM Auth OK!
Feb 27 05:35:54.283106 afpd[22811] {auth.c:231} (N:AFPDaemon): AFP3.3 Login by szaydel
Feb 27 05:35:54.283396 afpd[22811] {auth.c:237} (D5:AFPDaemon): obj->options.admingid == 0
Feb 27 05:35:54.283455 afpd[22811] {auth.c:293} (D5:AFPDaemon): login: supplementary groups: 10010
Feb 27 05:35:54.283504 afpd[22811] {afp_dsi.c:614} (D5:AFPDaemon): ==> Finished AFP command: AFP_LOGINCONT -> AFP_OK
Feb 27 05:35:54.283527 afpd[22811] {dsi_cmdreply.c:24} (D5:DSI): dsi_cmdreply(DSI ID: 4, len: 0): START
Feb 27 05:35:54.283687 afpd[22811] {dsi_cmdreply.c:33} (D5:DSI): dsi_cmdreply(DSI ID: 4, len: 0): END
Feb 27 05:35:54.283720 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.283760 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.284000 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.284031 afpd[22811] {dsi_stream.c:628} (D5:DSI): dsi_stream_receive: DSI cmdlen: 8
Feb 27 05:35:54.284050 afpd[22811] {afp_dsi.c:590} (D5:DSI): DSI request ID: 5
Feb 27 05:35:54.284068 afpd[22811] {afp_dsi.c:605} (D5:AFPDaemon): <== Start AFP command: AFP_GETUSERINFO
Feb 27 05:35:54.284085 afpd[22811] {auth.c:919} (D5:AFPDaemon): begin afp_getuserinfo:
Feb 27 05:35:54.284104 afpd[22811] {auth.c:979} (D5:AFPDaemon): END afp_getuserinfo:
Feb 27 05:35:54.284122 afpd[22811] {afp_dsi.c:614} (D5:AFPDaemon): ==> Finished AFP command: AFP_GETUSERINFO -> AFP_OK
Feb 27 05:35:54.284140 afpd[22811] {dsi_cmdreply.c:24} (D5:DSI): dsi_cmdreply(DSI ID: 5, len: 6): START
Feb 27 05:35:54.284229 afpd[22811] {dsi_cmdreply.c:33} (D5:DSI): dsi_cmdreply(DSI ID: 5, len: 6): END
Feb 27 05:35:54.284344 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.284366 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.285308 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.285347 afpd[22811] {dsi_stream.c:628} (D5:DSI): dsi_stream_receive: DSI cmdlen: 2
Feb 27 05:35:54.285393 afpd[22811] {afp_dsi.c:590} (D5:DSI): DSI request ID: 6
Feb 27 05:35:54.285414 afpd[22811] {afp_dsi.c:605} (D5:AFPDaemon): <== Start AFP command: AFP_GETSRVPARAM
Feb 27 05:35:54.285432 afpd[22811] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:35:54.285513 afpd[22811] {netatalk_conf.c:1388} (D5:AFPDaemon): load_volumes: no volumes yet
Feb 27 05:35:54.285560 afpd[22811] {netatalk_conf.c:1413} (D5:AFPDaemon): load_volumes: loading: /racktop/etc/afp.conf
Feb 27 05:35:54.285669 afpd[22811] {netatalk_conf.c:1008} (D5:AFPDaemon): readvolfile: BEGIN
Feb 27 05:35:54.285693 afpd[22811] {netatalk_conf.c:1011} (D5:AFPDaemon): readvolfile: sections: 2
Feb 27 05:35:54.285723 afpd[22811] {netatalk_conf.c:582} (D5:AFPDaemon): createvol(volume: 'a01', path: "/shares/a01", preset: '-'): BEGIN
Feb 27 05:35:54.285816 afpd[22811] {netatalk_conf.c:256} (D5:AFPDaemon): Volume "/shares/a01" ACL support: yes
Feb 27 05:35:54.285894 afpd[22811] {vfs.c:852} (D5:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Feb 27 05:35:54.285915 afpd[22811] {netatalk_conf.c:961} (D5:AFPDaemon): createvol: END: 0
Feb 27 05:35:54.285934 afpd[22811] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:35:54.286000 afpd[22811] {afp_dsi.c:614} (D5:AFPDaemon): ==> Finished AFP command: AFP_GETSRVPARAM -> AFP_OK
Feb 27 05:35:54.286024 afpd[22811] {dsi_cmdreply.c:24} (D5:DSI): dsi_cmdreply(DSI ID: 6, len: 10): START
Feb 27 05:35:54.286129 afpd[22811] {dsi_cmdreply.c:33} (D5:DSI): dsi_cmdreply(DSI ID: 6, len: 10): END
Feb 27 05:35:54.286160 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.286182 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.287066 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:35:54.287111 afpd[22811] {dsi_stream.c:628} (D5:DSI): dsi_stream_receive: DSI cmdlen: 8
Feb 27 05:35:54.287130 afpd[22811] {afp_dsi.c:590} (D5:DSI): DSI request ID: 7
Feb 27 05:35:54.287148 afpd[22811] {afp_dsi.c:605} (D5:AFPDaemon): <== Start AFP command: AFP_OPENVOL
Feb 27 05:35:54.287180 afpd[22811] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:35:54.287273 afpd[22811] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:35:54.287370 afpd[22811] {volume.c:642} (D5:AFPDaemon): CNID server: localhost:4700
Feb 27 05:35:54.287417 afpd[22811] {cnid_dbd.c:464} (D5:CNID): cnid_dbd_open: Finished initializing cnid dbd module for volume '/shares/a01'
Feb 27 05:35:54.287444 afpd[22811] {volume.c:305} (D5:AFPDaemon): getvolparams: Volume 'a01'
Feb 27 05:35:54.287490 afpd[22811] {ad_conv.c:272} (D5:ad): ad_convert("/shares/a01"): BEGIN
Feb 27 05:35:54.287517 afpd[22811] {ad_conv.c:64} (D5:ad): ad_conv_v22ea_hf("/shares/a01"): BEGIN
Feb 27 05:35:54.287526 afpd[22811] {ad_open.c:1721} (D5:ad): ad_open("/shares/a01", HF|DIR|O_RDWR): BEGIN {d: 0, m: 0, r: 0}[dfd: -1 (ref: 0), mfd: -1 (ref: 0), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287527 afpd[22811] {ad_open.c:956} (D5:ad): ad_open_hf_v2("/shares/a01", HF|DIR|O_RDWR): BEGIN [dfd: -1 (ref: 0), mfd: -1 (ref: 0), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287527 afpd[22811] {ad_open.c:976} (D5:ad): ad_open_hf_v2("/shares/a01"): open flags: O_RDWR
Feb 27 05:35:54.287528 afpd[22811] {ad_open.c:1068} (D5:ad): ad_open_hf_v2("/shares/a01", HF|DIR|O_RDWR): END: -1 [dfd: -1 (ref: 0), mfd: -1 (ref: 0), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287549 afpd[22811] {ad_open.c:1784} (D5:ad): ad_open("/shares/a01"): END: -1 {d: 0, m: 0, r: 0}[dfd: -1 (ref: 0), mfd: -1 (ref: 0), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287579 afpd[22811] {ad_flush.c:401} (D5:ad): ad_close(HF|SHRMD): BEGIN: {d: 0, m: 0, r: 0} [dfd: -1 (ref: 0), mfd: -1 (ref: 0), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287600 afpd[22811] {ad_flush.c:453} (D5:ad): ad_close(DF|HF|SHRMD): END: 0 {d: 0, m: 0, r: 0} [dfd: -1 (ref: 0), mfd: -1 (ref: 0), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287620 afpd[22811] {ad_flush.c:401} (D5:ad): ad_close(HF|SHRMD): BEGIN: {d: 0, m: 0, r: 0} [dfd: -1 (ref: 0), mfd: -1 (ref: 0), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287639 afpd[22811] {ad_flush.c:453} (D5:ad): ad_close(DF|HF|SHRMD): END: 0 {d: 0, m: 0, r: 0} [dfd: -1 (ref: 0), mfd: -1 (ref: 0), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287656 afpd[22811] {ad_conv.c:123} (D5:ad): ad_conv_v22ea_hf("/shares/a01"): END: -1
Feb 27 05:35:54.287676 afpd[22811] {ad_conv.c:187} (D5:ad): ad_conv_v22ea_hf("/shares/a01"): deleting adouble:v2 file: "/shares/a01/.AppleDouble/.Parent"
Feb 27 05:35:54.287711 afpd[22811] {ad_conv.c:222} (D5:ad): ad_conv_dehex("/shares/a01"): BEGIN
Feb 27 05:35:54.287735 afpd[22811] {ad_conv.c:290} (D5:ad): ad_convert("/shares/a01"): END: 0
Feb 27 05:35:54.287766 afpd[22811] {ad_open.c:1721} (D5:ad): ad_open("/shares/a01", HF|DIR|O_RDWR|O_CREAT): BEGIN {d: 0, m: 0, r: 0}[dfd: -1 (ref: 0), mfd: -1 (ref: 0), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287782 afpd[22811] {ad_open.c:1083} (D5:ad): ad_open_hf_ea("/shares/a01", HF|DIR|O_RDWR|O_CREAT): BEGIN [dfd: -1 (ref: 0), mfd: -1 (ref: 0), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287795 afpd[22811] {ad_open.c:1108} (D5:ad): ad_open_hf_ea("/shares/a01"): opening base file for meta adouble EA
Feb 27 05:35:54.287844 afpd[22811] {ad_open.c:1157} (D5:ad): ad_open_hf_ea("/shares/a01", HF|DIR|O_RDWR|O_CREAT): END: 0 [dfd: 5 (ref: 1), mfd: 5 (ref: 1), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287861 afpd[22811] {ad_open.c:1784} (D5:ad): ad_open("/shares/a01"): END: 0 {d: 0, m: 1, r: 0}[dfd: 5 (ref: 1), mfd: 5 (ref: 1), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287880 afpd[22811] {ad_flush.c:401} (D5:ad): ad_close(HF): BEGIN: {d: 0, m: 1, r: 0} [dfd: 5 (ref: 1), mfd: 5 (ref: 1), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287895 afpd[22811] {ad_flush.c:453} (D5:ad): ad_close(HF): END: 0 {d: 0, m: 0, r: 0} [dfd: -1 (ref: 0), mfd: -1 (ref: 0), rfd: -1 (ref: 0)]
Feb 27 05:35:54.287911 afpd[22811] {cnid_dbd.c:234} (D5:CNID): init_tsock: BEGIN. Opening volume '/shares/a01', CNID Server: localhost/4700
Feb 27 05:35:54.289231 afpd[22811] {cnid_dbd.c:253} (D5:CNID): init_tsock: ok
Feb 27 05:35:54.289262 afpd[22811] {cnid_dbd.c:370} (D5:CNID): transmit: attached to '/shares/a01'
Feb 27 05:35:54.289322 cnid_metad[22048] {cnid_metad.c:566} (D5:CNID): main: request for volume: /shares/a01
Feb 27 05:35:54.289347 cnid_metad[22048] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:35:54.289371 cnid_metad[22048] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:35:54.289398 cnid_metad[22048] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:35:54.289418 cnid_metad[22048] {cnid_metad.c:294} (D5:CNID): set_dbdir: volume: /shares/a01, db path: /racktop/var/netatalk/CNID//a01/
Feb 27 05:35:54.289476 cnid_metad[22048] {cnid_metad.c:169} (D5:CNID): maybe_start_dbd("/shares/a01"): BEGIN
Feb 27 05:35:54.289497 cnid_metad[22048] {cnid_metad.c:182} (D5:CNID): maybe_start_dbd: no cnid_dbd serving yet
Feb 27 05:35:54.300691 cnid_dbd[22812] {logger.c:357} (D5:Logger): Setup file logging: type: Default, level: DEBUG, file: /racktop/var/log/netatalk.log
Feb 27 05:35:54.300912 cnid_dbd[22812] {netatalk_conf.c:1853} (D5:AFPDaemon): CNID Server: localhost:4700
Feb 27 05:35:54.300933 cnid_dbd[22812] {netatalk_conf.c:1896} (D5:AFPDaemon): Global unix charset is UTF8
Feb 27 05:35:54.300947 cnid_dbd[22812] {netatalk_conf.c:1907} (D5:AFPDaemon): Global vol charset is UTF8
Feb 27 05:35:54.300961 cnid_dbd[22812] {netatalk_conf.c:1921} (D5:AFPDaemon): Global mac charset is MAC_ROMAN
Feb 27 05:35:54.300974 cnid_dbd[22812] {netatalk_conf.c:1227} (D5:AFPDaemon): readextmap: loading "/racktop/etc/extmap.conf"
Feb 27 05:35:54.301129 cnid_dbd[22812] {netatalk_conf.c:1248} (D5:AFPDaemon): readextmap: done
Feb 27 05:35:54.301148 cnid_dbd[22812] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:35:54.301160 cnid_dbd[22812] {netatalk_conf.c:1388} (D5:AFPDaemon): load_volumes: no volumes yet
Feb 27 05:35:54.301195 cnid_dbd[22812] {netatalk_conf.c:1413} (D5:AFPDaemon): load_volumes: loading: /racktop/etc/afp.conf
Feb 27 05:35:54.301278 cnid_dbd[22812] {netatalk_conf.c:1008} (D5:AFPDaemon): readvolfile: BEGIN
Feb 27 05:35:54.301298 cnid_dbd[22812] {netatalk_conf.c:1011} (D5:AFPDaemon): readvolfile: sections: 2
Feb 27 05:35:54.301339 cnid_dbd[22812] {netatalk_conf.c:582} (D5:AFPDaemon): createvol(volume: 'a01', path: "/shares/a01", preset: '-'): BEGIN
Feb 27 05:35:54.301500 cnid_dbd[22812] {netatalk_conf.c:256} (D5:AFPDaemon): Volume "/shares/a01" ACL support: yes
Feb 27 05:35:54.301575 cnid_dbd[22812] {vfs.c:852} (D5:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Feb 27 05:35:54.301591 cnid_dbd[22812] {netatalk_conf.c:961} (D5:AFPDaemon): createvol: END: 0
Feb 27 05:35:54.301605 cnid_dbd[22812] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:35:54.301618 cnid_dbd[22812] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:35:54.301639 cnid_dbd[22812] {main.c:526} (D5:CNID): db dir: "/racktop/var/netatalk/CNID//a01//.AppleDB"
Feb 27 05:35:54.301668 cnid_dbd[22812] {main.c:446} (D5:CNID): Setting uid/gid to 0/0
Feb 27 05:35:54.301721 cnid_dbd[22812] {main.c:112} (D5:CNID): get_lock(LOCK_EXCL, "/racktop/var/netatalk/CNID//a01//.AppleDB")
Feb 27 05:35:54.301767 cnid_dbd[22812] {main.c:167} (D5:CNID): get_lock: got LOCK_EXCL lock
Feb 27 05:35:54.301906 cnid_dbd[22812] {dbif.c:406} (D5:CNID): Running recovery
Feb 27 05:35:56.735703 afpd[22811] {cnid_dbd.c:331} (D5:CNID): dbd_rpc: Error reading header from fd (db_dir /shares/a01): closed
Feb 27 05:35:56.735758 afpd[22811] {cnid_dbd.c:234} (D5:CNID): init_tsock: BEGIN. Opening volume '/shares/a01', CNID Server: localhost/4700
Feb 27 05:35:56.736009 afpd[22811] {cnid_dbd.c:253} (D5:CNID): init_tsock: ok
Feb 27 05:35:56.736030 afpd[22811] {cnid_dbd.c:370} (D5:CNID): transmit: attached to '/shares/a01'
Feb 27 05:35:56.736131 cnid_metad[22048] {cnid_metad.c:525} (I:CNID): cnid_dbd[22812] got signal 11
Feb 27 05:35:56.736185 cnid_metad[22048] {cnid_metad.c:566} (D5:CNID): main: request for volume: /shares/a01
Feb 27 05:35:56.736200 cnid_metad[22048] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:35:56.736220 cnid_metad[22048] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:35:56.736238 cnid_metad[22048] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:35:56.736254 cnid_metad[22048] {cnid_metad.c:294} (D5:CNID): set_dbdir: volume: /shares/a01, db path: /racktop/var/netatalk/CNID//a01/
Feb 27 05:35:56.736299 cnid_metad[22048] {cnid_metad.c:169} (D5:CNID): maybe_start_dbd("/shares/a01"): BEGIN
Feb 27 05:35:56.736314 cnid_metad[22048] {cnid_metad.c:182} (D5:CNID): maybe_start_dbd: no cnid_dbd serving yet
Feb 27 05:35:56.746104 cnid_dbd[22813] {logger.c:357} (D5:Logger): Setup file logging: type: Default, level: DEBUG, file: /racktop/var/log/netatalk.log
Feb 27 05:35:56.746302 cnid_dbd[22813] {netatalk_conf.c:1853} (D5:AFPDaemon): CNID Server: localhost:4700
Feb 27 05:35:56.746321 cnid_dbd[22813] {netatalk_conf.c:1896} (D5:AFPDaemon): Global unix charset is UTF8
Feb 27 05:35:56.746335 cnid_dbd[22813] {netatalk_conf.c:1907} (D5:AFPDaemon): Global vol charset is UTF8
Feb 27 05:35:56.746347 cnid_dbd[22813] {netatalk_conf.c:1921} (D5:AFPDaemon): Global mac charset is MAC_ROMAN
Feb 27 05:35:56.746360 cnid_dbd[22813] {netatalk_conf.c:1227} (D5:AFPDaemon): readextmap: loading "/racktop/etc/extmap.conf"
Feb 27 05:35:56.746508 cnid_dbd[22813] {netatalk_conf.c:1248} (D5:AFPDaemon): readextmap: done
Feb 27 05:35:56.746525 cnid_dbd[22813] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:35:56.746541 cnid_dbd[22813] {netatalk_conf.c:1388} (D5:AFPDaemon): load_volumes: no volumes yet
Feb 27 05:35:56.746569 cnid_dbd[22813] {netatalk_conf.c:1413} (D5:AFPDaemon): load_volumes: loading: /racktop/etc/afp.conf
Feb 27 05:35:56.746632 cnid_dbd[22813] {netatalk_conf.c:1008} (D5:AFPDaemon): readvolfile: BEGIN
Feb 27 05:35:56.746650 cnid_dbd[22813] {netatalk_conf.c:1011} (D5:AFPDaemon): readvolfile: sections: 2
Feb 27 05:35:56.746689 cnid_dbd[22813] {netatalk_conf.c:582} (D5:AFPDaemon): createvol(volume: 'a01', path: "/shares/a01", preset: '-'): BEGIN
Feb 27 05:35:56.746834 cnid_dbd[22813] {netatalk_conf.c:256} (D5:AFPDaemon): Volume "/shares/a01" ACL support: yes
Feb 27 05:35:56.746954 cnid_dbd[22813] {vfs.c:852} (D5:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Feb 27 05:35:56.746974 cnid_dbd[22813] {netatalk_conf.c:961} (D5:AFPDaemon): createvol: END: 0
Feb 27 05:35:56.746987 cnid_dbd[22813] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:35:56.747001 cnid_dbd[22813] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:35:56.747022 cnid_dbd[22813] {main.c:526} (D5:CNID): db dir: "/racktop/var/netatalk/CNID//a01//.AppleDB"
Feb 27 05:35:56.747062 cnid_dbd[22813] {main.c:446} (D5:CNID): Setting uid/gid to 0/0
Feb 27 05:35:56.747127 cnid_dbd[22813] {main.c:112} (D5:CNID): get_lock(LOCK_EXCL, "/racktop/var/netatalk/CNID//a01//.AppleDB")
Feb 27 05:35:56.747179 cnid_dbd[22813] {main.c:167} (D5:CNID): get_lock: got LOCK_EXCL lock
Feb 27 05:35:56.747321 cnid_dbd[22813] {dbif.c:406} (D5:CNID): Running recovery
Feb 27 05:35:59.214727 afpd[22811] {cnid_dbd.c:331} (D5:CNID): dbd_rpc: Error reading header from fd (db_dir /shares/a01): closed
Feb 27 05:35:59.214877 cnid_metad[22048] {cnid_metad.c:525} (I:CNID): cnid_dbd[22813] got signal 11
Feb 27 05:36:00.224485 afpd[22811] {cnid_dbd.c:234} (D5:CNID): init_tsock: BEGIN. Opening volume '/shares/a01', CNID Server: localhost/4700
Feb 27 05:36:00.224907 afpd[22811] {cnid_dbd.c:253} (D5:CNID): init_tsock: ok
Feb 27 05:36:00.224943 afpd[22811] {cnid_dbd.c:370} (D5:CNID): transmit: attached to '/shares/a01'
Feb 27 05:36:00.224996 cnid_metad[22048] {cnid_metad.c:566} (D5:CNID): main: request for volume: /shares/a01
Feb 27 05:36:00.225806 cnid_metad[22048] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:36:00.225894 cnid_metad[22048] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:36:00.225959 cnid_metad[22048] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:36:00.225978 cnid_metad[22048] {cnid_metad.c:294} (D5:CNID): set_dbdir: volume: /shares/a01, db path: /racktop/var/netatalk/CNID//a01/
Feb 27 05:36:00.226029 cnid_metad[22048] {cnid_metad.c:169} (D5:CNID): maybe_start_dbd("/shares/a01"): BEGIN
Feb 27 05:36:00.226045 cnid_metad[22048] {cnid_metad.c:182} (D5:CNID): maybe_start_dbd: no cnid_dbd serving yet
Feb 27 05:36:00.235240 cnid_dbd[22824] {logger.c:357} (D5:Logger): Setup file logging: type: Default, level: DEBUG, file: /racktop/var/log/netatalk.log
Feb 27 05:36:00.235449 cnid_dbd[22824] {netatalk_conf.c:1853} (D5:AFPDaemon): CNID Server: localhost:4700
Feb 27 05:36:00.235470 cnid_dbd[22824] {netatalk_conf.c:1896} (D5:AFPDaemon): Global unix charset is UTF8
Feb 27 05:36:00.235485 cnid_dbd[22824] {netatalk_conf.c:1907} (D5:AFPDaemon): Global vol charset is UTF8
Feb 27 05:36:00.235500 cnid_dbd[22824] {netatalk_conf.c:1921} (D5:AFPDaemon): Global mac charset is MAC_ROMAN
Feb 27 05:36:00.235514 cnid_dbd[22824] {netatalk_conf.c:1227} (D5:AFPDaemon): readextmap: loading "/racktop/etc/extmap.conf"
Feb 27 05:36:00.235658 cnid_dbd[22824] {netatalk_conf.c:1248} (D5:AFPDaemon): readextmap: done
Feb 27 05:36:00.235677 cnid_dbd[22824] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:36:00.235695 cnid_dbd[22824] {netatalk_conf.c:1388} (D5:AFPDaemon): load_volumes: no volumes yet
Feb 27 05:36:00.235725 cnid_dbd[22824] {netatalk_conf.c:1413} (D5:AFPDaemon): load_volumes: loading: /racktop/etc/afp.conf
Feb 27 05:36:00.235789 cnid_dbd[22824] {netatalk_conf.c:1008} (D5:AFPDaemon): readvolfile: BEGIN
Feb 27 05:36:00.235808 cnid_dbd[22824] {netatalk_conf.c:1011} (D5:AFPDaemon): readvolfile: sections: 2
Feb 27 05:36:00.235848 cnid_dbd[22824] {netatalk_conf.c:582} (D5:AFPDaemon): createvol(volume: 'a01', path: "/shares/a01", preset: '-'): BEGIN
Feb 27 05:36:00.235991 cnid_dbd[22824] {netatalk_conf.c:256} (D5:AFPDaemon): Volume "/shares/a01" ACL support: yes
Feb 27 05:36:00.236069 cnid_dbd[22824] {vfs.c:852} (D5:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Feb 27 05:36:00.236087 cnid_dbd[22824] {netatalk_conf.c:961} (D5:AFPDaemon): createvol: END: 0
Feb 27 05:36:00.236103 cnid_dbd[22824] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:36:00.236119 cnid_dbd[22824] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:36:00.236168 cnid_dbd[22824] {main.c:526} (D5:CNID): db dir: "/racktop/var/netatalk/CNID//a01//.AppleDB"
Feb 27 05:36:00.236199 cnid_dbd[22824] {main.c:446} (D5:CNID): Setting uid/gid to 0/0
Feb 27 05:36:00.236253 cnid_dbd[22824] {main.c:112} (D5:CNID): get_lock(LOCK_EXCL, "/racktop/var/netatalk/CNID//a01//.AppleDB")
Feb 27 05:36:00.236301 cnid_dbd[22824] {main.c:167} (D5:CNID): get_lock: got LOCK_EXCL lock
Feb 27 05:36:00.236434 cnid_dbd[22824] {dbif.c:406} (D5:CNID): Running recovery
Feb 27 05:36:02.673079 afpd[22811] {cnid_dbd.c:331} (D5:CNID): dbd_rpc: Error reading header from fd (db_dir /shares/a01): closed
Feb 27 05:36:02.673160 cnid_metad[22048] {cnid_metad.c:525} (I:CNID): cnid_dbd[22824] got signal 11
Feb 27 05:36:03.673432 afpd[22811] {cnid_dbd.c:234} (D5:CNID): init_tsock: BEGIN. Opening volume '/shares/a01', CNID Server: localhost/4700
Feb 27 05:36:03.673963 afpd[22811] {cnid_dbd.c:253} (D5:CNID): init_tsock: ok
Feb 27 05:36:03.674013 afpd[22811] {cnid_dbd.c:370} (D5:CNID): transmit: attached to '/shares/a01'
Feb 27 05:36:03.674091 cnid_metad[22048] {cnid_metad.c:566} (D5:CNID): main: request for volume: /shares/a01
Feb 27 05:36:03.674125 cnid_metad[22048] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:36:03.674162 cnid_metad[22048] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:36:03.674206 cnid_metad[22048] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:36:03.674234 cnid_metad[22048] {cnid_metad.c:294} (D5:CNID): set_dbdir: volume: /shares/a01, db path: /racktop/var/netatalk/CNID//a01/
Feb 27 05:36:03.674311 cnid_metad[22048] {cnid_metad.c:169} (D5:CNID): maybe_start_dbd("/shares/a01"): BEGIN
Feb 27 05:36:03.674339 cnid_metad[22048] {cnid_metad.c:182} (D5:CNID): maybe_start_dbd: no cnid_dbd serving yet
Feb 27 05:36:03.684943 cnid_dbd[22852] {logger.c:357} (D5:Logger): Setup file logging: type: Default, level: DEBUG, file: /racktop/var/log/netatalk.log
Feb 27 05:36:03.685162 cnid_dbd[22852] {netatalk_conf.c:1853} (D5:AFPDaemon): CNID Server: localhost:4700
Feb 27 05:36:03.685183 cnid_dbd[22852] {netatalk_conf.c:1896} (D5:AFPDaemon): Global unix charset is UTF8
Feb 27 05:36:03.685197 cnid_dbd[22852] {netatalk_conf.c:1907} (D5:AFPDaemon): Global vol charset is UTF8
Feb 27 05:36:03.685211 cnid_dbd[22852] {netatalk_conf.c:1921} (D5:AFPDaemon): Global mac charset is MAC_ROMAN
Feb 27 05:36:03.685225 cnid_dbd[22852] {netatalk_conf.c:1227} (D5:AFPDaemon): readextmap: loading "/racktop/etc/extmap.conf"
Feb 27 05:36:03.685383 cnid_dbd[22852] {netatalk_conf.c:1248} (D5:AFPDaemon): readextmap: done
Feb 27 05:36:03.685401 cnid_dbd[22852] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:36:03.685418 cnid_dbd[22852] {netatalk_conf.c:1388} (D5:AFPDaemon): load_volumes: no volumes yet
Feb 27 05:36:03.685449 cnid_dbd[22852] {netatalk_conf.c:1413} (D5:AFPDaemon): load_volumes: loading: /racktop/etc/afp.conf
Feb 27 05:36:03.685545 cnid_dbd[22852] {netatalk_conf.c:1008} (D5:AFPDaemon): readvolfile: BEGIN
Feb 27 05:36:03.685567 cnid_dbd[22852] {netatalk_conf.c:1011} (D5:AFPDaemon): readvolfile: sections: 2
Feb 27 05:36:03.685610 cnid_dbd[22852] {netatalk_conf.c:582} (D5:AFPDaemon): createvol(volume: 'a01', path: "/shares/a01", preset: '-'): BEGIN
Feb 27 05:36:03.685769 cnid_dbd[22852] {netatalk_conf.c:256} (D5:AFPDaemon): Volume "/shares/a01" ACL support: yes
Feb 27 05:36:03.685849 cnid_dbd[22852] {vfs.c:852} (D5:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Feb 27 05:36:03.685867 cnid_dbd[22852] {netatalk_conf.c:961} (D5:AFPDaemon): createvol: END: 0
Feb 27 05:36:03.685880 cnid_dbd[22852] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:36:03.685894 cnid_dbd[22852] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:36:03.685914 cnid_dbd[22852] {main.c:526} (D5:CNID): db dir: "/racktop/var/netatalk/CNID//a01//.AppleDB"
Feb 27 05:36:03.685943 cnid_dbd[22852] {main.c:446} (D5:CNID): Setting uid/gid to 0/0
Feb 27 05:36:03.686000 cnid_dbd[22852] {main.c:112} (D5:CNID): get_lock(LOCK_EXCL, "/racktop/var/netatalk/CNID//a01//.AppleDB")
Feb 27 05:36:03.686043 cnid_dbd[22852] {main.c:167} (D5:CNID): get_lock: got LOCK_EXCL lock
Feb 27 05:36:03.686184 cnid_dbd[22852] {dbif.c:406} (D5:CNID): Running recovery
Feb 27 05:36:06.121775 afpd[22811] {cnid_dbd.c:331} (D5:CNID): dbd_rpc: Error reading header from fd (db_dir /shares/a01): closed
Feb 27 05:36:06.121957 cnid_metad[22048] {cnid_metad.c:525} (I:CNID): cnid_dbd[22852] got signal 11
Feb 27 05:36:07.131623 afpd[22811] {cnid_dbd.c:234} (D5:CNID): init_tsock: BEGIN. Opening volume '/shares/a01', CNID Server: localhost/4700
Feb 27 05:36:07.132033 afpd[22811] {cnid_dbd.c:253} (D5:CNID): init_tsock: ok
Feb 27 05:36:07.132572 afpd[22811] {cnid_dbd.c:370} (D5:CNID): transmit: attached to '/shares/a01'
Feb 27 05:36:07.132921 cnid_metad[22048] {cnid_metad.c:566} (D5:CNID): main: request for volume: /shares/a01
Feb 27 05:36:07.132948 cnid_metad[22048] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:36:07.132975 cnid_metad[22048] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:36:07.133014 cnid_metad[22048] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:36:07.133034 cnid_metad[22048] {cnid_metad.c:294} (D5:CNID): set_dbdir: volume: /shares/a01, db path: /racktop/var/netatalk/CNID//a01/
Feb 27 05:36:07.133090 cnid_metad[22048] {cnid_metad.c:169} (D5:CNID): maybe_start_dbd("/shares/a01"): BEGIN
Feb 27 05:36:07.133107 cnid_metad[22048] {cnid_metad.c:182} (D5:CNID): maybe_start_dbd: no cnid_dbd serving yet
Feb 27 05:36:07.142256 cnid_dbd[22853] {logger.c:357} (D5:Logger): Setup file logging: type: Default, level: DEBUG, file: /racktop/var/log/netatalk.log
Feb 27 05:36:07.142463 cnid_dbd[22853] {netatalk_conf.c:1853} (D5:AFPDaemon): CNID Server: localhost:4700
Feb 27 05:36:07.142485 cnid_dbd[22853] {netatalk_conf.c:1896} (D5:AFPDaemon): Global unix charset is UTF8
Feb 27 05:36:07.142501 cnid_dbd[22853] {netatalk_conf.c:1907} (D5:AFPDaemon): Global vol charset is UTF8
Feb 27 05:36:07.142518 cnid_dbd[22853] {netatalk_conf.c:1921} (D5:AFPDaemon): Global mac charset is MAC_ROMAN
Feb 27 05:36:07.142533 cnid_dbd[22853] {netatalk_conf.c:1227} (D5:AFPDaemon): readextmap: loading "/racktop/etc/extmap.conf"
Feb 27 05:36:07.142686 cnid_dbd[22853] {netatalk_conf.c:1248} (D5:AFPDaemon): readextmap: done
Feb 27 05:36:07.142707 cnid_dbd[22853] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:36:07.142725 cnid_dbd[22853] {netatalk_conf.c:1388} (D5:AFPDaemon): load_volumes: no volumes yet
Feb 27 05:36:07.142770 cnid_dbd[22853] {netatalk_conf.c:1413} (D5:AFPDaemon): load_volumes: loading: /racktop/etc/afp.conf
Feb 27 05:36:07.142839 cnid_dbd[22853] {netatalk_conf.c:1008} (D5:AFPDaemon): readvolfile: BEGIN
Feb 27 05:36:07.142860 cnid_dbd[22853] {netatalk_conf.c:1011} (D5:AFPDaemon): readvolfile: sections: 2
Feb 27 05:36:07.142902 cnid_dbd[22853] {netatalk_conf.c:582} (D5:AFPDaemon): createvol(volume: 'a01', path: "/shares/a01", preset: '-'): BEGIN
Feb 27 05:36:07.143050 cnid_dbd[22853] {netatalk_conf.c:256} (D5:AFPDaemon): Volume "/shares/a01" ACL support: yes
Feb 27 05:36:07.143131 cnid_dbd[22853] {vfs.c:852} (D5:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Feb 27 05:36:07.143150 cnid_dbd[22853] {netatalk_conf.c:961} (D5:AFPDaemon): createvol: END: 0
Feb 27 05:36:07.143166 cnid_dbd[22853] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:36:07.143182 cnid_dbd[22853] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:36:07.143205 cnid_dbd[22853] {main.c:526} (D5:CNID): db dir: "/racktop/var/netatalk/CNID//a01//.AppleDB"
Feb 27 05:36:07.143233 cnid_dbd[22853] {main.c:446} (D5:CNID): Setting uid/gid to 0/0
Feb 27 05:36:07.143234 cnid_dbd[22853] {main.c:112} (D5:CNID): get_lock(LOCK_EXCL, "/racktop/var/netatalk/CNID//a01//.AppleDB")
Feb 27 05:36:07.143235 cnid_dbd[22853] {main.c:167} (D5:CNID): get_lock: got LOCK_EXCL lock
Feb 27 05:36:07.143328 cnid_dbd[22853] {dbif.c:406} (D5:CNID): Running recovery
Feb 27 05:36:09.589414 afpd[22811] {cnid_dbd.c:331} (D5:CNID): dbd_rpc: Error reading header from fd (db_dir /shares/a01): closed
Feb 27 05:36:09.590340 cnid_metad[22048] {cnid_metad.c:525} (I:CNID): cnid_dbd[22853] got signal 11
Feb 27 05:36:10.599258 afpd[22811] {cnid_dbd.c:234} (D5:CNID): init_tsock: BEGIN. Opening volume '/shares/a01', CNID Server: localhost/4700
Feb 27 05:36:10.599777 afpd[22811] {cnid_dbd.c:253} (D5:CNID): init_tsock: ok
Feb 27 05:36:10.599828 afpd[22811] {cnid_dbd.c:370} (D5:CNID): transmit: attached to '/shares/a01'
Feb 27 05:36:10.599903 cnid_metad[22048] {cnid_metad.c:566} (D5:CNID): main: request for volume: /shares/a01
Feb 27 05:36:10.599937 cnid_metad[22048] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:36:10.599972 cnid_metad[22048] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:36:10.600013 cnid_metad[22048] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:36:10.600041 cnid_metad[22048] {cnid_metad.c:294} (D5:CNID): set_dbdir: volume: /shares/a01, db path: /racktop/var/netatalk/CNID//a01/
Feb 27 05:36:10.600175 cnid_metad[22048] {cnid_metad.c:169} (D5:CNID): maybe_start_dbd("/shares/a01"): BEGIN
Feb 27 05:36:10.600206 cnid_metad[22048] {cnid_metad.c:182} (D5:CNID): maybe_start_dbd: no cnid_dbd serving yet
Feb 27 05:36:10.611646 cnid_dbd[22854] {logger.c:357} (D5:Logger): Setup file logging: type: Default, level: DEBUG, file: /racktop/var/log/netatalk.log
Feb 27 05:36:10.611925 cnid_dbd[22854] {netatalk_conf.c:1853} (D5:AFPDaemon): CNID Server: localhost:4700
Feb 27 05:36:10.611963 cnid_dbd[22854] {netatalk_conf.c:1896} (D5:AFPDaemon): Global unix charset is UTF8
Feb 27 05:36:10.611977 cnid_dbd[22854] {netatalk_conf.c:1907} (D5:AFPDaemon): Global vol charset is UTF8
Feb 27 05:36:10.611991 cnid_dbd[22854] {netatalk_conf.c:1921} (D5:AFPDaemon): Global mac charset is MAC_ROMAN
Feb 27 05:36:10.612004 cnid_dbd[22854] {netatalk_conf.c:1227} (D5:AFPDaemon): readextmap: loading "/racktop/etc/extmap.conf"
Feb 27 05:36:10.612163 cnid_dbd[22854] {netatalk_conf.c:1248} (D5:AFPDaemon): readextmap: done
Feb 27 05:36:10.612182 cnid_dbd[22854] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:36:10.612199 cnid_dbd[22854] {netatalk_conf.c:1388} (D5:AFPDaemon): load_volumes: no volumes yet
Feb 27 05:36:10.612229 cnid_dbd[22854] {netatalk_conf.c:1413} (D5:AFPDaemon): load_volumes: loading: /racktop/etc/afp.conf
Feb 27 05:36:10.612296 cnid_dbd[22854] {netatalk_conf.c:1008} (D5:AFPDaemon): readvolfile: BEGIN
Feb 27 05:36:10.612314 cnid_dbd[22854] {netatalk_conf.c:1011} (D5:AFPDaemon): readvolfile: sections: 2
Feb 27 05:36:10.612353 cnid_dbd[22854] {netatalk_conf.c:582} (D5:AFPDaemon): createvol(volume: 'a01', path: "/shares/a01", preset: '-'): BEGIN
Feb 27 05:36:10.612385 cnid_dbd[22854] {netatalk_conf.c:256} (D5:AFPDaemon): Volume "/shares/a01" ACL support: yes
Feb 27 05:36:10.612465 cnid_dbd[22854] {vfs.c:852} (D5:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Feb 27 05:36:10.612482 cnid_dbd[22854] {netatalk_conf.c:961} (D5:AFPDaemon): createvol: END: 0
Feb 27 05:36:10.612495 cnid_dbd[22854] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:36:10.612509 cnid_dbd[22854] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:36:10.612529 cnid_dbd[22854] {main.c:526} (D5:CNID): db dir: "/racktop/var/netatalk/CNID//a01//.AppleDB"
Feb 27 05:36:10.612558 cnid_dbd[22854] {main.c:446} (D5:CNID): Setting uid/gid to 0/0
Feb 27 05:36:10.612614 cnid_dbd[22854] {main.c:112} (D5:CNID): get_lock(LOCK_EXCL, "/racktop/var/netatalk/CNID//a01//.AppleDB")
Feb 27 05:36:10.612660 cnid_dbd[22854] {main.c:167} (D5:CNID): get_lock: got LOCK_EXCL lock
Feb 27 05:36:10.612806 cnid_dbd[22854] {dbif.c:406} (D5:CNID): Running recovery
Feb 27 05:36:13.048649 afpd[22811] {cnid_dbd.c:331} (D5:CNID): dbd_rpc: Error reading header from fd (db_dir /shares/a01): closed
Feb 27 05:36:13.048840 cnid_metad[22048] {cnid_metad.c:525} (I:CNID): cnid_dbd[22854] got signal 11
Feb 27 05:36:14.049310 afpd[22811] {cnid_dbd.c:234} (D5:CNID): init_tsock: BEGIN. Opening volume '/shares/a01', CNID Server: localhost/4700
Feb 27 05:36:14.049979 afpd[22811] {cnid_dbd.c:253} (D5:CNID): init_tsock: ok
Feb 27 05:36:14.050023 afpd[22811] {cnid_dbd.c:370} (D5:CNID): transmit: attached to '/shares/a01'
Feb 27 05:36:14.050095 cnid_metad[22048] {cnid_metad.c:566} (D5:CNID): main: request for volume: /shares/a01
Feb 27 05:36:14.050123 cnid_metad[22048] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:36:14.050153 cnid_metad[22048] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:36:14.050191 cnid_metad[22048] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:36:14.050215 cnid_metad[22048] {cnid_metad.c:294} (D5:CNID): set_dbdir: volume: /shares/a01, db path: /racktop/var/netatalk/CNID//a01/
Feb 27 05:36:14.050282 cnid_metad[22048] {cnid_metad.c:169} (D5:CNID): maybe_start_dbd("/shares/a01"): BEGIN
Feb 27 05:36:14.050305 cnid_metad[22048] {cnid_metad.c:182} (D5:CNID): maybe_start_dbd: no cnid_dbd serving yet
Feb 27 05:36:14.061143 cnid_dbd[22855] {logger.c:357} (D5:Logger): Setup file logging: type: Default, level: DEBUG, file: /racktop/var/log/netatalk.log
Feb 27 05:36:14.061374 cnid_dbd[22855] {netatalk_conf.c:1853} (D5:AFPDaemon): CNID Server: localhost:4700
Feb 27 05:36:14.061397 cnid_dbd[22855] {netatalk_conf.c:1896} (D5:AFPDaemon): Global unix charset is UTF8
Feb 27 05:36:14.061410 cnid_dbd[22855] {netatalk_conf.c:1907} (D5:AFPDaemon): Global vol charset is UTF8
Feb 27 05:36:14.061410 cnid_dbd[22855] {netatalk_conf.c:1921} (D5:AFPDaemon): Global mac charset is MAC_ROMAN
Feb 27 05:36:14.061410 cnid_dbd[22855] {netatalk_conf.c:1227} (D5:AFPDaemon): readextmap: loading "/racktop/etc/extmap.conf"
Feb 27 05:36:14.061413 cnid_dbd[22855] {netatalk_conf.c:1248} (D5:AFPDaemon): readextmap: done
Feb 27 05:36:14.061413 cnid_dbd[22855] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:36:14.061414 cnid_dbd[22855] {netatalk_conf.c:1388} (D5:AFPDaemon): load_volumes: no volumes yet
Feb 27 05:36:14.061449 cnid_dbd[22855] {netatalk_conf.c:1413} (D5:AFPDaemon): load_volumes: loading: /racktop/etc/afp.conf
Feb 27 05:36:14.061519 cnid_dbd[22855] {netatalk_conf.c:1008} (D5:AFPDaemon): readvolfile: BEGIN
Feb 27 05:36:14.061550 cnid_dbd[22855] {netatalk_conf.c:1011} (D5:AFPDaemon): readvolfile: sections: 2
Feb 27 05:36:14.061592 cnid_dbd[22855] {netatalk_conf.c:582} (D5:AFPDaemon): createvol(volume: 'a01', path: "/shares/a01", preset: '-'): BEGIN
Feb 27 05:36:14.061739 cnid_dbd[22855] {netatalk_conf.c:256} (D5:AFPDaemon): Volume "/shares/a01" ACL support: yes
Feb 27 05:36:14.061830 cnid_dbd[22855] {vfs.c:852} (D5:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Feb 27 05:36:14.061850 cnid_dbd[22855] {netatalk_conf.c:961} (D5:AFPDaemon): createvol: END: 0
Feb 27 05:36:14.061866 cnid_dbd[22855] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:36:14.061883 cnid_dbd[22855] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:36:14.061906 cnid_dbd[22855] {main.c:526} (D5:CNID): db dir: "/racktop/var/netatalk/CNID//a01//.AppleDB"
Feb 27 05:36:14.062307 cnid_dbd[22855] {main.c:446} (D5:CNID): Setting uid/gid to 0/0
Feb 27 05:36:14.062519 cnid_dbd[22855] {main.c:112} (D5:CNID): get_lock(LOCK_EXCL, "/racktop/var/netatalk/CNID//a01//.AppleDB")
Feb 27 05:36:14.062568 cnid_dbd[22855] {main.c:167} (D5:CNID): get_lock: got LOCK_EXCL lock
Feb 27 05:36:14.062711 cnid_dbd[22855] {dbif.c:406} (D5:CNID): Running recovery
Feb 27 05:36:16.495760 afpd[22811] {cnid_dbd.c:331} (D5:CNID): dbd_rpc: Error reading header from fd (db_dir /shares/a01): closed
Feb 27 05:36:16.495900 cnid_metad[22048] {cnid_metad.c:525} (I:CNID): cnid_dbd[22855] got signal 11
Feb 27 05:36:17.505612 afpd[22811] {cnid_dbd.c:234} (D5:CNID): init_tsock: BEGIN. Opening volume '/shares/a01', CNID Server: localhost/4700
Feb 27 05:36:17.506017 afpd[22811] {cnid_dbd.c:253} (D5:CNID): init_tsock: ok
Feb 27 05:36:17.506059 afpd[22811] {cnid_dbd.c:370} (D5:CNID): transmit: attached to '/shares/a01'
Feb 27 05:36:17.506121 cnid_metad[22048] {cnid_metad.c:566} (D5:CNID): main: request for volume: /shares/a01
Feb 27 05:36:17.506149 cnid_metad[22048] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:36:17.506178 cnid_metad[22048] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:36:17.506214 cnid_metad[22048] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:36:17.506236 cnid_metad[22048] {cnid_metad.c:294} (D5:CNID): set_dbdir: volume: /shares/a01, db path: /racktop/var/netatalk/CNID//a01/
Feb 27 05:36:17.506496 cnid_metad[22048] {cnid_metad.c:169} (D5:CNID): maybe_start_dbd("/shares/a01"): BEGIN
Feb 27 05:36:17.506523 cnid_metad[22048] {cnid_metad.c:182} (D5:CNID): maybe_start_dbd: no cnid_dbd serving yet
Feb 27 05:36:17.515715 cnid_dbd[22856] {logger.c:357} (D5:Logger): Setup file logging: type: Default, level: DEBUG, file: /racktop/var/log/netatalk.log
Feb 27 05:36:17.515925 cnid_dbd[22856] {netatalk_conf.c:1853} (D5:AFPDaemon): CNID Server: localhost:4700
Feb 27 05:36:17.515945 cnid_dbd[22856] {netatalk_conf.c:1896} (D5:AFPDaemon): Global unix charset is UTF8
Feb 27 05:36:17.515968 cnid_dbd[22856] {netatalk_conf.c:1907} (D5:AFPDaemon): Global vol charset is UTF8
Feb 27 05:36:17.515983 cnid_dbd[22856] {netatalk_conf.c:1921} (D5:AFPDaemon): Global mac charset is MAC_ROMAN
Feb 27 05:36:17.515996 cnid_dbd[22856] {netatalk_conf.c:1227} (D5:AFPDaemon): readextmap: loading "/racktop/etc/extmap.conf"
Feb 27 05:36:17.516155 cnid_dbd[22856] {netatalk_conf.c:1248} (D5:AFPDaemon): readextmap: done
Feb 27 05:36:17.516173 cnid_dbd[22856] {netatalk_conf.c:1353} (D5:AFPDaemon): load_volumes: BEGIN
Feb 27 05:36:17.516189 cnid_dbd[22856] {netatalk_conf.c:1388} (D5:AFPDaemon): load_volumes: no volumes yet
Feb 27 05:36:17.516218 cnid_dbd[22856] {netatalk_conf.c:1413} (D5:AFPDaemon): load_volumes: loading: /racktop/etc/afp.conf
Feb 27 05:36:17.516282 cnid_dbd[22856] {netatalk_conf.c:1008} (D5:AFPDaemon): readvolfile: BEGIN
Feb 27 05:36:17.516300 cnid_dbd[22856] {netatalk_conf.c:1011} (D5:AFPDaemon): readvolfile: sections: 2
Feb 27 05:36:17.516339 cnid_dbd[22856] {netatalk_conf.c:582} (D5:AFPDaemon): createvol(volume: 'a01', path: "/shares/a01", preset: '-'): BEGIN
Feb 27 05:36:17.516530 cnid_dbd[22856] {netatalk_conf.c:256} (D5:AFPDaemon): Volume "/shares/a01" ACL support: yes
Feb 27 05:36:17.516617 cnid_dbd[22856] {vfs.c:852} (D5:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Feb 27 05:36:17.516635 cnid_dbd[22856] {netatalk_conf.c:961} (D5:AFPDaemon): createvol: END: 0
Feb 27 05:36:17.516649 cnid_dbd[22856] {netatalk_conf.c:1443} (D5:AFPDaemon): load_volumes: END
Feb 27 05:36:17.516663 cnid_dbd[22856] {netatalk_conf.c:1576} (D5:AFPDaemon): getvolbypath("/shares/a01")
Feb 27 05:36:17.516684 cnid_dbd[22856] {main.c:526} (D5:CNID): db dir: "/racktop/var/netatalk/CNID//a01//.AppleDB"
Feb 27 05:36:17.516715 cnid_dbd[22856] {main.c:446} (D5:CNID): Setting uid/gid to 0/0
Feb 27 05:36:17.516772 cnid_dbd[22856] {main.c:112} (D5:CNID): get_lock(LOCK_EXCL, "/racktop/var/netatalk/CNID//a01//.AppleDB")
Feb 27 05:36:17.516817 cnid_dbd[22856] {main.c:167} (D5:CNID): get_lock: got LOCK_EXCL lock
Feb 27 05:36:17.516959 cnid_dbd[22856] {dbif.c:406} (D5:CNID): Running recovery
Feb 27 05:36:19.983881 afpd[22811] {cnid_dbd.c:331} (D5:CNID): dbd_rpc: Error reading header from fd (db_dir /shares/a01): closed
Feb 27 05:36:19.983941 afpd[22811] {cnid_dbd.c:391} (E:CNID): transmit: Request to dbd daemon (db_dir /shares/a01) timed out.
Feb 27 05:36:19.984000 afpd[22811] {volume.c:862} (E:AFPDaemon): afp_openvol(/shares/a01): Fatal error: Unable to get stamp value from CNID backend
Feb 27 05:36:19.984024 afpd[22811] {cnid_dbd.c:492} (D5:CNID): closing database connection for volume '/shares/a01'
Feb 27 05:36:19.984040 afpd[22811] {afp_dsi.c:614} (D5:AFPDaemon): ==> Finished AFP command: AFP_OPENVOL -> AFPERR_MISC
Feb 27 05:36:19.984053 afpd[22811] {dsi_cmdreply.c:24} (D5:DSI): dsi_cmdreply(DSI ID: 7, len: 0): START
Feb 27 05:36:19.984138 afpd[22811] {dsi_cmdreply.c:33} (D5:DSI): dsi_cmdreply(DSI ID: 7, len: 0): END
Feb 27 05:36:19.984171 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:36:19.984188 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:36:19.984368 cnid_metad[22048] {cnid_metad.c:525} (I:CNID): cnid_dbd[22856] got signal 11
Feb 27 05:36:24.396636 afpd[22811] {dsi_stream.c:628} (D5:DSI): dsi_stream_receive: DSI cmdlen: 0
Feb 27 05:36:24.396696 afpd[22811] {afp_dsi.c:570} (D5:AFPDaemon): DSI: client tickle
Feb 27 05:36:24.396712 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Feb 27 05:36:24.396726 afpd[22811] {dsi_stream.c:162} (D5:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0