Sep 14 12:47:12 serverbox sshd[29764]: debug3: fd 4 is not O_NONBLOCK
Sep 14 12:47:12 serverbox sshd[29764]: debug1: Forked child 2272.
Sep 14 12:47:12 serverbox sshd[29764]: debug3: send_rexec_state: entering fd = 7 config len 1105
Sep 14 12:47:12 serverbox sshd[29764]: debug3: ssh_msg_send: type 0
Sep 14 12:47:12 serverbox sshd[29764]: debug3: send_rexec_state: done
Sep 14 12:47:12 serverbox sshd[2272]: debug3: oom_adjust_restore
Sep 14 12:47:12 serverbox sshd[2272]: Set /proc/self/oom_score_adj to 0
Sep 14 12:47:12 serverbox sshd[2272]: debug1: rexec start in 4 out 4 newsock 4 pipe 6 sock 7
Sep 14 12:47:12 serverbox sshd[2272]: FIPS mode initialized
Sep 14 12:47:12 serverbox sshd[2272]: debug1: inetd sockets after dupping: 3, 3
Sep 14 12:47:12 serverbox sshd[2272]: Connection from 1.1.1.77 port 19979 on $SERVER_IP port 22
Sep 14 12:47:12 serverbox sshd[2272]: debug1: Client protocol version 2.0; client software version PuTTY_Local:_May__9_2016_09:21:40
Sep 14 12:47:12 serverbox sshd[2272]: debug1: no match: PuTTY_Local:_May__9_2016_09:21:40
Sep 14 12:47:12 serverbox sshd[2272]: debug1: Enabling compatibility mode for protocol 2.0
Sep 14 12:47:12 serverbox sshd[2272]: debug1: Local version string SSH-2.0-OpenSSH_6.6.1
Sep 14 12:47:12 serverbox sshd[2272]: debug2: fd 3 setting O_NONBLOCK
Sep 14 12:47:12 serverbox sshd[2272]: debug3: ssh_sandbox_init: preparing rlimit sandbox
Sep 14 12:47:12 serverbox sshd[2272]: debug2: Network child is on pid 2289
Sep 14 12:47:12 serverbox sshd[2272]: debug3: preauth child monitor started
Sep 14 12:47:12 serverbox sshd[2272]: debug1: SELinux support enabled [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: ssh_selinux_change_context: setting context from 'system_u:system_r:sshd_t:s0-s0:c0.c1023' to 'system_u:system_r:sshd_net_t:s0-s0:c0.c1023' [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: privsep user:group 74:74 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: permanently_set_uid: 74/74 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: list_hostkey_types: ssh-rsa,ecdsa-sha2-nistp256 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: SSH2_MSG_KEXINIT sent [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: SSH2_MSG_KEXINIT received [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: ssh-rsa,ecdsa-sha2-nistp256 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,aes128-cbc,3des-cbc,aes192-cbc,aes256-cbc [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,aes128-cbc,3des-cbc,aes192-cbc,aes256-cbc [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: hmac-sha2-512,hmac-sha2-256,hmac-sha1 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: hmac-sha2-512,hmac-sha2-256,hmac-sha1 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: none,zlib@openssh.com [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: none,zlib@openssh.com [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: first_kex_follows 0 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: reserved 0 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,rsa2048-sha256,rsa1024-sha1,diffie-hellman-group1-sha1 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: ssh-rsa,ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-dss [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: aes256-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-ctr,aes192-cbc,aes128-ctr,aes128-cbc,chacha20-poly1305@openssh.com,blowfish-ctr,blowfish-cbc,3des-ctr,3des-cbc,arcfour256,arcfour128 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: aes256-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-ctr,aes192-cbc,aes128-ctr,aes128-cbc,chacha20-poly1305@openssh.com,blowfish-ctr,blowfish-cbc,3des-ctr,3des-cbc,arcfour256,arcfour128 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: hmac-sha2-256,hmac-sha1,hmac-sha1-96,hmac-md5,hmac-sha2-256-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-etm@openssh.com [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: hmac-sha2-256,hmac-sha1,hmac-sha1-96,hmac-md5,hmac-sha2-256-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-etm@openssh.com [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: none,zlib [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: none,zlib [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: first_kex_follows 0 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_parse_kexinit: reserved 0 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: mac_setup: setup hmac-sha2-256 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: kex: client->server aes256-ctr hmac-sha2-256 none [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: mac_setup: setup hmac-sha2-256 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: kex: server->client aes256-ctr hmac-sha2-256 none [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: kex: ecdh-sha2-nistp256 need=32 dh_need=32 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 120 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 121 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 120
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 121
Sep 14 12:47:12 serverbox sshd[2272]: debug1: kex: ecdh-sha2-nistp256 need=32 dh_need=32 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 120 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 121 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 120
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 121
Sep 14 12:47:12 serverbox sshd[2272]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_key_sign entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 6 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 7 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 6
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_answer_sign
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_answer_sign: signature 0x7fcbfac10000(271)
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 7
Sep 14 12:47:12 serverbox sshd[2272]: debug2: monitor_read: 6 used once, disabling now
Sep 14 12:47:12 serverbox sshd[2272]: debug2: kex_derive_keys [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: set_newkeys: mode 1 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: expecting SSH2_MSG_NEWKEYS [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: set_newkeys: mode 0 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: SSH2_MSG_NEWKEYS received [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: KEX done [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: userauth-request for user specialuser service ssh-connection method none [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: attempt 0 failures 0 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_getpwnamallow entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 8 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 9 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 8
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_answer_pwnamallow
Sep 14 12:47:12 serverbox sshd[2272]: debug3: Trying to reverse map address 1.1.1.77.
Sep 14 12:47:12 serverbox sshd[2272]: debug2: parse_server_config: config reprocess config len 1105
Sep 14 12:47:12 serverbox sshd[2272]: debug3: checking match for 'group sftponly' user specialuser host specialuser1234.sub.example.com addr 1.1.1.77 laddr $SERVER_IP lport 22
Sep 14 12:47:12 serverbox sshd[2272]: debug1: user specialuser matched group list sftponly at line 162
Sep 14 12:47:12 serverbox sshd[2272]: debug3: match found
Sep 14 12:47:12 serverbox sshd[2272]: debug3: reprocess config:163 setting PasswordAuthentication yes
Sep 14 12:47:12 serverbox sshd[2272]: debug3: reprocess config:164 setting ChrootDirectory %h
Sep 14 12:47:12 serverbox sshd[2272]: debug3: reprocess config:165 setting AllowTcpForwarding no
Sep 14 12:47:12 serverbox sshd[2272]: debug3: reprocess config:166 setting ForceCommand internal-sftp
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 9
Sep 14 12:47:12 serverbox sshd[2272]: debug2: monitor_read: 8 used once, disabling now
Sep 14 12:47:12 serverbox sshd[2272]: debug2: input_userauth_request: setting up authctxt for specialuser [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_start_pam entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 100 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_inform_authserv entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 4 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_inform_authrole entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 80 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_auth2_read_banner entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 10 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 11 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 100
Sep 14 12:47:12 serverbox sshd[2272]: debug1: PAM: initializing for "specialuser"
Sep 14 12:47:12 serverbox sshd[2272]: debug1: PAM: setting PAM_RHOST to "specialuser1234.sub.example.com"
Sep 14 12:47:12 serverbox sshd[2272]: debug1: PAM: setting PAM_TTY to "ssh"
Sep 14 12:47:12 serverbox sshd[2272]: debug2: monitor_read: 100 used once, disabling now
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 4
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_answer_authserv: service=ssh-connection, style=
Sep 14 12:47:12 serverbox sshd[2272]: debug2: monitor_read: 4 used once, disabling now
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 80
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_answer_authrole: role=
Sep 14 12:47:12 serverbox sshd[2272]: debug2: monitor_read: 80 used once, disabling now
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 10
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 11
Sep 14 12:47:12 serverbox sshd[2272]: debug2: monitor_read: 10 used once, disabling now
Sep 14 12:47:12 serverbox sshd[2272]: debug1: userauth_send_banner: sent [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: input_userauth_request: try method none [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: userauth_finish: failure partial=0 next methods="publickey,gssapi-keyex,gssapi-with-mic,password" [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: userauth-request for user specialuser service ssh-connection method password [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: attempt 1 failures 0 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: input_userauth_request: try method password [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_auth_password entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 12 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 13 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 12
Sep 14 12:47:12 serverbox sshd[2272]: debug3: PAM: sshpam_passwd_conv called with 1 messages
Sep 14 12:47:12 serverbox sshd[2272]: debug1: PAM: password authentication accepted for specialuser
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_answer_authpassword: sending result 1
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 13
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 102
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug1: do_pam_account: called
Sep 14 12:47:12 serverbox sshd[2272]: pam_unix(sshd:account): expired password for user specialuser (root enforced)
Sep 14 12:47:12 serverbox sshd[2272]: debug3: PAM: sshpam_passwd_conv called with 1 messages
Sep 14 12:47:12 serverbox sshd[2272]: debug3: PAM: do_pam_account pam_acct_mgmt = 12 (Authentication token is no longer valid; new one required)
Sep 14 12:47:12 serverbox sshd[2272]: debug3: sshpam_password_change_required 1
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 103
Sep 14 12:47:12 serverbox sshd[2272]: Accepted password for specialuser from 1.1.1.77 port 19979 ssh2
Sep 14 12:47:12 serverbox sshd[2272]: debug1: monitor_child_preauth: specialuser has been authenticated by privileged process
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_get_keystate: Waiting for new keys
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 26
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_newkeys_from_blob: 0x7fcbfac0fa70(159)
Sep 14 12:47:12 serverbox sshd[2272]: debug2: mac_setup: setup hmac-sha2-256
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_get_keystate: Waiting for second key
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_newkeys_from_blob: 0x7fcbfac0fa70(159)
Sep 14 12:47:12 serverbox sshd[2272]: debug2: mac_setup: setup hmac-sha2-256
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_get_keystate: Getting compression state
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_get_keystate: Getting Network I/O buffers
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 122
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 123
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_auth_password: user authenticated [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_do_pam_account entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 102 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 103 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_do_pam_account returning 1 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_send_keystate: Sending new keys: 0x7fcbfac1d080 0x7fcbfac10830 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_newkeys_to_blob: converting 0x7fcbfac1d080 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_newkeys_to_blob: converting 0x7fcbfac10830 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_send_keystate: New keys have been sent [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_send_keystate: Sending compression state [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 26 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_send_keystate: Finished sending state [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 122 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 123 [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering [preauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: monitor_read_log: child log fd closed
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_share_sync: Share sync
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_share_sync: Share sync end
Sep 14 12:47:12 serverbox sshd[2272]: debug3: ssh_sandbox_parent_finish: finished
Sep 14 12:47:12 serverbox sshd[2272]: debug1: temporarily_use_uid: 1001/1003 (e=0/0)
Sep 14 12:47:12 serverbox sshd[2272]: debug1: ssh_gssapi_storecreds: Not a GSSAPI mechanism
Sep 14 12:47:12 serverbox sshd[2272]: debug1: restore_uid: 0/0
Sep 14 12:47:12 serverbox sshd[2272]: debug1: SELinux support enabled
Sep 14 12:47:12 serverbox sshd[2272]: debug3: sshd_selinux_setup_variables: setting execution context
Sep 14 12:47:12 serverbox sshd[2272]: debug1: PAM: establishing credentials
Sep 14 12:47:12 serverbox sshd[2272]: debug3: PAM: opening session
Sep 14 12:47:12 serverbox sshd[2272]: pam_unix(sshd:session): session opened for user specialuser by (uid=0)
Sep 14 12:47:12 serverbox sshd[2272]: debug3: PAM: sshpam_store_conv called with 1 messages
Sep 14 12:47:12 serverbox sshd[2272]: debug3: PAM: sshpam_store_conv called with 1 messages
Sep 14 12:47:12 serverbox sshd[2272]: debug1: monitor_reinit: /dev/log doesn't exist in %h chroot - will try to log via monitor using [postauth] suffix
Sep 14 12:47:12 serverbox sshd[2272]: User child is on pid 2306
Sep 14 12:47:12 serverbox sshd[2272]: debug1: PAM: establishing credentials [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: sshd_selinux_setup_variables: setting execution context [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: safely_chroot: checking '/' [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: safely_chroot: checking '/home/' [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: safely_chroot: checking '/home/specialuser' [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: Changed root directory to "/home/specialuser" [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: permanently_set_uid: 1001/1003 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: sshd_selinux_copy_context: getcon failed with No such file or directory [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: set_newkeys: mode 0 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: set_newkeys: mode 1 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: Entering interactive session for SSH2. [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: fd 5 setting O_NONBLOCK [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: fd 7 setting O_NONBLOCK [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: server_init_dispatch_20 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: Received SSH2_MSG_IGNORE [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: server_input_channel_open: ctype session rchan 256 win 2147483647 max 16384 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: input_session_request [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: channel 0: new [server-session] [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: session_new: allocate (allocated 0 max 10) [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: session_unused: session id 0 unused [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: session_new: session 0 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: session_open: channel 0 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: session_open: session 0: link with channel 0 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: server_input_channel_open: confirm session [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: server_input_channel_req: channel 0 request simple@putty.projects.tartarus.org reply 0 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: session_by_channel: session 0 channel 0 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: session_input_channel_req: session 0 req simple@putty.projects.tartarus.org [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: server_input_channel_req: channel 0 request subsystem reply 1 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: session_by_channel: session 0 channel 0 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: session_input_channel_req: session 0 req subsystem [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: subsystem request for sftp by user specialuser [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: subsystem: internal-sftp [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: Starting session: forced-command (config) 'internal-sftp' for specialuser from 1.1.1.77 port 19979 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_audit_run_command entering command internal-sftp [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 114 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 115 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 114
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_answer_audit_command entering
Sep 14 12:47:12 serverbox sshd[2272]: debug2: session_new: allocate (allocated 0 max 10)
Sep 14 12:47:12 serverbox sshd[2272]: debug3: session_unused: session id 0 unused
Sep 14 12:47:12 serverbox sshd[2272]: debug1: session_new: session 0
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 115
Sep 14 12:47:12 serverbox sshd[2272]: debug2: fd 3 setting TCP_NODELAY [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: packet_set_tos: set IP_TOS 0x08 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: fd 11 setting O_NONBLOCK [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: fd 10 setting O_NONBLOCK [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: fd 13 setting O_NONBLOCK [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: read 83 from efd 13 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: channel 0: discard efd [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: Received SIGCHLD. [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: session_by_pid: pid 2307 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: session_exit_message: session 0 channel 0 pid 2307 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: request exit-status confirm 0 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: session_exit_message: release channel 0 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: write failed [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: close_write [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: send eow [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: output open -> closed [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: read<=0 rfd 11 len 0 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: read failed [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: close_read [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: input open -> drain [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: read 0 from efd 13 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: closing read-efd 13 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: ibuf empty [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: send eof [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: input drain -> closed [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: channel 0: send close [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug2: notify_done: reading [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: channel 0: will not send data after close [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: channel 0: will not send data after close [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: Connection closed by 1.1.1.77 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: channel 0: free: server-session, nchannels 1 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: channel 0: status: The following connections are open:\\r\\n #0 server-session (t4 r256 i3/0 o3/0 fd -1/-1 cc -1)\\r\\n [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: session_close: session 0 pid 0 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_audit_end_command entering command internal-sftp [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 116 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: session_unused: session id 0 unused [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug1: do_cleanup [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: PAM: sshpam_thread_cleanup entering [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 122 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive_expect entering: type 123 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 116
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_answer_audit_end_command entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_session_close: session 0 pid 0
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_session_close: command 0
Sep 14 12:47:12 serverbox sshd[2272]: debug3: session_unused: session id 0 unused
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 122
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 123
Sep 14 12:47:12 serverbox sshd[2272]: Transferred: sent 1976, received 1728 bytes [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: Closing connection to 1.1.1.77 port 19979 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_audit_event entering [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 112 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_send entering: type 50 [postauth]
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 112
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_answer_audit_event entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_request_receive entering
Sep 14 12:47:12 serverbox sshd[2272]: debug3: monitor_read: checking request 50
Sep 14 12:47:12 serverbox sshd[2272]: debug3: mm_answer_term: tearing down sessions
Sep 14 12:47:12 serverbox sshd[2272]: debug1: PAM: cleanup
Sep 14 12:47:12 serverbox sshd[2272]: debug1: PAM: closing session
Sep 14 12:47:12 serverbox sshd[2272]: pam_unix(sshd:session): session closed for user specialuser
Sep 14 12:47:12 serverbox sshd[2272]: debug1: PAM: deleting credentials