Project

General

Profile

Bug #27307

Allow unsigned 64-bit serials for certificates which allows AFP auth against macOS LDAP/KRB5

Added by Adrian Carpenter over 1 year ago. Updated 10 months ago.

Status:
Done
Priority:
No priority
Assignee:
John Hixson
Category:
OS
Target version:
Seen in:
Severity:
Medium
Reason for Closing:
Reason for Blocked:
Needs QA:
No
Needs Doc:
No
Needs Merging:
No
Needs Automation:
No
Support Suite Ticket:
n/a
Hardware Configuration:
ChangeLog Required:
No

Description

Still doesn't work on 11.1 I'm afraid.

getent passwd returns users
kinit userid completes

Dec 18 13:40:02.693348 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5945]
Dec 18 13:40:02.693751 afpd[5945] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(2 bytes)
Dec 18 13:40:02.693918 afpd[5945] {dsi_stream.c:179} (maxdebug:DSI): buf_read(2 bytes)
Dec 18 13:40:02.693956 afpd[5945] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 2 bytes
Dec 18 13:40:02.694005 afpd[5945] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.694088 afpd[5945] {dsi_stream.c:190} (maxdebug:DSI): buf_read(2 bytes): got: 2
Dec 18 13:40:02.694121 afpd[5945] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(2 bytes): got: 2
Dec 18 13:40:02.694175 afpd[5945] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(14 bytes)
Dec 18 13:40:02.694230 afpd[5945] {dsi_stream.c:179} (maxdebug:DSI): buf_read(14 bytes)
Dec 18 13:40:02.694273 afpd[5945] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 14 bytes
Dec 18 13:40:02.694305 afpd[5945] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.694346 afpd[5945] {dsi_stream.c:190} (maxdebug:DSI): buf_read(14 bytes): got: 14
Dec 18 13:40:02.694406 afpd[5945] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(14 bytes): got: 14
Dec 18 13:40:02.694451 afpd[5945] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(2 bytes)
Dec 18 13:40:02.694489 afpd[5945] {dsi_stream.c:179} (maxdebug:DSI): buf_read(2 bytes)
Dec 18 13:40:02.694534 afpd[5945] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 2 bytes
Dec 18 13:40:02.694577 afpd[5945] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.694629 afpd[5945] {dsi_stream.c:190} (maxdebug:DSI): buf_read(2 bytes): got: 2
Dec 18 13:40:02.694678 afpd[5945] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(2 bytes): got: 2
Dec 18 13:40:02.694742 afpd[5945] {dsi_tcp.c:241} (info:DSI): AFP/TCP session from 192.168.1.181:51168
Dec 18 13:40:02.694798 afpd[5945] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(383 bytes): START
Dec 18 13:40:02.694886 afpd[5945] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(383 bytes): END
Dec 18 13:40:02.696319 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5945]
Dec 18 13:40:02.697269 afpd[4378] {main.c:151} (info:AFPDaemon): child[5945]: done
Dec 18 13:40:02.749199 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5946]
Dec 18 13:40:02.749527 afpd[5946] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(2 bytes)
Dec 18 13:40:02.749694 afpd[5946] {dsi_stream.c:179} (maxdebug:DSI): buf_read(2 bytes)
Dec 18 13:40:02.749765 afpd[5946] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 2 bytes
Dec 18 13:40:02.749815 afpd[5946] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.749898 afpd[5946] {dsi_stream.c:190} (maxdebug:DSI): buf_read(2 bytes): got: 2
Dec 18 13:40:02.749929 afpd[5946] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(2 bytes): got: 2
Dec 18 13:40:02.749975 afpd[5946] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(14 bytes)
Dec 18 13:40:02.750017 afpd[5946] {dsi_stream.c:179} (maxdebug:DSI): buf_read(14 bytes)
Dec 18 13:40:02.750059 afpd[5946] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 14 bytes
Dec 18 13:40:02.750101 afpd[5946] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.750143 afpd[5946] {dsi_stream.c:190} (maxdebug:DSI): buf_read(14 bytes): got: 14
Dec 18 13:40:02.750174 afpd[5946] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(14 bytes): got: 14
Dec 18 13:40:02.750220 afpd[5946] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(6 bytes)
Dec 18 13:40:02.750258 afpd[5946] {dsi_stream.c:179} (maxdebug:DSI): buf_read(6 bytes)
Dec 18 13:40:02.750301 afpd[5946] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 6 bytes
Dec 18 13:40:02.750346 afpd[5946] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.750396 afpd[5946] {dsi_stream.c:190} (maxdebug:DSI): buf_read(6 bytes): got: 6
Dec 18 13:40:02.750429 afpd[5946] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(6 bytes): got: 6
Dec 18 13:40:02.750498 afpd[5946] {dsi_tcp.c:241} (info:DSI): AFP/TCP session from 192.168.1.181:51169
Dec 18 13:40:02.750561 afpd[5946] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(12 bytes): START
Dec 18 13:40:02.750623 afpd[5946] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(12 bytes): END
Dec 18 13:40:02.750663 afpd[5946] {netatalk_conf.c:1596} (debug:AFPDaemon): unload_volumes: BEGIN
Dec 18 13:40:02.750709 afpd[5946] {netatalk_conf.c:1609} (debug:AFPDaemon): unload_volumes: END
Dec 18 13:40:02.750939 afpd[5946] {dircache.c:575} (debug:AFPDaemon): dircache_init: done. max dircache size: 8192
Dec 18 13:40:02.751039 afpd[5946] {server_ipc.c:299} (debug:AFPDaemon): ipc_child_write(IPC_STATE)
Dec 18 13:40:02.751095 afpd[5946] {dsi_stream.c:602} (maxdebug:DSI): dsi_stream_receive: START
Dec 18 13:40:02.751098 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5946]
Dec 18 13:40:02.751130 afpd[5946] {dsi_stream.c:204} (maxdebug:DSI): dsi_buffered_stream_read: 16 bytes
Dec 18 13:40:02.751177 afpd[4378] {server_ipc.c:217} (debug:AFPDaemon): ipc_server_read(IPC_STATE): pid: 5946
Dec 18 13:40:02.751217 afpd[5946] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.751320 afpd[5946] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.751369 afpd[5946] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(16 bytes)
Dec 18 13:40:02.751401 afpd[5946] {dsi_stream.c:179} (maxdebug:DSI): buf_read(16 bytes)
Dec 18 13:40:02.751448 afpd[5946] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.751489 afpd[5946] {dsi_stream.c:162} (debug:DSI): from_buf(read: 16, unread:28 , space left: 12582868): returning 16
Dec 18 13:40:02.751527 afpd[5946] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(16 bytes): got: 16
Dec 18 13:40:02.751571 afpd[5946] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(28 bytes)
Dec 18 13:40:02.751611 afpd[5946] {dsi_stream.c:179} (maxdebug:DSI): buf_read(28 bytes)
Dec 18 13:40:02.751654 afpd[5946] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 28 bytes
Dec 18 13:40:02.751683 afpd[5946] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 28
Dec 18 13:40:02.751719 afpd[5946] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(28 bytes): got: 28
Dec 18 13:40:02.751749 afpd[5946] {dsi_stream.c:637} (debug:DSI): dsi_stream_receive: DSI cmdlen: 28
Dec 18 13:40:02.751786 afpd[5946] {afp_dsi.c:609} (debug:DSI): DSI request ID: 2
Dec 18 13:40:02.751818 afpd[5946] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGIN_EXT
Dec 18 13:40:02.794220 afpd[5946] {uams_dhx2_pam.c:330} (info:UAMS): DHX2 login: tac12
Dec 18 13:40:02.802889 afpd[5946] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_LOGIN_EXT -> AFPERR_AUTHCONT
Dec 18 13:40:02.802946 afpd[5946] {dsi_cmdreply.c:24} (debug:DSI): dsi_cmdreply(DSI ID: 2, len: 264): START
Dec 18 13:40:02.802981 afpd[5946] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(264 bytes): START
Dec 18 13:40:02.803042 afpd[5946] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(264 bytes): END
Dec 18 13:40:02.803075 afpd[5946] {dsi_cmdreply.c:33} (debug:DSI): dsi_cmdreply(DSI ID: 2, len: 264): END
Dec 18 13:40:02.803136 afpd[5946] {dsi_stream.c:602} (maxdebug:DSI): dsi_stream_receive: START
Dec 18 13:40:02.803168 afpd[5946] {dsi_stream.c:204} (maxdebug:DSI): dsi_buffered_stream_read: 16 bytes
Dec 18 13:40:02.803216 afpd[5946] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.803256 afpd[5946] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.803291 afpd[5946] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(16 bytes)
Dec 18 13:40:02.803332 afpd[5946] {dsi_stream.c:179} (maxdebug:DSI): buf_read(16 bytes)
Dec 18 13:40:02.803375 afpd[5946] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.803418 afpd[5946] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.812499 afpd[5946] {dsi_stream.c:190} (maxdebug:DSI): buf_read(16 bytes): got: 16
Dec 18 13:40:02.812563 afpd[5946] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(16 bytes): got: 16
Dec 18 13:40:02.812593 afpd[5946] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(148 bytes)
Dec 18 13:40:02.812652 afpd[5946] {dsi_stream.c:179} (maxdebug:DSI): buf_read(148 bytes)
Dec 18 13:40:02.812682 afpd[5946] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 148 bytes
Dec 18 13:40:02.812724 afpd[5946] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.812771 afpd[5946] {dsi_stream.c:190} (maxdebug:DSI): buf_read(148 bytes): got: 148
Dec 18 13:40:02.812821 afpd[5946] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(148 bytes): got: 148
Dec 18 13:40:02.812853 afpd[5946] {dsi_stream.c:637} (debug:DSI): dsi_stream_receive: DSI cmdlen: 148
Dec 18 13:40:02.812897 afpd[5946] {afp_dsi.c:609} (debug:DSI): DSI request ID: 3
Dec 18 13:40:02.812929 afpd[5946] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGINCONT
Dec 18 13:40:02.823204 afpd[5946] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_LOGINCONT -> AFPERR_AUTHCONT
Dec 18 13:40:02.823249 afpd[5946] {dsi_cmdreply.c:24} (debug:DSI): dsi_cmdreply(DSI ID: 3, len: 34): START
Dec 18 13:40:02.823298 afpd[5946] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(34 bytes): START
Dec 18 13:40:02.823359 afpd[5946] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(34 bytes): END
Dec 18 13:40:02.823392 afpd[5946] {dsi_cmdreply.c:33} (debug:DSI): dsi_cmdreply(DSI ID: 3, len: 34): END
Dec 18 13:40:02.823441 afpd[5946] {dsi_stream.c:602} (maxdebug:DSI): dsi_stream_receive: START
Dec 18 13:40:02.823471 afpd[5946] {dsi_stream.c:204} (maxdebug:DSI): dsi_buffered_stream_read: 16 bytes
Dec 18 13:40:02.823515 afpd[5946] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.823558 afpd[5946] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.823592 afpd[5946] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(16 bytes)
Dec 18 13:40:02.823632 afpd[5946] {dsi_stream.c:179} (maxdebug:DSI): buf_read(16 bytes)
Dec 18 13:40:02.823678 afpd[5946] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.823720 afpd[5946] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.823765 afpd[5946] {dsi_stream.c:190} (maxdebug:DSI): buf_read(16 bytes): got: 16
Dec 18 13:40:02.823795 afpd[5946] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(16 bytes): got: 16
Dec 18 13:40:02.823837 afpd[5946] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(276 bytes)
Dec 18 13:40:02.823878 afpd[5946] {dsi_stream.c:179} (maxdebug:DSI): buf_read(276 bytes)
Dec 18 13:40:02.823919 afpd[5946] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 276 bytes
Dec 18 13:40:02.823961 afpd[5946] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.823995 afpd[5946] {dsi_stream.c:190} (maxdebug:DSI): buf_read(276 bytes): got: 276
Dec 18 13:40:02.824036 afpd[5946] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(276 bytes): got: 276
Dec 18 13:40:02.824076 afpd[5946] {dsi_stream.c:637} (debug:DSI): dsi_stream_receive: DSI cmdlen: 276
Dec 18 13:40:02.824118 afpd[5946] {afp_dsi.c:609} (debug:DSI): DSI request ID: 4
Dec 18 13:40:02.824161 afpd[5946] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGINCONT
Dec 18 13:40:02.829750 afpd[5946] {uams_dhx2_pam.c:215} (info:UAMS): PAM DHX2: PAM Success
Dec 18 13:40:02.830751 afpd[5946] {uams_dhx2_pam.c:215} (info:UAMS): PAM DHX2: PAM Success
Dec 18 13:40:02.831269 afpd[5946] {uams_dhx2_pam.c:667} (info:UAMS): DHX2: PAM_Error: authentication error
Dec 18 13:40:02.831321 afpd[5946] {dsi_cmdreply.c:24} (debug:DSI): dsi_cmdreply(DSI ID: 4, len: 0): START
Dec 18 13:40:02.831363 afpd[5946] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(0 bytes): START
Dec 18 13:40:02.831406 afpd[5946] {dsi_stream.c:538} (maxdebug:DSI): dsi_stream_send(16 bytes): DSI header, no data
Dec 18 13:40:02.831455 afpd[5946] {dsi_stream.c:281} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): START
Dec 18 13:40:02.831522 afpd[5946] {dsi_stream.c:325} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): END
Dec 18 13:40:02.831555 afpd[5946] {dsi_cmdreply.c:33} (debug:DSI): dsi_cmdreply(DSI ID: 4, len: 0): END
Dec 18 13:40:02.831588 afpd[5946] {dsi_stream.c:281} (maxdebug:DSI): dsi_stream_write(send: 18 bytes): START
Dec 18 13:40:02.831655 afpd[5946] {dsi_stream.c:325} (maxdebug:DSI): dsi_stream_write(send: 18 bytes): END
Dec 18 13:40:02.831744 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5946]
Dec 18 13:40:02.831763 afpd[5946] {afp_dsi.c:108} (note:AFPDaemon): AFP statistics: 0.51 KB read, 0.38 KB written
Dec 18 13:40:02.831839 afpd[5946] {dircache.c:615} (info:AFPDaemon): dircache statistics: entries: 0, lookups: 0, hits: 0, misses: 0, added: 0, removed: 0, expunged: 0, evicted: 0
Dec 18 13:40:02.831879 afpd[5946] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(0 bytes): START
Dec 18 13:40:02.831922 afpd[5946] {dsi_stream.c:538} (maxdebug:DSI): dsi_stream_send(16 bytes): DSI header, no data
Dec 18 13:40:02.831964 afpd[5946] {dsi_stream.c:281} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): START
Dec 18 13:40:02.832013 afpd[5946] {dsi_stream.c:325} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): END
Dec 18 13:40:02.834115 afpd[4378] {main.c:151} (info:AFPDaemon): child[5946]: done
Dec 18 13:40:02.840924 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5947]
Dec 18 13:40:02.841267 afpd[5947] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(2 bytes)
Dec 18 13:40:02.841357 afpd[5947] {dsi_stream.c:179} (maxdebug:DSI): buf_read(2 bytes)
Dec 18 13:40:02.841401 afpd[5947] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 2 bytes
Dec 18 13:40:02.841446 afpd[5947] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.841511 afpd[5947] {dsi_stream.c:190} (maxdebug:DSI): buf_read(2 bytes): got: 2
Dec 18 13:40:02.841542 afpd[5947] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(2 bytes): got: 2
Dec 18 13:40:02.841593 afpd[5947] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(14 bytes)
Dec 18 13:40:02.841637 afpd[5947] {dsi_stream.c:179} (maxdebug:DSI): buf_read(14 bytes)
Dec 18 13:40:02.841679 afpd[5947] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 14 bytes
Dec 18 13:40:02.841720 afpd[5947] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.841764 afpd[5947] {dsi_stream.c:190} (maxdebug:DSI): buf_read(14 bytes): got: 14
Dec 18 13:40:02.841795 afpd[5947] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(14 bytes): got: 14
Dec 18 13:40:02.841838 afpd[5947] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(6 bytes)
Dec 18 13:40:02.841874 afpd[5947] {dsi_stream.c:179} (maxdebug:DSI): buf_read(6 bytes)
Dec 18 13:40:02.841914 afpd[5947] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 6 bytes
Dec 18 13:40:02.841956 afpd[5947] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.842008 afpd[5947] {dsi_stream.c:190} (maxdebug:DSI): buf_read(6 bytes): got: 6
Dec 18 13:40:02.842051 afpd[5947] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(6 bytes): got: 6
Dec 18 13:40:02.842108 afpd[5947] {dsi_tcp.c:241} (info:DSI): AFP/TCP session from 192.168.1.181:51170
Dec 18 13:40:02.842168 afpd[5947] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(12 bytes): START
Dec 18 13:40:02.842225 afpd[5947] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(12 bytes): END
Dec 18 13:40:02.842258 afpd[5947] {netatalk_conf.c:1596} (debug:AFPDaemon): unload_volumes: BEGIN
Dec 18 13:40:02.842288 afpd[5947] {netatalk_conf.c:1609} (debug:AFPDaemon): unload_volumes: END
Dec 18 13:40:02.842523 afpd[5947] {dircache.c:575} (debug:AFPDaemon): dircache_init: done. max dircache size: 8192
Dec 18 13:40:02.842622 afpd[5947] {server_ipc.c:299} (debug:AFPDaemon): ipc_child_write(IPC_STATE)
Dec 18 13:40:02.842680 afpd[5947] {dsi_stream.c:602} (maxdebug:DSI): dsi_stream_receive: START
Dec 18 13:40:02.842685 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5947]
Dec 18 13:40:02.842716 afpd[5947] {dsi_stream.c:204} (maxdebug:DSI): dsi_buffered_stream_read: 16 bytes
Dec 18 13:40:02.842775 afpd[4378] {server_ipc.c:217} (debug:AFPDaemon): ipc_server_read(IPC_STATE): pid: 5947
Dec 18 13:40:02.842820 afpd[5947] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.842913 afpd[5947] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.842963 afpd[5947] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(16 bytes)
Dec 18 13:40:02.843009 afpd[5947] {dsi_stream.c:179} (maxdebug:DSI): buf_read(16 bytes)
Dec 18 13:40:02.843053 afpd[5947] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.843098 afpd[5947] {dsi_stream.c:162} (debug:DSI): from_buf(read: 16, unread:28 , space left: 12582868): returning 16
Dec 18 13:40:02.843139 afpd[5947] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(16 bytes): got: 16
Dec 18 13:40:02.843178 afpd[5947] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(28 bytes)
Dec 18 13:40:02.843215 afpd[5947] {dsi_stream.c:179} (maxdebug:DSI): buf_read(28 bytes)
Dec 18 13:40:02.843252 afpd[5947] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 28 bytes
Dec 18 13:40:02.843290 afpd[5947] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 28
Dec 18 13:40:02.843327 afpd[5947] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(28 bytes): got: 28
Dec 18 13:40:02.843363 afpd[5947] {dsi_stream.c:637} (debug:DSI): dsi_stream_receive: DSI cmdlen: 28
Dec 18 13:40:02.843402 afpd[5947] {afp_dsi.c:609} (debug:DSI): DSI request ID: 2
Dec 18 13:40:02.843439 afpd[5947] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGIN_EXT
Dec 18 13:40:02.885297 afpd[5947] {uams_dhx2_pam.c:330} (info:UAMS): DHX2 login: tac12
Dec 18 13:40:02.893918 afpd[5947] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_LOGIN_EXT -> AFPERR_AUTHCONT
Dec 18 13:40:02.893970 afpd[5947] {dsi_cmdreply.c:24} (debug:DSI): dsi_cmdreply(DSI ID: 2, len: 264): START
Dec 18 13:40:02.894002 afpd[5947] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(264 bytes): START
Dec 18 13:40:02.894065 afpd[5947] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(264 bytes): END
Dec 18 13:40:02.894099 afpd[5947] {dsi_cmdreply.c:33} (debug:DSI): dsi_cmdreply(DSI ID: 2, len: 264): END
Dec 18 13:40:02.894165 afpd[5947] {dsi_stream.c:602} (maxdebug:DSI): dsi_stream_receive: START
Dec 18 13:40:02.894197 afpd[5947] {dsi_stream.c:204} (maxdebug:DSI): dsi_buffered_stream_read: 16 bytes
Dec 18 13:40:02.894245 afpd[5947] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.894302 afpd[5947] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.894349 afpd[5947] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(16 bytes)
Dec 18 13:40:02.894379 afpd[5947] {dsi_stream.c:179} (maxdebug:DSI): buf_read(16 bytes)
Dec 18 13:40:02.894423 afpd[5947] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.894466 afpd[5947] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.903662 afpd[5947] {dsi_stream.c:190} (maxdebug:DSI): buf_read(16 bytes): got: 16
Dec 18 13:40:02.903733 afpd[5947] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(16 bytes): got: 16
Dec 18 13:40:02.903787 afpd[5947] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(148 bytes)
Dec 18 13:40:02.903819 afpd[5947] {dsi_stream.c:179} (maxdebug:DSI): buf_read(148 bytes)
Dec 18 13:40:02.903859 afpd[5947] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 148 bytes
Dec 18 13:40:02.903889 afpd[5947] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.903924 afpd[5947] {dsi_stream.c:190} (maxdebug:DSI): buf_read(148 bytes): got: 148
Dec 18 13:40:02.903955 afpd[5947] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(148 bytes): got: 148
Dec 18 13:40:02.903995 afpd[5947] {dsi_stream.c:637} (debug:DSI): dsi_stream_receive: DSI cmdlen: 148
Dec 18 13:40:02.904042 afpd[5947] {afp_dsi.c:609} (debug:DSI): DSI request ID: 3
Dec 18 13:40:02.904073 afpd[5947] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGINCONT
Dec 18 13:40:02.914333 afpd[5947] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_LOGINCONT -> AFPERR_AUTHCONT
Dec 18 13:40:02.914373 afpd[5947] {dsi_cmdreply.c:24} (debug:DSI): dsi_cmdreply(DSI ID: 3, len: 34): START
Dec 18 13:40:02.914420 afpd[5947] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(34 bytes): START
Dec 18 13:40:02.914473 afpd[5947] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(34 bytes): END
Dec 18 13:40:02.914506 afpd[5947] {dsi_cmdreply.c:33} (debug:DSI): dsi_cmdreply(DSI ID: 3, len: 34): END
Dec 18 13:40:02.914554 afpd[5947] {dsi_stream.c:602} (maxdebug:DSI): dsi_stream_receive: START
Dec 18 13:40:02.914587 afpd[5947] {dsi_stream.c:204} (maxdebug:DSI): dsi_buffered_stream_read: 16 bytes
Dec 18 13:40:02.914629 afpd[5947] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.914682 afpd[5947] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.914731 afpd[5947] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(16 bytes)
Dec 18 13:40:02.914762 afpd[5947] {dsi_stream.c:179} (maxdebug:DSI): buf_read(16 bytes)
Dec 18 13:40:02.914805 afpd[5947] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.914848 afpd[5947] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.914892 afpd[5947] {dsi_stream.c:190} (maxdebug:DSI): buf_read(16 bytes): got: 16
Dec 18 13:40:02.914922 afpd[5947] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(16 bytes): got: 16
Dec 18 13:40:02.914966 afpd[5947] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(276 bytes)
Dec 18 13:40:02.915010 afpd[5947] {dsi_stream.c:179} (maxdebug:DSI): buf_read(276 bytes)
Dec 18 13:40:02.915050 afpd[5947] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 276 bytes
Dec 18 13:40:02.915091 afpd[5947] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.915137 afpd[5947] {dsi_stream.c:190} (maxdebug:DSI): buf_read(276 bytes): got: 276
Dec 18 13:40:02.915167 afpd[5947] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(276 bytes): got: 276
Dec 18 13:40:02.915210 afpd[5947] {dsi_stream.c:637} (debug:DSI): dsi_stream_receive: DSI cmdlen: 276
Dec 18 13:40:02.915247 afpd[5947] {afp_dsi.c:609} (debug:DSI): DSI request ID: 4
Dec 18 13:40:02.915284 afpd[5947] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGINCONT
Dec 18 13:40:02.920443 afpd[5947] {uams_dhx2_pam.c:215} (info:UAMS): PAM DHX2: PAM Success
Dec 18 13:40:02.921306 afpd[5947] {uams_dhx2_pam.c:215} (info:UAMS): PAM DHX2: PAM Success
Dec 18 13:40:02.921850 afpd[5947] {uams_dhx2_pam.c:667} (info:UAMS): DHX2: PAM_Error: authentication error
Dec 18 13:40:02.921896 afpd[5947] {dsi_cmdreply.c:24} (debug:DSI): dsi_cmdreply(DSI ID: 4, len: 0): START
Dec 18 13:40:02.921928 afpd[5947] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(0 bytes): START
Dec 18 13:40:02.921971 afpd[5947] {dsi_stream.c:538} (maxdebug:DSI): dsi_stream_send(16 bytes): DSI header, no data
Dec 18 13:40:02.922006 afpd[5947] {dsi_stream.c:281} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): START
Dec 18 13:40:02.922057 afpd[5947] {dsi_stream.c:325} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): END
Dec 18 13:40:02.922088 afpd[5947] {dsi_cmdreply.c:33} (debug:DSI): dsi_cmdreply(DSI ID: 4, len: 0): END
Dec 18 13:40:02.922140 afpd[5947] {dsi_stream.c:281} (maxdebug:DSI): dsi_stream_write(send: 18 bytes): START
Dec 18 13:40:02.922191 afpd[5947] {dsi_stream.c:325} (maxdebug:DSI): dsi_stream_write(send: 18 bytes): END
Dec 18 13:40:02.922271 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5947]
Dec 18 13:40:02.922294 afpd[5947] {afp_dsi.c:108} (note:AFPDaemon): AFP statistics: 0.51 KB read, 0.38 KB written
Dec 18 13:40:02.922411 afpd[5947] {dircache.c:615} (info:AFPDaemon): dircache statistics: entries: 0, lookups: 0, hits: 0, misses: 0, added: 0, removed: 0, expunged: 0, evicted: 0
Dec 18 13:40:02.922461 afpd[5947] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(0 bytes): START
Dec 18 13:40:02.922506 afpd[5947] {dsi_stream.c:538} (maxdebug:DSI): dsi_stream_send(16 bytes): DSI header, no data
Dec 18 13:40:02.922550 afpd[5947] {dsi_stream.c:281} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): START
Dec 18 13:40:02.922592 afpd[5947] {dsi_stream.c:325} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): END
Dec 18 13:40:02.924790 afpd[4378] {main.c:151} (info:AFPDaemon): child[5947]: done
Dec 18 13:40:02.927112 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5948]
Dec 18 13:40:02.927455 afpd[5948] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(2 bytes)
Dec 18 13:40:02.927546 afpd[5948] {dsi_stream.c:179} (maxdebug:DSI): buf_read(2 bytes)
Dec 18 13:40:02.927591 afpd[5948] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 2 bytes
Dec 18 13:40:02.927622 afpd[5948] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.927694 afpd[5948] {dsi_stream.c:190} (maxdebug:DSI): buf_read(2 bytes): got: 2
Dec 18 13:40:02.927725 afpd[5948] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(2 bytes): got: 2
Dec 18 13:40:02.927764 afpd[5948] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(14 bytes)
Dec 18 13:40:02.927794 afpd[5948] {dsi_stream.c:179} (maxdebug:DSI): buf_read(14 bytes)
Dec 18 13:40:02.927831 afpd[5948] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 14 bytes
Dec 18 13:40:02.927860 afpd[5948] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.927893 afpd[5948] {dsi_stream.c:190} (maxdebug:DSI): buf_read(14 bytes): got: 14
Dec 18 13:40:02.927922 afpd[5948] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(14 bytes): got: 14
Dec 18 13:40:02.927960 afpd[5948] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(2 bytes)
Dec 18 13:40:02.927989 afpd[5948] {dsi_stream.c:179} (maxdebug:DSI): buf_read(2 bytes)
Dec 18 13:40:02.928026 afpd[5948] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 2 bytes
Dec 18 13:40:02.928055 afpd[5948] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.928101 afpd[5948] {dsi_stream.c:190} (maxdebug:DSI): buf_read(2 bytes): got: 2
Dec 18 13:40:02.928141 afpd[5948] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(2 bytes): got: 2
Dec 18 13:40:02.928186 afpd[5948] {dsi_tcp.c:241} (info:DSI): AFP/TCP session from 192.168.1.181:51171
Dec 18 13:40:02.928245 afpd[5948] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(383 bytes): START
Dec 18 13:40:02.928303 afpd[5948] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(383 bytes): END
Dec 18 13:40:02.929672 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5948]
Dec 18 13:40:02.930592 afpd[4378] {main.c:151} (info:AFPDaemon): child[5948]: done
Dec 18 13:40:02.942195 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5949]
Dec 18 13:40:02.942509 afpd[5949] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(2 bytes)
Dec 18 13:40:02.942587 afpd[5949] {dsi_stream.c:179} (maxdebug:DSI): buf_read(2 bytes)
Dec 18 13:40:02.942631 afpd[5949] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 2 bytes
Dec 18 13:40:02.942704 afpd[5949] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.942785 afpd[5949] {dsi_stream.c:190} (maxdebug:DSI): buf_read(2 bytes): got: 2
Dec 18 13:40:02.942815 afpd[5949] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(2 bytes): got: 2
Dec 18 13:40:02.942854 afpd[5949] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(14 bytes)
Dec 18 13:40:02.942883 afpd[5949] {dsi_stream.c:179} (maxdebug:DSI): buf_read(14 bytes)
Dec 18 13:40:02.942927 afpd[5949] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 14 bytes
Dec 18 13:40:02.942981 afpd[5949] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.943013 afpd[5949] {dsi_stream.c:190} (maxdebug:DSI): buf_read(14 bytes): got: 14
Dec 18 13:40:02.943048 afpd[5949] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(14 bytes): got: 14
Dec 18 13:40:02.943089 afpd[5949] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(6 bytes)
Dec 18 13:40:02.943120 afpd[5949] {dsi_stream.c:179} (maxdebug:DSI): buf_read(6 bytes)
Dec 18 13:40:02.943162 afpd[5949] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 6 bytes
Dec 18 13:40:02.943202 afpd[5949] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.943241 afpd[5949] {dsi_stream.c:190} (maxdebug:DSI): buf_read(6 bytes): got: 6
Dec 18 13:40:02.943284 afpd[5949] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(6 bytes): got: 6
Dec 18 13:40:02.943345 afpd[5949] {dsi_tcp.c:241} (info:DSI): AFP/TCP session from 192.168.1.181:51172
Dec 18 13:40:02.943401 afpd[5949] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(12 bytes): START
Dec 18 13:40:02.943461 afpd[5949] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(12 bytes): END
Dec 18 13:40:02.943507 afpd[5949] {netatalk_conf.c:1596} (debug:AFPDaemon): unload_volumes: BEGIN
Dec 18 13:40:02.943548 afpd[5949] {netatalk_conf.c:1609} (debug:AFPDaemon): unload_volumes: END
Dec 18 13:40:02.943801 afpd[5949] {dircache.c:575} (debug:AFPDaemon): dircache_init: done. max dircache size: 8192
Dec 18 13:40:02.943895 afpd[5949] {server_ipc.c:299} (debug:AFPDaemon): ipc_child_write(IPC_STATE)
Dec 18 13:40:02.943953 afpd[5949] {dsi_stream.c:602} (maxdebug:DSI): dsi_stream_receive: START
Dec 18 13:40:02.943956 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5949]
Dec 18 13:40:02.943986 afpd[5949] {dsi_stream.c:204} (maxdebug:DSI): dsi_buffered_stream_read: 16 bytes
Dec 18 13:40:02.944032 afpd[4378] {server_ipc.c:217} (debug:AFPDaemon): ipc_server_read(IPC_STATE): pid: 5949
Dec 18 13:40:02.944068 afpd[5949] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.944156 afpd[5949] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.944196 afpd[5949] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(16 bytes)
Dec 18 13:40:02.944226 afpd[5949] {dsi_stream.c:179} (maxdebug:DSI): buf_read(16 bytes)
Dec 18 13:40:02.944267 afpd[5949] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.944297 afpd[5949] {dsi_stream.c:162} (debug:DSI): from_buf(read: 16, unread:28 , space left: 12582868): returning 16
Dec 18 13:40:02.944335 afpd[5949] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(16 bytes): got: 16
Dec 18 13:40:02.944367 afpd[5949] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(28 bytes)
Dec 18 13:40:02.944405 afpd[5949] {dsi_stream.c:179} (maxdebug:DSI): buf_read(28 bytes)
Dec 18 13:40:02.944433 afpd[5949] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 28 bytes
Dec 18 13:40:02.944474 afpd[5949] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 28
Dec 18 13:40:02.944502 afpd[5949] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(28 bytes): got: 28
Dec 18 13:40:02.944542 afpd[5949] {dsi_stream.c:637} (debug:DSI): dsi_stream_receive: DSI cmdlen: 28
Dec 18 13:40:02.944573 afpd[5949] {afp_dsi.c:609} (debug:DSI): DSI request ID: 2
Dec 18 13:40:02.944611 afpd[5949] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGIN_EXT
Dec 18 13:40:02.985953 afpd[5949] {uams_dhx2_pam.c:330} (info:UAMS): DHX2 login: tac12
Dec 18 13:40:02.994580 afpd[5949] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_LOGIN_EXT -> AFPERR_AUTHCONT
Dec 18 13:40:02.994635 afpd[5949] {dsi_cmdreply.c:24} (debug:DSI): dsi_cmdreply(DSI ID: 2, len: 264): START
Dec 18 13:40:02.994672 afpd[5949] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(264 bytes): START
Dec 18 13:40:02.994749 afpd[5949] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(264 bytes): END
Dec 18 13:40:02.994809 afpd[5949] {dsi_cmdreply.c:33} (debug:DSI): dsi_cmdreply(DSI ID: 2, len: 264): END
Dec 18 13:40:02.994855 afpd[5949] {dsi_stream.c:602} (maxdebug:DSI): dsi_stream_receive: START
Dec 18 13:40:02.994894 afpd[5949] {dsi_stream.c:204} (maxdebug:DSI): dsi_buffered_stream_read: 16 bytes
Dec 18 13:40:02.994980 afpd[5949] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.995021 afpd[5949] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:02.995065 afpd[5949] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(16 bytes)
Dec 18 13:40:02.995118 afpd[5949] {dsi_stream.c:179} (maxdebug:DSI): buf_read(16 bytes)
Dec 18 13:40:02.995172 afpd[5949] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:02.995222 afpd[5949] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.004276 afpd[5949] {dsi_stream.c:190} (maxdebug:DSI): buf_read(16 bytes): got: 16
Dec 18 13:40:03.004309 afpd[5949] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(16 bytes): got: 16
Dec 18 13:40:03.004353 afpd[5949] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(148 bytes)
Dec 18 13:40:03.004395 afpd[5949] {dsi_stream.c:179} (maxdebug:DSI): buf_read(148 bytes)
Dec 18 13:40:03.004434 afpd[5949] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 148 bytes
Dec 18 13:40:03.004477 afpd[5949] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.004521 afpd[5949] {dsi_stream.c:190} (maxdebug:DSI): buf_read(148 bytes): got: 148
Dec 18 13:40:03.004584 afpd[5949] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(148 bytes): got: 148
Dec 18 13:40:03.004621 afpd[5949] {dsi_stream.c:637} (debug:DSI): dsi_stream_receive: DSI cmdlen: 148
Dec 18 13:40:03.004671 afpd[5949] {afp_dsi.c:609} (debug:DSI): DSI request ID: 3
Dec 18 13:40:03.004712 afpd[5949] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGINCONT
Dec 18 13:40:03.014971 afpd[5949] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_LOGINCONT -> AFPERR_AUTHCONT
Dec 18 13:40:03.015015 afpd[5949] {dsi_cmdreply.c:24} (debug:DSI): dsi_cmdreply(DSI ID: 3, len: 34): START
Dec 18 13:40:03.015061 afpd[5949] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(34 bytes): START
Dec 18 13:40:03.015132 afpd[5949] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(34 bytes): END
Dec 18 13:40:03.015193 afpd[5949] {dsi_cmdreply.c:33} (debug:DSI): dsi_cmdreply(DSI ID: 3, len: 34): END
Dec 18 13:40:03.015261 afpd[5949] {dsi_stream.c:602} (maxdebug:DSI): dsi_stream_receive: START
Dec 18 13:40:03.015320 afpd[5949] {dsi_stream.c:204} (maxdebug:DSI): dsi_buffered_stream_read: 16 bytes
Dec 18 13:40:03.015355 afpd[5949] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:03.015418 afpd[5949] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.015460 afpd[5949] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(16 bytes)
Dec 18 13:40:03.015493 afpd[5949] {dsi_stream.c:179} (maxdebug:DSI): buf_read(16 bytes)
Dec 18 13:40:03.015534 afpd[5949] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:03.015579 afpd[5949] {dsi_stream.c:162} (debug:DSI): from_buf(read: 16, unread:276 , space left: 12582620): returning 16
Dec 18 13:40:03.015610 afpd[5949] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(16 bytes): got: 16
Dec 18 13:40:03.015662 afpd[5949] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(276 bytes)
Dec 18 13:40:03.015703 afpd[5949] {dsi_stream.c:179} (maxdebug:DSI): buf_read(276 bytes)
Dec 18 13:40:03.015743 afpd[5949] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 276 bytes
Dec 18 13:40:03.015784 afpd[5949] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 276
Dec 18 13:40:03.015814 afpd[5949] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(276 bytes): got: 276
Dec 18 13:40:03.015855 afpd[5949] {dsi_stream.c:637} (debug:DSI): dsi_stream_receive: DSI cmdlen: 276
Dec 18 13:40:03.015894 afpd[5949] {afp_dsi.c:609} (debug:DSI): DSI request ID: 4
Dec 18 13:40:03.015924 afpd[5949] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGINCONT
Dec 18 13:40:03.021231 afpd[5949] {uams_dhx2_pam.c:215} (info:UAMS): PAM DHX2: PAM Success
Dec 18 13:40:03.022127 afpd[5949] {uams_dhx2_pam.c:215} (info:UAMS): PAM DHX2: PAM Success
Dec 18 13:40:03.022650 afpd[5949] {uams_dhx2_pam.c:667} (info:UAMS): DHX2: PAM_Error: authentication error
Dec 18 13:40:03.022705 afpd[5949] {dsi_cmdreply.c:24} (debug:DSI): dsi_cmdreply(DSI ID: 4, len: 0): START
Dec 18 13:40:03.022737 afpd[5949] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(0 bytes): START
Dec 18 13:40:03.022784 afpd[5949] {dsi_stream.c:538} (maxdebug:DSI): dsi_stream_send(16 bytes): DSI header, no data
Dec 18 13:40:03.022819 afpd[5949] {dsi_stream.c:281} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): START
Dec 18 13:40:03.022879 afpd[5949] {dsi_stream.c:325} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): END
Dec 18 13:40:03.022911 afpd[5949] {dsi_cmdreply.c:33} (debug:DSI): dsi_cmdreply(DSI ID: 4, len: 0): END
Dec 18 13:40:03.023016 afpd[5949] {dsi_stream.c:281} (maxdebug:DSI): dsi_stream_write(send: 18 bytes): START
Dec 18 13:40:03.023074 afpd[5949] {dsi_stream.c:325} (maxdebug:DSI): dsi_stream_write(send: 18 bytes): END
Dec 18 13:40:03.023155 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5949]
Dec 18 13:40:03.023186 afpd[5949] {afp_dsi.c:108} (note:AFPDaemon): AFP statistics: 0.51 KB read, 0.38 KB written
Dec 18 13:40:03.023266 afpd[5949] {dircache.c:615} (info:AFPDaemon): dircache statistics: entries: 0, lookups: 0, hits: 0, misses: 0, added: 0, removed: 0, expunged: 0, evicted: 0
Dec 18 13:40:03.023303 afpd[5949] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(0 bytes): START
Dec 18 13:40:03.023336 afpd[5949] {dsi_stream.c:538} (maxdebug:DSI): dsi_stream_send(16 bytes): DSI header, no data
Dec 18 13:40:03.023378 afpd[5949] {dsi_stream.c:281} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): START
Dec 18 13:40:03.023417 afpd[5949] {dsi_stream.c:325} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): END
Dec 18 13:40:03.025419 afpd[4378] {main.c:151} (info:AFPDaemon): child[5949]: done
Dec 18 13:40:03.032062 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5950]
Dec 18 13:40:03.032418 afpd[5950] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(2 bytes)
Dec 18 13:40:03.032508 afpd[5950] {dsi_stream.c:179} (maxdebug:DSI): buf_read(2 bytes)
Dec 18 13:40:03.032557 afpd[5950] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 2 bytes
Dec 18 13:40:03.032603 afpd[5950] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.032676 afpd[5950] {dsi_stream.c:190} (maxdebug:DSI): buf_read(2 bytes): got: 2
Dec 18 13:40:03.032716 afpd[5950] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(2 bytes): got: 2
Dec 18 13:40:03.032758 afpd[5950] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(14 bytes)
Dec 18 13:40:03.032796 afpd[5950] {dsi_stream.c:179} (maxdebug:DSI): buf_read(14 bytes)
Dec 18 13:40:03.032834 afpd[5950] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 14 bytes
Dec 18 13:40:03.032875 afpd[5950] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.032909 afpd[5950] {dsi_stream.c:190} (maxdebug:DSI): buf_read(14 bytes): got: 14
Dec 18 13:40:03.032946 afpd[5950] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(14 bytes): got: 14
Dec 18 13:40:03.032985 afpd[5950] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(6 bytes)
Dec 18 13:40:03.033016 afpd[5950] {dsi_stream.c:179} (maxdebug:DSI): buf_read(6 bytes)
Dec 18 13:40:03.033056 afpd[5950] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 6 bytes
Dec 18 13:40:03.033094 afpd[5950] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.033142 afpd[5950] {dsi_stream.c:190} (maxdebug:DSI): buf_read(6 bytes): got: 6
Dec 18 13:40:03.033188 afpd[5950] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(6 bytes): got: 6
Dec 18 13:40:03.033243 afpd[5950] {dsi_tcp.c:241} (info:DSI): AFP/TCP session from 192.168.1.181:51173
Dec 18 13:40:03.033307 afpd[5950] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(12 bytes): START
Dec 18 13:40:03.033364 afpd[5950] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(12 bytes): END
Dec 18 13:40:03.033412 afpd[5950] {netatalk_conf.c:1596} (debug:AFPDaemon): unload_volumes: BEGIN
Dec 18 13:40:03.033453 afpd[5950] {netatalk_conf.c:1609} (debug:AFPDaemon): unload_volumes: END
Dec 18 13:40:03.033687 afpd[5950] {dircache.c:575} (debug:AFPDaemon): dircache_init: done. max dircache size: 8192
Dec 18 13:40:03.033784 afpd[5950] {server_ipc.c:299} (debug:AFPDaemon): ipc_child_write(IPC_STATE)
Dec 18 13:40:03.033838 afpd[5950] {dsi_stream.c:602} (maxdebug:DSI): dsi_stream_receive: START
Dec 18 13:40:03.033847 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5950]
Dec 18 13:40:03.033871 afpd[5950] {dsi_stream.c:204} (maxdebug:DSI): dsi_buffered_stream_read: 16 bytes
Dec 18 13:40:03.033915 afpd[4378] {server_ipc.c:217} (debug:AFPDaemon): ipc_server_read(IPC_STATE): pid: 5950
Dec 18 13:40:03.033954 afpd[5950] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:03.034045 afpd[5950] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.034094 afpd[5950] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(16 bytes)
Dec 18 13:40:03.034126 afpd[5950] {dsi_stream.c:179} (maxdebug:DSI): buf_read(16 bytes)
Dec 18 13:40:03.034169 afpd[5950] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:03.034207 afpd[5950] {dsi_stream.c:162} (debug:DSI): from_buf(read: 16, unread:28 , space left: 12582868): returning 16
Dec 18 13:40:03.034237 afpd[5950] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(16 bytes): got: 16
Dec 18 13:40:03.034275 afpd[5950] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(28 bytes)
Dec 18 13:40:03.034304 afpd[5950] {dsi_stream.c:179} (maxdebug:DSI): buf_read(28 bytes)
Dec 18 13:40:03.034340 afpd[5950] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 28 bytes
Dec 18 13:40:03.034370 afpd[5950] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 28
Dec 18 13:40:03.034408 afpd[5950] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(28 bytes): got: 28
Dec 18 13:40:03.034437 afpd[5950] {dsi_stream.c:637} (debug:DSI): dsi_stream_receive: DSI cmdlen: 28
Dec 18 13:40:03.034475 afpd[5950] {afp_dsi.c:609} (debug:DSI): DSI request ID: 2
Dec 18 13:40:03.034506 afpd[5950] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGIN_EXT
Dec 18 13:40:03.076771 afpd[5950] {uams_dhx2_pam.c:330} (info:UAMS): DHX2 login: tac12
Dec 18 13:40:03.085456 afpd[5950] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_LOGIN_EXT -> AFPERR_AUTHCONT
Dec 18 13:40:03.085509 afpd[5950] {dsi_cmdreply.c:24} (debug:DSI): dsi_cmdreply(DSI ID: 2, len: 264): START
Dec 18 13:40:03.085542 afpd[5950] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(264 bytes): START
Dec 18 13:40:03.085601 afpd[5950] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(264 bytes): END
Dec 18 13:40:03.085640 afpd[5950] {dsi_cmdreply.c:33} (debug:DSI): dsi_cmdreply(DSI ID: 2, len: 264): END
Dec 18 13:40:03.085705 afpd[5950] {dsi_stream.c:602} (maxdebug:DSI): dsi_stream_receive: START
Dec 18 13:40:03.085737 afpd[5950] {dsi_stream.c:204} (maxdebug:DSI): dsi_buffered_stream_read: 16 bytes
Dec 18 13:40:03.085785 afpd[5950] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:03.085826 afpd[5950] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.085862 afpd[5950] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(16 bytes)
Dec 18 13:40:03.085907 afpd[5950] {dsi_stream.c:179} (maxdebug:DSI): buf_read(16 bytes)
Dec 18 13:40:03.085946 afpd[5950] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:03.085988 afpd[5950] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.095735 afpd[5950] {dsi_stream.c:190} (maxdebug:DSI): buf_read(16 bytes): got: 16
Dec 18 13:40:03.095771 afpd[5950] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(16 bytes): got: 16
Dec 18 13:40:03.095821 afpd[5950] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(148 bytes)
Dec 18 13:40:03.095872 afpd[5950] {dsi_stream.c:179} (maxdebug:DSI): buf_read(148 bytes)
Dec 18 13:40:03.095913 afpd[5950] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 148 bytes
Dec 18 13:40:03.095958 afpd[5950] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.096003 afpd[5950] {dsi_stream.c:190} (maxdebug:DSI): buf_read(148 bytes): got: 148
Dec 18 13:40:03.096036 afpd[5950] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(148 bytes): got: 148
Dec 18 13:40:03.096081 afpd[5950] {dsi_stream.c:637} (debug:DSI): dsi_stream_receive: DSI cmdlen: 148
Dec 18 13:40:03.096122 afpd[5950] {afp_dsi.c:609} (debug:DSI): DSI request ID: 3
Dec 18 13:40:03.096166 afpd[5950] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGINCONT
Dec 18 13:40:03.106377 afpd[5950] {afp_dsi.c:633} (debug:AFPDaemon): ==> Finished AFP command: AFP_LOGINCONT -> AFPERR_AUTHCONT
Dec 18 13:40:03.106422 afpd[5950] {dsi_cmdreply.c:24} (debug:DSI): dsi_cmdreply(DSI ID: 3, len: 34): START
Dec 18 13:40:03.106471 afpd[5950] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(34 bytes): START
Dec 18 13:40:03.106519 afpd[5950] {dsi_stream.c:584} (maxdebug:DSI): dsi_stream_send(34 bytes): END
Dec 18 13:40:03.106560 afpd[5950] {dsi_cmdreply.c:33} (debug:DSI): dsi_cmdreply(DSI ID: 3, len: 34): END
Dec 18 13:40:03.106607 afpd[5950] {dsi_stream.c:602} (maxdebug:DSI): dsi_stream_receive: START
Dec 18 13:40:03.106644 afpd[5950] {dsi_stream.c:204} (maxdebug:DSI): dsi_buffered_stream_read: 16 bytes
Dec 18 13:40:03.106685 afpd[5950] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:03.106727 afpd[5950] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.106766 afpd[5950] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(16 bytes)
Dec 18 13:40:03.106802 afpd[5950] {dsi_stream.c:179} (maxdebug:DSI): buf_read(16 bytes)
Dec 18 13:40:03.106846 afpd[5950] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 16 bytes
Dec 18 13:40:03.106883 afpd[5950] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.106917 afpd[5950] {dsi_stream.c:190} (maxdebug:DSI): buf_read(16 bytes): got: 16
Dec 18 13:40:03.106946 afpd[5950] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(16 bytes): got: 16
Dec 18 13:40:03.106987 afpd[5950] {dsi_stream.c:489} (maxdebug:DSI): dsi_stream_read(276 bytes)
Dec 18 13:40:03.107017 afpd[5950] {dsi_stream.c:179} (maxdebug:DSI): buf_read(276 bytes)
Dec 18 13:40:03.107057 afpd[5950] {dsi_stream.c:148} (maxdebug:DSI): from_buf: 276 bytes
Dec 18 13:40:03.107086 afpd[5950] {dsi_stream.c:162} (debug:DSI): from_buf(read: 0, unread:0 , space left: 12582912): returning 0
Dec 18 13:40:03.107130 afpd[5950] {dsi_stream.c:190} (maxdebug:DSI): buf_read(276 bytes): got: 276
Dec 18 13:40:03.107171 afpd[5950] {dsi_stream.c:514} (maxdebug:DSI): dsi_stream_read(276 bytes): got: 276
Dec 18 13:40:03.107208 afpd[5950] {dsi_stream.c:637} (debug:DSI): dsi_stream_receive: DSI cmdlen: 276
Dec 18 13:40:03.107237 afpd[5950] {afp_dsi.c:609} (debug:DSI): DSI request ID: 4
Dec 18 13:40:03.107273 afpd[5950] {afp_dsi.c:624} (debug:AFPDaemon): <== Start AFP command: AFP_LOGINCONT
Dec 18 13:40:03.112537 afpd[5950] {uams_dhx2_pam.c:215} (info:UAMS): PAM DHX2: PAM Success
Dec 18 13:40:03.113386 afpd[5950] {uams_dhx2_pam.c:215} (info:UAMS): PAM DHX2: PAM Success
Dec 18 13:40:03.113924 afpd[5950] {uams_dhx2_pam.c:667} (info:UAMS): DHX2: PAM_Error: authentication error
Dec 18 13:40:03.113975 afpd[5950] {dsi_cmdreply.c:24} (debug:DSI): dsi_cmdreply(DSI ID: 4, len: 0): START
Dec 18 13:40:03.114021 afpd[5950] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(0 bytes): START
Dec 18 13:40:03.114051 afpd[5950] {dsi_stream.c:538} (maxdebug:DSI): dsi_stream_send(16 bytes): DSI header, no data
Dec 18 13:40:03.114096 afpd[5950] {dsi_stream.c:281} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): START
Dec 18 13:40:03.114158 afpd[5950] {dsi_stream.c:325} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): END
Dec 18 13:40:03.114190 afpd[5950] {dsi_cmdreply.c:33} (debug:DSI): dsi_cmdreply(DSI ID: 4, len: 0): END
Dec 18 13:40:03.114223 afpd[5950] {dsi_stream.c:281} (maxdebug:DSI): dsi_stream_write(send: 18 bytes): START
Dec 18 13:40:03.114260 afpd[5950] {dsi_stream.c:325} (maxdebug:DSI): dsi_stream_write(send: 18 bytes): END
Dec 18 13:40:03.114342 afpd[4378] {main.c:440} (debug:AFPDaemon): main: IPC request from child[5950]
Dec 18 13:40:03.114364 afpd[5950] {afp_dsi.c:108} (note:AFPDaemon): AFP statistics: 0.51 KB read, 0.38 KB written
Dec 18 13:40:03.114459 afpd[5950] {dircache.c:615} (info:AFPDaemon): dircache statistics: entries: 0, lookups: 0, hits: 0, misses: 0, added: 0, removed: 0, expunged: 0, evicted: 0
Dec 18 13:40:03.114496 afpd[5950] {dsi_stream.c:530} (maxdebug:DSI): dsi_stream_send(0 bytes): START
Dec 18 13:40:03.114547 afpd[5950] {dsi_stream.c:538} (maxdebug:DSI): dsi_stream_send(16 bytes): DSI header, no data
Dec 18 13:40:03.114589 afpd[5950] {dsi_stream.c:281} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): START
Dec 18 13:40:03.114628 afpd[5950] {dsi_stream.c:325} (maxdebug:DSI): dsi_stream_write(send: 16 bytes): END
Dec 18 13:40:03.116722 afpd[4378] {main.c:151} (info:AFPDaemon): child[5950]: done

IMG_2560.jpg (1.51 MB) IMG_2560.jpg Adrian Carpenter, 05/25/2018 12:24 AM
17787

Related issues

Has duplicate FreeNAS - Bug #26596: AFP auth against macOS LDAP/KRB5 stoppedClosed: Duplicate2017-11-10
Copied to FreeNAS - Bug #40724: Allow unsigned 64-bit serials for certificates which allows AFP auth against macOS LDAP/KRB5Done

Associated revisions

Revision e41a5b8b (diff)
Added by John Hixson 12 months ago

'cert_certificate_path' -> 'certificate_path'

Ticket: #27307

Revision a25428b7 (diff)
Added by John Hixson 12 months ago

'cert_certificate_path' -> 'certificate_path'

Ticket: #27307

Revision 05958c32 (diff)
Added by John Hixson 12 months ago

Allow unsigned 64-bit serials for certificates

Ticket: #27307

Revision 18be47ff (diff)
Added by John Hixson 11 months ago

Allow self signed certificates

Ticket: #27307

Revision e6cf8335 (diff)
Added by John Hixson 11 months ago

Allow self signed certificates

Ticket: #27307
(cherry picked from commit 18be47ff1bfbd03cb1a1c6458f2a270c1605b55a)

Revision e35b0e47 (diff)
Added by John Hixson 9 months ago

Allow unsigned 64-bit serials for certificates

Ticket: #27307
(cherry picked from commit 05958c32baa63a295ea06d3bfaa0e121ef132116)

(11.1-stable)
Ticket: #40724

History

#1 Updated by Adrian Carpenter over 1 year ago

  • File debug-tm0-20171218134531.txz added

#2 Updated by Dru Lavigne over 1 year ago

  • Has duplicate Bug #26596: AFP auth against macOS LDAP/KRB5 stopped added

#3 Updated by Dru Lavigne over 1 year ago

  • Assignee changed from Release Council to John Hixson
  • Target version set to 11.1-U1
  • Private changed from No to Yes

#4 Updated by John Hixson over 1 year ago

  • Status changed from Unscreened to Screened

#5 Avatar?id=14398&size=24x24 Updated by Kris Moore over 1 year ago

  • Target version changed from 11.1-U1 to 11.2-BETA1

#6 Updated by Dru Lavigne about 1 year ago

  • Status changed from Screened to Not Started
  • Target version changed from 11.2-BETA1 to 11.2-RC2

#7 Updated by John Hixson about 1 year ago

  • Assignee changed from John Hixson to Timur Bakeyev

#8 Updated by Timur Bakeyev about 1 year ago

  • Description updated (diff)
  • Assignee changed from Timur Bakeyev to John Hixson

#10 Updated by John Hixson about 1 year ago

  • Severity set to Medium

#11 Updated by John Hixson 12 months ago

I can confirm this is broken here as well. Diving in, it looks very broke ;-) I'll be working on making this fix. This might be a good time to bring in nss-pam-ldapd as described in ticket #23392 .

#12 Updated by John Hixson 12 months ago

I have committed some fixes for this. I can make this work so long as I modify the SSL/TLS stuff to not verify the certificate, since for some reason that is failing when a self signed certificate is in the chain. I'm currently looking into how to handle this.

#13 Updated by John Hixson 12 months ago

So I created a new CA and certificate chain on macOS to debug this, and tried importing the CA into FreeNAS only for it backtrace because of an integer overflow. This is due to the serial being an unsigned 64-bit integer. I'm fixing this while here and will continue with this once done.

#14 Updated by John Hixson 12 months ago

  • Status changed from Not Started to In Progress

#15 Updated by John Hixson 12 months ago

This is working for me after my latest round of commits. This should be available in the nightly tonight or tomorrow. Can you verify?

#16 Updated by Adrian Carpenter 12 months ago

John Hixson wrote:

This is working for me after my latest round of commits. This should be available in the nightly tonight or tomorrow. Can you verify?

Hi John yes I give it a go on Friday.

Adrian

#17 Updated by Dru Lavigne 11 months ago

  • Subject changed from AFP auth against macOS LDAP/KRB5 to Allow unsigned 64-bit serials for certificates which allows AFP auth against macOS LDAP/KRB5
  • Status changed from In Progress to Ready for Testing
  • Target version changed from 11.2-RC2 to 11.2-BETA1
  • Private changed from Yes to No
  • Needs Doc changed from Yes to No
  • Needs Merging changed from Yes to No

#18 Updated by Dru Lavigne 11 months ago

  • File deleted (debug-tm0-20171218134531.txz)

#20 Updated by John Hixson 11 months ago

Adrian Carpenter wrote:

John Hixson wrote:

This is working for me after my latest round of commits. This should be available in the nightly tonight or tomorrow. Can you verify?

Hi John yes I give it a go on Friday.

Adrian

Adrian, did you get a chance to test this?

#21 Updated by Adrian Carpenter 11 months ago

17787

Hi John - I tried last weekend but after switch to the nightly stream, updating etc the machine didn't come back. I was doing this remove and sadly the box does not have remove KVM. I'm also on sick leave at the moment recovering from a stroke. So I when to the machine yesterday and found the console not finding a kernel (see attached screen shot). I got the machine back by booting from an install USB of the U4 release, and via upgrade install got it back. I then switched to the nightly stream and did the update only to arrive back at the same place! I will get the machine back today and await further instructions. Adrian

#22 Updated by Eric Turgeon 10 months ago

Any news Adrian.

#23 Updated by Adrian Carpenter 10 months ago

Eric Turgeon wrote:

Any news Adrian.

Hi Eric

As noted above changing to nightly stream breaks my machine. If I build from git will that make an install image with the fixes?

I’m away until the weekend and wait your suggestions
Adrian

#24 Updated by Nick Wolff 10 months ago

  • Status changed from Ready for Testing to Passed Testing

Marking as passed testing because are QA department doesn't have the proper setup to verify this.

Adrian. 11.2-Beta1 will be out soon that you will be able to test with. We appreciate any feedback you have

#25 Updated by Dru Lavigne 10 months ago

  • Status changed from Passed Testing to Done
  • Needs QA changed from Yes to No

#26 Updated by John Hixson 9 months ago

  • Copied to Bug #40724: Allow unsigned 64-bit serials for certificates which allows AFP auth against macOS LDAP/KRB5 added

Also available in: Atom PDF