#12442 Random hangs when pushing to pkgs.fedoraproject.org
Closed: Fixed by kevin. Opened by ngompa.

I've been seeing this randomly for some time, and I was finally able to capture some logs about what's going on:

ngompa@fedora ~> ssh -Tvvv ssh://ngompa@pkgs.fedoraproject.org
OpenSSH_9.9p1, OpenSSL 3.2.2 4 Jun 2024
debug1: Reading configuration data /home/ngompa/.ssh/config
debug1: Reading configuration data /etc/ssh/ssh_config
debug3: /etc/ssh/ssh_config line 55: Including file /etc/ssh/ssh_config.d/20-systemd-ssh-proxy.conf depth 0
debug1: Reading configuration data /etc/ssh/ssh_config.d/20-systemd-ssh-proxy.conf
debug3: /etc/ssh/ssh_config line 55: Including file /etc/ssh/ssh_config.d/30-libvirt-ssh-proxy.conf depth 0
debug1: Reading configuration data /etc/ssh/ssh_config.d/30-libvirt-ssh-proxy.conf
debug3: /etc/ssh/ssh_config line 55: Including file /etc/ssh/ssh_config.d/50-redhat.conf depth 0
debug1: Reading configuration data /etc/ssh/ssh_config.d/50-redhat.conf
debug2: checking match for 'final all' host pkgs.fedoraproject.org originally pkgs.fedoraproject.org
debug3: /etc/ssh/ssh_config.d/50-redhat.conf line 3: not matched 'final'
debug2: match not found
debug3: /etc/ssh/ssh_config.d/50-redhat.conf line 5: Including file /etc/crypto-policies/back-ends/openssh.config depth 1 (parse only)
debug1: Reading configuration data /etc/crypto-policies/back-ends/openssh.config
debug3: gss kex names ok: [gss-curve25519-sha256-,gss-nistp256-sha256-,gss-group14-sha256-,gss-group16-sha512-]
debug3: kex names ok: [curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512]
debug1: configuration requests final Match pass
debug1: re-parsing configuration
debug1: Reading configuration data /home/ngompa/.ssh/config
debug1: Reading configuration data /etc/ssh/ssh_config
debug3: /etc/ssh/ssh_config line 55: Including file /etc/ssh/ssh_config.d/20-systemd-ssh-proxy.conf depth 0
debug1: Reading configuration data /etc/ssh/ssh_config.d/20-systemd-ssh-proxy.conf
debug3: /etc/ssh/ssh_config line 55: Including file /etc/ssh/ssh_config.d/30-libvirt-ssh-proxy.conf depth 0
debug1: Reading configuration data /etc/ssh/ssh_config.d/30-libvirt-ssh-proxy.conf
debug3: /etc/ssh/ssh_config line 55: Including file /etc/ssh/ssh_config.d/50-redhat.conf depth 0
debug1: Reading configuration data /etc/ssh/ssh_config.d/50-redhat.conf
debug2: checking match for 'final all' host pkgs.fedoraproject.org originally pkgs.fedoraproject.org
debug3: /etc/ssh/ssh_config.d/50-redhat.conf line 3: matched 'final'
debug2: match found
debug3: /etc/ssh/ssh_config.d/50-redhat.conf line 5: Including file /etc/crypto-policies/back-ends/openssh.config depth 1
debug1: Reading configuration data /etc/crypto-policies/back-ends/openssh.config
debug3: gss kex names ok: [gss-curve25519-sha256-,gss-nistp256-sha256-,gss-group14-sha256-,gss-group16-sha512-]
debug3: kex names ok: [curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512]
debug3: expanded UserKnownHostsFile '~/.ssh/known_hosts' -> '/home/ngompa/.ssh/known_hosts'
debug3: expanded UserKnownHostsFile '~/.ssh/known_hosts2' -> '/home/ngompa/.ssh/known_hosts2'
debug2: resolving "pkgs.fedoraproject.org" port 22
debug3: resolve_host: lookup pkgs.fedoraproject.org:22
debug3: channel_clear_timeouts: clearing
debug3: ssh_connect_direct: entering
debug1: Connecting to pkgs.fedoraproject.org [38.145.60.17] port 22.
debug3: set_sock_tos: set socket 3 IP_TOS 0x48
debug1: connect to address 38.145.60.17 port 22: Connection timed out
ssh: connect to host pkgs.fedoraproject.org port 22: Connection timed out

Metadata Update from @zlopez:
- Issue priority set to: Waiting on Assignee (was: Needs Review)
- Issue tagged with: Needs investigation, low-gain

I was unable to reproduce(but you did say it was something randomly occurring), was there any specific date/time that this occurred?

FWIW I tried looking at the logs for pkgs01.iad2.fedoraproject.org/2025/03/08 and nothing looks different, there were four sessions around that time:

15:39:37
15:39:59
15:40:24
15:40:41

...they all look like the same things happened.

Okay, I used lnav and that helped me find these SELinux errors from the first session:

Mar 8 15:39:43 pkgs01 tag_audit_log: type=USER_ERR msg=audit(1741448375.478:6440543): pid=2063495 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=PAM:bad_ident grantors=? acct="?" exe="/usr/sbin/sshd" hostname=218.92.0.243 addr=218.92.0.243 terminal=ssh res=failed'^]UID="root" AUID="unset"

Mar 8 15:39:43 pkgs01 tag_audit_log: type=USER_LOGIN msg=audit(1741448375.479:6440545): pid=2063495 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=login acct="root" exe="/usr/sbin/sshd" hostname=? addr=218.92.0.243 terminal=ssh res=failed'^]UID="root" AUID="unset"

Blah, that's probably a false hit ... it doesn't always happen, but it happens a bunch for a lot of different sessions.

It seems like it never even connects to the pkgs side... just tries and times out.

I wonder if there could something going on at the router/NAT level here? Like it's shutting down due to too many connections or something. ;(

@ngompa when this happens... is it after you have connected a bunch? Or that doesn't seem to matter? and how long do the timeouts last? Or hard to say?

This is happening right now. And I've been stuck for several minutes now.

I've only done a couple of sequential pushes and then I'm locked out via SSH.

I'm also now seeing it with HTTPS too:

ngompa@fedora ~/f/miracle-wm (f42)> git merge rawhide && fedpkg push
Updating 5d09240..f200dc9
Fast-forward
 miracle-wm.spec | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)
Total 0 (delta 0), reused 0 (delta 0), pack-reused 0 (from 0)
error: RPC failed; HTTP 500 curl 22 The requested URL returned error: 500
send-pack: unexpected disconnect while reading sideband packet
fatal: the remote end hung up unexpectedly
Everything up-to-date
Could not execute push: Failed to execute command.

I wonder if you have seen this since the dc move? ie, if it moved with the config or if it could have been related to something network there?

ok. I guess if you see it again, reopen this or file a new one and we can dig more...

Metadata Update from @kevin:
- Issue close_status updated to: Fixed
- Issue status updated to: Closed (was: Open)

Metadata