sftp falla: “client_loop: enviar desconexión: tubería rota”; El registro muestra: "cierre forzado"

sftp falla: “client_loop: enviar desconexión: tubería rota”; El registro muestra: "cierre forzado"

Las transferencias sftp fallan aproximadamente 1/5 veces y se informan client_loop: send disconnect: Broken pipeen mi caso. el registro sshd muestra: forced closeen lugar de closedy los archivos pueden ser más pequeños de lo esperado. en aproximadamente (nuevamente) 1/5 veces (en caso de que el sftp falle con el mensaje anterior), el archivo está bien, lo que probablemente significa que la conexión se interrumpió justo después de la transferencia del archivo.

servidor1: OpenSSH_8.0p1, OpenSSL 1.1.1c FIPS 28 de mayo de 2019 (CentOS 8.2.2004)
servidor2: OpenSSH_8.3p1, OpenSSL 1.1.1g FIPS 21 de abril de 2020 (Fedora 32)
cliente1: OpenSSH_8.3p1, OpenSSL 1.1.1g FIPS 21 Abril de 2020 (Fedora 32)
cliente2: OpenSSH_6.6.1p1, OpenSSL 1.0.1e-fips 11 de febrero de 2013 (RHEL/CentOS 7.2)

comando (algo como): (versión larga a continuación)f=file.pdf echo -e "-ls -l $f\nput $f\nls -l $f" | sftp -b- [email protected]:/upload

lo siguiente parece irrelevante (aunque se informa y a veces se da como "solución", en otros lugares):

  • opción ChrootDirectoryen el lado del servidor (sshd)
  • Persissiones del directorio de inicio en el lado del servidor.
  • opción -oIPQoS=throughputen el servidor y/o cliente
  • Tamaño de MTU en la interfaz de red del servidor (probé 1200 y 1500)
  • configuración de tráfico/QoS en el firewall/puerta de enlace en el lado del servidor
  • Configuración de TCP MSS a través de iptables/firewalld

PERO, en caso de AMBAS opciones

  • -B1500
  • -oCiphers=aes128-cbc

se utilizan, la tasa de error es mucho menor. a -B1000 OR -oCiphers=aes256-cbc OR -oCiphers=aes128-ctr aumenta el nivel de error.

mejores resultados que obtengo usando -oCiphers=aes128-cbc -oBatchMode=yes -oCompression=no -oIPQoS=throughput -oRequestTTY=no -B1500:

  • 4 errores en 1216 transmisiones (0,33% malas) de un archivo de 109kbytes
  • 10 errores en 2695 transmisiones (0,37% malas) de un archivo de 6,81 mbytes

Lo mismo (¿o similar?) sucede al intentar enviar sftp/scp sthg a un host vmware. "Tubería rota" se informa casi inmediatamente después del comando "poner". resulta que sólo la opción -B ayuda. en mi caso -B265 dio un resultado estable. -B266 funcionó una vez, luego siempre (no lo intenté con tanta frecuencia) "Tubería rota". De hecho, estaba transmitiendo una imagen del sistema operativo al almacén de datos local.

servidor: OpenSSH_7.9p1, OpenSSL 1.0.2r-fips 26 de febrero de 2019 (ESXi 6.7?)
Cliente: OpenSSH_7.4p1, OpenSSL 1.0.2k-fips 26 de enero de 2017 (Fedora 25)

tal vez alguien pueda descubrir qué está pasando aquí. Parece un problema con openssl, tal vez en combinación con openssh, no necesariamente relacionado con sftp en sí.

en realidad estoy usando

dd if=/dev/urandom of=x.rand bs=1021 count=6999
n=1; f=x.rand; while true; do
    echo "=== $n ==="
    date
    echo -e "-ls -l $f\nput $f\nls -l $f" \
         | sftp -b- -oPort=22 -B1500 -oCiphers=aes128-cbc -oBatchMode=yes -oCompression=no -oIPQoS=throughput -oRequestTTY=no [email protected]:/upload
    n=`expr $n + 1`
    sleep 0.1
done 2>&1 | tee output_x_rand.log

para probar esto.

sshd_config:

Match User user
    ForceCommand internal-sftp -m 640 -e -P remove,mkdir,rmdir,symlink,posix-rename,hardlink,readlink,setstat,fsetstat,lsetstat,statvfs,fstatvfs -l INFO
    PasswordAuthentication no
    GSSAPIAuthentication no
    HostbasedAuthentication no
    KbdInteractiveAuthentication no
    KerberosAuthentication no
    PubkeyAuthentication yes
    ChrootDirectory /var/transfer/incoming
    PermitTunnel no
    AllowAgentForwarding no
    AllowTcpForwarding no
    X11Forwarding no

esto es lo que pasa (strace) en elservidor, en caso de que se rompa la conexión:

    168224 read(5, 0x7fff0f71e350, 16384)   = -1 ECONNRESET (Connection reset by peer)
    168224 getpid()                         = 168224
    168224 getuid()                         = 1000
    168224 write(9, "\0\0\0{|", 5)          = 5
    168211 <... poll resumed>)              = 1 ([{fd=12, revents=POLLIN}])
    168224 write(9, "\0\0\0fSHA256:fc:5f:4c:91:1a:75:eb:"..., 122 <unfinished ...>
    168211 read(12,  <unfinished ...>
    168224 <... write resumed>)             = 122
    168211 <... read resumed>"\0\0\0{", 4)  = 4
    168224 getuid( <unfinished ...>
    168211 read(12,  <unfinished ...>
    168224 <... getuid resumed>)            = 1000
    168211 <... read resumed>"|\0\0\0fSHA256:fc:5f:4c:91:1a:75:eb"..., 123) = 123
    168224 getpid( <unfinished ...>
    168211 socket(AF_NETLINK, SOCK_RAW, NETLINK_AUDIT <unfinished ...>
    168224 <... getpid resumed>)            = 168224
    168211 <... socket resumed>)            = 9
    168224 write(9, "\0\0\0\25z", 5 <unfinished ...>
    168211 fcntl(9, F_SETFD, FD_CLOEXEC <unfinished ...>
    168224 <... write resumed>)             = 5
    168211 <... fcntl resumed>)             = 0
    168224 write(9, "\0\0\0\2\0\0\0\0\0\2\221 \0\0\0\0\0\0\3\350", 20 <unfinished ...>
    168211 ioctl(0, TCGETS <unfinished ...>
    168224 <... write resumed>)             = 20
    168211 <... ioctl resumed>, 0x7fff0f71fbe0) = -1 ENOTTY (Inappropriate ioctl for device)
    168224 read(9,  <unfinished ...>
    168211 ioctl(1, TCGETS, 0x7fff0f71fbe0) = -1 ENOTTY (Inappropriate ioctl for device)
    168211 ioctl(2, TCGETS, 0x7fff0f71fbe0) = -1 ENOTTY (Inappropriate ioctl for device)
    168211 sendto(9, {{len=244, type=0x964 /* NLMSG_??? */, flags=NLM_F_REQUEST|NLM_F_ACK, seq=15, pid=0}, "\x6f\x70\x3d\x64\x65\x73\x74\x72\x6f\x79\x20\x6b\x69\x6e\x64\x3d\x73\x65\x72\x76\x65\x72\x20\x66\x70\x3d\x53\x48\x41\x32\x35\x36"...}, 244, 0, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, 12) = 244
    168211 poll([{fd=9, events=POLLIN}], 1, 500) = 1 ([{fd=9, revents=POLLIN}])
    168211 recvfrom(9, {{len=36, type=NLMSG_ERROR, flags=NLM_F_CAPPED, seq=15, pid=168211}, {error=0, msg={len=244, type=0x964 /* AUDIT_??? */, flags=NLM_F_REQUEST|NLM_F_ACK, seq=15, pid=0}}}, 8988, MSG_PEEK|MSG_DONTWAIT, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, [12]) = 36
    168211 recvfrom(9, {{len=36, type=NLMSG_ERROR, flags=NLM_F_CAPPED, seq=15, pid=168211}, {error=0, msg={len=244, type=0x964 /* AUDIT_??? */, flags=NLM_F_REQUEST|NLM_F_ACK, seq=15, pid=0}}}, 8988, MSG_DONTWAIT, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, [12]) = 36
    168211 close(9)                         = 0
    168211 poll([{fd=12, events=POLLIN}], 1, -1) = 1 ([{fd=12, revents=POLLIN}])
    168211 read(12, "\0\0\0\25", 4)         = 4
    168211 read(12, "z\0\0\0\2\0\0\0\0\0\2\221 \0\0\0\0\0\0\3\350", 21) = 21
    168211 getsockname(5, {sa_family=AF_INET, sin_port=htons(22), sin_addr=inet_addr("172.17.17.2")}, [128->16]) = 0
    168211 socket(AF_NETLINK, SOCK_RAW, NETLINK_AUDIT) = 9
    168211 fcntl(9, F_SETFD, FD_CLOEXEC)    = 0
    168211 ioctl(0, TCGETS, 0x7fff0f71fbb0) = -1 ENOTTY (Inappropriate ioctl for device)
    168211 ioctl(1, TCGETS, 0x7fff0f71fbb0) = -1 ENOTTY (Inappropriate ioctl for device)
    168211 ioctl(2, TCGETS, 0x7fff0f71fbb0) = -1 ENOTTY (Inappropriate ioctl for device)
    168211 sendto(9, {{len=196, type=0x964 /* NLMSG_??? */, flags=NLM_F_REQUEST|NLM_F_ACK, seq=16, pid=0}, "\x6f\x70\x3d\x64\x65\x73\x74\x72\x6f\x79\x20\x6b\x69\x6e\x64\x3d\x73\x65\x73\x73\x69\x6f\x6e\x20\x66\x70\x3d\x3f\x20\x64\x69\x72"...}, 196, 0, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, 12) = 196
    168211 poll([{fd=9, events=POLLIN}], 1, 500) = 1 ([{fd=9, revents=POLLIN}])
    168211 recvfrom(9, {{len=36, type=NLMSG_ERROR, flags=NLM_F_CAPPED, seq=16, pid=168211}, {error=0, msg={len=196, type=0x964 /* AUDIT_??? */, flags=NLM_F_REQUEST|NLM_F_ACK, seq=16, pid=0}}}, 8988, MSG_PEEK|MSG_DONTWAIT, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, [12]) = 36
    168211 recvfrom(9, {{len=36, type=NLMSG_ERROR, flags=NLM_F_CAPPED, seq=16, pid=168211}, {error=0, msg={len=196, type=0x964 /* AUDIT_??? */, flags=NLM_F_REQUEST|NLM_F_ACK, seq=16, pid=0}}}, 8988, MSG_DONTWAIT, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, [12]) = 36
    168211 close(9)                         = 0
    168211 write(12, "\0\0\0\1{", 5 <unfinished ...>
    168224 <... read resumed>"\0\0\0\1", 4) = 4
    168211 <... write resumed>)             = 5
    168224 read(9,  <unfinished ...>
    168211 poll([{fd=12, events=POLLIN}], 1, -1 <unfinished ...>
    168224 <... read resumed>"{", 1)        = 1
    168224 exit_group(255)                  = ?
    168225 <... select resumed>)            = 1 (in [0])
    168224 +++ exited with 255 +++
    168225 read(0,  <unfinished ...>
    168211 <... poll resumed>)              = ? ERESTART_RESTARTBLOCK (Interrupted by signal)
    168225 <... read resumed>"", 16384)     = 0
    168211 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=168224, si_uid=1000, si_status=255, si_utime=0, si_stime=1} ---
    168225 write(2, "forced close \"/upload/xx.rand\" b"..., 60 <unfinished ...>
    168211 restart_syscall(<... resuming interrupted poll ...> <unfinished ...>
    168225 <... write resumed>)             = -1 EPIPE (Broken pipe)
    168225 --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=168225, si_uid=1000} ---
    168225 +++ killed by SIGPIPE +++

esto es lo que pasa (strace) en elcliente, en caso de que se rompa la conexión:

48403 select(7, [3 4], [3], NULL, {tv_sec=59, tv_usec=0}) = 1 (in [4], left {tv_sec=58, tv_usec=999997})
48403 read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 16384) = 16384
48403 mmap(NULL, 2019328, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f00c3731000
48403 munmap(0x7f00c391e000, 2002944)   = 0
48403 select(7, [3 4], [3], NULL, {tv_sec=59, tv_usec=0}) = 1 (in [4], left {tv_sec=58, tv_usec=999997})
48403 read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 16384) = 16384
48402 <... writev resumed>)             = 32797
48403 mmap(NULL, 2035712, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0 <unfinished ...>
48402 read(3,  <unfinished ...>
48403 <... mmap resumed>)               = 0x7f00c3afb000
48402 <... read resumed>"\0\0\0\30", 4) = 4
48402 read(3, "e\0\0\0\f\0\0\0\0\0\0\0\7Success\0\0\0\0", 24) = 24
48402 read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 32768) = 32768
48402 writev(3, [{iov_base="\0\0\200\31", iov_len=4}, {iov_base="\6\0\0\0M\0\0\0\4\0\0\0\0\0\0\0\0\0#\0\0\0\0\200\0\0\0\0\0\0\0\0"..., iov_len=32793}], 2) = 32797
48402 read(3,  <unfinished ...>
48403 munmap(0x7f00c3731000, 2019328)   = 0
48403 select(7, [3 4], [3], NULL, {tv_sec=59, tv_usec=0}) = 1 (in [4], left {tv_sec=58, tv_usec=999997})
48403 read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 16384) = 16384
48403 mmap(NULL, 2052096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f00c3906000
48403 munmap(0x7f00c3afb000, 2035712)   = 0
48403 select(7, [3 4], [3], NULL, {tv_sec=59, tv_usec=0}) = 1 (in [4], left {tv_sec=58, tv_usec=999997})
48403 read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 16384) = 16384
48403 mmap(NULL, 2068480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f00c370d000
48403 munmap(0x7f00c3906000, 2052096)   = 0
48403 select(7, [3 4], [3], NULL, {tv_sec=59, tv_usec=0}) = 1 (in [4], left {tv_sec=58, tv_usec=999997})
48403 read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 16384) = 16384
48403 mmap(NULL, 2084864, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f00c3aef000
48403 munmap(0x7f00c370d000, 2068480)   = 0
48403 select(7, [3 4], [3], NULL, {tv_sec=59, tv_usec=0}) = 1 (in [4], left {tv_sec=58, tv_usec=999997})
48403 read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 16384) = 16384
48403 mmap(NULL, 2101248, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f00c38ee000
48403 munmap(0x7f00c3aef000, 2084864)   = 0
48403 select(7, [3], [3], NULL, {tv_sec=59, tv_usec=0}) = 2 (in [3], out [3], left {tv_sec=58, tv_usec=981048})
48403 read(3, 0x7ffc9bb9c500, 8192)     = -1 ECONNRESET (Connection reset by peer)
48403 rt_sigaction(SIGWINCH, {sa_handler=SIG_DFL, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f00c3f83ab0}, {sa_handler=0x55ff7bcc73f0, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f00c3f83ab0}, 8) = 0
48403 getpid()                          = 48403
48403 write(3, "\364\3301X\302Y\34\361\310:\323\275\315!Hy\334;\312\201\231\273\217\17h\363)&\207bD7"..., 154924) = -1 EPIPE (Broken pipe)
48403 --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=48403, si_uid=1000} ---
48403 write(2, "client_loop: send disconnect: Br"..., 43) = 43
48403 exit_group(255)                   = ?
48402 <... read resumed>0x5611a3af2810, 4) = -1 ECONNRESET (Connection reset by peer)
48403 +++ exited with 255 +++
48402 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=48403, si_uid=1000, si_status=255, si_utime=15, si_stime=24} ---
48402 wait4(48403, NULL, WNOHANG, NULL) = 48403
48402 write(2, "\rConnection closed.  \n", 22) = 22
48402 rt_sigreturn({mask=[]})           = -1 ECONNRESET (Connection reset by peer)
48402 write(2, "Connection closed\r\n", 19) = 19
48402 exit_group(255)                   = ?
48402 +++ exited with 255 +++

Respuesta1

bueno. Lo he rastreado hasta la protección contra amenazas meraki, prevención de intrusiones.

En caso de que la regla IPS SSH_EVENT_RESPOVERFLOW esté en la lista blanca, el error desapareció.

sin embargo, creo que blanquear la regla IPS no es la solución adecuada. La regla IPS debería detectar mejor la intrusión para evitar falsos positivos.

información relacionada