Oct 15 19:01:50 S0W1 sshd[16842774]: debug1: fd 6 clearing O_NONBLOCK Oct 15 19:01:50 S0W1 sshd[16842774]: debug3: zsshMaybePropagateJscbauthToChildOnFork: propagate JSCBAUTH to child(PRVMON) Oct 15 19:01:51 S0W1 sshd[16842774]: debug1: Forked child 50397435. Oct 15 19:01:51 S0W1 sshd[50397435]: debug1: rexec start in 6 out 6 newsock 6 pipe 8 sock 9 Oct 15 19:01:51 S0W1 sshd[16842774]: debug3: send_rexec_state: entering fd = 9 config len 519, zos_config len 1 Oct 15 19:01:51 S0W1 sshd[16842774]: debug3: ssh_msg_send: type 0 Oct 15 19:01:51 S0W1 sshd[16842774]: debug3: send_rexec_state: done Oct 15 19:01:51 S0W1 sshd[50397435]: debug1: inetd sockets after dupping: 5, 5 Oct 15 19:01:51 S0W1 sshd[50397435]: debug1: cipher_init: none from source none, used in non-FIPS mode Oct 15 19:01:51 S0W1 sshd[50397435]: debug1: cipher_init: none from source none, used in non-FIPS mode Oct 15 19:01:51 S0W1 sshd[50397435]: debug3: zssh_packet_configure_socket: current getsockopt(5, SOL_SOCKET,SO_SNDBUF) = 65536 Oct 15 19:01:51 S0W1 sshd[50397435]: debug3: zssh_packet_configure_socket: current getsockopt(5, SOL_SOCKET,SO_RCVBUF) = 65536 Oct 15 19:01:51 S0W1 sshd[50397435]: Connection from xx.xx.xx.xx port 54743 on 10.1.1.2 port 22 Oct 15 19:01:51 S0W1 sshd[50397435]: debug1: zsshSmfSetConnSmfStatus: SMF status is 0 Oct 15 19:01:51 S0W1 sshd[50397435]: debug1: zsshSmfTestRecord: SMF is collecting type 119, subtype 98 records Oct 15 19:01:51 S0W1 sshd[50397435]: debug1: zsshSmfTestRecord: SMF is collecting type 119, subtype 95 records Oct 15 19:01:51 S0W1 sshd[50397435]: debug3: zsshSmfSetCommonData: SMF type 119 subtype 98 Oct 15 19:01:51 S0W1 sshd[50397435]: debug1: Client protocol version 2.0; client software version OpenSSH_9.0 Oct 15 19:01:51 S0W1 sshd[50397435]: debug1: match: OpenSSH_9.0 pat OpenSSH* compat 0x04000000 Oct 15 19:01:51 S0W1 sshd[50397435]: debug1: Local version string SSH-2.0-OpenSSH_7.6 Oct 15 19:01:51 S0W1 sshd[50397435]: debug2: fd 5 setting O_NONBLOCK Oct 15 19:01:51 S0W1 sshd[50397435]: debug3: zsshMaybePropagateJscbauthToChildOnFork: No propagate JSCBAUTH to child(PRVCHLD) Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: Network child is on pid 16843004 Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: Current IBM Release level: 27 Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: MLS: seclabel of AS: uid:0 pid:50397435 Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: MLS: peer socket: rc:0 t:0 seclabel: terminal:093DF217 poe_profile: Oct 15 19:01:52 S0W1 sshd[50397435]: Port of Entry information retained for uid:0 pid:50397435. Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: MLS: seclabel of AS: uid:0 pid:50397435 Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: MLS: peer socket: rc:0 t:0 seclabel: terminal:093DF217 poe_profile: Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: MLS: /var/empty: rc:0 t:1 seclabel: terminal: poe_profile: Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: preauth child monitor started Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: privsep user:group 9:9 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug1: permanently_set_uid: 9/9 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: setUseZEDC: 0 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: list_hostkey_types: ssh-dss key not permitted by HostkeyAlgorithms [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: send packet: type 20 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug1: SSH2_MSG_KEXINIT sent [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: receive packet: type 20 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug1: SSH2_MSG_KEXINIT received [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: local server KEXINIT proposal [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: host key algorithms: ssh-rsa,rsa-sha2-512,rsa-sha2-256 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: ciphers ctos: aes128-ctr,aes192-ctr,aes256-ctr,aes128-cbc,aes192-cbc,aes256-cbc [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: ciphers stoc: aes128-ctr,aes192-ctr,aes256-ctr,aes128-cbc,aes192-cbc,aes256-cbc [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: MACs ctos: hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: MACs stoc: hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: compression ctos: none,zlib@openssh.com [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: compression stoc: none,zlib@openssh.com [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: languages ctos: [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: languages stoc: [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: first_kex_follows 0 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: reserved 0 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: peer client KEXINIT proposal [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: KEX algorithms: sntrup761x25519-sha512@openssh.com,curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,ext-info-c [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: host key algorithms: rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-ed25519-cert-v01@openssh.com,ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: compression ctos: none,zlib@openssh.com,zlib [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: compression stoc: none,zlib@openssh.com,zlib [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: languages ctos: [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: languages stoc: [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: first_kex_follows 0 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug2: reserved 0 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug1: kex: algorithm: curve25519-sha256 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug1: choose_kex: curve25519-sha256 from source OpenSSL, used in non-FIPS mode [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug1: kex: host key algorithm: rsa-sha2-512 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug1: mac_setup_by_alg: hmac-sha2-256-etm@openssh.com from source CPACF, used in non-FIPS mode [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug1: mac_setup_by_alg: hmac-sha2-256-etm@openssh.com from source CPACF, used in non-FIPS mode [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: receive packet: type 30 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: mm_key_sign entering [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 6 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: mm_request_receive_expect entering: type 7 [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: mm_request_receive entering [preauth] Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: mm_request_receive entering Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: monitor_read: checking request 6 Oct 15 19:01:52 S0W1 sshd[50397435]: debug3: mm_answer_sign Oct 15 19:01:53 S0W1 sshd[50397435]: debug3: mm_answer_sign: hostkey proof signature 209A85D0(276) Oct 15 19:01:53 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 7 Oct 15 19:01:53 S0W1 sshd[50397435]: debug2: monitor_read: 6 used once, disabling now Oct 15 19:01:53 S0W1 sshd[50397435]: debug3: send packet: type 31 [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug3: send packet: type 21 [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug2: set_newkeys: mode 1 [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug1: cipher_init: aes128-ctr from source CPACF, used in non-FIPS mode [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug1: rekey after 4294967296 blocks [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug1: SSH2_MSG_NEWKEYS sent [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug1: expecting SSH2_MSG_NEWKEYS [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug3: send packet: type 7 [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug3: receive packet: type 21 [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug1: SSH2_MSG_NEWKEYS received [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug2: set_newkeys: mode 0 [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug1: cipher_init: aes128-ctr from source CPACF, used in non-FIPS mode [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug1: rekey after 4294967296 blocks [preauth] Oct 15 19:01:53 S0W1 sshd[50397435]: debug1: KEX done [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: receive packet: type 5 [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: send packet: type 6 [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: receive packet: type 50 [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug1: userauth-request for user ibmuser service ssh-connection method none [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug1: attempt 0 failures 0 [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_getpwnamallow entering [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 8 [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_request_receive_expect entering: type 9 [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_request_receive entering [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_request_receive entering Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: monitor_read: checking request 8 Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_answer_pwnamallow Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: get_pwnamallow: input user name ibmuser, user database name IBMUSER Oct 15 19:01:54 S0W1 sshd[50397435]: debug2: parse_server_config: config reprocess config len 519 Oct 15 19:01:54 S0W1 sshd[50397435]: debug2: parse_server_config: config reprocess config len 1 Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1 Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 9 Oct 15 19:01:54 S0W1 sshd[50397435]: debug2: monitor_read: 8 used once, disabling now Oct 15 19:01:54 S0W1 sshd[50397435]: debug2: input_userauth_request: setting up authctxt for ibmuser [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug1: zsshSmfSetConnSmfStatus: SMF status is 0 [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_inform_authserv entering [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 4 [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug2: input_userauth_request: try method none [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug2: userauth_finish: skipping server login failure record for method none on attempt 1 [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: userauth_finish: failure partial=0 next methods="publickey,password" [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: send packet: type 51 [preauth] Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_request_receive entering Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: monitor_read: checking request 4 Oct 15 19:01:54 S0W1 sshd[50397435]: debug3: mm_answer_authserv: service=ssh-connection, style= Oct 15 19:01:54 S0W1 sshd[50397435]: debug2: monitor_read: 4 used once, disabling now Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: receive packet: type 50 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: userauth-request for user ibmuser service ssh-connection method publickey [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: attempt 1 failures 0 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug2: input_userauth_request: try method publickey [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: zsshSmfSetAuthenticationKey: serverKey=0 key=209B36C8 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: userauth_pubkey: test whether pkalg/pkblob are acceptable for RSA SHA256:xxxxxxxxxxxxxxxxxxxxxxxx [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_key_allowed entering [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 22 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive_expect entering: type 23 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive entering [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive entering Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: monitor_read: checking request 22 Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_answer_keyallowed entering Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_answer_keyallowed: key_from_blob: 209B30B8 Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: temporarily_use_uid: 0/0 (e=0/0) Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: trying public key file /u/ibmuser/.ssh/authorized_keys Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: fd 4 clearing O_NONBLOCK Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: matching key found: file /u/ibmuser/.ssh/authorized_keys, line 7 RSA SHA256:xxxxxxxxxxxxxxxxxxxxxxxx Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: restore_uid: 0/0 Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_answer_keyallowed: key is allowed Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 23 Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: send packet: type 60 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug2: userauth_pubkey: authenticated 0 pkalg rsa-sha2-512 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: auth_log: authenticated 0, valid 1, failures 0, max 6, half 3, method publickey [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: Postponed publickey for ibmuser from xx.xx.xx.xx port 54743 ssh2 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: receive packet: type 50 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: userauth-request for user ibmuser service ssh-connection method publickey [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: attempt 2 failures 0 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug2: input_userauth_request: try method publickey [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: zsshSmfSetAuthenticationKey: serverKey=0 key=209B33C0 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: userauth_pubkey: have signature for RSA SHA256:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_key_allowed entering [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 22 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive_expect entering: type 23 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive entering [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive entering Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: monitor_read: checking request 22 Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_answer_keyallowed entering Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_answer_keyallowed: key_from_blob: 209B3368 Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: temporarily_use_uid: 0/0 (e=0/0) Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: trying public key file /u/ibmuser/.ssh/authorized_keys Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: fd 4 clearing O_NONBLOCK Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: matching key found: file /u/ibmuser/.ssh/authorized_keys, line 7 RSA SHA256:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: restore_uid: 0/0 Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_answer_keyallowed: key is allowed Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 23 Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_sshkey_verify entering [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 24 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_sshkey_verify: waiting for MONITOR_ANS_KEYVERIFY [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive_expect entering: type 25 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive entering [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive entering Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: monitor_read: checking request 24 Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_answer_keyverify: publickey 209B30F8 signature verified Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 25 Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: auth_log: authenticated 1, valid 1, failures 0, max 6, half 3, method publickey Oct 15 19:01:55 S0W1 sshd[50397435]: Accepted publickey for ibmuser from xx.xx.xx.xx port 54743 ssh2: RSA SHA256:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: monitor_child_preauth: ibmuser has been authenticated by privileged process Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_get_keystate: Waiting for new keys Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive_expect entering: type 26 Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive entering Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_get_keystate: GOT new keys Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: zsshSmfGetConnectionInfo: Waiting for SMF connection info. Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive_expect entering: type 114 Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_receive entering Oct 15 19:01:55 S0W1 sshd[50397435]: debug2: userauth_pubkey: authenticated 1 pkalg rsa-sha2-512 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: send packet: type 52 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 26 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_send_keystate: Finished sending state [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: zsshSmfSendConnectionInfo: Sending SMF connection info. [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: mm_request_send entering: type 114 [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: zsshSmfSendConnectionInfo: Finished sending SMF connection info. [preauth] Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: monitor_read_log: child log fd closed Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: setUseZEDC: 0 Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: monitor_apply_keystate: packet_set_state Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: mac_setup_by_alg: hmac-sha2-256-etm@openssh.com from source CPACF, used in non-FIPS mode Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: mac_setup_by_alg: hmac-sha2-256-etm@openssh.com from source CPACF, used in non-FIPS mode Oct 15 19:01:55 S0W1 sshd[50397435]: debug2: set_newkeys: mode 0 Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: cipher_init: aes128-ctr from source CPACF, used in non-FIPS mode Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: rekey after 4294967296 blocks Oct 15 19:01:55 S0W1 sshd[50397435]: debug2: set_newkeys: mode 1 Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: cipher_init: aes128-ctr from source CPACF, used in non-FIPS mode Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: rekey after 4294967296 blocks Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: ssh_packet_set_postauth: called Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: ssh_packet_set_state: done Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: notify_hostkeys: key 0: ssh-rsa SHA256:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: notify_hostkeys: key 1: ssh-dss SHA256:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: notify_hostkeys: sent 2 hostkeys Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: send packet: type 80 Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: Entering interactive session for SSH2. Oct 15 19:01:55 S0W1 sshd[50397435]: debug2: fd 4 setting O_NONBLOCK Oct 15 19:01:55 S0W1 sshd[50397435]: debug2: fd 6 setting O_NONBLOCK Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: server_init_dispatch Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: receive packet: type 90 Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768 Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: input_session_request Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: channel 0: new [server-session] Oct 15 19:01:55 S0W1 sshd[50397435]: debug2: session_new: allocate (allocated 0 max 10) Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: session_unused: session id 0 unused Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: session_new: session 0 Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: session_open: channel 0 Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: session_open: session 0: link with channel 0 Oct 15 19:01:55 S0W1 sshd[50397435]: debug1: server_input_channel_open: confirm session Oct 15 19:01:55 S0W1 sshd[50397435]: debug3: send packet: type 91 Oct 15 19:01:56 S0W1 sshd[50397435]: debug3: receive packet: type 80 Oct 15 19:01:56 S0W1 sshd[50397435]: debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0 Oct 15 19:01:56 S0W1 sshd[50397435]: debug3: receive packet: type 98 Oct 15 19:01:56 S0W1 sshd[50397435]: debug1: server_input_channel_req: channel 0 request env reply 0 Oct 15 19:01:56 S0W1 sshd[50397435]: debug3: channel 0: is not converting type "env" Oct 15 19:01:56 S0W1 sshd[50397435]: debug1: session_by_channel: session 0 channel 0 Oct 15 19:01:56 S0W1 sshd[50397435]: debug1: session_input_channel_req: session 0 req env Oct 15 19:01:56 S0W1 sshd[50397435]: debug2: Ignoring env request LANG: disallowed name Oct 15 19:01:56 S0W1 sshd[50397435]: debug3: receive packet: type 98 Oct 15 19:01:56 S0W1 sshd[50397435]: debug1: server_input_channel_req: channel 0 request exec reply 1 Oct 15 19:01:56 S0W1 sshd[50397435]: debug3: channel 0: is converting type "exec" Oct 15 19:01:56 S0W1 sshd[50397435]: debug1: session_by_channel: session 0 channel 0 Oct 15 19:01:56 S0W1 sshd[50397435]: debug1: session_input_channel_req: session 0 req exec Oct 15 19:01:56 S0W1 sshd[50397435]: Starting session: command for IBMUSER from xx.xx.xx.xx port 54743 id 0 Oct 15 19:01:56 S0W1 sshd[50397435]: debug3: do_exec: subsystem 0 Oct 15 19:01:56 S0W1 sshd[50397435]: debug3: do_exec: passwd name=IBMUSER, uid=0, gid=0, dir=/u/ibmuser, shell=/bin/sh Oct 15 19:01:56 S0W1 sshd[50397435]: debug3: zsshMaybePropagateJscbauthToChildOnFork: No propagate JSCBAUTH to child(OTHER) Oct 15 19:01:56 S0W1 sshd[50397435]: debug2: fd 5 setting TCP_NODELAY Oct 15 19:01:56 S0W1 sshd[33620220]: debug3: zsshCloseOldDev: fd=-1 Oct 15 19:01:56 S0W1 sshd[50397435]: debug2: fd 10 setting O_NONBLOCK Oct 15 19:01:56 S0W1 sshd[33620220]: debug3: zsshCloseOldDev: fd=-1 Oct 15 19:01:56 S0W1 sshd[50397435]: debug2: fd 9 setting O_NONBLOCK Oct 15 19:01:56 S0W1 sshd[50397435]: debug2: fd 13 setting O_NONBLOCK Oct 15 19:01:56 S0W1 sshd[50397435]: debug3: zsshZertSetAttributes(2): SECATTR_IOCTL: 010202000000113c00000000206a4800c9c2d440d6978595e2e2c8404040404000000000000000000000000000000000 Oct 15 19:01:56 S0W1 sshd[33620220]: debug1: permanently_set_uid: 0/0 Oct 15 19:01:56 S0W1 sshd[50397435]: debug3: zsshZertSetAttributes(2): _SECATTR_SSH_SPEC: 0200c00000000000e2c3d7e24040404000030000000f00060013000f00060013000100000002100000000020 Oct 15 19:01:56 S0W1 sshd[50397435]: debug3: zERT SIOCSECATTR failed: EDC5247I Operation not supported. (errno2=0x76647365) Oct 15 19:01:56 S0W1 sshd[50397435]: debug3: send packet: type 99