Netatalk

From PGWiki

Netatalk애플 파일링 프로토콜 서버를 구현하는 오픈소스 프로젝트다.


로그인 과정 분석(추후 위키로그로 이동)

Mar 18 18:40:36.086296 afpd[29370] {status.c:363} (info:AFPDaemon): servername: VM7SET6-1
Mar 18 18:40:36.086309 afpd[29370] {afp_config.c:198} (note:AFPDaemon): Netatalk AFP/TCP listening on 10.238.3.20:548
Mar 18 18:40:36.086322 afpd[29370] {ldap_config.c:84} (debug:AFPDaemon): LDAP: Missing option: "ldap server"
Mar 18 18:40:36.086327 afpd[29370] {ldap_config.c:101} (info:AFPDaemon): LDAP: not used
Mar 18 18:40:36.086332 afpd[29370] {afp_config.c:215} (note:AFPDaemon): Fce events: login
Mar 18 18:40:36.086340 afpd[29370] {afp_config.c:219} (debug:AFPDaemon): Fce version: 2
Mar 18 18:40:36.086352 afpd[29370] {cnid.c:55} (info:AFPDaemon): Registering CNID module [last]
Mar 18 18:40:36.086356 afpd[29370] {cnid.c:55} (info:AFPDaemon): Registering CNID module [dbd]
Mar 18 18:40:36.086360 afpd[29370] {cnid.c:55} (info:AFPDaemon): Registering CNID module [tdb]
Mar 18 18:40:36.086364 afpd[29370] {cnid.c:55} (info:AFPDaemon): Registering CNID module [mysql]
Mar 18 18:41:24.442984 afpd[29370] {main.c:151} (info:AFPDaemon): child[31180]: done
Mar 18 18:41:27.148182 afpd[29370] {main.c:440} (debug:AFPDaemon): main: IPC request from child[31253]
Mar 18 18:41:27.148503 afpd[31253] {netatalk_conf.c:1596} (debug:AFPDaemon): unload_volumes: BEGIN
Mar 18 18:41:27.148754 afpd[31253] {netatalk_conf.c:1609} (debug:AFPDaemon): unload_volumes: END
Mar 18 18:41:27.148803 afpd[31253] {dircache.c:575} (debug:AFPDaemon): dircache_init: done. max dircache size: 8192
Mar 18 18:41:27.148847 afpd[31253] {server_ipc.c:299} (debug:AFPDaemon): ipc_child_write(IPC_STATE)
Mar 18 18:41:27.148920 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGIN_EXT
Mar 18 18:41:27.148928 afpd[29370] {main.c:440} (debug:AFPDaemon): main: IPC request from child[31253]
Mar 18 18:41:27.148965 afpd[29370] {server_ipc.c:217} (debug:AFPDaemon): ipc_server_read(IPC_STATE): pid: 31253
Mar 18 18:41:27.151417 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_LOGIN_EXT -> AFPERR_AUTHCONT
Mar 18 18:41:27.161841 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGINCONT
Mar 18 18:41:27.165475 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_LOGINCONT -> AFPERR_AUTHCONT
Mar 18 18:41:27.166061 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGINCONT
Mar 18 18:41:27.206021 afpd[31253] {auth.c:235} (note:AFPDaemon): Login by user1 (AFP3.4)
Mar 18 18:41:27.206315 afpd[31253] {auth.c:240} (debug:AFPDaemon): obj->options.admingid == 0
Mar 18 18:41:27.206339 afpd[31253] {auth.c:275} (debug:AFPDaemon): login: supplementary groups:  100
Mar 18 18:41:27.206452 afpd[31253] {afprun.c:274} (debug:AFPDaemon): running /root/fce_ev_script.sh -v 2 -e FCE_CONN_START -i 0 -p 31253 -u user1 as user 0
Mar 18 18:41:27.207143 afpd[31253] {afprun.c:274} (debug:AFPDaemon): running /root/fce_ev_script.sh -v 2 -e FCE_LOGIN -i 1 -p 31253 -u user1 as user 0
Mar 18 18:41:27.207626 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_LOGINCONT -> AFP_OK
Mar 18 18:41:27.208550 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETUSERINFO
Mar 18 18:41:27.208578 afpd[31253] {auth.c:900} (debug:AFPDaemon): begin afp_getuserinfo:
Mar 18 18:41:27.208585 afpd[31253] {auth.c:960} (debug:AFPDaemon): END afp_getuserinfo:
Mar 18 18:41:27.208590 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETUSERINFO -> AFP_OK
Mar 18 18:41:27.208982 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETSRVPARAM
Mar 18 18:41:27.209001 afpd[31253] {netatalk_conf.c:1490} (debug:AFPDaemon): load_volumes: BEGIN
Mar 18 18:41:27.209058 afpd[31253] {netatalk_conf.c:1525} (debug:AFPDaemon): load_volumes: no volumes yet
Mar 18 18:41:27.218502 afpd[31253] {netatalk_conf.c:1557} (debug:AFPDaemon): load_volumes: loading: /etc/netatalk//afp.conf
Mar 18 18:41:27.219379 afpd[31253] {netatalk_conf.c:1138} (debug:AFPDaemon): readvolfile: BEGIN
Mar 18 18:41:27.219401 afpd[31253] {netatalk_conf.c:1141} (debug:AFPDaemon): readvolfile: sections: 2
Mar 18 18:41:27.221406 afpd[31253] {netatalk_conf.c:614} (debug:AFPDaemon): creatvol(volume: 'test_share', path: "/export/test_share", preset: '-'): BEGIN
Mar 18 18:41:27.221504 afpd[31253] {netatalk_conf.c:963} (maxdebug:AFPDaemon): creatvol: Volume 'test_share' -> UTF8-MAC Name: 'test_share'
Mar 18 18:41:27.221547 afpd[31253] {netatalk_conf.c:1001} (maxdebug:AFPDaemon): creatvol: Volume 'test_share' ->  Longname: 'test_share'
Mar 18 18:41:27.221916 afpd[31253] {netatalk_conf.c:256} (debug:AFPDaemon): Volume "/export/test_share" ACL support: yes
Mar 18 18:41:27.222176 afpd[31253] {vfs.c:868} (debug:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Mar 18 18:41:27.222237 afpd[31253] {netatalk_conf.c:115} (debug:AFPDaemon): get_uuid('test_share'): UUID: '2A6CBB68-C6ED-5C07-BB47-C5E92DAB0BCC'
Mar 18 18:41:27.222270 afpd[31253] {netatalk_conf.c:1047} (debug:AFPDaemon): Volume 'test_share': UUID '2A6CBB68-C6ED-5C07-BB47-C5E92DAB0BCC'
Mar 18 18:41:27.222287 afpd[31253] {netatalk_conf.c:1056} (debug:AFPDaemon): creatvol: END: 0
Mar 18 18:41:27.222427 afpd[31253] {netatalk_conf.c:1588} (debug:AFPDaemon): load_volumes: END
Mar 18 18:41:27.222470 afpd[31253] {acls.c:1783} (maxdebug:AFPDaemon): acltoownermode("///export/test_share", 0x87)
Mar 18 18:41:27.222762 afpd[31253] {acls.c:621} (maxdebug:AFPDaemon): ACL_GROUP_OBJ: 0
Mar 18 18:41:27.222783 afpd[31253] {acls.c:639} (maxdebug:AFPDaemon): ACL_MASK: 0x07
Mar 18 18:41:27.222789 afpd[31253] {acls.c:1796} (maxdebug:AFPDaemon): resulting user maccess: 0x87 group maccess: 0x07
Mar 18 18:41:27.222804 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETSRVPARAM -> AFP_OK
Mar 18 18:41:27.224064 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETSRVPARAM
Mar 18 18:41:27.224092 afpd[31253] {netatalk_conf.c:1490} (debug:AFPDaemon): load_volumes: BEGIN
Mar 18 18:41:27.224169 afpd[31253] {netatalk_conf.c:1588} (debug:AFPDaemon): load_volumes: END
Mar 18 18:41:27.224186 afpd[31253] {acls.c:1783} (maxdebug:AFPDaemon): acltoownermode("///export/test_share", 0x87)
Mar 18 18:41:27.224441 afpd[31253] {acls.c:621} (maxdebug:AFPDaemon): ACL_GROUP_OBJ: 0
Mar 18 18:41:27.224464 afpd[31253] {acls.c:639} (maxdebug:AFPDaemon): ACL_MASK: 0x07
Mar 18 18:41:27.224473 afpd[31253] {acls.c:1796} (maxdebug:AFPDaemon): resulting user maccess: 0x87 group maccess: 0x07
Mar 18 18:41:27.224488 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETSRVPARAM -> AFP_OK
Mar 18 18:41:27.226264 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_OPENVOL
Mar 18 18:41:27.226289 afpd[31253] {netatalk_conf.c:1490} (debug:AFPDaemon): load_volumes: BEGIN
Mar 18 18:41:27.226335 afpd[31253] {netatalk_conf.c:1588} (debug:AFPDaemon): load_volumes: END
Mar 18 18:41:27.226401 afpd[31253] {volume.c:309} (debug:AFPDaemon): getvolparams: Volume 'test_share'
Mar 18 18:41:27.228919 cnid_metad[29371] {netatalk_conf.c:1490} (debug:AFPDaemon): load_volumes: BEGIN
Mar 18 18:41:27.228960 cnid_metad[29371] {netatalk_conf.c:1525} (debug:AFPDaemon): load_volumes: no volumes yet
Mar 18 18:41:27.233299 cnid_metad[29371] {netatalk_conf.c:1557} (debug:AFPDaemon): load_volumes: loading: /etc/netatalk//afp.conf
Mar 18 18:41:27.233975 cnid_metad[29371] {netatalk_conf.c:1138} (debug:AFPDaemon): readvolfile: BEGIN
Mar 18 18:41:27.233999 cnid_metad[29371] {netatalk_conf.c:1141} (debug:AFPDaemon): readvolfile: sections: 2
Mar 18 18:41:27.234030 cnid_metad[29371] {netatalk_conf.c:614} (debug:AFPDaemon): creatvol(volume: 'test_share', path: "/export/test_share", preset: '-'): BEGIN
Mar 18 18:41:27.234112 cnid_metad[29371] {netatalk_conf.c:963} (maxdebug:AFPDaemon): creatvol: Volume 'test_share' -> UTF8-MAC Name: 'test_share'
Mar 18 18:41:27.234127 cnid_metad[29371] {netatalk_conf.c:1001} (maxdebug:AFPDaemon): creatvol: Volume 'test_share' ->  Longname: 'test_share'
Mar 18 18:41:27.234772 cnid_metad[29371] {netatalk_conf.c:256} (debug:AFPDaemon): Volume "/export/test_share" ACL support: yes
Mar 18 18:41:27.235228 cnid_metad[29371] {vfs.c:868} (debug:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Mar 18 18:41:27.235272 cnid_metad[29371] {netatalk_conf.c:115} (debug:AFPDaemon): get_uuid('test_share'): UUID: '2A6CBB68-C6ED-5C07-BB47-C5E92DAB0BCC'
Mar 18 18:41:27.235294 cnid_metad[29371] {netatalk_conf.c:1047} (debug:AFPDaemon): Volume 'test_share': UUID '2A6CBB68-C6ED-5C07-BB47-C5E92DAB0BCC'
Mar 18 18:41:27.235302 cnid_metad[29371] {netatalk_conf.c:1056} (debug:AFPDaemon): creatvol: END: 0
Mar 18 18:41:27.235413 cnid_metad[29371] {netatalk_conf.c:1588} (debug:AFPDaemon): load_volumes: END
Mar 18 18:41:27.235425 cnid_metad[29371] {netatalk_conf.c:1724} (debug:AFPDaemon): getvolbypath("/export/test_share")
Mar 18 18:41:27.235435 cnid_metad[29371] {netatalk_conf.c:1753} (debug:AFPDaemon): getvolbypath: path("/export/test_share") == volume("/export/test_share")
Mar 18 18:41:27.236688 cnid_metad[29371] {netatalk_conf.c:1596} (debug:AFPDaemon): unload_volumes: BEGIN
Mar 18 18:41:27.236736 cnid_metad[29371] {netatalk_conf.c:1609} (debug:AFPDaemon): unload_volumes: END
Mar 18 18:41:27.242675 cnid_dbd[31258] {netatalk_conf.c:2050} (debug:AFPDaemon): CNID Server: localhost:4700
Mar 18 18:41:27.242742 cnid_dbd[31258] {netatalk_conf.c:2093} (debug:AFPDaemon): Global unix charset is UTF8
Mar 18 18:41:27.242752 cnid_dbd[31258] {netatalk_conf.c:2104} (debug:AFPDaemon): Global vol charset is UTF8
Mar 18 18:41:27.242769 cnid_dbd[31258] {netatalk_conf.c:2118} (debug:AFPDaemon): Global mac charset is MAC_ROMAN
Mar 18 18:41:27.242775 cnid_dbd[31258] {netatalk_conf.c:1362} (debug:AFPDaemon): readextmap: loading "/etc/netatalk//extmap.conf"
Mar 18 18:41:27.243554 cnid_dbd[31258] {netatalk_conf.c:1383} (debug:AFPDaemon): readextmap: done
Mar 18 18:41:27.243782 cnid_dbd[31258] {netatalk_conf.c:1490} (debug:AFPDaemon): load_volumes: BEGIN
Mar 18 18:41:27.243805 cnid_dbd[31258] {netatalk_conf.c:1525} (debug:AFPDaemon): load_volumes: no volumes yet
Mar 18 18:41:27.244823 cnid_dbd[31258] {netatalk_conf.c:1557} (debug:AFPDaemon): load_volumes: loading: /etc/netatalk//afp.conf
Mar 18 18:41:27.245439 cnid_dbd[31258] {netatalk_conf.c:1138} (debug:AFPDaemon): readvolfile: BEGIN
Mar 18 18:41:27.245466 cnid_dbd[31258] {netatalk_conf.c:1141} (debug:AFPDaemon): readvolfile: sections: 2
Mar 18 18:41:27.245501 cnid_dbd[31258] {netatalk_conf.c:614} (debug:AFPDaemon): creatvol(volume: 'test_share', path: "/export/test_share", preset: '-'): BEGIN
Mar 18 18:41:27.245615 cnid_dbd[31258] {netatalk_conf.c:963} (maxdebug:AFPDaemon): creatvol: Volume 'test_share' -> UTF8-MAC Name: 'test_share'
Mar 18 18:41:27.245643 cnid_dbd[31258] {netatalk_conf.c:1001} (maxdebug:AFPDaemon): creatvol: Volume 'test_share' ->  Longname: 'test_share'
Mar 18 18:41:27.246196 cnid_dbd[31258] {netatalk_conf.c:256} (debug:AFPDaemon): Volume "/export/test_share" ACL support: yes
Mar 18 18:41:27.246488 cnid_dbd[31258] {vfs.c:868} (debug:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Mar 18 18:41:27.246538 cnid_dbd[31258] {netatalk_conf.c:115} (debug:AFPDaemon): get_uuid('test_share'): UUID: '2A6CBB68-C6ED-5C07-BB47-C5E92DAB0BCC'
Mar 18 18:41:27.246564 cnid_dbd[31258] {netatalk_conf.c:1047} (debug:AFPDaemon): Volume 'test_share': UUID '2A6CBB68-C6ED-5C07-BB47-C5E92DAB0BCC'
Mar 18 18:41:27.246581 cnid_dbd[31258] {netatalk_conf.c:1056} (debug:AFPDaemon): creatvol: END: 0
Mar 18 18:41:27.246695 cnid_dbd[31258] {netatalk_conf.c:1588} (debug:AFPDaemon): load_volumes: END
Mar 18 18:41:27.246706 cnid_dbd[31258] {netatalk_conf.c:1724} (debug:AFPDaemon): getvolbypath("/export/test_share")
Mar 18 18:41:27.246719 cnid_dbd[31258] {netatalk_conf.c:1753} (debug:AFPDaemon): getvolbypath: path("/export/test_share") == volume("/export/test_share")
Mar 18 18:41:27.916440 afpd[31253] {server_ipc.c:299} (debug:AFPDaemon): ipc_child_write(IPC_VOLUMES)
Mar 18 18:41:27.916472 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_OPENVOL -> AFP_OK
Mar 18 18:41:27.916524 afpd[29370] {main.c:440} (debug:AFPDaemon): main: IPC request from child[31253]
Mar 18 18:41:27.916543 afpd[29370] {server_ipc.c:217} (debug:AFPDaemon): ipc_server_read(IPC_VOLUMES): pid: 31253
Mar 18 18:41:27.917178 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETFLDRPARAM
Mar 18 18:41:27.917203 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.917210 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.917217 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.917234 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.917242 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.917312 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.'}
Mar 18 18:41:27.917326 afpd[31253] {filedir.c:83} (debug:AFPDaemon): getfildirparams(vid:1, did:2, f/d:0000/2000) {cwdid:2, cwd: /export/test_share, name:'.'}
Mar 18 18:41:27.917334 afpd[31253] {ofork.c:289} (debug:AFPDaemon): of_statdir: stating: '../test_share'
Mar 18 18:41:27.917344 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETFLDRPARAM -> AFP_OK
Mar 18 18:41:27.918942 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETUSERINFO
Mar 18 18:41:27.918978 afpd[31253] {auth.c:900} (debug:AFPDaemon): begin afp_getuserinfo:
Mar 18 18:41:27.918989 afpd[31253] {auth.c:944} (debug:AFPDaemon): afp_getuserinfo: get UUID for 'user1'
Mar 18 18:41:27.919008 afpd[31253] {uuid.c:176} (debug:AFPDaemon): getuuidfromname("user1",t:1): no result from ldap search
Mar 18 18:41:27.919074 afpd[31253] {uuid.c:123} (debug:AFPDaemon): uuid_bin2string{uuid}: mask: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
Mar 18 18:41:27.919108 afpd[31253] {uuid.c:192} (debug:AFPDaemon): getuuidfromname{local}: name: user1, type: USER -> UUID: FFFFEEEE-DDDD-CCCC-BBBB-AAAA000003E8
Mar 18 18:41:27.919121 afpd[31253] {uuid.c:123} (debug:AFPDaemon): uuid_bin2string{uuid}: mask: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
Mar 18 18:41:27.919133 afpd[31253] {auth.c:952} (debug:AFPDaemon): afp_getuserinfo: got UUID: FFFFEEEE-DDDD-CCCC-BBBB-AAAA000003E8
Mar 18 18:41:27.919143 afpd[31253] {auth.c:960} (debug:AFPDaemon): END afp_getuserinfo:
Mar 18 18:41:27.919151 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETUSERINFO -> AFP_OK
Mar 18 18:41:27.920290 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETSRVPARAM
Mar 18 18:41:27.920318 afpd[31253] {netatalk_conf.c:1490} (debug:AFPDaemon): load_volumes: BEGIN
Mar 18 18:41:27.920400 afpd[31253] {netatalk_conf.c:1588} (debug:AFPDaemon): load_volumes: END
Mar 18 18:41:27.920421 afpd[31253] {acls.c:1783} (maxdebug:AFPDaemon): acltoownermode("/export/test_share//export/test_share", 0x87)
Mar 18 18:41:27.921036 afpd[31253] {acls.c:621} (maxdebug:AFPDaemon): ACL_GROUP_OBJ: 0
Mar 18 18:41:27.921061 afpd[31253] {acls.c:639} (maxdebug:AFPDaemon): ACL_MASK: 0x07
Mar 18 18:41:27.921070 afpd[31253] {acls.c:1796} (maxdebug:AFPDaemon): resulting user maccess: 0x87 group maccess: 0x07
Mar 18 18:41:27.921095 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETSRVPARAM -> AFP_OK
Mar 18 18:41:27.921721 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETVOLPARAM
Mar 18 18:41:27.921748 afpd[31253] {volume.c:309} (debug:AFPDaemon): getvolparams: Volume 'test_share'
Mar 18 18:41:27.955312 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETVOLPARAM -> AFP_OK
Mar 18 18:41:27.957261 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETFLDRPARAM
Mar 18 18:41:27.957294 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.957303 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.957309 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.957318 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.957323 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.957883 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.'}
Mar 18 18:41:27.957916 afpd[31253] {filedir.c:83} (debug:AFPDaemon): getfildirparams(vid:1, did:2, f/d:0000/0020) {cwdid:2, cwd: /export/test_share, name:'.'}
Mar 18 18:41:27.957924 afpd[31253] {ofork.c:289} (debug:AFPDaemon): of_statdir: stating: '../test_share'
Mar 18 18:41:27.958318 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETFLDRPARAM -> AFP_OK
Mar 18 18:41:27.958769 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETSESSTOKEN
Mar 18 18:41:27.958789 afpd[31253] {server_ipc.c:299} (debug:AFPDaemon): ipc_child_write(IPC_GETSESSION)
Mar 18 18:41:27.958805 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETSESSTOKEN -> AFP_OK
Mar 18 18:41:27.958838 afpd[29370] {main.c:440} (debug:AFPDaemon): main: IPC request from child[31253]
Mar 18 18:41:27.958853 afpd[29370] {server_ipc.c:217} (debug:AFPDaemon): ipc_server_read(IPC_GETSESSION): pid: 31253
Mar 18 18:41:27.958859 afpd[29370] {server_ipc.c:98} (debug:AFPDaemon): ipc_get_session(pid: 31253, uid: 1000, time: 0x5c8f67c7)
Mar 18 18:41:27.959243 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETFLDRPARAM
Mar 18 18:41:27.959255 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.959260 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.959265 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.959272 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.959277 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.959851 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.'}
Mar 18 18:41:27.959866 afpd[31253] {filedir.c:83} (debug:AFPDaemon): getfildirparams(vid:1, did:2, f/d:e93f/a33f) {cwdid:2, cwd: /export/test_share, name:'.'}
Mar 18 18:41:27.959872 afpd[31253] {ofork.c:289} (debug:AFPDaemon): of_statdir: stating: '../test_share'
Mar 18 18:41:27.960226 afpd[31253] {directory.c:1498} (debug:AFPDaemon): metadata('.'):     Parent DID: 1
Mar 18 18:41:27.960242 afpd[31253] {directory.c:1552} (debug:AFPDaemon): metadata('.'):            DID: 2
Mar 18 18:41:27.961611 afpd[31253] {acls.c:1783} (maxdebug:AFPDaemon): acltoownermode("/export/test_share/.", 0x87)
Mar 18 18:41:27.961938 afpd[31253] {acls.c:621} (maxdebug:AFPDaemon): ACL_GROUP_OBJ: 0
Mar 18 18:41:27.961951 afpd[31253] {acls.c:639} (maxdebug:AFPDaemon): ACL_MASK: 0x07
Mar 18 18:41:27.961971 afpd[31253] {acls.c:1796} (maxdebug:AFPDaemon): resulting user maccess: 0x87 group maccess: 0x07
Mar 18 18:41:27.961979 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETFLDRPARAM -> AFP_OK
Mar 18 18:41:27.963536 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETSRVPARAM
Mar 18 18:41:27.963560 afpd[31253] {netatalk_conf.c:1490} (debug:AFPDaemon): load_volumes: BEGIN
Mar 18 18:41:27.963620 afpd[31253] {netatalk_conf.c:1588} (debug:AFPDaemon): load_volumes: END
Mar 18 18:41:27.963687 afpd[31253] {acls.c:1783} (maxdebug:AFPDaemon): acltoownermode("/export/test_share//export/test_share", 0x87)
Mar 18 18:41:27.964044 afpd[31253] {acls.c:621} (maxdebug:AFPDaemon): ACL_GROUP_OBJ: 0
Mar 18 18:41:27.964067 afpd[31253] {acls.c:639} (maxdebug:AFPDaemon): ACL_MASK: 0x07
Mar 18 18:41:27.964078 afpd[31253] {acls.c:1796} (maxdebug:AFPDaemon): resulting user maccess: 0x87 group maccess: 0x07
Mar 18 18:41:27.964092 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETSRVPARAM -> AFP_OK
Mar 18 18:41:27.967066 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETFLDRPARAM
Mar 18 18:41:27.967098 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.967108 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.967115 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.967126 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.967133 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.967609 afpd[31253] {directory.c:341} (maxdebug:AFPDaemon): cname_mtouname('DCIM',did:2) {demangled:'DCIM', fileid:0}
Mar 18 18:41:27.967634 afpd[31253] {directory.c:1168} (maxdebug:AFPDaemon): came('/export/test_share'): {node: 'DCIM}
Mar 18 18:41:27.968780 afpd[31253] {ofork.c:242} (debug:AFPDaemon): of_stat('/export/test_share/DCIM': No such file or directory)
Mar 18 18:41:27.968835 afpd[31253] {directory.c:1220} (maxdebug:AFPDaemon): came('/export/test_share'): {leave-cnode ENOENT (possile create request): 'DCIM'}
Mar 18 18:41:27.968853 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'DCIM'}
Mar 18 18:41:27.968864 afpd[31253] {filedir.c:83} (debug:AFPDaemon): getfildirparams(vid:1, did:2, f/d:e93f/a33f) {cwdid:2, cwd: /export/test_share, name:'DCIM'}
Mar 18 18:41:27.968873 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETFLDRPARAM -> AFPERR_NOOBJ
Mar 18 18:41:27.969345 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETFLDRPARAM
Mar 18 18:41:27.969361 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.969367 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.969372 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.969381 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.969387 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.969423 afpd[31253] {directory.c:341} (maxdebug:AFPDaemon): cname_mtouname('.Spotlight-V100',did:2) {demangled:'.Spotlight-V100', fileid:0}
Mar 18 18:41:27.969461 afpd[31253] {directory.c:1168} (maxdebug:AFPDaemon): came('/export/test_share'): {node: '.Spotlight-V100}
Mar 18 18:41:27.970068 afpd[31253] {ofork.c:242} (debug:AFPDaemon): of_stat('/export/test_share/.Spotlight-V100': No such file or directory)
Mar 18 18:41:27.970088 afpd[31253] {directory.c:1220} (maxdebug:AFPDaemon): came('/export/test_share'): {leave-cnode ENOENT (possile create request): '.Spotlight-V100'}
Mar 18 18:41:27.970103 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.Spotlight-V100'}
Mar 18 18:41:27.970109 afpd[31253] {filedir.c:83} (debug:AFPDaemon): getfildirparams(vid:1, did:2, f/d:e93f/a33f) {cwdid:2, cwd: /export/test_share, name:'.Spotlight-V100'}
Mar 18 18:41:27.970115 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETFLDRPARAM -> AFPERR_NOOBJ
Mar 18 18:41:27.971679 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETFLDRPARAM
Mar 18 18:41:27.971710 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.971721 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.971735 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.971746 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.971757 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.971804 afpd[31253] {directory.c:341} (maxdebug:AFPDaemon): cname_mtouname('.metadata_never_index',did:2) {demangled:'.metadata_never_index', fileid:0}
Mar 18 18:41:27.971830 afpd[31253] {directory.c:1168} (maxdebug:AFPDaemon): came('/export/test_share'): {node: '.metadata_never_index}
Mar 18 18:41:27.972573 afpd[31253] {ofork.c:242} (debug:AFPDaemon): of_stat('/export/test_share/.metadata_never_index': No such file or directory)
Mar 18 18:41:27.972600 afpd[31253] {directory.c:1220} (maxdebug:AFPDaemon): came('/export/test_share'): {leave-cnode ENOENT (possile create request): '.metadata_never_index'}
Mar 18 18:41:27.972616 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.metadata_never_index'}
Mar 18 18:41:27.972627 afpd[31253] {filedir.c:83} (debug:AFPDaemon): getfildirparams(vid:1, did:2, f/d:e93f/a33f) {cwdid:2, cwd: /export/test_share, name:'.metadata_never_index'}
Mar 18 18:41:27.972637 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETFLDRPARAM -> AFPERR_NOOBJ
Mar 18 18:41:27.972953 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETFLDRPARAM
Mar 18 18:41:27.972969 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.972977 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.972986 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.972996 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.973005 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.973048 afpd[31253] {directory.c:341} (maxdebug:AFPDaemon): cname_mtouname('.metadata_never_index_unless_rootfs',did:2) {demangled:'.metadata_never_index_unless_rootfs', fileid:0}
Mar 18 18:41:27.973062 afpd[31253] {directory.c:1168} (maxdebug:AFPDaemon): came('/export/test_share'): {node: '.metadata_never_index_unless_rootfs}
Mar 18 18:41:27.974350 afpd[31253] {ofork.c:242} (debug:AFPDaemon): of_stat('/export/test_share/.metadata_never_index_unless_rootfs': No such file or directory)
Mar 18 18:41:27.974379 afpd[31253] {directory.c:1220} (maxdebug:AFPDaemon): came('/export/test_share'): {leave-cnode ENOENT (possile create request): '.metadata_never_index_unless_rootfs'}
Mar 18 18:41:27.974396 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.metadata_never_index_unless_rootfs'}
Mar 18 18:41:27.974409 afpd[31253] {filedir.c:83} (debug:AFPDaemon): getfildirparams(vid:1, did:2, f/d:e93f/a33f) {cwdid:2, cwd: /export/test_share, name:'.metadata_never_index_unless_rootfs'}
Mar 18 18:41:27.974420 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETFLDRPARAM -> AFPERR_NOOBJ
Mar 18 18:41:27.980020 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETFLDRPARAM
Mar 18 18:41:27.980063 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.980075 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.980085 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.980097 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.980106 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.980176 afpd[31253] {directory.c:341} (maxdebug:AFPDaemon): cname_mtouname('.localized',did:2) {demangled:'.localized', fileid:0}
Mar 18 18:41:27.980192 afpd[31253] {directory.c:1168} (maxdebug:AFPDaemon): came('/export/test_share'): {node: '.localized}
Mar 18 18:41:27.980965 afpd[31253] {ofork.c:242} (debug:AFPDaemon): of_stat('/export/test_share/.localized': No such file or directory)
Mar 18 18:41:27.980987 afpd[31253] {directory.c:1220} (maxdebug:AFPDaemon): came('/export/test_share'): {leave-cnode ENOENT (possile create request): '.localized'}
Mar 18 18:41:27.980993 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.localized'}
Mar 18 18:41:27.981001 afpd[31253] {filedir.c:83} (debug:AFPDaemon): getfildirparams(vid:1, did:2, f/d:e93f/a33f) {cwdid:2, cwd: /export/test_share, name:'.localized'}
Mar 18 18:41:27.981022 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETFLDRPARAM -> AFPERR_NOOBJ
Mar 18 18:41:27.981452 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETFLDRPARAM
Mar 18 18:41:27.981467 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.981472 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.981477 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.981484 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.981489 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.981544 afpd[31253] {directory.c:341} (maxdebug:AFPDaemon): cname_mtouname('.DS_Store',did:2) {demangled:'.DS_Store', fileid:0}
Mar 18 18:41:27.981563 afpd[31253] {directory.c:1168} (maxdebug:AFPDaemon): came('/export/test_share'): {node: '.DS_Store}
Mar 18 18:41:27.981571 afpd[31253] {directory.c:1227} (debug:AFPDaemon): came('/export/test_share'): {file: '.DS_Store'}
Mar 18 18:41:27.981577 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.DS_Store'}
Mar 18 18:41:27.981584 afpd[31253] {filedir.c:83} (debug:AFPDaemon): getfildirparams(vid:1, did:2, f/d:e93f/a33f) {cwdid:2, cwd: /export/test_share, name:'.DS_Store'}
Mar 18 18:41:27.981597 afpd[31253] {file.c:625} (debug:AFPDaemon): getfilparams(".DS_Store")
Mar 18 18:41:27.982897 afpd[31253] {file.c:308} (debug:AFPDaemon): getmetadata(".DS_Store")
Mar 18 18:41:27.982920 afpd[31253] {dircache.c:385} (debug:AFPDaemon): dircache_search_by_name(did:2, ".DS_Store")
Mar 18 18:41:27.982927 afpd[31253] {dircache.c:418} (debug:AFPDaemon): dircache(did:2,".DS_Store"): {not in cache}
Mar 18 18:41:27.983656 afpd[31253] {file.c:328} (debug:AFPDaemon): getmetadata: caching: did:2, ".DS_Store", cnid:17
Mar 18 18:41:27.983688 afpd[31253] {dircache.c:494} (debug:AFPDaemon): dircache(did:17,'.DS_Store'): {added}
Mar 18 18:41:27.983697 afpd[31253] {file.c:398} (debug:AFPDaemon): metadata('.DS_Store'): AFP Attributes: 0001
Mar 18 18:41:27.983702 afpd[31253] {file.c:405} (debug:AFPDaemon): metadata('.DS_Store'):     Parent DID: 2
Mar 18 18:41:27.983714 afpd[31253] {file.c:453} (debug:AFPDaemon): metadata('.DS_Store'):           CNID: 17
Mar 18 18:41:27.983726 afpd[31253] {acls.c:1783} (maxdebug:AFPDaemon): acltoownermode("/export/test_share/.DS_Store", 0x87)
Mar 18 18:41:27.983886 afpd[31253] {acls.c:621} (maxdebug:AFPDaemon): ACL_GROUP_OBJ: 100
Mar 18 18:41:27.983906 afpd[31253] {acls.c:1796} (maxdebug:AFPDaemon): resulting user maccess: 0x87 group maccess: 0x03
Mar 18 18:41:27.984139 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETFLDRPARAM -> AFP_OK
Mar 18 18:41:27.984728 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_OPENFORK
Mar 18 18:41:27.984762 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.984769 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.984775 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.984782 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.984787 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.984822 afpd[31253] {directory.c:341} (maxdebug:AFPDaemon): cname_mtouname('.DS_Store',did:2) {demangled:'.DS_Store', fileid:0}
Mar 18 18:41:27.984851 afpd[31253] {directory.c:1168} (maxdebug:AFPDaemon): came('/export/test_share'): {node: '.DS_Store}
Mar 18 18:41:27.984862 afpd[31253] {directory.c:1227} (debug:AFPDaemon): came('/export/test_share'): {file: '.DS_Store'}
Mar 18 18:41:27.984869 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.DS_Store'}
Mar 18 18:41:27.984876 afpd[31253] {acls.c:1783} (maxdebug:AFPDaemon): acltoownermode("/export/test_share/.DS_Store", 0x87)
Mar 18 18:41:27.984954 afpd[31253] {acls.c:621} (maxdebug:AFPDaemon): ACL_GROUP_OBJ: 100
Mar 18 18:41:27.984964 afpd[31253] {acls.c:1796} (maxdebug:AFPDaemon): resulting user maccess: 0x87 group maccess: 0x03
Mar 18 18:41:27.984971 afpd[31253] {directory.c:1384} (debug:AFPDaemon): file_access(".DS_Store"): mapped user mode: 0x87
Mar 18 18:41:27.985016 afpd[31253] {fork.c:359} (debug:AFPDaemon): afp_openfork("/export/test_share/.DS_Store", data, O_RDONLY)
Mar 18 18:41:27.985940 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.985963 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.985976 afpd[31253] {file.c:308} (debug:AFPDaemon): getmetadata(".DS_Store")
Mar 18 18:41:27.986639 afpd[31253] {fork.c:496} (debug:AFPDaemon): afp_openfork("/export/test_share/.DS_Store"): fork: 1
Mar 18 18:41:27.986664 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_OPENFORK -> AFP_OK
Mar 18 18:41:27.986700 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_SPOTLIGHT_PRIVATE
Mar 18 18:41:27.986723 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_SPOTLIGHT_PRIVATE -> AFPERR_NOOP
Mar 18 18:41:27.987065 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_READ_EXT
Mar 18 18:41:27.987095 afpd[31253] {fork.c:829} (debug:AFPDaemon): afp_read(fork: 1 [data], off: 0, len: 8196, size: 8196)
Mar 18 18:41:27.987140 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_READ_EXT -> AFP_OK
Mar 18 18:41:27.987183 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_SPOTLIGHT_PRIVATE
Mar 18 18:41:27.987194 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_SPOTLIGHT_PRIVATE -> AFPERR_NOOP
Mar 18 18:41:27.988438 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_CLOSEFORK
Mar 18 18:41:27.988479 afpd[31253] {fork.c:1075} (debug:AFPDaemon): afp_closefork(fork: 1 [data])
Mar 18 18:41:27.988518 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.988591 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.988929 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_CLOSEFORK -> AFP_OK
Mar 18 18:41:27.989261 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETFLDRPARAM
Mar 18 18:41:27.989288 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.989299 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.989311 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.989324 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.989336 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.989416 afpd[31253] {directory.c:341} (maxdebug:AFPDaemon): cname_mtouname('.DS_Store',did:2) {demangled:'.DS_Store', fileid:0}
Mar 18 18:41:27.989439 afpd[31253] {directory.c:1168} (maxdebug:AFPDaemon): came('/export/test_share'): {node: '.DS_Store}
Mar 18 18:41:27.989454 afpd[31253] {directory.c:1227} (debug:AFPDaemon): came('/export/test_share'): {file: '.DS_Store'}
Mar 18 18:41:27.989475 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.DS_Store'}
Mar 18 18:41:27.989489 afpd[31253] {filedir.c:83} (debug:AFPDaemon): getfildirparams(vid:1, did:2, f/d:e93f/a33f) {cwdid:2, cwd: /export/test_share, name:'.DS_Store'}
Mar 18 18:41:27.989499 afpd[31253] {file.c:625} (debug:AFPDaemon): getfilparams(".DS_Store")
Mar 18 18:41:27.990865 afpd[31253] {file.c:308} (debug:AFPDaemon): getmetadata(".DS_Store")
Mar 18 18:41:27.990894 afpd[31253] {dircache.c:385} (debug:AFPDaemon): dircache_search_by_name(did:2, ".DS_Store")
Mar 18 18:41:27.990929 afpd[31253] {dircache.c:414} (debug:AFPDaemon): dircache(did:2,".DS_Store"): {found in cache}
Mar 18 18:41:27.990968 afpd[31253] {file.c:398} (debug:AFPDaemon): metadata('.DS_Store'): AFP Attributes: 0001
Mar 18 18:41:27.990988 afpd[31253] {file.c:405} (debug:AFPDaemon): metadata('.DS_Store'):     Parent DID: 2
Mar 18 18:41:27.991004 afpd[31253] {file.c:453} (debug:AFPDaemon): metadata('.DS_Store'):           CNID: 17
Mar 18 18:41:27.991020 afpd[31253] {acls.c:1783} (maxdebug:AFPDaemon): acltoownermode("/export/test_share/.DS_Store", 0x87)
Mar 18 18:41:27.991111 afpd[31253] {acls.c:621} (maxdebug:AFPDaemon): ACL_GROUP_OBJ: 100
Mar 18 18:41:27.991130 afpd[31253] {acls.c:1796} (maxdebug:AFPDaemon): resulting user maccess: 0x87 group maccess: 0x03
Mar 18 18:41:27.991229 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETFLDRPARAM -> AFP_OK
Mar 18 18:41:27.991822 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_OPENFORK
Mar 18 18:41:27.991849 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.991884 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.991909 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.991934 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.991952 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.992007 afpd[31253] {directory.c:341} (maxdebug:AFPDaemon): cname_mtouname('.DS_Store',did:2) {demangled:'.DS_Store', fileid:0}
Mar 18 18:41:27.992028 afpd[31253] {directory.c:1168} (maxdebug:AFPDaemon): came('/export/test_share'): {node: '.DS_Store}
Mar 18 18:41:27.992043 afpd[31253] {directory.c:1227} (debug:AFPDaemon): came('/export/test_share'): {file: '.DS_Store'}
Mar 18 18:41:27.992053 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.DS_Store'}
Mar 18 18:41:27.992076 afpd[31253] {acls.c:1783} (maxdebug:AFPDaemon): acltoownermode("/export/test_share/.DS_Store", 0x87)
Mar 18 18:41:27.992163 afpd[31253] {acls.c:621} (maxdebug:AFPDaemon): ACL_GROUP_OBJ: 100
Mar 18 18:41:27.992183 afpd[31253] {acls.c:1796} (maxdebug:AFPDaemon): resulting user maccess: 0x87 group maccess: 0x03
Mar 18 18:41:27.992195 afpd[31253] {directory.c:1384} (debug:AFPDaemon): file_access(".DS_Store"): mapped user mode: 0x87
Mar 18 18:41:27.992211 afpd[31253] {fork.c:359} (debug:AFPDaemon): afp_openfork("/export/test_share/.DS_Store", data, O_RDONLY)
Mar 18 18:41:27.993725 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.993763 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.993779 afpd[31253] {file.c:308} (debug:AFPDaemon): getmetadata(".DS_Store")
Mar 18 18:41:27.994373 afpd[31253] {fork.c:496} (debug:AFPDaemon): afp_openfork("/export/test_share/.DS_Store"): fork: 2
Mar 18 18:41:27.994395 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_OPENFORK -> AFP_OK
Mar 18 18:41:27.994760 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_READ_EXT
Mar 18 18:41:27.994788 afpd[31253] {fork.c:829} (debug:AFPDaemon): afp_read(fork: 2 [data], off: 0, len: 8196, size: 8196)
Mar 18 18:41:27.994816 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_READ_EXT -> AFP_OK
Mar 18 18:41:27.995906 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_CLOSEFORK
Mar 18 18:41:27.995930 afpd[31253] {fork.c:1075} (debug:AFPDaemon): afp_closefork(fork: 2 [data])
Mar 18 18:41:27.995940 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.995950 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.996212 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_CLOSEFORK -> AFP_OK
Mar 18 18:41:27.996504 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETFLDRPARAM
Mar 18 18:41:27.996538 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:27.996562 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:27.996605 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:27.996636 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:27.996655 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:27.996710 afpd[31253] {directory.c:341} (maxdebug:AFPDaemon): cname_mtouname('.DS_Store',did:2) {demangled:'.DS_Store', fileid:0}
Mar 18 18:41:27.996730 afpd[31253] {directory.c:1168} (maxdebug:AFPDaemon): came('/export/test_share'): {node: '.DS_Store}
Mar 18 18:41:27.996745 afpd[31253] {directory.c:1227} (debug:AFPDaemon): came('/export/test_share'): {file: '.DS_Store'}
Mar 18 18:41:27.996757 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.DS_Store'}
Mar 18 18:41:27.996774 afpd[31253] {filedir.c:83} (debug:AFPDaemon): getfildirparams(vid:1, did:2, f/d:e93f/a33f) {cwdid:2, cwd: /export/test_share, name:'.DS_Store'}
Mar 18 18:41:27.996786 afpd[31253] {file.c:625} (debug:AFPDaemon): getfilparams(".DS_Store")
Mar 18 18:41:27.997962 afpd[31253] {file.c:308} (debug:AFPDaemon): getmetadata(".DS_Store")
Mar 18 18:41:27.997989 afpd[31253] {dircache.c:385} (debug:AFPDaemon): dircache_search_by_name(did:2, ".DS_Store")
Mar 18 18:41:27.998022 afpd[31253] {dircache.c:414} (debug:AFPDaemon): dircache(did:2,".DS_Store"): {found in cache}
Mar 18 18:41:27.998065 afpd[31253] {file.c:398} (debug:AFPDaemon): metadata('.DS_Store'): AFP Attributes: 0001
Mar 18 18:41:27.998085 afpd[31253] {file.c:405} (debug:AFPDaemon): metadata('.DS_Store'):     Parent DID: 2
Mar 18 18:41:27.998112 afpd[31253] {file.c:453} (debug:AFPDaemon): metadata('.DS_Store'):           CNID: 17
Mar 18 18:41:27.998134 afpd[31253] {acls.c:1783} (maxdebug:AFPDaemon): acltoownermode("/export/test_share/.DS_Store", 0x87)
Mar 18 18:41:27.998225 afpd[31253] {acls.c:621} (maxdebug:AFPDaemon): ACL_GROUP_OBJ: 100
Mar 18 18:41:27.998244 afpd[31253] {acls.c:1796} (maxdebug:AFPDaemon): resulting user maccess: 0x87 group maccess: 0x03
Mar 18 18:41:27.998408 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETFLDRPARAM -> AFP_OK
Mar 18 18:41:28.040556 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETVOLPARAM
Mar 18 18:41:28.040605 afpd[31253] {volume.c:309} (debug:AFPDaemon): getvolparams: Volume 'test_share'
Mar 18 18:41:28.046861 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETVOLPARAM -> AFP_OK
Mar 18 18:41:28.051322 afpd[29370] {main.c:151} (info:AFPDaemon): child[31338]: done
Mar 18 18:41:28.061537 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_GETFLDRPARAM
Mar 18 18:41:28.061579 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:28.061592 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:28.063544 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:28.063582 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:28.063671 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:28.063805 afpd[31253] {directory.c:341} (maxdebug:AFPDaemon): cname_mtouname('.hidden',did:2) {demangled:'.hidden', fileid:0}
Mar 18 18:41:28.063826 afpd[31253] {directory.c:1168} (maxdebug:AFPDaemon): came('/export/test_share'): {node: '.hidden}
Mar 18 18:41:28.064621 afpd[31253] {ofork.c:242} (debug:AFPDaemon): of_stat('/export/test_share/.hidden': No such file or directory)
Mar 18 18:41:28.064643 afpd[31253] {directory.c:1220} (maxdebug:AFPDaemon): came('/export/test_share'): {leave-cnode ENOENT (possile create request): '.hidden'}
Mar 18 18:41:28.064649 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.hidden'}
Mar 18 18:41:28.064655 afpd[31253] {filedir.c:83} (debug:AFPDaemon): getfildirparams(vid:1, did:2, f/d:e93f/a33f) {cwdid:2, cwd: /export/test_share, name:'.hidden'}
Mar 18 18:41:28.064661 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_GETFLDRPARAM -> AFPERR_NOOBJ
Mar 18 18:41:28.067062 afpd[29370] {main.c:440} (debug:AFPDaemon): main: IPC request from child[31341]
Mar 18 18:41:28.067542 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_ENUMERATE_EXT2
Mar 18 18:41:28.067565 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:28.067571 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:28.067577 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:28.067585 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:28.067590 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:28.067656 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.'}
Mar 18 18:41:28.067669 afpd[31253] {enumerate.c:274} (debug:AFPDaemon): enumerate("/export/test_share/.", f/d:e92f/a12f, rc:100, i:1, max:26400)
Mar 18 18:41:28.069423 afpd[31253] {file.c:625} (debug:AFPDaemon): getfilparams(".DS_Store")
Mar 18 18:41:28.070327 afpd[31253] {file.c:308} (debug:AFPDaemon): getmetadata(".DS_Store")
Mar 18 18:41:28.070348 afpd[31253] {dircache.c:385} (debug:AFPDaemon): dircache_search_by_name(did:2, ".DS_Store")
Mar 18 18:41:28.070367 afpd[31253] {dircache.c:414} (debug:AFPDaemon): dircache(did:2,".DS_Store"): {found in cache}
Mar 18 18:41:28.070383 afpd[31253] {file.c:398} (debug:AFPDaemon): metadata('.DS_Store'): AFP Attributes: 0001
Mar 18 18:41:28.070388 afpd[31253] {file.c:405} (debug:AFPDaemon): metadata('.DS_Store'):     Parent DID: 2
Mar 18 18:41:28.070394 afpd[31253] {file.c:453} (debug:AFPDaemon): metadata('.DS_Store'):           CNID: 17
Mar 18 18:41:28.070401 afpd[31253] {acls.c:1783} (maxdebug:AFPDaemon): acltoownermode("/export/test_share/.DS_Store", 0x87)
Mar 18 18:41:28.070505 afpd[31253] {acls.c:621} (maxdebug:AFPDaemon): ACL_GROUP_OBJ: 100
Mar 18 18:41:28.070528 afpd[31253] {acls.c:1796} (maxdebug:AFPDaemon): resulting user maccess: 0x87 group maccess: 0x03
Mar 18 18:41:28.070537 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_ENUMERATE_EXT2 -> AFP_OK
Mar 18 18:41:28.071038 afpd[31253] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_ENUMERATE_EXT2
Mar 18 18:41:28.071050 afpd[31253] {directory.c:566} (debug:AFPDaemon): dirlookup(did: 2): START
Mar 18 18:41:28.071055 afpd[31253] {directory.c:716} (debug:AFPDaemon): dirlookup(did: 2): RESULT: pdid: 1, path: "/export/test_share"
Mar 18 18:41:28.071061 afpd[31253] {directory.c:1086} (maxdebug:AFPDaemon): cname('/export/test_share'): {start}
Mar 18 18:41:28.071068 afpd[31253] {directory.c:1313} (maxdebug:AFPDaemon): movecwd: from: curdir:"/export/test_share", cwd:"/export/test_share"
Mar 18 18:41:28.071073 afpd[31253] {directory.c:1321} (debug:AFPDaemon): movecwd(to: did: 2, "/export/test_share")
Mar 18 18:41:28.071128 afpd[31253] {directory.c:1292} (debug:AFPDaemon): cname('/export/test_share') {end: curdir:'/export/test_share', path:'.'}
Mar 18 18:41:28.071140 afpd[31253] {enumerate.c:274} (debug:AFPDaemon): enumerate("/export/test_share/.", f/d:e92f/a12f, rc:100, i:2, max:26400)
Mar 18 18:41:28.071683 afpd[31253] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_ENUMERATE_EXT2 -> AFPERR_NOOBJ
Mar 18 18:41:28.073104 afpd[29370] {main.c:440} (debug:AFPDaemon): main: IPC request from child[31341]

바깥 고리