Error during pull

[nine-2-five]

This error occurs during docker compose pull with --context argument

Steps to reproduce the issue:

1. docker --context mycontext compose -f docker-compose.letsencrypt.yml pull
2. error during connect: Get "http://docker.example.com/v1.41/images/mongo-express/json": command [ssh -l root -- pharma-bio.hr docker system dial-stdio] has exited with exit status 255, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=kex_exchange_identification: Connection closed by remote host

Describe the results you received: error during connect: Get "http://docker.example.com/v1.41/images/mongo-express/json": command [ssh -l root -- pharma-bio.hr docker system dial-stdio] has exited with exit status 255, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=kex_exchange_identification: Connection closed by remote host

Describe the results you expected: Normal pull of all images, both from my docker hub and public ones

Additional information you deem important (e.g. issue happens only occasionally):

Output of docker compose version:

Docker Compose version v2.4.1

Output of docker info:

Client:
 Context:    default
 Debug Mode: false
 Plugins:
  buildx: Docker Buildx (Docker Inc., v0.8.2)
  compose: Docker Compose (Docker Inc., v2.4.1)
  sbom: View the packaged-based Software Bill Of Materials (SBOM) for an image (Anchore Inc., 0.6.0)
  scan: Docker Scan (Docker Inc., v0.17.0)

Server:
 Containers: 22
  Running: 13
  Paused: 0
  Stopped: 9
 Images: 111
 Server Version: 20.10.14
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Native Overlay Diff: true
  userxattr: false
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Cgroup Version: 1
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 io.containerd.runtime.v1.linux runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 3df54a852345ae127d1fa3092b95168e4a88e2f8
 runc version: v1.0.3-0-gf46b6ba
 init version: de40ad0
 Security Options:
  seccomp
   Profile: default
 Kernel Version: 5.10.60.1-microsoft-standard-WSL2
 Operating System: Docker Desktop
 OSType: linux
 Architecture: x86_64
 CPUs: 20
 Total Memory: 15.52GiB
 Name: docker-desktop
 ID: MGP6:OKSX:HXN5:OL2J:CK7W:OJQ2:HTGL:COC7:OFZY:DYIQ:HZNR:UB35
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 HTTP Proxy: http.docker.internal:3128
 HTTPS Proxy: http.docker.internal:3128
 No Proxy: hubproxy.docker.internal
 Registry: https://index.docker.io/v1/
 Labels:
 Experimental: false
 Insecure Registries:
  hubproxy.docker.internal:5000
  127.0.0.0/8
 Live Restore Enabled: false

WARNING: No blkio throttle.read_bps_device support
WARNING: No blkio throttle.write_bps_device support
WARNING: No blkio throttle.read_iops_device support
WARNING: No blkio throttle.write_iops_device support

Additional environment details: I'm using Ubuntu 20.04 WSL on client side, and deploying to Ubuntu server 20.04 (both sides fully patched).

[glours]

What did you get if you try to run docker --context mycontext pull an_image_from_compose_file ?

[nine-2-five]

I get OK output:

docker --context mycontext pull jwilder/nginx-proxy
Using default tag: latest
latest: Pulling from jwilder/nginx-proxy
Digest: sha256:a9fe1315b24a866335b0bea8a34c67cd49ae6fbe6b47ebbf8a1d0c4b06c79731
Status: Image is up to date for jwilder/nginx-proxy:latest
docker.io/jwilder/nginx-proxy:latest

[miroslavmachura]

I'm also hitting this issue, it happens for both ssh and tcp contexts.

[zachberger]

What is strange is I don't see this with v2.4.1 as noted in #9435, however this issue, #9448, seems to reproduce it on that build

[hansbogert]

What is strange is I don't see this with v2.4.1 as noted in #9435, however this issue, #9448, seems to reproduce it on that build

I am experiencing the same. But the 'non-popularity' of this issue seems strange. Is there a hidden common factor just for us? Seems easy to reproduce though.

Maybe not a lot of persons are using d-compose v2.5.0 icw remote SSH.

[Benjamin-Tan]

In https://github.com/docker/compose/issues/8544#issuecomment-974639028, the comment suggested to use remote docker context with unix:// (unix socket forwarding over the SSH connection) instead of ssh:// seems to a possible workaround.

[zachberger]

Still reproducible in 2.6.0

[figure002]

I suddenly run into the same issue in GitLab pipelines. The pipeline looks like this:

accept-deploy:
  image: docker:latest
  stage: accept
  variables:
    DOCKER_HOST: ssh://gitlab@example.com
  before_script:
    - apk update && apk add docker docker-compose openssh-client
    - ...
    - docker login -u "$CI_REGISTRY_USER" -p "$CI_JOB_TOKEN" "$CI_REGISTRY"
  script:
    - docker-compose build --pull
    - docker-compose pull
    - docker-compose up -d

And the error message:

$ docker-compose pull
time="2022-06-13T08:42:05Z" level=warning msg="network public: network.external.name is deprecated in favor of network.name"
nginx Skipped 
uwsgi Pulling 
postgres Pulling 
time="2022-06-13T08:42:05Z" level=warning msg="commandConn.CloseWrite: commandconn: failed to wait: signal: killed"
postgres Error 
uwsgi Error 
error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=postgres&tag=13-alpine": command [ssh -l gitlab -- example.com docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=

This pipeline used to work just fine about a month ago. The Docker Compose version on Alpine Linux a month ago was 1.29.2-r1, but now it's 1.29.2-r2.

[figure002]

I manged to fix this for now by reverting to an older Docker image:

Latest working version: docker:20.10.14 Broken for: docker:20.10.15 and later.

[figure002]

This is weird. I have more projects on GitLab with the same pipeline setup that use docker:latest, so I would expect those to fail as well, but they don't.

[ivlis]

I have the exact same error. 2.4.1 works just fine, fails to pull on and after 2.5.0.

Please fix this!

[etienned]

I can confirm that the 2.4.1 version works. So there's some chances that the problem come from this change: https://github.com/docker/compose/commit/625a48dcf712f52e1aae64cd664a97699a4fe5bf

[fergalmoran]

Also have this issue with 2.7.0

[zachberger]

This continues on 2.8.0

[zachberger]

@ndeloof could you PTAL since this seems related to 625a48d?

[glours]

I tried to reproduce with a very(too?) simple example to reproduce. I setup an multipass ubuntu VM with a rootless docker installation via the convenience script of the official documentation. Then I configure thdocker service to be available via tcp.

In the following screenshot, the left tab is the vm displaying docker info, you can see that I'm using a 20.10.17 engine and Compose v2.6.0 note the warning about the API accessible without encryption (I said simple test 😅)

Can you test the same example and maybe you'll be able to give me more context/hints to reproduce your issue? here the compose file used:

services:
  common:
    image: busybox
    environment:
      TZ: utc
      PORT: 80

[ivlis]

I believe docker -c context compose works, while docker-compose -c context does not.

[glours]

@ivlis works as expected on my side 🤔

[zachberger]

@glours what about with a ssh context instead of tcp context?

[ivlis]

@glours @zachberger

Here is a minimal example demonstrating the problem. It seems it deals with the custom repositories.

this does not work:

version: '3.9'
services:
  hass:
    image: ghcr.io/home-assistant/home-assistant:2022.7.5
  ubuntu:
    image: ubuntu

docker --context xxxx compose  -f ./docker-compose-bad.yml pull
WARN[0000] commandConn.CloseWrite: commandconn: failed to wait: signal: killed 
[+] Running 0/0
 ⠿ hass Error                                                                                                                0.0s
 ⠿ ubuntu Error                                                                                                              0.0s
error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=ubuntu&tag=latest": command [ssh -l user -- xxxx docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=

But commenting out either one of the services results in a successful pull.

docker context inspect xxxx
[
    {
        "Name": "xxxx",
        "Metadata": {},
        "Endpoints": {
            "docker": {
                "Host": "ssh://user@xxxx",
                "SkipTLSVerify": false
            }
        },
        "TLSMaterial": {},
        "Storage": {
            "MetadataPath": "/home/ivlis/.docker/contexts/meta/1f54ca1cf12c1f6a1c7c11ab42fe5b58e6bddead8e8024e3a4d9cd7ef345ff55",
            "TLSPath": "/home/ivlis/.docker/contexts/tls/1f54ca1cf12c1f6a1c7c11ab42fe5b58e6bddead8e8024e3a4d9cd7ef345ff55"
        }
    }
]

[glours]

@ivlis @zachberger no issue with ssh also, and I used @ivlis compose file for this test I also had the warning message but was able to pull the 2 images

> bat compose.yaml
───────┬──────────────────────────────────────────────────────────────────────────────────────────────────────────────
       │ File: compose.yaml
       │ Size: 104 B
───────┼──────────────────────────────────────────────────────────────────────────────────────────────────────────────
   1   │ services:
   2   │   hass:
   3   │     image: ghcr.io/home-assistant/home-assistant:2022.7.5
   4   │   ubuntu:
   5   │     image: ubuntu
───────┴──────────────────────────────────────────────────────────────────────────────────────────────────────────────
> docker --context=remote-engine compose pull
WARN[0000] commandConn.CloseWrite: commandconn: failed to wait: signal: killed
[+] Running 30/30
 ⠿ hass Pulled                                                                                                  42.4s
   ⠿ b3c136eddcbf Pull complete                                                                                  0.9s
   ⠿ 7ccb820019d9 Pull complete                                                                                  0.9s
   ⠿ 7946c12c8fa4 Pull complete                                                                                  2.6s
   ⠿ d8668b875010 Pull complete                                                                                  2.6s
   ⠿ 7f072ea1c427 Pull complete                                                                                  5.7s
   ⠿ 90b8edde1fa7 Pull complete                                                                                  5.7s
   ⠿ c53f79b7d344 Pull complete                                                                                  6.1s
   ⠿ 78f64f24b1ea Pull complete                                                                                  7.6s
   ⠿ 1f7441c5835c Pull complete                                                                                  7.7s
   ⠿ da41e69aeaed Pull complete                                                                                  7.9s
   ⠿ f7aa1915a47f Pull complete                                                                                  8.0s
   ⠿ 9aebc1dab72e Pull complete                                                                                  8.0s
   ⠿ ba965dcd5383 Pull complete                                                                                  8.0s
   ⠿ 8f9e054f1555 Pull complete                                                                                  8.1s
   ⠿ 22a1b6a1c0b4 Pull complete                                                                                  8.2s
   ⠿ 79cb73331227 Pull complete                                                                                  8.3s
   ⠿ 7fea82b91979 Pull complete                                                                                  8.3s
   ⠿ 39c2416e5f59 Pull complete                                                                                  8.3s
   ⠿ 2b4ea8f2c2f8 Pull complete                                                                                  8.4s
   ⠿ 8aba4297a7c0 Pull complete                                                                                  8.6s
   ⠿ 17bb02260fae Pull complete                                                                                  9.4s
   ⠿ f6cdded59d63 Pull complete                                                                                  9.4s
   ⠿ 62744569fdaf Pull complete                                                                                 31.2s
   ⠿ 8940cac1884a Pull complete                                                                                 33.8s
   ⠿ 7b610ca278fd Pull complete                                                                                 34.7s
   ⠿ 27bc02b17114 Pull complete                                                                                 34.8s
   ⠿ 967057c052b4 Pull complete                                                                                 34.8s
 ⠿ ubuntu Pulled                                                                                                 7.8s
   ⠿ 4a3049d340b7 Pull complete                                                                                  2.6s
> docker context inspect remote-engine
[
    {
        "Name": "remote-engine",
        "Metadata": {},
        "Endpoints": {
            "docker": {
                "Host": "ssh://ubuntu@192.168.64.4",
                "SkipTLSVerify": false
            }
        },
        "TLSMaterial": {},
        "Storage": {
            "MetadataPath": "/Users/glours/.docker/contexts/meta/7619d3b88f9c1911b5599a392f472255651c39a73ffc5db4101815caa3295ee5",
            "TLSPath": "/Users/glours/.docker/contexts/tls/7619d3b88f9c1911b5599a392f472255651c39a73ffc5db4101815caa3295ee5"
        }
    }
]

[zapotocnylubos]

Hello, I have been trying to get ssh docker compose deployment (pull is the first step) working for days now. I have tried the connection to and from 4 new fresh VMS - the latest Debian, latest ubuntu, and latest arch.

None of these connections worked, but I have now tried to just spam and do over and over docker compose pull with remote context, and approximately in 1 of 10 tries, the pull actually gets started and finishes without a problem. But why in 9 of 10 cases ssh connection interrupts and the docker compose pull does not even start? Could this be an issue with server sshd configuration? I have always used the default ubuntu/Debian/arch sshd configuration without any modification. Or even with networking (packet size etc.)?

[zapotocnylubos@workstation docker-ssh-test]$ docker compose pull 
WARN[0000] commandConn.CloseWrite: commandconn: failed to wait: signal: killed 
[+] Running 0/0
 ⠿ hass Error                                                                                                                                                              0.0s
 ⠿ ubuntu Error                                                                                                                                                            0.0s
error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=ubuntu&tag=latest": command [ssh -l zapotocnylubos -- 10.0.1.106 docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=
[zapotocnylubos@workstation docker-ssh-test]$ docker compose pull 
WARN[0000] commandConn.CloseWrite: commandconn: failed to wait: signal: killed 
[+] Running 0/0
 ⠿ ubuntu Error                                                                                                                                                            0.0s
 ⠿ hass Error                                                                                                                                                              0.0s
error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=ubuntu&tag=latest": command [ssh -l zapotocnylubos -- 10.0.1.106 docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=
[zapotocnylubos@workstation docker-ssh-test]$ docker compose pull 
WARN[0000] commandConn.CloseWrite: commandconn: failed to wait: signal: killed 
[+] Running 0/0
 ⠿ ubuntu Error                                                                                                                                                            0.0s
 ⠿ hass Error                                                                                                                                                              0.0s
error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=ubuntu&tag=latest": command [ssh -l zapotocnylubos -- 10.0.1.106 docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=
[zapotocnylubos@workstation docker-ssh-test]$ docker compose pull 
WARN[0000] commandConn.CloseWrite: commandconn: failed to wait: signal: killed 
[+] Running 0/0
 ⠿ ubuntu Error                                                                                                                                                            0.0s
 ⠿ hass Error                                                                                                                                                              0.0s
error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=ubuntu&tag=latest": command [ssh -l zapotocnylubos -- 10.0.1.106 docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=
[zapotocnylubos@workstation docker-ssh-test]$ docker compose pull 
WARN[0000] commandConn.CloseWrite: commandconn: failed to wait: signal: killed 
[+] Running 0/0
 ⠿ ubuntu Error                                                                                                                                                            0.0s
 ⠿ hass Error                                                                                                                                                              0.0s
error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=ubuntu&tag=latest": command [ssh -l zapotocnylubos -- 10.0.1.106 docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=
[zapotocnylubos@workstation docker-ssh-test]$ docker compose pull 
WARN[0000] commandConn.CloseWrite: commandconn: failed to wait: signal: killed 
[+] Running 0/0
 ⠿ hass Error                                                                                                                                                              0.0s
 ⠿ ubuntu Error                                                                                                                                                            0.0s
error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=ubuntu&tag=latest": command [ssh -l zapotocnylubos -- 10.0.1.106 docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=
[zapotocnylubos@workstation docker-ssh-test]$ docker compose pull 
WARN[0000] commandConn.CloseWrite: commandconn: failed to wait: signal: killed 
[+] Running 0/0
 ⠿ hass Error                                                                                                                                                              0.0s
 ⠿ ubuntu Error                                                                                                                                                            0.0s
error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=ubuntu&tag=latest": command [ssh -l zapotocnylubos -- 10.0.1.106 docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=
[zapotocnylubos@workstation docker-ssh-test]$ docker compose pull 
WARN[0000] commandConn.CloseWrite: commandconn: failed to wait: signal: killed 
[+] Running 0/0
 ⠿ hass Error                                                                                                                                                              0.0s
 ⠿ ubuntu Error                                                                                                                                                            0.0s
error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=ubuntu&tag=latest": command [ssh -l zapotocnylubos -- 10.0.1.106 docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=
[zapotocnylubos@workstation docker-ssh-test]$ docker compose pull 
WARN[0000] commandConn.CloseWrite: commandconn: failed to wait: signal: killed 
[+] Running 0/2
 ⠋ ubuntu Pulling                                                                                                                                                          1.0s
 ⠋ hass Pulling                                                                                                                                                            1.0s
   ⠋ 2408cc74d12b Pulling fs layer 

This is log from my server, when I try to docker compose pull, that ends in error (9 of 10 cases)

Aug 13 23:03:59 public-hosting sshd[31908]: Accepted publickey for zapotocnylubos from 78.24.15.212 port 53594 ssh2: ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk
Aug 13 23:03:59 public-hosting sshd[31908]: pam_unix(sshd:session): session opened for user zapotocnylubos(uid=1000) by (uid=0)
Aug 13 23:04:00 public-hosting sshd[31926]: Accepted publickey for zapotocnylubos from 78.24.15.212 port 23330 ssh2: ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk
Aug 13 23:04:00 public-hosting sshd[31926]: pam_unix(sshd:session): session opened for user zapotocnylubos(uid=1000) by (uid=0)
Aug 13 23:04:01 public-hosting sshd[31946]: Accepted publickey for zapotocnylubos from 78.24.15.212 port 50482 ssh2: ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk
Aug 13 23:04:01 public-hosting sshd[31946]: pam_unix(sshd:session): session opened for user zapotocnylubos(uid=1000) by (uid=0)
Aug 13 23:04:01 public-hosting sshd[31946]: pam_unix(sshd:session): session closed for user zapotocnylubos
Aug 13 23:04:01 public-hosting sshd[31926]: pam_unix(sshd:session): session closed for user zapotocnylubos
Aug 13 23:04:01 public-hosting sshd[31908]: pam_unix(sshd:session): session closed for user zapotocnylubos

Is it supposed to initiate 3 connections for a single pull?

With DEBUG3 loglevel on sshd server, these are a logs for a failed docker compose pull attempt

Aug 13 23:19:46 public-hosting sshd[34868]: debug3: fd 5 is not O_NONBLOCK
Aug 13 23:19:46 public-hosting sshd[34868]: debug1: Forked child 34874.
Aug 13 23:19:46 public-hosting sshd[34868]: debug3: send_rexec_state: entering fd = 8 config len 408
Aug 13 23:19:46 public-hosting sshd[34868]: debug3: ssh_msg_send: type 0
Aug 13 23:19:46 public-hosting sshd[34868]: debug3: send_rexec_state: done
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: oom_adjust_restore
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: Set /proc/self/oom_score_adj to 0
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: rexec start in 5 out 5 newsock 5 pipe 7 sock 8
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: inetd sockets after dupping: 4, 4
Aug 13 23:19:46 public-hosting sshd[34874]: Connection from 10.0.1.219 port 49790 on 10.0.1.105 port 22 rdomain ""
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: Local version string SSH-2.0-OpenSSH_8.4p1 Debian-5+deb11u1
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: Remote protocol version 2.0, remote software version OpenSSH_9.0
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: match: OpenSSH_9.0 pat OpenSSH* compat 0x04000000
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: fd 4 setting O_NONBLOCK
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: ssh_sandbox_init: preparing seccomp filter sandbox
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: Network child is on pid 34875
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: preauth child monitor started
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: privsep user:group 105:65534 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: permanently_set_uid: 105/65534 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: ssh_sandbox_child: setting PR_SET_NO_NEW_PRIVS [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: ssh_sandbox_child: attaching seccomp filter program [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: send packet: type 20 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: SSH2_MSG_KEXINIT sent [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: receive packet: type 20 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: SSH2_MSG_KEXINIT received [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: local server KEXINIT proposal [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: 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-group14-sha256 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: 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]
Aug 13 23:19:46 public-hosting sshd[34874]: 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]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: compression ctos: none,zlib@openssh.com [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: compression stoc: none,zlib@openssh.com [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: languages ctos:  [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: languages stoc:  [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: first_kex_follows 0  [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: reserved 0  [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: peer client KEXINIT proposal [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: 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]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: host key algorithms: 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,sk-ssh-ed25519-cert-v01@openssh.com,sk-ecdsa-sha2-nistp256-cert-v01@openssh.com,rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ssh-ed25519@openssh.com,sk-ecdsa-sha2-nistp256@openssh.com,rsa-sha2-512,rsa-sha2-256 [preaut
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: 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]
Aug 13 23:19:46 public-hosting sshd[34874]: 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]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: compression ctos: none,zlib@openssh.com,zlib [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: compression stoc: none,zlib@openssh.com,zlib [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: languages ctos:  [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: languages stoc:  [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: first_kex_follows 0  [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: reserved 0  [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: kex: algorithm: curve25519-sha256 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: kex: host key algorithm: ssh-ed25519 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: receive packet: type 30 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_sshkey_sign entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 6 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive_expect entering: type 7 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: monitor_read: checking request 6
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_sign
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_sign: KEX signature 0x5591910a83b0(83)
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 7
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: monitor_read: 6 used once, disabling now
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: send packet: type 31 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: send packet: type 21 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: set_newkeys: mode 1 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: rekey out after 134217728 blocks [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: Sending SSH2_MSG_EXT_INFO [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: send packet: type 7 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: expecting SSH2_MSG_NEWKEYS [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: receive packet: type 21 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: SSH2_MSG_NEWKEYS received [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: set_newkeys: mode 0 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: rekey in after 134217728 blocks [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: KEX done [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: receive packet: type 5 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: send packet: type 6 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: receive packet: type 50 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: userauth-request for user zapotocnylubos service ssh-connection method none [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: attempt 0 failures 0 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_getpwnamallow entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 8 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive_expect entering: type 9 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: monitor_read: checking request 8
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_pwnamallow
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: parse_server_config_depth: config reprocess config len 408
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: parse_server_config_depth: config  len 0
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 9
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: monitor_read: 8 used once, disabling now
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: input_userauth_request: setting up authctxt for zapotocnylubos [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_start_pam entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 100 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_inform_authserv entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 4 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: input_userauth_request: try method none [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: ensure_minimum_time_since: elapsed 0.983ms, delaying 8.271ms (requested 9.254ms) [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: monitor_read: checking request 100
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: PAM: initializing for "zapotocnylubos"
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: PAM: setting PAM_RHOST to "10.0.1.219"
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: PAM: setting PAM_TTY to "ssh"
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: monitor_read: 100 used once, disabling now
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: monitor_read: checking request 4
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_authserv: service=ssh-connection, style=, role=
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: monitor_read: 4 used once, disabling now
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: userauth_finish: failure partial=0 next methods="publickey,password" [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: send packet: type 51 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: receive packet: type 50 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: userauth-request for user zapotocnylubos service ssh-connection method publickey [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: attempt 1 failures 0 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: input_userauth_request: try method publickey [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: userauth_pubkey: valid user zapotocnylubos querying public key ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBEjyOpwvdEJpYpU1+gPsSw50lL0ptdv++o6D9F/Jz8/Y1HJ3yuKqDrR5XhP5ClAfT1/NWPSQnFJu3DkIdpgM9mw= [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: userauth_pubkey: test pkalg ecdsa-sha2-nistp256 pkblob ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_key_allowed entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 22 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive_expect entering: type 23 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: monitor_read: checking request 22
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_keyallowed entering
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_keyallowed: key_from_blob: 0x5591910c6740
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: trying public key file /home/zapotocnylubos/.ssh/authorized_keys
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: fd 5 clearing O_NONBLOCK
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: /home/zapotocnylubos/.ssh/authorized_keys:1: matching key found: ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: /home/zapotocnylubos/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:46 public-hosting sshd[34874]: Accepted key ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk found at /home/zapotocnylubos/.ssh/authorized_keys:1
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: restore_uid: 0/0
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_keyallowed: publickey authentication test: ECDSA key is allowed
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 23
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: send packet: type 60 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: userauth_pubkey: authenticated 0 pkalg ecdsa-sha2-nistp256 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: ensure_minimum_time_since: elapsed 1.431ms, delaying 7.823ms (requested 9.254ms) [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: Postponed publickey for zapotocnylubos from 10.0.1.219 port 49790 ssh2 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: receive packet: type 50 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: userauth-request for user zapotocnylubos service ssh-connection method publickey [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: attempt 2 failures 0 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: input_userauth_request: try method publickey [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: userauth_pubkey: valid user zapotocnylubos attempting public key ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBEjyOpwvdEJpYpU1+gPsSw50lL0ptdv++o6D9F/Jz8/Y1HJ3yuKqDrR5XhP5ClAfT1/NWPSQnFJu3DkIdpgM9mw= [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: userauth_pubkey: have ecdsa-sha2-nistp256 signature for ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_key_allowed entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 22 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive_expect entering: type 23 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: monitor_read: checking request 22
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_keyallowed entering
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_keyallowed: key_from_blob: 0x5591910c6740
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: trying public key file /home/zapotocnylubos/.ssh/authorized_keys
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: fd 5 clearing O_NONBLOCK
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: /home/zapotocnylubos/.ssh/authorized_keys:1: matching key found: ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: /home/zapotocnylubos/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:46 public-hosting sshd[34874]: Accepted key ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk found at /home/zapotocnylubos/.ssh/authorized_keys:1
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: restore_uid: 0/0
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_keyallowed: publickey authentication: ECDSA key is allowed
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 23
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_sshkey_verify entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 24 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_sshkey_verify: waiting for MONITOR_ANS_KEYVERIFY [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive_expect entering: type 25 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: monitor_read: checking request 24
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_keyverify: publickey 0x5591910c70e0 signature verified
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: auth_activate_options: setting new authentication options
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 25
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive_expect entering: type 102
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: do_pam_account: called
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: do_pam_account: auth information in SSH_AUTH_INFO_0
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success)
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 103
Aug 13 23:19:46 public-hosting sshd[34874]: Accepted publickey for zapotocnylubos from 10.0.1.219 port 49790 ssh2: ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: monitor_child_preauth: zapotocnylubos has been authenticated by privileged process
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_get_keystate: Waiting for new keys
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive_expect entering: type 26
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_get_keystate: GOT new keys
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: auth_activate_options: setting new authentication options [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: userauth_pubkey: authenticated 1 pkalg ecdsa-sha2-nistp256 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: ensure_minimum_time_since: elapsed 1.187ms, delaying 8.067ms (requested 9.254ms) [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_do_pam_account entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 102 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive_expect entering: type 103 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_do_pam_account returning 1 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: send packet: type 52 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_send entering: type 26 [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_send_keystate: Finished sending state [preauth]
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: monitor_read_log: child log fd closed
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: ssh_sandbox_parent_finish: finished
Aug 13 23:19:46 public-hosting sshd[34874]: debug1: PAM: establishing credentials
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: PAM: opening session
Aug 13 23:19:46 public-hosting sshd[34874]: debug2: do_pam_session: auth information in SSH_AUTH_INFO_0
Aug 13 23:19:46 public-hosting sshd[34874]: pam_unix(sshd:session): session opened for user zapotocnylubos(uid=1000) by (uid=0)
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: PAM: sshpam_store_conv called with 1 messages
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: PAM: sshpam_store_conv called with 1 messages
Aug 13 23:19:46 public-hosting sshd[34874]: User child is on pid 34880
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: SELinux support disabled
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: PAM: establishing credentials
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: permanently_set_uid: 1000/1000
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: monitor_apply_keystate: packet_set_state
Aug 13 23:19:46 public-hosting sshd[34880]: debug2: set_newkeys: mode 0
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: rekey in after 134217728 blocks
Aug 13 23:19:46 public-hosting sshd[34880]: debug2: set_newkeys: mode 1
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: rekey out after 134217728 blocks
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: ssh_packet_set_postauth: called
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: ssh_packet_set_state: done
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: notify_hostkeys: key 0: ssh-rsa SHA256:5Rr6I50CbYZJGMaxMonloie0/NM5gg/Td+1PCbFMgyc
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: notify_hostkeys: key 1: ecdsa-sha2-nistp256 SHA256:zmf8noBmlNNMrI1g5Px8/Zctb3vS9p3cJ/n4L6eIcdA
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: notify_hostkeys: key 2: ssh-ed25519 SHA256:XFDgckSeN0Wl+R0vx7bUxXbZo6K/LTXlGzsP5rjHA/M
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: notify_hostkeys: sent 3 hostkeys
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: send packet: type 80
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: sending debug message: /home/zapotocnylubos/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: send packet: type 4
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: sending debug message: /home/zapotocnylubos/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: send packet: type 4
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: Entering interactive session for SSH2.
Aug 13 23:19:46 public-hosting sshd[34880]: debug2: fd 5 setting O_NONBLOCK
Aug 13 23:19:46 public-hosting sshd[34880]: debug2: fd 7 setting O_NONBLOCK
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: server_init_dispatch
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: receive packet: type 90
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: input_session_request
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: channel 0: new [server-session]
Aug 13 23:19:46 public-hosting sshd[34880]: debug2: session_new: allocate (allocated 0 max 20)
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: session_unused: session id 0 unused
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: session_new: session 0
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: session_open: channel 0
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: session_open: session 0: link with channel 0
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: server_input_channel_open: confirm session
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: send packet: type 91
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: receive packet: type 80
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: receive packet: type 98
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: server_input_channel_req: channel 0 request exec reply 1
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: session_by_channel: session 0 channel 0
Aug 13 23:19:46 public-hosting sshd[34880]: debug1: session_input_channel_req: session 0 req exec
Aug 13 23:19:46 public-hosting sshd[34880]: Starting session: command for zapotocnylubos from 10.0.1.219 port 49790 id 0
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: mm_audit_run_command entering command docker system dial-stdio
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: mm_request_send entering: type 113
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_request_receive entering
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: monitor_read: checking request 113
Aug 13 23:19:46 public-hosting sshd[34874]: debug3: mm_answer_audit_command entering
Aug 13 23:19:46 public-hosting sshd[34880]: debug2: fd 4 setting TCP_NODELAY
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: ssh_packet_set_tos: set IP_TOS 0x08
Aug 13 23:19:46 public-hosting sshd[34880]: debug2: fd 11 setting O_NONBLOCK
Aug 13 23:19:46 public-hosting sshd[34880]: debug2: fd 10 setting O_NONBLOCK
Aug 13 23:19:46 public-hosting sshd[34880]: debug2: fd 13 setting O_NONBLOCK
Aug 13 23:19:46 public-hosting sshd[34880]: debug3: send packet: type 99
Aug 13 23:19:46 public-hosting sshd[34881]: debug3: Copy environment: XDG_SESSION_ID=496
Aug 13 23:19:46 public-hosting sshd[34881]: debug3: Copy environment: XDG_RUNTIME_DIR=/run/user/1000
Aug 13 23:19:46 public-hosting sshd[34881]: debug3: Copy environment: DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
Aug 13 23:19:46 public-hosting sshd[34881]: debug3: Copy environment: XDG_SESSION_TYPE=tty
Aug 13 23:19:46 public-hosting sshd[34881]: debug3: Copy environment: XDG_SESSION_CLASS=user
Aug 13 23:19:46 public-hosting sshd[34881]: debug3: Copy environment: MOTD_SHOWN=pam
Aug 13 23:19:46 public-hosting sshd[34881]: debug3: Copy environment: LANG=en_US.UTF-8
Aug 13 23:19:46 public-hosting sshd[34881]: debug3: Copy environment: LANGUAGE=en_US:en
Aug 13 23:19:47 public-hosting sshd[34868]: debug3: fd 5 is not O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34868]: debug1: Forked child 34890.
Aug 13 23:19:47 public-hosting sshd[34868]: debug3: send_rexec_state: entering fd = 8 config len 408
Aug 13 23:19:47 public-hosting sshd[34868]: debug3: ssh_msg_send: type 0
Aug 13 23:19:47 public-hosting sshd[34868]: debug3: send_rexec_state: done
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: oom_adjust_restore
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: Set /proc/self/oom_score_adj to 0
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: rexec start in 5 out 5 newsock 5 pipe 7 sock 8
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: inetd sockets after dupping: 4, 4
Aug 13 23:19:47 public-hosting sshd[34890]: Connection from 10.0.1.219 port 49794 on 10.0.1.105 port 22 rdomain ""
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: Local version string SSH-2.0-OpenSSH_8.4p1 Debian-5+deb11u1
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: Remote protocol version 2.0, remote software version OpenSSH_9.0
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: match: OpenSSH_9.0 pat OpenSSH* compat 0x04000000
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: fd 4 setting O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: ssh_sandbox_init: preparing seccomp filter sandbox
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: Network child is on pid 34891
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: preauth child monitor started
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: privsep user:group 105:65534 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: permanently_set_uid: 105/65534 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: ssh_sandbox_child: setting PR_SET_NO_NEW_PRIVS [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: ssh_sandbox_child: attaching seccomp filter program [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: send packet: type 20 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: SSH2_MSG_KEXINIT sent [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: receive packet: type 20 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: SSH2_MSG_KEXINIT received [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: local server KEXINIT proposal [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: 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-group14-sha256 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: 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]
Aug 13 23:19:47 public-hosting sshd[34890]: 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]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: compression ctos: none,zlib@openssh.com [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: compression stoc: none,zlib@openssh.com [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: languages ctos:  [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: languages stoc:  [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: first_kex_follows 0  [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: reserved 0  [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: peer client KEXINIT proposal [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: 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]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: host key algorithms: 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,sk-ssh-ed25519-cert-v01@openssh.com,sk-ecdsa-sha2-nistp256-cert-v01@openssh.com,rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ssh-ed25519@openssh.com,sk-ecdsa-sha2-nistp256@openssh.com,rsa-sha2-512,rsa-sha2-256 [preaut
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: 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]
Aug 13 23:19:47 public-hosting sshd[34890]: 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]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: compression ctos: none,zlib@openssh.com,zlib [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: compression stoc: none,zlib@openssh.com,zlib [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: languages ctos:  [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: languages stoc:  [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: first_kex_follows 0  [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: reserved 0  [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: kex: algorithm: curve25519-sha256 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: kex: host key algorithm: ssh-ed25519 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: receive packet: type 30 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_sshkey_sign entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 6 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive_expect entering: type 7 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: monitor_read: checking request 6
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_sign
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_sign: KEX signature 0x561f9b0e93b0(83)
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 7
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: monitor_read: 6 used once, disabling now
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: send packet: type 31 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: send packet: type 21 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: set_newkeys: mode 1 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: rekey out after 134217728 blocks [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: Sending SSH2_MSG_EXT_INFO [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: send packet: type 7 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: expecting SSH2_MSG_NEWKEYS [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: receive packet: type 21 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: SSH2_MSG_NEWKEYS received [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: set_newkeys: mode 0 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: rekey in after 134217728 blocks [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: KEX done [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: receive packet: type 5 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: send packet: type 6 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: receive packet: type 50 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: userauth-request for user zapotocnylubos service ssh-connection method none [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: attempt 0 failures 0 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_getpwnamallow entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 8 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive_expect entering: type 9 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: monitor_read: checking request 8
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_pwnamallow
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: parse_server_config_depth: config reprocess config len 408
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: parse_server_config_depth: config  len 0
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 9
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: monitor_read: 8 used once, disabling now
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: input_userauth_request: setting up authctxt for zapotocnylubos [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_start_pam entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 100 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_inform_authserv entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 4 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: input_userauth_request: try method none [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: ensure_minimum_time_since: elapsed 0.951ms, delaying 8.303ms (requested 9.254ms) [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: monitor_read: checking request 100
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: PAM: initializing for "zapotocnylubos"
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: PAM: setting PAM_RHOST to "10.0.1.219"
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: PAM: setting PAM_TTY to "ssh"
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: monitor_read: 100 used once, disabling now
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: monitor_read: checking request 4
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_authserv: service=ssh-connection, style=, role=
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: monitor_read: 4 used once, disabling now
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: userauth_finish: failure partial=0 next methods="publickey,password" [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: send packet: type 51 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: receive packet: type 50 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: userauth-request for user zapotocnylubos service ssh-connection method publickey [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: attempt 1 failures 0 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: input_userauth_request: try method publickey [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: userauth_pubkey: valid user zapotocnylubos querying public key ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBEjyOpwvdEJpYpU1+gPsSw50lL0ptdv++o6D9F/Jz8/Y1HJ3yuKqDrR5XhP5ClAfT1/NWPSQnFJu3DkIdpgM9mw= [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: userauth_pubkey: test pkalg ecdsa-sha2-nistp256 pkblob ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_key_allowed entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 22 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive_expect entering: type 23 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: monitor_read: checking request 22
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_keyallowed entering
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_keyallowed: key_from_blob: 0x561f9b107740
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: trying public key file /home/zapotocnylubos/.ssh/authorized_keys
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: fd 5 clearing O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: /home/zapotocnylubos/.ssh/authorized_keys:1: matching key found: ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: /home/zapotocnylubos/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:47 public-hosting sshd[34890]: Accepted key ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk found at /home/zapotocnylubos/.ssh/authorized_keys:1
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: restore_uid: 0/0
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_keyallowed: publickey authentication test: ECDSA key is allowed
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 23
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: send packet: type 60 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: userauth_pubkey: authenticated 0 pkalg ecdsa-sha2-nistp256 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: ensure_minimum_time_since: elapsed 1.381ms, delaying 7.873ms (requested 9.254ms) [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: Postponed publickey for zapotocnylubos from 10.0.1.219 port 49794 ssh2 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: receive packet: type 50 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: userauth-request for user zapotocnylubos service ssh-connection method publickey [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: attempt 2 failures 0 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: input_userauth_request: try method publickey [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: userauth_pubkey: valid user zapotocnylubos attempting public key ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBEjyOpwvdEJpYpU1+gPsSw50lL0ptdv++o6D9F/Jz8/Y1HJ3yuKqDrR5XhP5ClAfT1/NWPSQnFJu3DkIdpgM9mw= [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: userauth_pubkey: have ecdsa-sha2-nistp256 signature for ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_key_allowed entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 22 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive_expect entering: type 23 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: monitor_read: checking request 22
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_keyallowed entering
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_keyallowed: key_from_blob: 0x561f9b107740
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: trying public key file /home/zapotocnylubos/.ssh/authorized_keys
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: fd 5 clearing O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: /home/zapotocnylubos/.ssh/authorized_keys:1: matching key found: ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: /home/zapotocnylubos/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:47 public-hosting sshd[34890]: Accepted key ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk found at /home/zapotocnylubos/.ssh/authorized_keys:1
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: restore_uid: 0/0
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_keyallowed: publickey authentication: ECDSA key is allowed
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 23
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_sshkey_verify entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 24 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_sshkey_verify: waiting for MONITOR_ANS_KEYVERIFY [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive_expect entering: type 25 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: monitor_read: checking request 24
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_keyverify: publickey 0x561f9b1080e0 signature verified
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: auth_activate_options: setting new authentication options
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 25
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive_expect entering: type 102
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: do_pam_account: called
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: do_pam_account: auth information in SSH_AUTH_INFO_0
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success)
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 103
Aug 13 23:19:47 public-hosting sshd[34890]: Accepted publickey for zapotocnylubos from 10.0.1.219 port 49794 ssh2: ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: monitor_child_preauth: zapotocnylubos has been authenticated by privileged process
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_get_keystate: Waiting for new keys
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive_expect entering: type 26
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_get_keystate: GOT new keys
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: auth_activate_options: setting new authentication options [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: userauth_pubkey: authenticated 1 pkalg ecdsa-sha2-nistp256 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: ensure_minimum_time_since: elapsed 1.496ms, delaying 7.758ms (requested 9.254ms) [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_do_pam_account entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 102 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive_expect entering: type 103 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_do_pam_account returning 1 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: send packet: type 52 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_send entering: type 26 [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_send_keystate: Finished sending state [preauth]
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: monitor_read_log: child log fd closed
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: ssh_sandbox_parent_finish: finished
Aug 13 23:19:47 public-hosting sshd[34890]: debug1: PAM: establishing credentials
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: PAM: opening session
Aug 13 23:19:47 public-hosting sshd[34890]: debug2: do_pam_session: auth information in SSH_AUTH_INFO_0
Aug 13 23:19:47 public-hosting sshd[34890]: pam_unix(sshd:session): session opened for user zapotocnylubos(uid=1000) by (uid=0)
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: PAM: sshpam_store_conv called with 1 messages
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: PAM: sshpam_store_conv called with 1 messages
Aug 13 23:19:47 public-hosting sshd[34890]: User child is on pid 34896
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: SELinux support disabled
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: PAM: establishing credentials
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: permanently_set_uid: 1000/1000
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: monitor_apply_keystate: packet_set_state
Aug 13 23:19:47 public-hosting sshd[34896]: debug2: set_newkeys: mode 0
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: rekey in after 134217728 blocks
Aug 13 23:19:47 public-hosting sshd[34896]: debug2: set_newkeys: mode 1
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: rekey out after 134217728 blocks
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: ssh_packet_set_postauth: called
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: ssh_packet_set_state: done
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: notify_hostkeys: key 0: ssh-rsa SHA256:5Rr6I50CbYZJGMaxMonloie0/NM5gg/Td+1PCbFMgyc
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: notify_hostkeys: key 1: ecdsa-sha2-nistp256 SHA256:zmf8noBmlNNMrI1g5Px8/Zctb3vS9p3cJ/n4L6eIcdA
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: notify_hostkeys: key 2: ssh-ed25519 SHA256:XFDgckSeN0Wl+R0vx7bUxXbZo6K/LTXlGzsP5rjHA/M
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: notify_hostkeys: sent 3 hostkeys
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: send packet: type 80
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: sending debug message: /home/zapotocnylubos/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: send packet: type 4
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: sending debug message: /home/zapotocnylubos/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: send packet: type 4
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: Entering interactive session for SSH2.
Aug 13 23:19:47 public-hosting sshd[34896]: debug2: fd 5 setting O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34896]: debug2: fd 7 setting O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: server_init_dispatch
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: receive packet: type 90
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: input_session_request
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: channel 0: new [server-session]
Aug 13 23:19:47 public-hosting sshd[34896]: debug2: session_new: allocate (allocated 0 max 20)
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: session_unused: session id 0 unused
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: session_new: session 0
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: session_open: channel 0
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: session_open: session 0: link with channel 0
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: server_input_channel_open: confirm session
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: send packet: type 91
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: receive packet: type 80
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: receive packet: type 98
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: server_input_channel_req: channel 0 request exec reply 1
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: session_by_channel: session 0 channel 0
Aug 13 23:19:47 public-hosting sshd[34896]: debug1: session_input_channel_req: session 0 req exec
Aug 13 23:19:47 public-hosting sshd[34896]: Starting session: command for zapotocnylubos from 10.0.1.219 port 49794 id 0
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: mm_audit_run_command entering command docker system dial-stdio
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: mm_request_send entering: type 113
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: monitor_read: checking request 113
Aug 13 23:19:47 public-hosting sshd[34890]: debug3: mm_answer_audit_command entering
Aug 13 23:19:47 public-hosting sshd[34896]: debug2: fd 4 setting TCP_NODELAY
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: ssh_packet_set_tos: set IP_TOS 0x08
Aug 13 23:19:47 public-hosting sshd[34896]: debug2: fd 11 setting O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34896]: debug2: fd 10 setting O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34896]: debug2: fd 13 setting O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34896]: debug3: send packet: type 99
Aug 13 23:19:47 public-hosting sshd[34897]: debug3: Copy environment: XDG_SESSION_ID=497
Aug 13 23:19:47 public-hosting sshd[34897]: debug3: Copy environment: XDG_RUNTIME_DIR=/run/user/1000
Aug 13 23:19:47 public-hosting sshd[34897]: debug3: Copy environment: DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
Aug 13 23:19:47 public-hosting sshd[34897]: debug3: Copy environment: XDG_SESSION_TYPE=tty
Aug 13 23:19:47 public-hosting sshd[34897]: debug3: Copy environment: XDG_SESSION_CLASS=user
Aug 13 23:19:47 public-hosting sshd[34897]: debug3: Copy environment: MOTD_SHOWN=pam
Aug 13 23:19:47 public-hosting sshd[34897]: debug3: Copy environment: LANG=en_US.UTF-8
Aug 13 23:19:47 public-hosting sshd[34897]: debug3: Copy environment: LANGUAGE=en_US:en
Aug 13 23:19:47 public-hosting sshd[34868]: debug3: fd 5 is not O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34868]: debug1: Forked child 34912.
Aug 13 23:19:47 public-hosting sshd[34868]: debug3: send_rexec_state: entering fd = 8 config len 408
Aug 13 23:19:47 public-hosting sshd[34868]: debug3: ssh_msg_send: type 0
Aug 13 23:19:47 public-hosting sshd[34868]: debug3: send_rexec_state: done
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: oom_adjust_restore
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: Set /proc/self/oom_score_adj to 0
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: rexec start in 5 out 5 newsock 5 pipe 7 sock 8
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: inetd sockets after dupping: 4, 4
Aug 13 23:19:47 public-hosting sshd[34912]: Connection from 10.0.1.219 port 49808 on 10.0.1.105 port 22 rdomain ""
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: Local version string SSH-2.0-OpenSSH_8.4p1 Debian-5+deb11u1
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: Remote protocol version 2.0, remote software version OpenSSH_9.0
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: match: OpenSSH_9.0 pat OpenSSH* compat 0x04000000
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: fd 4 setting O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: ssh_sandbox_init: preparing seccomp filter sandbox
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: Network child is on pid 34913
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: preauth child monitor started
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: privsep user:group 105:65534 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: permanently_set_uid: 105/65534 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: ssh_sandbox_child: setting PR_SET_NO_NEW_PRIVS [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: ssh_sandbox_child: attaching seccomp filter program [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: send packet: type 20 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: SSH2_MSG_KEXINIT sent [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: receive packet: type 20 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: SSH2_MSG_KEXINIT received [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: local server KEXINIT proposal [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: 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-group14-sha256 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: 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]
Aug 13 23:19:47 public-hosting sshd[34912]: 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]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: compression ctos: none,zlib@openssh.com [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: compression stoc: none,zlib@openssh.com [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: languages ctos:  [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: languages stoc:  [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: first_kex_follows 0  [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: reserved 0  [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: peer client KEXINIT proposal [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: 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]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: host key algorithms: 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,sk-ssh-ed25519-cert-v01@openssh.com,sk-ecdsa-sha2-nistp256-cert-v01@openssh.com,rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ssh-ed25519@openssh.com,sk-ecdsa-sha2-nistp256@openssh.com,rsa-sha2-512,rsa-sha2-256 [preaut
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: 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]
Aug 13 23:19:47 public-hosting sshd[34912]: 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]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: compression ctos: none,zlib@openssh.com,zlib [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: compression stoc: none,zlib@openssh.com,zlib [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: languages ctos:  [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: languages stoc:  [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: first_kex_follows 0  [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: reserved 0  [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: kex: algorithm: curve25519-sha256 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: kex: host key algorithm: ssh-ed25519 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: receive packet: type 30 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_sshkey_sign entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_send entering: type 6 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive_expect entering: type 7 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: monitor_read: checking request 6
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_answer_sign
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_answer_sign: KEX signature 0x557a35c59b50(83)
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_send entering: type 7
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: monitor_read: 6 used once, disabling now
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: send packet: type 31 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: send packet: type 21 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: set_newkeys: mode 1 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: rekey out after 134217728 blocks [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: Sending SSH2_MSG_EXT_INFO [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: send packet: type 7 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: expecting SSH2_MSG_NEWKEYS [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: receive packet: type 21 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: SSH2_MSG_NEWKEYS received [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: set_newkeys: mode 0 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: rekey in after 134217728 blocks [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: KEX done [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: receive packet: type 5 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: send packet: type 6 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: receive packet: type 50 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: userauth-request for user zapotocnylubos service ssh-connection method none [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: attempt 0 failures 0 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_getpwnamallow entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_send entering: type 8 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive_expect entering: type 9 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: monitor_read: checking request 8
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_answer_pwnamallow
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: parse_server_config_depth: config reprocess config len 408
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: parse_server_config_depth: config  len 0
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_send entering: type 9
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: monitor_read: 8 used once, disabling now
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: input_userauth_request: setting up authctxt for zapotocnylubos [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_start_pam entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_send entering: type 100 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_inform_authserv entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_send entering: type 4 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: input_userauth_request: try method none [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: ensure_minimum_time_since: elapsed 0.968ms, delaying 8.286ms (requested 9.254ms) [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: monitor_read: checking request 100
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: PAM: initializing for "zapotocnylubos"
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: PAM: setting PAM_RHOST to "10.0.1.219"
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: PAM: setting PAM_TTY to "ssh"
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: monitor_read: 100 used once, disabling now
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: monitor_read: checking request 4
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_answer_authserv: service=ssh-connection, style=, role=
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: monitor_read: 4 used once, disabling now
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: userauth_finish: failure partial=0 next methods="publickey,password" [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: send packet: type 51 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: receive packet: type 50 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: userauth-request for user zapotocnylubos service ssh-connection method publickey [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: attempt 1 failures 0 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: input_userauth_request: try method publickey [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: userauth_pubkey: valid user zapotocnylubos querying public key ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBEjyOpwvdEJpYpU1+gPsSw50lL0ptdv++o6D9F/Jz8/Y1HJ3yuKqDrR5XhP5ClAfT1/NWPSQnFJu3DkIdpgM9mw= [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: userauth_pubkey: test pkalg ecdsa-sha2-nistp256 pkblob ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_key_allowed entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_send entering: type 22 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive_expect entering: type 23 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: monitor_read: checking request 22
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_answer_keyallowed entering
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_answer_keyallowed: key_from_blob: 0x557a35c6a6e0
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: trying public key file /home/zapotocnylubos/.ssh/authorized_keys
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: fd 5 clearing O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: /home/zapotocnylubos/.ssh/authorized_keys:1: matching key found: ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: /home/zapotocnylubos/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:47 public-hosting sshd[34912]: Accepted key ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk found at /home/zapotocnylubos/.ssh/authorized_keys:1
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: restore_uid: 0/0
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_answer_keyallowed: publickey authentication test: ECDSA key is allowed
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_send entering: type 23
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: send packet: type 60 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: userauth_pubkey: authenticated 0 pkalg ecdsa-sha2-nistp256 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: ensure_minimum_time_since: elapsed 1.394ms, delaying 7.860ms (requested 9.254ms) [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: Postponed publickey for zapotocnylubos from 10.0.1.219 port 49808 ssh2 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: receive packet: type 50 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: userauth-request for user zapotocnylubos service ssh-connection method publickey [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: attempt 2 failures 0 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: input_userauth_request: try method publickey [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug2: userauth_pubkey: valid user zapotocnylubos attempting public key ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBEjyOpwvdEJpYpU1+gPsSw50lL0ptdv++o6D9F/Jz8/Y1HJ3yuKqDrR5XhP5ClAfT1/NWPSQnFJu3DkIdpgM9mw= [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: userauth_pubkey: have ecdsa-sha2-nistp256 signature for ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_key_allowed entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_send entering: type 22 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive_expect entering: type 23 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: monitor_read: checking request 22
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_answer_keyallowed entering
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_answer_keyallowed: key_from_blob: 0x557a35c6a6e0
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: trying public key file /home/zapotocnylubos/.ssh/authorized_keys
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: fd 5 clearing O_NONBLOCK
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: /home/zapotocnylubos/.ssh/authorized_keys:1: matching key found: ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: /home/zapotocnylubos/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:47 public-hosting sshd[34912]: Accepted key ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk found at /home/zapotocnylubos/.ssh/authorized_keys:1
Aug 13 23:19:47 public-hosting sshd[34912]: debug1: restore_uid: 0/0
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_answer_keyallowed: publickey authentication: ECDSA key is allowed
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_send entering: type 23
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_sshkey_verify entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_send entering: type 24 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_sshkey_verify: waiting for MONITOR_ANS_KEYVERIFY [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive_expect entering: type 25 [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_request_receive entering
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: monitor_read: checking request 24
Aug 13 23:19:47 public-hosting sshd[34912]: debug3: mm_answer_keyverify: publickey 0x557a35c6a6e0 signature verified
Aug 13 23:19:48 public-hosting sshd[34912]: debug1: auth_activate_options: setting new authentication options
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_send entering: type 25
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_receive_expect entering: type 102
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_receive entering
Aug 13 23:19:48 public-hosting sshd[34912]: debug1: do_pam_account: called
Aug 13 23:19:48 public-hosting sshd[34912]: debug2: do_pam_account: auth information in SSH_AUTH_INFO_0
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success)
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_send entering: type 103
Aug 13 23:19:48 public-hosting sshd[34912]: Accepted publickey for zapotocnylubos from 10.0.1.219 port 49808 ssh2: ECDSA SHA256:1MN9JRq4ZJkIylJWExoP6HFENg4ZZbTt6yMQ3KSuxrk
Aug 13 23:19:48 public-hosting sshd[34912]: debug1: monitor_child_preauth: zapotocnylubos has been authenticated by privileged process
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_get_keystate: Waiting for new keys
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_receive_expect entering: type 26
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_receive entering
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_get_keystate: GOT new keys
Aug 13 23:19:48 public-hosting sshd[34912]: debug1: auth_activate_options: setting new authentication options [preauth]
Aug 13 23:19:48 public-hosting sshd[34912]: debug2: userauth_pubkey: authenticated 1 pkalg ecdsa-sha2-nistp256 [preauth]
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: ensure_minimum_time_since: elapsed 1.064ms, delaying 8.190ms (requested 9.254ms) [preauth]
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_do_pam_account entering [preauth]
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_send entering: type 102 [preauth]
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_receive_expect entering: type 103 [preauth]
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_receive entering [preauth]
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_do_pam_account returning 1 [preauth]
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: send packet: type 52 [preauth]
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_send entering: type 26 [preauth]
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_send_keystate: Finished sending state [preauth]
Aug 13 23:19:48 public-hosting sshd[34912]: debug1: monitor_read_log: child log fd closed
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: ssh_sandbox_parent_finish: finished
Aug 13 23:19:48 public-hosting sshd[34912]: debug1: PAM: establishing credentials
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: PAM: opening session
Aug 13 23:19:48 public-hosting sshd[34912]: debug2: do_pam_session: auth information in SSH_AUTH_INFO_0
Aug 13 23:19:48 public-hosting sshd[34912]: pam_unix(sshd:session): session opened for user zapotocnylubos(uid=1000) by (uid=0)
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: PAM: sshpam_store_conv called with 1 messages
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: PAM: sshpam_store_conv called with 1 messages
Aug 13 23:19:48 public-hosting sshd[34912]: User child is on pid 34918
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: SELinux support disabled
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: PAM: establishing credentials
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: permanently_set_uid: 1000/1000
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: monitor_apply_keystate: packet_set_state
Aug 13 23:19:48 public-hosting sshd[34918]: debug2: set_newkeys: mode 0
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: rekey in after 134217728 blocks
Aug 13 23:19:48 public-hosting sshd[34918]: debug2: set_newkeys: mode 1
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: rekey out after 134217728 blocks
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: ssh_packet_set_postauth: called
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: ssh_packet_set_state: done
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: notify_hostkeys: key 0: ssh-rsa SHA256:5Rr6I50CbYZJGMaxMonloie0/NM5gg/Td+1PCbFMgyc
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: notify_hostkeys: key 1: ecdsa-sha2-nistp256 SHA256:zmf8noBmlNNMrI1g5Px8/Zctb3vS9p3cJ/n4L6eIcdA
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: notify_hostkeys: key 2: ssh-ed25519 SHA256:XFDgckSeN0Wl+R0vx7bUxXbZo6K/LTXlGzsP5rjHA/M
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: notify_hostkeys: sent 3 hostkeys
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: send packet: type 80
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: sending debug message: /home/zapotocnylubos/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: send packet: type 4
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: sending debug message: /home/zapotocnylubos/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: send packet: type 4
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: Entering interactive session for SSH2.
Aug 13 23:19:48 public-hosting sshd[34918]: debug2: fd 5 setting O_NONBLOCK
Aug 13 23:19:48 public-hosting sshd[34918]: debug2: fd 7 setting O_NONBLOCK
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: server_init_dispatch
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: receive packet: type 90
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: input_session_request
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: channel 0: new [server-session]
Aug 13 23:19:48 public-hosting sshd[34918]: debug2: session_new: allocate (allocated 0 max 20)
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: session_unused: session id 0 unused
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: session_new: session 0
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: session_open: channel 0
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: session_open: session 0: link with channel 0
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: server_input_channel_open: confirm session
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: send packet: type 91
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: receive packet: type 80
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: receive packet: type 98
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: server_input_channel_req: channel 0 request exec reply 1
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: session_by_channel: session 0 channel 0
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: session_input_channel_req: session 0 req exec
Aug 13 23:19:48 public-hosting sshd[34918]: Starting session: command for zapotocnylubos from 10.0.1.219 port 49808 id 0
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: mm_audit_run_command entering command docker system dial-stdio
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: mm_request_send entering: type 113
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_receive entering
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: monitor_read: checking request 113
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_answer_audit_command entering
Aug 13 23:19:48 public-hosting sshd[34918]: debug2: fd 4 setting TCP_NODELAY
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: ssh_packet_set_tos: set IP_TOS 0x08
Aug 13 23:19:48 public-hosting sshd[34918]: debug2: fd 11 setting O_NONBLOCK
Aug 13 23:19:48 public-hosting sshd[34918]: debug2: fd 10 setting O_NONBLOCK
Aug 13 23:19:48 public-hosting sshd[34918]: debug2: fd 13 setting O_NONBLOCK
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: send packet: type 99
Aug 13 23:19:48 public-hosting sshd[34919]: debug3: Copy environment: XDG_SESSION_ID=498
Aug 13 23:19:48 public-hosting sshd[34919]: debug3: Copy environment: XDG_RUNTIME_DIR=/run/user/1000
Aug 13 23:19:48 public-hosting sshd[34919]: debug3: Copy environment: DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
Aug 13 23:19:48 public-hosting sshd[34919]: debug3: Copy environment: XDG_SESSION_TYPE=tty
Aug 13 23:19:48 public-hosting sshd[34919]: debug3: Copy environment: XDG_SESSION_CLASS=user
Aug 13 23:19:48 public-hosting sshd[34919]: debug3: Copy environment: MOTD_SHOWN=pam
Aug 13 23:19:48 public-hosting sshd[34919]: debug3: Copy environment: LANG=en_US.UTF-8
Aug 13 23:19:48 public-hosting sshd[34919]: debug3: Copy environment: LANGUAGE=en_US:en
Aug 13 23:19:48 public-hosting sshd[34918]: Connection closed by 10.0.1.219 port 49808
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: channel 0: free: server-session, nchannels 1
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: channel 0: status: The following connections are open:\r\n  #0 server-session (t4 r0 i0/0 o0/0 e[read]/0 fd 11/10/13 sock -1 cc -1)\r\n
Aug 13 23:19:48 public-hosting sshd[34918]: Close session: user zapotocnylubos from 10.0.1.219 port 49808 id 0
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: session_unused: session id 0 unused
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: do_cleanup
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: PAM: sshpam_thread_cleanup entering
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: temporarily_use_uid: 1000/1000 (e=1000/1000)
Aug 13 23:19:48 public-hosting sshd[34918]: debug1: restore_uid: (unprivileged)
Aug 13 23:19:48 public-hosting sshd[34918]: Transferred: sent 3080, received 2488 bytes
Aug 13 23:19:48 public-hosting sshd[34918]: Closing connection to 10.0.1.219 port 49808
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: mm_audit_event entering
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: mm_request_send entering: type 112
Aug 13 23:19:48 public-hosting sshd[34918]: debug3: mm_request_send entering: type 50
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_receive entering
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: monitor_read: checking request 112
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_answer_audit_event entering
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_request_receive entering
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: monitor_read: checking request 50
Aug 13 23:19:48 public-hosting sshd[34912]: debug3: mm_answer_term: tearing down sessions
Aug 13 23:19:48 public-hosting sshd[34912]: debug1: PAM: cleanup
Aug 13 23:19:48 public-hosting sshd[34912]: debug1: PAM: closing session
Aug 13 23:19:48 public-hosting sshd[34912]: pam_unix(sshd:session): session closed for user zapotocnylubos
Aug 13 23:19:48 public-hosting sshd[34912]: debug1: PAM: deleting credentials
Aug 13 23:19:48 public-hosting sshd[34868]: debug1: main_sigchld_handler: Child exited
Aug 13 23:19:48 public-hosting sshd[34896]: Connection closed by 10.0.1.219 port 49794
Aug 13 23:19:48 public-hosting sshd[34896]: debug1: channel 0: free: server-session, nchannels 1
Aug 13 23:19:48 public-hosting sshd[34896]: debug3: channel 0: status: The following connections are open:\r\n  #0 server-session (t4 r0 i0/0 o0/0 e[read]/0 fd 11/10/13 sock -1 cc -1)\r\n
Aug 13 23:19:48 public-hosting sshd[34896]: Close session: user zapotocnylubos from 10.0.1.219 port 49794 id 0
Aug 13 23:19:48 public-hosting sshd[34896]: debug3: session_unused: session id 0 unused
Aug 13 23:19:48 public-hosting sshd[34896]: debug1: do_cleanup
Aug 13 23:19:48 public-hosting sshd[34896]: debug3: PAM: sshpam_thread_cleanup entering
Aug 13 23:19:48 public-hosting sshd[34896]: debug1: temporarily_use_uid: 1000/1000 (e=1000/1000)
Aug 13 23:19:48 public-hosting sshd[34896]: debug1: restore_uid: (unprivileged)
Aug 13 23:19:48 public-hosting sshd[34896]: Transferred: sent 7760, received 2720 bytes
Aug 13 23:19:48 public-hosting sshd[34896]: Closing connection to 10.0.1.219 port 49794
Aug 13 23:19:48 public-hosting sshd[34896]: debug3: mm_audit_event entering
Aug 13 23:19:48 public-hosting sshd[34896]: debug3: mm_request_send entering: type 112
Aug 13 23:19:48 public-hosting sshd[34896]: debug3: mm_request_send entering: type 50
Aug 13 23:19:48 public-hosting sshd[34890]: debug3: mm_request_receive entering
Aug 13 23:19:48 public-hosting sshd[34890]: debug3: monitor_read: checking request 112
Aug 13 23:19:48 public-hosting sshd[34890]: debug3: mm_answer_audit_event entering
Aug 13 23:19:48 public-hosting sshd[34890]: debug3: mm_request_receive entering
Aug 13 23:19:48 public-hosting sshd[34890]: debug3: monitor_read: checking request 50
Aug 13 23:19:48 public-hosting sshd[34890]: debug3: mm_answer_term: tearing down sessions
Aug 13 23:19:48 public-hosting sshd[34890]: debug1: PAM: cleanup
Aug 13 23:19:48 public-hosting sshd[34890]: debug1: PAM: closing session
Aug 13 23:19:48 public-hosting sshd[34890]: pam_unix(sshd:session): session closed for user zapotocnylubos
Aug 13 23:19:48 public-hosting sshd[34890]: debug1: PAM: deleting credentials
Aug 13 23:19:48 public-hosting sshd[34868]: debug1: main_sigchld_handler: Child exited
Aug 13 23:19:48 public-hosting sshd[34880]: Connection closed by 10.0.1.219 port 49790
Aug 13 23:19:48 public-hosting sshd[34880]: debug1: channel 0: free: server-session, nchannels 1
Aug 13 23:19:48 public-hosting sshd[34880]: debug3: channel 0: status: The following connections are open:\r\n  #0 server-session (t4 r0 i0/0 o0/0 e[read]/0 fd 11/10/13 sock -1 cc -1)\r\n
Aug 13 23:19:48 public-hosting sshd[34880]: Close session: user zapotocnylubos from 10.0.1.219 port 49790 id 0
Aug 13 23:19:48 public-hosting sshd[34880]: debug3: session_unused: session id 0 unused
Aug 13 23:19:48 public-hosting sshd[34880]: debug1: do_cleanup
Aug 13 23:19:48 public-hosting sshd[34880]: debug3: PAM: sshpam_thread_cleanup entering
Aug 13 23:19:48 public-hosting sshd[34880]: debug1: temporarily_use_uid: 1000/1000 (e=1000/1000)
Aug 13 23:19:48 public-hosting sshd[34880]: debug1: restore_uid: (unprivileged)
Aug 13 23:19:48 public-hosting sshd[34880]: Transferred: sent 3008, received 2400 bytes
Aug 13 23:19:48 public-hosting sshd[34880]: Closing connection to 10.0.1.219 port 49790
Aug 13 23:19:48 public-hosting sshd[34880]: debug3: mm_audit_event entering
Aug 13 23:19:48 public-hosting sshd[34880]: debug3: mm_request_send entering: type 112
Aug 13 23:19:48 public-hosting sshd[34880]: debug3: mm_request_send entering: type 50
Aug 13 23:19:48 public-hosting sshd[34874]: debug3: mm_request_receive entering
Aug 13 23:19:48 public-hosting sshd[34874]: debug3: monitor_read: checking request 112
Aug 13 23:19:48 public-hosting sshd[34874]: debug3: mm_answer_audit_event entering
Aug 13 23:19:48 public-hosting sshd[34874]: debug3: mm_request_receive entering
Aug 13 23:19:48 public-hosting sshd[34874]: debug3: monitor_read: checking request 50
Aug 13 23:19:48 public-hosting sshd[34874]: debug3: mm_answer_term: tearing down sessions
Aug 13 23:19:48 public-hosting sshd[34874]: debug1: PAM: cleanup
Aug 13 23:19:48 public-hosting sshd[34874]: debug1: PAM: closing session
Aug 13 23:19:48 public-hosting sshd[34874]: pam_unix(sshd:session): session closed for user zapotocnylubos
Aug 13 23:19:48 public-hosting sshd[34874]: debug1: PAM: deleting credentials
Aug 13 23:19:48 public-hosting sshd[34868]: debug1: main_sigchld_handler: Child exited

Thanks

[zapotocnylubos]

Weirdly enough, the same setup works every time from my local MacBook via ssh to a remote Linux server.

Mac: Docker Compose version v2.7.0 Remote Workstation (Archlinux): Docker Compose version 2.9.0

But from Linux to Linux server, it works only in 1 of 10 attempts.

[demonshreder]

My setup - deploy containers from one remote server to another via local IP SSH. docker-compose always works for replicas until 10 or 11. Any number more than that fails 8 out of 10 times.

[Oblosys]

I ran into these errors ~75% of the time when doing a docker-compose ps over ssh from an M1 Mac to an ubuntu machine. They also happened during other docker-compose commands over ssh, and using context or DOCKER_HOST made no difference.

Thanks to this comment, I finally managed to get rid of them completely, by putting

MaxStartups 500

in /etc/ssh/sshd_config on the ubuntu target (followed by a sudo service ssh restart).

[mahnunchik]

Any news?

[mahnunchik]

The same issue on: compose: Docker Compose (Docker Inc., v2.11.2)

MaxStartups 500 on remote host doesn't solve the issue.

error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=mongo&tag=4": command [ssh -l root -- 1.2.3.4 docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=

[9r1nc3w1ll]

I got around this by locking the docker compose version to v2.3.3. Every other suggestion here failed. Using Github actions, this is what the job looks like.

      - name: Setup Docker
        run: |
          sudo apt-get update
          sudo apt-get install -y ca-certificates curl gnupg lsb-release
          sudo mkdir -p /etc/apt/keyrings
          curl -fsSL https://download.docker.com/linux/ubuntu/gpg | sudo gpg --dearmor -o /etc/apt/keyrings/docker.gpg
          echo "deb [arch=$(dpkg --print-architecture) signed-by=/etc/apt/keyrings/docker.gpg] https://download.docker.com/linux/ubuntu $(lsb_release -cs) stable" | sudo tee /etc/apt/sources.list.d/docker.list > /dev/null
          sudo apt-get update
          sudo apt-get install -y docker-ce docker-ce-cli containerd.io docker-compose-plugin=2.3.3~ubuntu-focal

I hope this helps.

[pdaig]

I also have the issue. It's intermittent but I'm able to reproduce it about 9/10 times.

error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=docker&tag=latest": command [ssh -l user -- host docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=

After some (lots) of trial and errors and poking around, I think I've found the cause and some possible solution. I tried the MaxStartups 500 fix above, but it didn't solve the issue for me (in fact the problem seems to be on the client, see below).

TLDR: it's some kind of race condition with the ssh process spawned on the client.

Minimal repro steps

version: "3.9"
services:
  docker:
    image: docker
  alpine:
    image: alpine

docker -H ssh://[user]@[host] compose pull
OR
DOCKER_HOST=ssh://[user]@[host] docker compose pull

Environment (client)

• Latest docker image (15b7f46c4c94) OR
• Ubuntu 20.04 with docker-ce-cli 5:20.10.18~3-0~ubuntu-focal

As the error message points out, a command is "killed" while doing the pull. By tracing the docker daemon logs (journalctl -fxu docker.service on the remote machine) and comparing a successful attempt with a failed attempt, I found out that some of the requests sent by the client were never received by the daemon.

Since there were no signs of a process being killed or any sign of an issue on the remote, it had to be on the client. But what could possibly kill the ssh client ? I used auditctl to find out. The answer is a bit surprising : it's the docker-compose binary itself (which is the parent process) !

Digging further:

As some previous comments suggested, this commit 625a48d indeed triggers the issue, specifically lines 58-62. Commenting out these lines seems to completely fix the issue.

I print-debugged my way to understand what exactly was going on. Here's what I think is happening: Disclaimer: I don't have much experience in Go (in fact, never used it before) so my comprehension might be flawed. Please correct me, if I'm wrong.

1. The call to getLocalImagesDigests in turn calls getImages: The for loop starts many goroutines in parallel which are then awaited before returning.

   eg, ctx := errgroup.WithContext(ctx)
   for _, img := range images {
   img := img
   eg.Go(func() error {
     inspect, _, err := s.apiClient().ImageInspectWithRaw(ctx, img)
     // ... returns err or nil
   })
   }
   return summary, eg.Wait()

2. Each call to ImageInspectWithRaw ends up spawning a new ssh connection. The http request is piped through ssh to docker system dial-stdio on the remote. In the docker cli, commandconn.go : the command is passed the shared Context from the errgroup in the caller (this will be important later).
3. The goroutine executes the http request and returns once the whole response body is read.
4. When all goroutine finish the call to eg.Wait() unblocks and the shared Context (linked to each ssh command) becomes Done().
5. As documented, the context's completion kills the process.
6. Even thought the whole http response body has been read and the goroutine has returned, the ssh process is still running because Go's http client implementation seems to keep the net.Conn open (in this case, the ssh commandConn) - maybe even reuses it (?). It still tries to read stdout:

   github.com/docker/cli/cli/connhelper/commandconn.(*commandConn).onEOF(0xc0000bf080, {0x20404c0?, 0xc0000a2120})
       github.com/docker/cli@v20.10.17+incompatible/cli/connhelper/commandconn/commandconn.go:216 +0x4fb
   github.com/docker/cli/cli/connhelper/commandconn.(*commandConn).Read(0xc0000bf080, {0xc000535000, 0x0?, 0x1000})
       github.com/docker/cli@v20.10.17+incompatible/cli/connhelper/commandconn/commandconn.go:268 +0x28c
   net/http.(*persistConn).Read(0xc000695c20, {0xc000535000?, 0xc000520ba0?, 0xc0005afd30?})
       net/http/transport.go:1929 +0x4e
   bufio.(*Reader).fill(0xc0005bca20)
       bufio/bufio.go:106 +0xff
   bufio.(*Reader).Peek(0xc0005bca20, 0x1)
       bufio/bufio.go:144 +0x5d
   net/http.(*persistConn).readLoop(0xc000695c20)
       net/http/transport.go:2093 +0x1ac
   created by net/http.(*Transport).dialConn
       net/http/transport.go:1751 +0x173e

   (line numbers in the stack trace won't match for commandconn.go due to some logs I sprinkled around)

7. We end up in onEOF, where we wait for the process to exit normally but it fails because it was previously killed.

   go func() { werrCh <- c.cmd.Wait() }()

   On line 165, the observed error message is returned to the caller, the whole errgroup fails and everything is aborted.

Solutions

1. ❌ Linking the Context to the command is what causes the process to be killed. However, I think it's legitimate to do so in case there's an actual error. All requests run in parallel and all needs to succeeds in order to continue. If one of them fails, we want to kill/cancel the others to avoid unnecessary waiting.
2. 💡 It would be nice if there was a way that errgroup.Wait() would not set the Context to done when there is no error. Or some way to know if the Context is done because of an error or because everything completed successfully. Then with a small change we could kill the command only in the case of an error. In theory, this would allow connection reuse (so potentially faster). The ssh process would keep running after the request/response completes. Subsequent request could then be run through it (docker system dial-stdio seems to support multiple requests on the same session). IMO, this would be the ideal solution if doable (preferable to solution # 4 below).
3. ❌ Not running things in parallel : this would slow things down.
4. ✅ Actually close the net.Conn before the goroutine returns - not just finish reading the response. I found that calling CloseIdleConnections properly closes the commandConn. Just before returning from ImageInspectWithRaw, I added cli.client.CloseIdleConnections() and it completely fixed the issue 🎉 However, since this could theoretically also happen in other functions, there is probably a better place to put this. Maybe somewhere in request.go ? Since this needs to happen after the body is completely read, there would need to be a way to detect that.

I know this is a lot of things to digest for what looks like a complicated issue, but could someone confirm some of this and chime in on the possible solutions ? Help is welcome to get a PR started :)

One of the reasons I dedicated this much time to investigate the issue is because our CI pipeline rely on this behavior for deployments. Having it fail most of the time is not ideal to say the least ;)

[mahnunchik]

@pdaig minimal example works as expected with client on macos.

Engine: 20.10.17 Compose: v2.10.2

But doesn't work with client in docker image even on the same macos host or gitlab CI.

UPD:

docker compose pull docker
docker compose pull alpine

Pulling multiple images one by one works without any issue.

[pdaig]

@mahnunchik

macos -> maybe something to do with how "quickly" the os handles the kill signal and closes stdout ? I don't know...

Couldn't reproduce the issue either when pulling a single image. Debugging it I can see that the Context of the errgroup is set to done. However, no read attempt returns EOF so that's why it works.

I noticed that all requests made during the pull go through the same ssh process (same PID). So the same connection is reused for all requests. The first request (HEAD /_ping) establishes the connection and it's the Context passed in at this point that gets linked to the process. This context never seems to get set to done. The context passed by the errgroup isn't linked to the process (the first one is) so when it gets done it doesn't kill it.

Also, commandConn.Close() is never called so it would seem the process never gets cleanly shut down? In the end, I guess everything gets cleaned up either by go and/or the os. There's no remaining ssh process after docker compose exits.

All in all, it seems to make sense.

[lUNuXl]

I got around this by locking the docker compose version to v2.3.3. Every other suggestion here failed. Using Github actions, this is what the job looks like.

I can confirm this workaround works on archlinux, for anyone needing to downgrade docker-compose package:

wget https://archive.archlinux.org/packages/d/docker-compose/docker-compose-2.3.3-1-x86_64.pkg.tar.zst
sudo pacman -U ./docker-compose-2.3.3-1-x86_64.pkg.tar.zst

[mahnunchik]

@ndeloof ping

[stephanGarland]

@pdaig I can confirm that avoiding 625a48d (I did `git checkout 625a48d^ pkg/compose/pull.go) fixes the problem, most of the time. I was able to get this to still fail, however intermittently.

❯ docker version
Client: Docker Engine - Community
 Version:           20.10.21
 API version:       1.41
 Go version:        go1.19.2
 Git commit:        baeda1f82a
 Built:             Tue Oct 25 17:53:02 2022
 OS/Arch:           darwin/amd64
 Context:           default
 Experimental:      true

Server: linux/amd64/fedora-36
 Podman Engine:
  Version:          4.3.0
  APIVersion:       4.3.0
  Arch:             amd64
  BuildTime:        2022-10-21T04:16:35-04:00
  Experimental:     false
  GitCommit:
  GoVersion:        go1.18.7
  KernelVersion:    6.0.5-200.fc36.x86_64
  MinAPIVersion:    4.0.0
  Os:               linux
 Conmon:
  Version:          conmon version 2.1.4, commit:
  Package:          conmon-2.1.4-3.fc36.x86_64
 OCI Runtime (crun):
  Version:          crun version 1.6
commit: 18cf2efbb8feb2b2f20e316520e0fd0b6c41ef4d
spec: 1.0.0
+SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +CRIU +YAJL
  Package:          crun-1.6-2.fc36.x86_64
 Engine:
  Version:          4.3.0
  API version:      1.41 (minimum version 1.24)
  Go version:       go1.18.7
  Git commit:
  Built:            Fri Oct 21 04:16:35 2022
  OS/Arch:          linux/amd64
  Experimental:     false

The error message I received:

[+2419] error during connect: Post "http://docker.example.com/v1.41/containers/543154281a08879f86a1eca7ef56b8e32398e8a96b573909bd683f1169bf361f/stop": command [ssh -l core -p 64596 -- localhost docker system dial-stdio] has exited with exit status 255, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=kex_exchange_identification: Connection closed by remote host

If it matters, the application I'm using this for is an extremely intensive collection of images, so there are quite a few connections being made over the SSH tunnel. I can provide more details as needed.

[ndeloof]

If it matters, the application I'm using this for is an extremely intensive collection of images, so there are quite a few connections being made over the SSH tunnel

I wonder this issue could be caused by the way we run stuff concurrently without limitations. Typically, compose will pull all missing images with parallel ssh streams from client to engine. Maybe we should limit concurrency

[sam-mathews]

I'm also seeing this on: Docker Compose version v2.12.2 with docker version:

Client: Docker Engine - Community
 Version:           20.10.21
 API version:       1.41
 Go version:        go1.18.7
 Git commit:        baeda1f
 Built:             Tue Oct 25 18:01:58 2022
 OS/Arch:           linux/amd64
 Context:           default
 Experimental:      true

Server: Docker Engine - Community
 Engine:
  Version:          20.10.21
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.18.7
  Git commit:       3056208
  Built:            Tue Oct 25 17:59:49 2022
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.6.10
  GitCommit:        770bd0108c32f3fb5c73ae1264f7e503fe7b2661
 runc:
  Version:          1.1.4
  GitCommit:        v1.1.4-0-g5fd4c4d
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0

Was experiencing this problem in GitHub Actions, so I changed my local setup to reproduce. I wasn't experiencing it on docker-compose, but am experiencing on docker compose. The MaxStartups change did not make any difference to me.

Current workaround is to do:

docker compose pull my-image-1
docker compose pull my-image-2

Pulling images individually has also fixed my GitHub actions problem. It's good there is a workaround, but it's not particularly maintainable.

[fergalmoran]

Still an issue in 2.13.0 and the MaxStartups trick from @Oblosys doesn't appear to work any more.

[pdaig]

@stephanGarland You may have hit another similar issue I encountered a while ago.

The error message is a bit different. Have you tried MaxSessions 500 and/or MaxStartups 500 as suggested above and in this thread ? This has worked for me. There's still the other issue thought, but as you already figured out, you can work around it by using a version without 625a48d.

To summarize: There seems to be 2 distinct issues with a similar error message.

• The first one indicates that the ssh client process was killed ([...] has exited with signal: killed). This seems to be an issue with the docker client. It's the behavior I described in my previous comment. As far as I know, there's no fix yet for this one but there are workarounds:

  • Downgrade to docker compose v2.4.1 or older. Be aware that older versions may have other bugs that were fixed or a slight difference in behavior or might not support newer compose file syntax. _{In particular, the change to environment variable handling (#9879) introduced in v2.11.2. Depending on your use case this may or may not be a viable solution.}
  • Compile a custom version and revert 625a48d
  • pull each image individually

    docker compose pull service1
    docker compose pull service2
    ...

• The other issue is related to the ssh server. The error message might include stderr=kex_exchange_identification: Connection closed by remote host. The docker client seems to open lots of connections and depending on your os/server configuration, you might need to bump MaxSessions and/or MaxStartups in your sshd server configuration.

[pdaig]

I found a solution. I've opened a PR in docker/cli#3900.

[ndeloof]

Closing as "fixed by https://github.com/docker/cli/pull/3900" Thanks @pdaig 👍

[krzysieqq]

Tested on:

$ docker info
Client:
 Context:    default
 Debug Mode: false
 Plugins:
  app: Docker App (Docker Inc., v0.9.1-beta3)
  buildx: Docker Buildx (Docker Inc., v0.9.1-docker)
  compose: Docker Compose (Docker Inc., v2.14.1)
  scan: Docker Scan (Docker Inc., v0.23.0)

Server:
 Containers: 21
  Running: 2
  Paused: 0
  Stopped: 19
 Images: 280
 Server Version: 20.10.22

and I think it isn't fixed

$ DOCKER_HOST=ssh://root@<server>:<port> docker compose pull
[+] Running 1/2
 ⠿ web Warning                                                                                                                                            0.0s
 ⠿ db Pulled                                                                                                                                              1.3s
WARNING: Some service image(s) must be built from source by running:
    docker compose build web
1 error occurred:
    * error during connect: Post "http://docker.example.com/v1.41/images/create?fromImage=local%2Fdjango_poll&tag=local": command [ssh -l root -p <port> -- <server> docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=

My docker compose:

services:
  db:
    image: postgres
    volumes:
    - postgresql_data:/var/lib/postgresql/data
    environment:
    - POSTGRES_PASSWORD=${POSTGRES_PASSWORD:-postgres}
  web:
    image: ${CI_REGISTRY_IMAGE:-local/django_poll}:${CI_COMMIT_REF_SLUG:-local}
    build: .
    command: bash -c "
      python manage.py migrate --noinput &&
      python manage.py collectstatic --noinput &&
      gunicorn django_poll.wsgi --workers 2 --bind 0.0.0.0:8000
      "
    ports:
    - "8000:8000"
    environment:
    - POSTGRES_PASSWORD=${POSTGRES_PASSWORD:-postgres}
    depends_on:
    - db

volumes:
  postgresql_data:

[ndeloof]

@krzysieqq we still need to upgrade docker CLI to benefit the upstream fix

[krzysieqq]

@ndeloof Oh, I thought that I was updated already. Do you know when we can expect an update?

[ndeloof]

@krzysieqq not sure. A v23.x release is on his way, we should be able to upgrade to align with it

[nitzel]

@krzysieqq not sure. A v23.x release is on his way, we should be able to upgrade to align with it

Does that mean the fix is live now? Milesteon 23.0 is closed 🥳

[jcandan]

Doesn't seem to be. I have Docker version 23.0.0 with docker-compose v2.15.1, and I am getting that same error:

error during connect: Post "http://docker.example.com/v1.42/images/create?fromImage=bitnami%2Fdrupal&tag=latest": command [ssh -l [MASKED] -- [MASKED] docker system dial-stdio] has exited with signal: killed, please make sure the URL is valid, and Docker 18.09 or later is installed on the remote host: stderr=

when i run docker-compose -H "ssh://$SERVER_USER@$SERVER_IP" pull from my Gitlab pipeline.

Note: just previous to this, i am running docker-compose -H "ssh://$SERVER_USER@$SERVER_IP" down --remove-orphans, but not getting the error then.

[jcandan]

On a whim, I simplified my docker-compose to just a simple single container, and it worked. So, is this SSH error a red-herring?

[pdaig]

Does that mean the fix is live now? Milesteon 23.0 is closed 🥳

@nitzel I don't think so... as I understand it, not yet but very soon.

I just tried it with the official v23.0 release and it's not fixed. The fix is live for docker/cli v23.0 but docker/compose v2.15.1 references an older version of docker/cli (v20.10.20). However, docker/compose v2.16 which was just released about 6 hours ago bumped that to v23. I guess depending on your installation method (Docker Desktop, OS package manager, image on Docker Hub) it might take more or less time for the new version to be distributed. I think Docker Hub is pretty fast to update but Docker Desktop might take a bit more time?

On a whim, I simplified my docker-compose to just a simple single container, and it worked. So, is this SSH error a red-herring?

@jcandan v2.15.1 still has the bug so this is normal. 2 or more containers cause the issue, but 1 container is fine.

[pdaig]

Update: docker:23 has been updated on Docker Hub with compose v2.16. I can happily confirm the issue is fixed! 🥳

Docker Desktop and packages for Ubuntu/Debian/other OS should follow as well, but I don't have the update schedule.

[Dkhusainov]

Client: Docker Engine - Community
 Version:           23.0.4
 API version:       1.42
 Go version:        go1.19.8
 Git commit:        f480fb1
 Built:             Fri Apr 14 10:32:04 2023
 OS/Arch:           linux/amd64
 Context:           default

Server: Docker Engine - Community
 Engine:
  Version:          23.0.4
  API version:      1.42 (minimum version 1.12)
  Go version:       go1.19.8
  Git commit:       cbce331
  Built:            Fri Apr 14 10:32:04 2023
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.6.20
  GitCommit:        2806fc1057397dbaeefbea0e4e17bddfbd388f38
 runc:
  Version:          1.1.5
  GitCommit:        v1.1.5-0-gf19387a
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0

I have this docker installed on my linux machine and still getting this error sporadically, maybe 70% of the time. The command I use:

docker context create my-context --docker "host=ssh://jenkins@1.1.1.1"
docker context use my-context
docker compose --parallel 1 pull

Does anyone know If lower docker version on remote context causes the issue maybe? it's 20.10.7