SSH rekey not being handled and causing all jobs to fail

luke · April 13, 2022, 6:28pm

Is this your first time deploying Airbyte?: No
Deployment: Kubernetes
Airbyte Version: 0.35.31
Source name/version: MSSQL 0.3.19
Destination name/version: Snowflake 0.4.24
Step: sync
Description:

We utilize SSH tunneling (via key auth) for client database connections. For our MSSQL (SQL Server) connections, we’re seeing our jobs/syncs fail as soon as an SSH rekey (exchanging the session keys) occurs (for us this happens every time the negotiated cipher hits its max transfer limit of 2GB). Here’s what we’re seeing in the logs (rekey occurs at 16:46:26):
Airbyte logs:

2022-04-13 16:46:27 source > 2022-04-13 16:46:26 WARN o.a.s.c.k.StaticServerKeyVerifier(handleAcceptance):59 - {} - Server at ssh-proxy.dataprod.overlayanalytics.com/10.226.0.48:22 presented unverified EC key: SHA256:lXlNFtUHEnTPxn6d/cTXffBZueEOiz0S64IQBzbWdJ4
2022-04-13 16:47:16 source > 2022-04-13 16:47:16 WARN o.a.s.c.u.l.LoggingUtils(warn):618 - {} - exceptionCaught(ClientSessionImpl[airbyte@ssh-proxy.dataprod.overlayanalytics.com/10.226.0.48:22])[state=Opened] RuntimeSshException: null

SSH logs:

Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: rekey in after 4294967296 blocks
Apr 13 16:47:20 ip-10-226-0-48 sshd[20837]: Connection closed by 10.226.2.71 port 29260

To reproduce you can set the rekey limit to be very small in your sshd_config (I.E. RekeyLimit 10M none for a 10MB transfer limit). We were unable to set ours to a value greater than 2GB.

Any idea on a workaround or plans to handle an SSH rekey event?

Here’s a full SSH log for reference:

Apr 13 16:32:20 ip-10-226-0-48 sshd[742]: debug1: Received SIGHUP; waiting for children
Apr 13 16:32:20 ip-10-226-0-48 sshd[742]: Received SIGHUP; restarting.
Apr 13 16:32:20 ip-10-226-0-48 sshd[742]: debug1: Set /proc/self/oom_score_adj to 0
Apr 13 16:32:20 ip-10-226-0-48 sshd[742]: debug1: Set /proc/self/oom_score_adj from 0 to -1000
Apr 13 16:32:20 ip-10-226-0-48 sshd[742]: debug1: Bind to port 22 on 0.0.0.0.
Apr 13 16:32:20 ip-10-226-0-48 sshd[742]: Server listening on 0.0.0.0 port 22.
Apr 13 16:32:20 ip-10-226-0-48 sshd[742]: debug1: Bind to port 22 on ::.
Apr 13 16:32:20 ip-10-226-0-48 sshd[742]: Server listening on :: port 22.
Apr 13 16:36:20 ip-10-226-0-48 sshd[742]: debug1: Forked child 20736.
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: Set /proc/self/oom_score_adj to 0
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: rexec start in 5 out 5 newsock 5 pipe 7 sock 8
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: inetd sockets after dupping: 4, 4
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: Connection from 10.226.2.71 port 29260 on 10.226.0.48 port 22 rdomain ""
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: Local version string SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.4
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: Remote protocol version 2.0, remote software version APACHE-SSHD-2.7.0
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: no match: APACHE-SSHD-2.7.0
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: permanently_set_uid: 109/65534 [preauth]
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: SSH2_MSG_KEXINIT sent [preauth]
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: SSH2_MSG_KEXINIT received [preauth]
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: kex: algorithm: ecdh-sha2-nistp521 [preauth]
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none [preauth]
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none [preauth]
Apr 13 16:36:20 ip-10-226-0-48 sshd[20736]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: rekey out after 4294967296 blocks [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: Sending SSH2_MSG_EXT_INFO [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: expecting SSH2_MSG_NEWKEYS [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: SSH2_MSG_NEWKEYS received [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: rekey in after 4294967296 blocks [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: KEX done [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: userauth-request for user airbyte service ssh-connection method none [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: attempt 0 failures 0 [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: PAM: initializing for "airbyte"
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: PAM: setting PAM_RHOST to "10.226.2.71"
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: PAM: setting PAM_TTY to "ssh"
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: userauth-request for user airbyte service ssh-connection method publickey [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: attempt 1 failures 0 [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: userauth_pubkey: test pkalg rsa-sha2-512 pkblob RSA SHA256:KnWanF1bQtjNkk7R3WFtcIOiEcmSlQau9sNx+ooJ2kY [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: trying public key file /home/airbyte/.ssh/authorized_keys
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: fd 5 clearing O_NONBLOCK
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: /home/airbyte/.ssh/authorized_keys:1: matching key found: RSA SHA256:KnWanF1bQtjNkk7R3WFtcIOiEcmSlQau9sNx+ooJ2kY
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: /home/airbyte/.ssh/authorized_keys:1: key options: command port-forwarding
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: /home/airbyte/.ssh/authorized_keys:1: forced command: "/bin/false"
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: Accepted key RSA SHA256:KnWanF1bQtjNkk7R3WFtcIOiEcmSlQau9sNx+ooJ2kY found at /home/airbyte/.ssh/authorized_keys:1
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: restore_uid: 0/0
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: Postponed publickey for airbyte from 10.226.2.71 port 29260 ssh2 [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: userauth-request for user airbyte service ssh-connection method publickey [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: attempt 2 failures 0 [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: trying public key file /home/airbyte/.ssh/authorized_keys
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: fd 5 clearing O_NONBLOCK
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: /home/airbyte/.ssh/authorized_keys:1: matching key found: RSA SHA256:KnWanF1bQtjNkk7R3WFtcIOiEcmSlQau9sNx+ooJ2kY
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: /home/airbyte/.ssh/authorized_keys:1: key options: command port-forwarding
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: /home/airbyte/.ssh/authorized_keys:1: forced command: "/bin/false"
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: Accepted key RSA SHA256:KnWanF1bQtjNkk7R3WFtcIOiEcmSlQau9sNx+ooJ2kY found at /home/airbyte/.ssh/authorized_keys:1
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: restore_uid: 0/0
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: auth_activate_options: setting new authentication options
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: do_pam_account: called
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: Accepted publickey for airbyte from 10.226.2.71 port 29260 ssh2: RSA SHA256:KnWanF1bQtjNkk7R3WFtcIOiEcmSlQau9sNx+ooJ2kY
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: monitor_child_preauth: airbyte has been authenticated by privileged process
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: auth_activate_options: setting new authentication options [preauth]
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: monitor_read_log: child log fd closed
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: debug1: PAM: establishing credentials
Apr 13 16:36:21 ip-10-226-0-48 sshd[20736]: pam_unix(sshd:session): session opened for user airbyte by (uid=0)
Apr 13 16:36:22 ip-10-226-0-48 sshd[20736]: User child is on pid 20837
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: SELinux support disabled
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: PAM: establishing credentials
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: permanently_set_uid: 1000/1000
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: rekey in after 4294967296 blocks
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: rekey out after 4294967296 blocks
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: ssh_packet_set_postauth: called
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: active: key options: command port-forwarding
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: active: forced command: "/bin/false"
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: Entering interactive session for SSH2.
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: server_init_dispatch
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: server_input_channel_open: ctype direct-tcpip rchan 0 win 2097152 max 32768
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: server_request_direct_tcpip: originator 127.0.0.1 port 38284, target 52.176.157.123 port 1433
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: connect_next: host 52.176.157.123 ([52.176.157.123]:1433) in progress, fd=9
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: channel 0: new [direct-tcpip]
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: server_input_channel_open: confirm direct-tcpip
Apr 13 16:36:22 ip-10-226-0-48 sshd[20837]: debug1: channel 0: connected to 52.176.157.123 port 1433
Apr 13 16:36:23 ip-10-226-0-48 sshd[20837]: debug1: server_input_channel_open: ctype direct-tcpip rchan 1 win 2097152 max 32768
Apr 13 16:36:23 ip-10-226-0-48 sshd[20837]: debug1: server_request_direct_tcpip: originator 127.0.0.1 port 38314, target 52.176.157.123 port 1433
Apr 13 16:36:23 ip-10-226-0-48 sshd[20837]: debug1: connect_next: host 52.176.157.123 ([52.176.157.123]:1433) in progress, fd=10
Apr 13 16:36:23 ip-10-226-0-48 sshd[20837]: debug1: channel 1: new [direct-tcpip]
Apr 13 16:36:23 ip-10-226-0-48 sshd[20837]: debug1: server_input_channel_open: confirm direct-tcpip
Apr 13 16:36:23 ip-10-226-0-48 sshd[20837]: debug1: channel 0: free: direct-tcpip, nchannels 2
Apr 13 16:36:23 ip-10-226-0-48 sshd[20837]: debug1: channel 1: connected to 52.176.157.123 port 1433
Apr 13 16:36:32 ip-10-226-0-48 sshd[742]: debug1: Forked child 20839.
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: Set /proc/self/oom_score_adj to 0
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: rexec start in 5 out 5 newsock 5 pipe 7 sock 8
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: inetd sockets after dupping: 4, 4
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: Connection from 10.226.2.71 port 35141 on 10.226.0.48 port 22 rdomain ""
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: Local version string SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.4
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: Remote protocol version 2.0, remote software version APACHE-SSHD-2.7.0
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: no match: APACHE-SSHD-2.7.0
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: permanently_set_uid: 109/65534 [preauth]
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: SSH2_MSG_KEXINIT sent [preauth]
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: SSH2_MSG_KEXINIT received [preauth]
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: kex: algorithm: ecdh-sha2-nistp521 [preauth]
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none [preauth]
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none [preauth]
Apr 13 16:36:32 ip-10-226-0-48 sshd[20839]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: rekey out after 4294967296 blocks [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: Sending SSH2_MSG_EXT_INFO [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: expecting SSH2_MSG_NEWKEYS [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: SSH2_MSG_NEWKEYS received [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: rekey in after 4294967296 blocks [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: KEX done [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: userauth-request for user airbyte service ssh-connection method none [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: attempt 0 failures 0 [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: PAM: initializing for "airbyte"
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: PAM: setting PAM_RHOST to "10.226.2.71"
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: PAM: setting PAM_TTY to "ssh"
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: userauth-request for user airbyte service ssh-connection method publickey [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: attempt 1 failures 0 [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: userauth_pubkey: test pkalg rsa-sha2-512 pkblob RSA SHA256:KnWanF1bQtjNkk7R3WFtcIOiEcmSlQau9sNx+ooJ2kY [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: trying public key file /home/airbyte/.ssh/authorized_keys
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: fd 5 clearing O_NONBLOCK
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: /home/airbyte/.ssh/authorized_keys:1: matching key found: RSA SHA256:KnWanF1bQtjNkk7R3WFtcIOiEcmSlQau9sNx+ooJ2kY
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: /home/airbyte/.ssh/authorized_keys:1: key options: command port-forwarding
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: /home/airbyte/.ssh/authorized_keys:1: forced command: "/bin/false"
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: Accepted key RSA SHA256:KnWanF1bQtjNkk7R3WFtcIOiEcmSlQau9sNx+ooJ2kY found at /home/airbyte/.ssh/authorized_keys:1
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: restore_uid: 0/0
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: Postponed publickey for airbyte from 10.226.2.71 port 35141 ssh2 [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: userauth-request for user airbyte service ssh-connection method publickey [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: attempt 2 failures 0 [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: trying public key file /home/airbyte/.ssh/authorized_keys
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: fd 5 clearing O_NONBLOCK
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: /home/airbyte/.ssh/authorized_keys:1: matching key found: RSA SHA256:KnWanF1bQtjNkk7R3WFtcIOiEcmSlQau9sNx+ooJ2kY
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: /home/airbyte/.ssh/authorized_keys:1: key options: command port-forwarding
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: /home/airbyte/.ssh/authorized_keys:1: forced command: "/bin/false"
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: Accepted key RSA SHA256:KnWanF1bQtjNkk7R3WFtcIOiEcmSlQau9sNx+ooJ2kY found at /home/airbyte/.ssh/authorized_keys:1
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: restore_uid: 0/0
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: auth_activate_options: setting new authentication options
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: do_pam_account: called
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: Accepted publickey for airbyte from 10.226.2.71 port 35141 ssh2: RSA SHA256:KnWanF1bQtjNkk7R3WFtcIOiEcmSlQau9sNx+ooJ2kY
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: monitor_child_preauth: airbyte has been authenticated by privileged process
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: auth_activate_options: setting new authentication options [preauth]
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: monitor_read_log: child log fd closed
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: debug1: PAM: establishing credentials
Apr 13 16:36:34 ip-10-226-0-48 sshd[20839]: pam_unix(sshd:session): session opened for user airbyte by (uid=0)
Apr 13 16:36:35 ip-10-226-0-48 sshd[20839]: User child is on pid 20912
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: SELinux support disabled
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: PAM: establishing credentials
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: permanently_set_uid: 1000/1000
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: rekey in after 4294967296 blocks
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: rekey out after 4294967296 blocks
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: ssh_packet_set_postauth: called
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: active: key options: command port-forwarding
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: active: forced command: "/bin/false"
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: Entering interactive session for SSH2.
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: server_init_dispatch
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: server_input_channel_open: ctype direct-tcpip rchan 0 win 2097152 max 32768
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: server_request_direct_tcpip: originator 127.0.0.1 port 53308, target 52.176.157.123 port 1433
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: connect_next: host 52.176.157.123 ([52.176.157.123]:1433) in progress, fd=9
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: channel 0: new [direct-tcpip]
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: server_input_channel_open: confirm direct-tcpip
Apr 13 16:36:35 ip-10-226-0-48 sshd[20912]: debug1: channel 0: connected to 52.176.157.123 port 1433
Apr 13 16:36:36 ip-10-226-0-48 sshd[20837]: debug1: server_input_channel_open: ctype direct-tcpip rchan 2 win 2097152 max 32768
Apr 13 16:36:36 ip-10-226-0-48 sshd[20837]: debug1: server_request_direct_tcpip: originator 127.0.0.1 port 38598, target 52.176.157.123 port 1433
Apr 13 16:36:36 ip-10-226-0-48 sshd[20837]: debug1: connect_next: host 52.176.157.123 ([52.176.157.123]:1433) in progress, fd=9
Apr 13 16:36:36 ip-10-226-0-48 sshd[20837]: debug1: channel 0: new [direct-tcpip]
Apr 13 16:36:36 ip-10-226-0-48 sshd[20837]: debug1: server_input_channel_open: confirm direct-tcpip
Apr 13 16:36:36 ip-10-226-0-48 sshd[20837]: debug1: channel 0: connected to 52.176.157.123 port 1433
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: debug1: server_input_channel_open: ctype direct-tcpip rchan 1 win 2097152 max 32768
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: debug1: server_request_direct_tcpip: originator 127.0.0.1 port 53338, target 52.176.157.123 port 1433
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: debug1: connect_next: host 52.176.157.123 ([52.176.157.123]:1433) in progress, fd=10
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: debug1: channel 1: new [direct-tcpip]
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: debug1: server_input_channel_open: confirm direct-tcpip
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: debug1: channel 0: free: direct-tcpip, nchannels 2
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: debug1: channel 1: connected to 52.176.157.123 port 1433
Apr 13 16:36:37 ip-10-226-0-48 sshd[20837]: debug1: server_input_channel_open: ctype direct-tcpip rchan 3 win 2097152 max 32768
Apr 13 16:36:37 ip-10-226-0-48 sshd[20837]: debug1: server_request_direct_tcpip: originator 127.0.0.1 port 38608, target 52.176.157.123 port 1433
Apr 13 16:36:37 ip-10-226-0-48 sshd[20837]: debug1: connect_next: host 52.176.157.123 ([52.176.157.123]:1433) in progress, fd=11
Apr 13 16:36:37 ip-10-226-0-48 sshd[20837]: debug1: channel 2: new [direct-tcpip]
Apr 13 16:36:37 ip-10-226-0-48 sshd[20837]: debug1: server_input_channel_open: confirm direct-tcpip
Apr 13 16:36:37 ip-10-226-0-48 sshd[20837]: debug1: channel 0: free: direct-tcpip, nchannels 3
Apr 13 16:36:37 ip-10-226-0-48 sshd[20837]: debug1: channel 2: connected to 52.176.157.123 port 1433
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: debug1: channel 1: free: direct-tcpip, nchannels 1
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: Connection closed by 10.226.2.71 port 35141
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: debug1: do_cleanup
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: debug1: temporarily_use_uid: 1000/1000 (e=1000/1000)
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: debug1: restore_uid: (unprivileged)
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: Transferred: sent 7576, received 6160 bytes
Apr 13 16:36:37 ip-10-226-0-48 sshd[20912]: Closing connection to 10.226.2.71 port 35141
Apr 13 16:36:37 ip-10-226-0-48 sshd[20839]: debug1: PAM: cleanup
Apr 13 16:36:37 ip-10-226-0-48 sshd[20839]: debug1: PAM: closing session
Apr 13 16:36:37 ip-10-226-0-48 sshd[20839]: pam_unix(sshd:session): session closed for user airbyte
Apr 13 16:36:37 ip-10-226-0-48 sshd[20839]: debug1: PAM: deleting credentials
Apr 13 16:36:37 ip-10-226-0-48 sshd[742]: debug1: main_sigchld_handler: Child exited
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: SSH2_MSG_KEXINIT received
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: SSH2_MSG_KEXINIT sent
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: kex: algorithm: ecdh-sha2-nistp521
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: kex: host key algorithm: ecdsa-sha2-nistp256
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: ssh_set_newkeys: rekeying out, input 75308 bytes 4241 blocks, output 1074901840 bytes 67163788 blocks
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: rekey out after 4294967296 blocks
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: SSH2_MSG_NEWKEYS sent
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: expecting SSH2_MSG_NEWKEYS
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: SSH2_MSG_NEWKEYS received
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: ssh_set_newkeys: rekeying in, input 75344 bytes 4243 blocks, output 1074901840 bytes 0 blocks
Apr 13 16:44:56 ip-10-226-0-48 sshd[20837]: debug1: rekey in after 4294967296 blocks
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: SSH2_MSG_KEXINIT received
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: SSH2_MSG_KEXINIT sent
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: kex: algorithm: ecdh-sha2-nistp521
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: kex: host key algorithm: ecdsa-sha2-nistp256
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: ssh_set_newkeys: rekeying out, input 113292 bytes 2117 blocks, output 2151271236 bytes 67253414 blocks
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: rekey out after 4294967296 blocks
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: SSH2_MSG_NEWKEYS sent
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: expecting SSH2_MSG_NEWKEYS
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: SSH2_MSG_NEWKEYS received
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: ssh_set_newkeys: rekeying in, input 113328 bytes 2119 blocks, output 2151271236 bytes 0 blocks
Apr 13 16:46:26 ip-10-226-0-48 sshd[20837]: debug1: rekey in after 4294967296 blocks
Apr 13 16:47:20 ip-10-226-0-48 sshd[20837]: Connection closed by 10.226.2.71 port 29260
Apr 13 16:47:20 ip-10-226-0-48 sshd[20837]: debug1: channel 1: free: direct-tcpip, nchannels 2
Apr 13 16:47:20 ip-10-226-0-48 sshd[20837]: debug1: channel 2: free: direct-tcpip, nchannels 1
Apr 13 16:47:20 ip-10-226-0-48 sshd[20837]: debug1: do_cleanup
Apr 13 16:47:20 ip-10-226-0-48 sshd[20837]: debug1: temporarily_use_uid: 1000/1000 (e=1000/1000)
Apr 13 16:47:20 ip-10-226-0-48 sshd[20837]: debug1: restore_uid: (unprivileged)
Apr 13 16:47:20 ip-10-226-0-48 sshd[20837]: Transferred: sent 2606418496, received 128736 bytes
Apr 13 16:47:20 ip-10-226-0-48 sshd[20837]: Closing connection to 10.226.2.71 port 29260
Apr 13 16:47:20 ip-10-226-0-48 sshd[20736]: debug1: PAM: cleanup
Apr 13 16:47:20 ip-10-226-0-48 sshd[20736]: debug1: PAM: closing session
Apr 13 16:47:20 ip-10-226-0-48 sshd[20736]: pam_unix(sshd:session): session closed for user airbyte
Apr 13 16:47:20 ip-10-226-0-48 sshd[20736]: debug1: PAM: deleting credentials
Apr 13 16:47:20 ip-10-226-0-48 sshd[742]: debug1: main_sigchld_handler: Child exited

luke · April 13, 2022, 6:47pm

Here’s part of an example Airbyte log (really the only potentially applicable line I see is errors: $.tunnel_method: must be a constant value NO_TUNNEL)

alafanechere · April 15, 2022, 4:46pm

Hey @luke,
I’m not sure to what extent our JDBC connectors support SSH Rekey. Do you mind opening an issue on our repo to request support for SSH Rekey on MSSQL and share its link here?

Is SSH rekey the default behavior of SSH connections to MSSQL or is it a custom setting your source DB has?

@tuliren do you have any insight to share around this topic?

marcosmarxm · July 13, 2022, 12:00am

Hi there from the Community Assistance team.
We’re letting you know about an issue we discovered with the back-end process we use to handle topics and responses on the forum. If you experienced a situation where you posted the last message in a topic that did not receive any further replies, please open a new topic to continue the discussion. In addition, if you’re having a problem and find a closed topic on the subject, go ahead and open a new topic on it and we’ll follow up with you. We apologize for the inconvenience, and appreciate your willingness to work with us to provide a supportive community.

Topic		Replies	Views
Large sync fails but successfully loads data after failed retry (with different error) Connector Questions & Issues data-loading	18	1454	July 14, 2022
All connectors fails test without clear error Connector Questions & Issues getting-started , connectors , kubernetes	4	1316	April 29, 2023
Running too many syncs concurrently causing non-explicit failures Connector Questions & Issues normalization , data-loading	3	1263	March 7, 2023
Sync MSSQL to Snowflake "closing connection" Connector Questions & Issues data-loading , connectors	1	208	February 9, 2023
All syncs hanging for days Connector Questions & Issues source-postgres , destination-snowflake	12	1784	August 24, 2022

SSH rekey not being handled and causing all jobs to fail

Related topics