Ningún detalle es anecdótico...: aws

Mostrando entradas con la etiqueta aws. Mostrar todas las entradas

domingo, 29 de noviembre de 2015

Asegura tu información en tránsito - VPN IPSec con OpenSwan

La idea de este post es mostrar una manera sencilla y económica de levantar un tunel IPSec con OpenSwan para conectar dos redes separadas geográficamente.

Podría tratarse de dos sucursales en una misma ciudad o en lugares diferentes del mundo. En este caso en particular se van a tratar de dos redes en dos regiones diferentes de AWS. Una en eu-west-1 (Dublin) y otra en us-east-1 (North Virginia). A continuación una imagen que posiblemente aclare un poco mas el entorno (estrenando pizarra jajaj):

Qué hace falta?

Dado que se va a tratar de un entorno virtual, los requerimientos son sencillos:

Dos redes privadas diferentes separadas geográficamente de tal forma que la hostil Internet sea el único medio viable para comunicarlas.

Dos endpoints uno en cada región:

En este caso dos instancias EC2 en VPCs con redes diferentes.
Cada endpoint debe contar con una EIP asociada.
Ubuntu 14.04 LTS con OpenSwan instalado en ambos endpoints (apt-get install -y openswan)

El tráfico a los puertos UDP 500 y 4500 debe estar permitido entre los endpoints. Estos puertos se utilizaran para establecer las Asociaciones de Seguridad y transportar los paquetes ESP cifrados (respectivamente).

Configuración del kernel

Dado que los endpoints oficiaran de routers en este caso, es necesario setear algunos parámetros extras en el kernel de los mismos. OpenSwan provee los mismos en el archivo /etc/ipsec.d/examples/sysctl.conf, por lo tanto podemos copiarlos a /etc/sysctl.d (para garantizarnos que se cargan luego en caso de reinicio) y ejecutarlos manualmente:

root@ip-172-31-16-163:/etc/ipsec.d# cp /etc/ipsec.d/examples/sysctl.conf /etc/sysctl.d/11-openswan.conf
root@ip-172-31-16-163:/etc/ipsec.d# sysctl -p /etc/sysctl.d/11-openswan.conf
net.ipv4.ip_forward = 1
net.ipv4.conf.default.rp_filter = 0
net.ipv4.conf.all.rp_filter = 0
net.ipv4.conf.all.send_redirects = 0
net.ipv4.conf.default.send_redirects = 0
net.ipv4.icmp_ignore_bogus_error_responses = 1
net.ipv4.conf.default.log_martians = 0
net.ipv4.conf.all.log_martians = 0
net.ipv4.conf.default.accept_source_route = 0
net.ipv4.conf.all.accept_redirects = 0
net.ipv4.conf.default.accept_redirects = 0
net.ipv4.neigh.default.gc_thresh1 = 1024
net.ipv4.neigh.default.gc_thresh2 = 2048
net.ipv4.neigh.default.gc_thresh3 = 4096
root@ip-172-31-16-163:/etc/ipsec.d#

Con el kernel ya listo procedemos a configurar OpenSwan

Configuración de OpenSwan:

Por defecto OpenSwan viene casi listo para arrancar y con el soporte para NAT-Traversal activado así que no nos tenemos que preocupar por esa parte. Para corroborar que la instalación fue exitosa podemos ver los puertos en estado LISTEN en el sistema:

ubuntu@ip-10-0-61-63:~$ sudo netstat -ntpul
sudo: unable to resolve host ip-10-0-61-63
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      1071/sshd
tcp6       0      0 :::22                   :::*                    LISTEN      1071/sshd
udp        0      0 0.0.0.0:11854           0.0.0.0:*                           589/dhclient
udp        0      0 0.0.0.0:68              0.0.0.0:*                           589/dhclient
udp        0      0 127.0.0.1:4500          0.0.0.0:*                           2372/pluto
udp        0      0 10.0.61.63:4500         0.0.0.0:*                           2372/pluto
udp        0      0 127.0.0.1:500           0.0.0.0:*                           2372/pluto
udp        0      0 10.0.61.63:500          0.0.0.0:*                           2372/pluto
udp6       0      0 ::1:500                 :::*                                2372/plutoudp6       0      0 :::1255                 :::*                                589/dhclient
ubuntu@ip-10-0-61-63:~$

en ambos endpoints deberíamos ver los puertos UDP 500 y 4500.

Como primer paso debemos editar el archivo /etc/ipsec.conf para indicarle donde pondremos las configuraciones extra de nuestros túneles, agregamos la siguiente linea al final:

include /etc/ipsec.d/*.conf

Ahora creamos el archivo /etc/ipsec.d/eu-west-1_us-east-1.conf con el siguiente contenido:

En el endpoint de eu-west-1:

conn tunnel
    authby=secret
    type=tunnel
    left=172.31.16.163
    leftsubnet=172.31.0.0/16
    right=52.23.178.X
    rightid=10.0.61.63
    rightsubnet=10.0.0.0/16

En el endpoint de us-east-1:

conn tunnel
    type=tunnel
    auto=start
    authby=secret
    left=54.77.119.X
    leftid=172.31.16.163
    leftsubnet=172.31.0.0/16
    right=10.0.61.63
    rightsubnet=10.0.0.0/16

Como pueden ver las configuraciones son similares, pero a la vez espejadas en algunos campos como los left/right y las subnets. El modo de la VPN sera Tunel, se iniciará automáticamente y se autenticará con pre-shared key (el método mas sencillo de autenticación).

El último paso consiste en definir la autenticación en el archivo /etc/ipsec.secrets de la siguiente manera:

En el endpoint de eu-west-1 agregar:

10.0.61.63 172.31.16.163: PSK "bjimQ0jc"

En el endpoint the us-east-1 agregar:

172.31.16.163 10.0.61.63: PSK "bjimQ0jc"

Ahora solo basta reiniciar el servicio ipsec en ambos endpoints:

root@ip-172-31-16-163:/home/ubuntu# service ipsec restart
ipsec_setup: Stopping Openswan IPsec...
ipsec_setup: Starting Openswan IPsec 2.6.38...
ipsec_setup: No KLIPS support found while requested, desperately falling back to netkey
ipsec_setup: NETKEY support found. Use protostack=netkey in /etc/ipsec.conf to avoid attempts to use KLIPS. Attempting to continue with NETKEY
root@ip-172-31-16-163:/home/ubuntu#

root@ip-10-0-61-63:/home/ubuntu# service ipsec restart
ipsec_setup: Stopping Openswan IPsec...
ipsec_setup: Starting Openswan IPsec 2.6.38...
ipsec_setup: No KLIPS support found while requested, desperately falling back to netkey
ipsec_setup: NETKEY support found. Use protostack=netkey in /etc/ipsec.conf to avoid attempts to use KLIPS. Attempting to continue with NETKEY
root@ip-10-0-61-63:/home/ubuntu#

Y si todo salio bien, deberíamos poder ver los túneles de la siguiente manera:

root@ip-172-31-16-163:/home/ubuntu# service ipsec status
IPsec running - pluto pid: 17635
pluto pid 17635
2 tunnels up
some eroutes exist
root@ip-172-31-16-163:/home/ubuntu#

root@ip-10-0-61-63:/home/ubuntu# service ipsec status
IPsec running - pluto pid: 11655
pluto pid 11655
2 tunnels up
some eroutes exist
root@ip-10-0-61-63:/home/ubuntu#

Para mas detalles puede ejecutar ipsec auto --status.

Probando el túnel

Dado que el túnel se encuentra listo, ahora probemos hacer ping desde un endpoint al otro pero mediante las IPs privadas:

root@ip-172-31-16-163:/etc/ipsec.d# ping -c 5 10.0.61.63
PING 10.0.61.63 (10.0.61.63) 56(84) bytes of data.
64 bytes from 10.0.61.63: icmp_seq=1 ttl=64 time=81.3 ms
64 bytes from 10.0.61.63: icmp_seq=2 ttl=64 time=81.3 ms
64 bytes from 10.0.61.63: icmp_seq=3 ttl=64 time=81.3 ms
64 bytes from 10.0.61.63: icmp_seq=4 ttl=64 time=81.3 ms
64 bytes from 10.0.61.63: icmp_seq=5 ttl=64 time=81.1 ms

--- 10.0.61.63 ping statistics ---
5 packets transmitted, 5 received, 0% packet loss, time 4005ms
rtt min/avg/max/mdev = 81.161/81.321/81.378/0.267 ms
root@ip-172-31-16-163:/etc/ipsec.d#

Vemos que todo funciona perfectamente, y con una latencia de unos 81ms, mas que razonable si consideramos que los endpoints están separadas por un buen pedazo de mundo. Con tcpdump en otra ventana capturé el tráfico que sale del endpoint en eu-west-1 con destino al otro endpoint :

root@ip-172-31-16-163:/home/ubuntu# tcpdump -n host 52.23.178.X
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), capture size 65535 bytes
22:52:38.065238 IP 172.31.16.163.4500 > 52.23.178.X.4500: UDP-encap: ESP(spi=0x71e9743c,seq=0x1), length 132
22:52:38.146578 IP 52.23.178.X.4500 > 172.31.16.163.4500: UDP-encap: ESP(spi=0x8261d38d,seq=0x1), length 132
22:52:39.066729 IP 172.31.16.163.4500 > 52.23.178.X.4500: UDP-encap: ESP(spi=0x71e9743c,seq=0x2), length 132
22:52:39.148078 IP 52.23.178.X.4500 > 172.31.16.163.4500: UDP-encap: ESP(spi=0x8261d38d,seq=0x2), length 132
22:52:40.068222 IP 172.31.16.163.4500 > 52.23.178.X.4500: UDP-encap: ESP(spi=0x71e9743c,seq=0x3), length 132
22:52:40.149553 IP 52.23.178.X.4500 > 172.31.16.163.4500: UDP-encap: ESP(spi=0x8261d38d,seq=0x3), length 132
22:52:41.069703 IP 172.31.16.163.4500 > 52.23.178.X.4500: UDP-encap: ESP(spi=0x71e9743c,seq=0x4), length 132
22:52:41.151020 IP 52.23.178.X.4500 > 172.31.16.163.4500: UDP-encap: ESP(spi=0x8261d38d,seq=0x4), length 132
22:52:42.071171 IP 172.31.16.163.4500 > 52.23.178.X.4500: UDP-encap: ESP(spi=0x71e9743c,seq=0x5), length 132
22:52:42.152306 IP 52.23.178.X.4500 > 172.31.16.163.4500: UDP-encap: ESP(spi=0x8261d38d,seq=0x5), length 132
^C
10 packets captured
10 packets received by filter
0 packets dropped by kernel
root@ip-172-31-16-163:/home/ubuntu#

Cada uno de estos paquetes UDP 4500 lleva los mensajes ICMP enviados anteriormente dentro de un paquete ESP Algo como (((((ICMP)IP)ESP)UDP)IP). Por eso vemos 5 mensajes que salen del endpoint y 5 que vuelven.

En este punto ya tenemos la conectividad resuelta de endpoint a endpoint perfectamente, ahora sólo nos queda por resolver la conectividad con las otras instancias en las redes en cuestión. Esto tiene dos aristas:

Deshabilitar el src/dst check en las instancias que ofician de endpoints
Configurar las tablas de ruteo en las VPCs para que el tráfico hacia las redes en cuestión sea enrutado por los endpoints.

Dado que el primer punto es trivial voy a mostrar los pasos del segundo unicamente xD.

Basicamente hay que identificar las tablas de ruteo en ambas regiones y modificarlas de la siguiente manera:

Tabla en eu-west-1, dirigimos todo el tráfico con destino a 10.0.0.0/16 hacia la instancia endpoint de la región:

Tabla en us-east-1, dirigimos todo el tráfico destinado a 172.31.0.0/16 hacia la instancia endpoint de la región:

y ahora hacemos ping entre las instancias internas libremente:

[ec2-user@ip-172-31-17-235 ~]$ ping -c 5 10.0.207.203
PING 10.0.207.203 (10.0.207.203) 56(84) bytes of data.
64 bytes from 10.0.207.203: icmp_seq=1 ttl=62 time=82.1 ms
64 bytes from 10.0.207.203: icmp_seq=2 ttl=62 time=82.0 ms
64 bytes from 10.0.207.203: icmp_seq=3 ttl=62 time=82.2 ms
64 bytes from 10.0.207.203: icmp_seq=4 ttl=62 time=82.1 ms
64 bytes from 10.0.207.203: icmp_seq=5 ttl=62 time=82.2 ms

--- 10.0.207.203 ping statistics ---
5 packets transmitted, 5 received, 0% packet loss, time 4087ms
rtt min/avg/max/mdev = 82.089/82.190/82.286/0.192 ms
[ec2-user@ip-172-31-17-235 ~]$

Reiniciar uno de los endpoints

Para corroborar que la configuración sea correcta y todo inicie normalmente mandé a reiniciar uno de los endpoints mientras hacía ping entre las instancias internas. Eh aquí van los resultados:

[ec2-user@ip-172-31-17-235 ~]$ ping 10.0.207.203
PING 10.0.207.203 (10.0.207.203) 56(84) bytes of data.
64 bytes from 10.0.207.203: icmp_seq=1 ttl=62 time=77.2 ms
64 bytes from 10.0.207.203: icmp_seq=2 ttl=62 time=77.1 ms
64 bytes from 10.0.207.203: icmp_seq=3 ttl=62 time=77.2 ms
64 bytes from 10.0.207.203: icmp_seq=4 ttl=62 time=77.6 ms
64 bytes from 10.0.207.203: icmp_seq=5 ttl=62 time=77.2 ms
64 bytes from 10.0.207.203: icmp_seq=6 ttl=62 time=77.1 ms
64 bytes from 10.0.207.203: icmp_seq=7 ttl=62 time=77.1 ms
64 bytes from 10.0.207.203: icmp_seq=8 ttl=62 time=77.3 ms
64 bytes from 10.0.207.203: icmp_seq=9 ttl=62 time=77.4 ms
64 bytes from 10.0.207.203: icmp_seq=10 ttl=62 time=77.5 ms
64 bytes from 10.0.207.203: icmp_seq=11 ttl=62 time=77.1 ms
64 bytes from 10.0.207.203: icmp_seq=13 ttl=62 time=77.1 ms
64 bytes from 10.0.207.203: icmp_seq=14 ttl=62 time=77.1 ms
64 bytes from 10.0.207.203: icmp_seq=15 ttl=62 time=77.2 ms

64 bytes from 10.0.207.203: icmp_seq=69 ttl=62 time=77.3 ms
64 bytes from 10.0.207.203: icmp_seq=70 ttl=62 time=77.2 ms
64 bytes from 10.0.207.203: icmp_seq=71 ttl=62 time=76.9 ms
64 bytes from 10.0.207.203: icmp_seq=72 ttl=62 time=77.6 ms
64 bytes from 10.0.207.203: icmp_seq=73 ttl=62 time=77.3 ms
64 bytes from 10.0.207.203: icmp_seq=74 ttl=62 time=77.0 ms
64 bytes from 10.0.207.203: icmp_seq=75 ttl=62 time=77.1 ms
64 bytes from 10.0.207.203: icmp_seq=76 ttl=62 time=76.9 ms
^C
--- 10.0.207.203 ping statistics ---
76 packets transmitted, 22 received, 71% packet loss, time 76043ms
rtt min/avg/max/mdev = 76.929/77.259/77.671/0.255 ms
[ec2-user@ip-172-31-17-235 ~]$

podemos ver que los paquetes entre el 15 y el 69 se perdieron por la caída del endpoint. Pero a su vez sin intervención alguna la conexión se reestableció exitosamente!!!

Overhead de la VPN

Nada es perfecto ni gratis en este mundo, y las VPNs no son la excepci'on. Por lo tanto, es esperable que el uso de la VPN venga con un costo asociado.

En pequeñas transferencias no para ser perceptible:

Ping entre los endpoints sin utilizar el tunel:

root@ip-172-31-16-163:/etc/ipsec.d# ping -c 5 52.23.178.X
PING 52.23.178.X (52.23.178.X) 56(84) bytes of data.
64 bytes from 52.23.178.X: icmp_seq=1 ttl=52 time=76.0 ms
64 bytes from 52.23.178.X: icmp_seq=2 ttl=52 time=76.3 ms
64 bytes from 52.23.178.X: icmp_seq=3 ttl=52 time=76.1 ms
64 bytes from 52.23.178.X: icmp_seq=4 ttl=52 time=76.1 ms
64 bytes from 52.23.178.X: icmp_seq=5 ttl=52 time=76.0 ms

--- 52.23.178.X ping statistics ---
5 packets transmitted, 5 received, 0% packet loss, time 4005ms
rtt min/avg/max/mdev = 76.021/76.164/76.349/0.206 ms
root@ip-172-31-16-163:/etc/ipsec.d#

Ping entre los endpoints utilizando el tunel:

root@ip-172-31-16-163:/etc/ipsec.d# ping -c 5 10.0.61.63
PING 10.0.61.63 (10.0.61.63) 56(84) bytes of data.
64 bytes from 10.0.61.63: icmp_seq=1 ttl=64 time=76.1 ms
64 bytes from 10.0.61.63: icmp_seq=2 ttl=64 time=76.1 ms
64 bytes from 10.0.61.63: icmp_seq=3 ttl=64 time=76.2 ms
64 bytes from 10.0.61.63: icmp_seq=4 ttl=64 time=76.0 ms
64 bytes from 10.0.61.63: icmp_seq=5 ttl=64 time=76.1 ms

--- 10.0.61.63 ping statistics ---
5 packets transmitted, 5 received, 0% packet loss, time 4005ms
rtt min/avg/max/mdev = 76.086/76.166/76.245/0.053 ms
root@ip-172-31-16-163:/etc/ipsec.d#

Con tráfico un poco mas denso la diferencia comienza a notarse, en este caso hay 6 segundos de diferencia en una transferencia de 500 MBytes:

root@ip-172-31-16-163:/home/ubuntu# time nc 10.0.61.63 80 < 500MB_file

real    0m44.957s
user    0m0.013s
sys     0m1.591s
root@ip-172-31-16-163:/home/ubuntu# time nc 52.23.178.X 80 < 500MB_file

real    0m38.693s
user    0m0.004s
sys     0m0.429s
root@ip-172-31-16-163:/home/ubuntu#

Conclusión

Hoy por hoy con soluciones Open Source como OpenSwan no hay motivo alguno para que no utilicemos VPNs para asegurar nuestra información en tránsito. Es cierto que en algunos escenarios las VPNs con SSL pueden ser mas sencillas de desplegar, pero IPSec tarde o temprano las va a reemplazar, así que gente... ponganse a probar OpenSwan!!!

sábado, 14 de noviembre de 2015

Snapshots automáticos y consistentes en AWS

Los snapshots pueden ser una forma muy tentadora de backups, dado que proveen una imagen de un volumen en un punto particular del tiempo. Pero como todo tipo de backup debemos asegurarnos que se hagan correctamente, de lo contrario el día que lo precisemos podríamos arrepentirnos de no haberlo hecho xD.

AWS permite crear snapshots de los volúmenes EBS que tengamos bajo nuestro control. Estos son algunos de los detalles al respecto:

Se almacenan en S3, por lo tanto la durabilidad y disponibilidad de los mismos es mas que razonable.
Son incrementales, por lo tanto son eficientes en espacio y tiempo.
Restaurar un snapshot es muy sencillo, simplemente hay que crear un nuevo volumen del snapshot.

Los mismos documentos de AWS sugieren que para obtener snapshots consistentes y evitar la corrupción de los datos se deben detener las operaciones de escritura sobre el volumen por el tiempo que demore la creación del snapshot. Una forma muy sencilla de hacer esto es deteniendo totalmente la instancia, por ejemplo, o al menos desmontando el volumen del cual se está tomando el snapshot.

En casos donde detener la instancia o desmontar los volúmenes no sea posible se puede optar por congelar el sistema de archivos durante la creación del snapshot haciendo uso de xfs_freeze.

xfs_freeze permite detener las operaciones de escrituras sobre un sistema de archivos (-f), y luego retomarlas (-u).

En este post se va a describir una prueba de concepto de como se puede lograr un snapshot consistente deteniendo las operaciones de escritura sobre el volumen.

Role IAM para las instancias

Para poder tomar los snapshots de manera automática y desde las mismas instancias debemos permitirles ciertas operaciones (API calls) como CreateSnapshot, DescribeInstances y DescribeSnapshots. Para lograr esta parte podemos valernos de un Role IAM y adjuntarle la siguiente Policy:

{
    "Version": "2012-10-17",
    "Statement": [
        {
            "Sid": "Stmt1447448059000",
            "Effect": "Allow",
            "Action": [
                "ec2:CreateSnapshot",
                "ec2:DescribeInstances",
                "ec2:DescribeSnapshots"
            ],
            "Resource": [
                "*"
            ]
        }
    ]
}

El rol nos permitirá darle a las instancias la capacidad de acceder a este subconjunto de la API sin tener que preocuparnos por mantener las credenciales.

Una vez creado el rol las instancias deben lanzarse utilizando dicho rol. Para comprobar que el rol se encuentra aplicado a la instancia correctamente podemos hacer lo siguiente:

[ec2-user@ip-172-31-20-132 ~]$ curl http://169.254.169.254/latest/meta-data/iam/security-credentials/
EC2-BackupRole
[ec2-user@ip-172-31-20-132 ~]$

Se puede ver que el role EC2-BackupRole se encuentra asociado a la instancia. Para comprobar la autorización podemos, por ejemplo, describir el volumen del que tomaremos el snapshot:

[ec2-user@ip-172-31-20-132 ~]$ aws ec2 describe-instances --instance-ids i-8161a338 --query 'Reservations[0].Instances[0].BlockDeviceMappings[?DeviceName==`/dev/sdb`]' --output json
[
    {
        "DeviceName": "/dev/sdb",
        "Ebs": {
            "Status": "attached",
            "DeleteOnTermination": false,
            "VolumeId": "vol-e3490220",
            "AttachTime": "2015-11-14T10:28:41.000Z"
        }
    }
]
[ec2-user@ip-172-31-20-132 ~]$

Script para la creación de los snapshots

Una vez solucionada la parte de la autorización con IAM, sólo queda escribir el script que cree los snapshots. Los siguientes puntos se tendrán en cuenta:

El script debe crear un snapshot del volumen /dev/sdb, o cualquiera sea el volumen en cuestión.
El snapshot debe ser consistente. Por lo tanto debe detener las operaciones de escritura.
Se debe poder definir un timeout que permita recuperar las operaciones de escritura en caso de que la creación del snapshot demore demasiado tiempo. Por supuesto, esto pone en riesgo la integridad del snapshot, pero garantiza que se conocerá el tiempo máximo que el servicio se encontrará degradado (sin posibilidades de escribir).

A continuación el script:

#!/bin/bash

VOLUME='/dev/sdb'
MOUNT='/mnt'
LOGS=/var/log/backups.log
DONE=0
TIMEOUT=300
TIMEDOUT=0
SLEEP=30
INSTANCEID=`curl http://169.254.169.254/latest/meta-data/instance-id 2>/dev/null`
REGION=`curl http://169.254.169.254/latest/dynamic/instance-identity/document 2>/dev/null | grep region | awk -F\" '{print $4}'`
VOLUMEID=`aws ec2 describe-instances --instance-ids $INSTANCEID --region $REGION --query "Reservations[0].Instances[0].BlockDeviceMappings[?DeviceName=='$VOLUME'].Ebs.{ID:VolumeId}" --output text`
DESCRIPTION="$INSTANCEID-$VOLUMEID-$(date +%F)"

echo "$(date) Iniciando backup de: $INSTANCEID $REGION $VOLUMEID"

#Detener los servicios que quieras detener aqui

###

sync
xfs_freeze -f $MOUNT
echo "$(date) Escrituras detenidas."
SNAPSHOTID=`aws ec2 create-snapshot --volume-id $VOLUMEID --region $REGION --description $DESCRIPTION --query '{ID:SnapshotId}' --output text`
OUT=$?
if [ $OUT -ne 0 ]; then
        echo "$(date) La creacion del snapshot fallo."
        xfs_freeze -u $MOUNT
        echo "$(date) Escrituras reestablecidas."
        exit
fi
while [ $DONE = "0" ]; do
        PROGRESS=`aws ec2 describe-snapshots --snapshot-id $SNAPSHOTID --region $REGION --query 'Snapshots[0].{Progress:Progress}' --output text`
        OUT=$?
        if [ $OUT -ne 0 ]; then
                echo "$(date) Snapshot $SNAPSHOTID aun no esta disponible."
                sleep $SLEEP
                TIMEOUT=`echo "$TIMEOUT-$SLEEP" | bc`
        else
                if [ $PROGRESS = "100%" ]; then
                        DONE="1"
                        echo "$(date) Snapshot $SNAPSHOTID listo"
    else
                        echo "$(date) Snapshot $SNAPSHOTID $PROGRESS"
                        sleep $SLEEP
                        TIMEOUT=`echo "$TIMEOUT-$SLEEP" | bc`
                fi
        fi
        if [ $TIMEOUT -le 0 ]; then
                DONE="1"
                TIMEDOUT="1"
        fi
done
xfs_freeze -u $MOUNT
echo "$(date) Escrituras reestablecidas."
if [ $TIMEDOUT = "1" ]; then
        echo "$(date) Snapshot $SNAPSHOTID timed out!!! Podria ser inconsistente"
else
        echo "$(date) Snapshot $SNAPSHOTID terminado exitosamente"
fi

Prueba 1: Primer snapshot

Dada la naturaleza incremental de los snapshots, mientras mas bloques "Sucios" haya por copiar mas va a demorar el snapshot. Esto se hace mas evidente generalmente en el primer snapshot que se tome de un volumen.

Lanzamos una escritura aleatoria en background de unos 12GB de la siguiente manera

[ec2-user@ip-172-31-20-132 ~]$ sudo dd if=/dev/urandom of=/mnt/archivo_borrar bs=1M count=12000 &
[2] 4783
[ec2-user@ip-172-31-20-132 ~]$

cuando llevan escritos unos 8GB

[ec2-user@ip-172-31-20-132 ~]$ df -h
Filesystem      Size Used Avail Use% Mounted on
/dev/xvda1      7.8G 1.1G 6.6G 15% /
devtmpfs        3.9G   60K 3.9G   1% /dev
tmpfs           3.9G     0 3.9G   0% /dev/shm
/dev/xvdb        99G 8.4G   85G   9% /mnt
[ec2-user@ip-172-31-20-132 ~]$

lanzamos el snapshot

[ec2-user@ip-172-31-20-132 ~]$ sudo ./backups.sh
Sat Nov 14 17:13:24 UTC 2015 Iniciando backup de: i-8161a338 eu-west-1 vol-e3490220
Sat Nov 14 17:13:26 UTC 2015 Escrituras detenidas.
Sat Nov 14 17:13:26 UTC 2015 Snapshot snap-27582071 0%
Sat Nov 14 17:13:57 UTC 2015 Snapshot snap-27582071 0%
Sat Nov 14 17:14:27 UTC 2015 Snapshot snap-27582071 0%
Sat Nov 14 17:14:58 UTC 2015 Snapshot snap-27582071 0%
Sat Nov 14 17:15:28 UTC 2015 Snapshot snap-27582071 0%
Sat Nov 14 17:15:58 UTC 2015 Snapshot snap-27582071 0%
Sat Nov 14 17:16:29 UTC 2015 Snapshot snap-27582071 0%
Sat Nov 14 17:16:59 UTC 2015 Snapshot snap-27582071 0%
Sat Nov 14 17:17:30 UTC 2015 Snapshot snap-27582071 0%
Sat Nov 14 17:18:00 UTC 2015 Snapshot snap-27582071 0%
Sat Nov 14 17:18:30 UTC 2015 Escrituras reestablecidas.
Sat Nov 14 17:18:30 UTC 2015 Snapshot snap-27582071 timed out!!! Podria ser inconsistente
[ec2-user@ip-172-31-20-132 ~]$

este primer snapshot no pudo terminar en el lapso de los 300 segundos, por lo tanto podría tratarse de un snapshot inconsistente.

Poco antes de lanzar la creación del snapshot, en una segunda consola puse a correr iostat para ver el comportamiento de las operaciones de escritura, aquí están los resultados:

[ec2-user@ip-172-31-20-132 ~]$ sudo iostat -x -d /dev/xvdb 5 30
Linux 4.1.10-17.31.amzn1.x86_64 (ip-172-31-20-132)      11/14/2015      _x86_64_        (2 CPU)

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00    10.24    0.12   78.65     1.00 20046.09   254.48     9.79 124.28   0.92   7.27

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     1.60    0.00 637.40     0.00 163038.40   255.79    84.64 132.79   0.95 60.24

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     0.20    0.00    0.40     0.00     4.80    12.00     0.00    0.00   0.00   0.00

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     0.20    0.00   54.80     0.00 13931.20   254.22     4.92   55.08   0.64   3.52

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     2.40    0.00 171.60     0.00 43056.00   250.91    21.20 134.67   0.95 16.32
Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

...

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     0.00    0.00    0.20     0.00     1.60     8.00     0.00    0.00   0.00   0.00

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     0.80    0.00 101.40     0.00 25816.00   254.60     7.65   75.46   0.78   7.92

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     0.80    0.00    0.40     0.00     9.60    24.00     0.00    0.00   0.00   0.00

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await svctm %util
xvdb              0.00     0.20    0.00    0.40     0.00     4.80    12.00     0.00    0.00   0.00   0.00

^C[ec2-user@ip-172-31-20-132 ~]$

se puede ver la linea en negrita (azul), como a partir de ese punto no hay mas operaciones de escritura sobre el disco. Los altos valores de escrituras en ese momento se deben a las operaciones sync y xfs_freeze. Las operaciones de escritura se re establecen mas adelante (también en negrita, roja) cuando el timeout se cumple en el script.

Prueba 2: Segundo snapshot

El segundo snapshot termina antes del timeout, por lo que se lo puede considerar aboslutamente consistente.

[ec2-user@ip-172-31-20-132 ~]$ sudo ./backups.sh
Sat Nov 14 18:14:26 UTC 2015 Iniciando backup de: i-8161a338 eu-west-1 vol-e3490220
Sat Nov 14 18:14:26 UTC 2015 Escrituras detenidas.
Sat Nov 14 18:14:27 UTC 2015 Snapshot snap-39405312 0%
Sat Nov 14 18:14:57 UTC 2015 Snapshot snap-39405312 0%
Sat Nov 14 18:15:27 UTC 2015 Snapshot snap-39405312 0%
Sat Nov 14 18:15:58 UTC 2015 Snapshot snap-39405312 0%
Sat Nov 14 18:16:28 UTC 2015 Snapshot snap-39405312 0%
Sat Nov 14 18:16:59 UTC 2015 Snapshot snap-39405312 0%
Sat Nov 14 18:17:29 UTC 2015 Snapshot snap-39405312 listo
Sat Nov 14 18:17:29 UTC 2015 Escrituras reestablecidas.
Sat Nov 14 18:17:29 UTC 2015 Snapshot snap-39405312 terminado exitosamente
[ec2-user@ip-172-31-20-132 ~]$

Resumen

Esto es una simple prueba de concepto y no fue realmente probado en ambientes de producción. Desde mis pruebas puedo decir que dd (el proceso bloqueado por xfs_freeze) no sufrió mas que el bloqueo que era de esperarse, posiblemente esto no sea tan factible en una partición donde trabaja una BD que realiza muchos inserts por ejemplo. El script podría lanzarse sencillamente desde un cronjob y tendriamos todo automatizado y aceitado!!!

domingo, 4 de octubre de 2015

Cómo convertir de MBR a GPT nuestro disco y no morir en el intento!

Este post es un poco la continuación de ¿MBR o GPT? deep dive pero ahora voy a mostrar de qué manera se puede convertir un volumen root de MBR a GPT sin morir en el intento. Para hacer esto voy a utilizar dos instancias EC2 corriendo Ubuntu 14.04 LTS.

Siendo sincero, la verdad es que este no es un escenario que se le vaya a presentar a muchas personas, pero me pareció interesante explorarlo.

Entonces tenemos dos instancias idénticas:

Corriendo en la misma AZ (para poder intercambiar los discos)
Una instancia la llamaré auxiliar, que es donde se hará el trabajo sucio.
La otra instancia se llama oveja_negra y es la que recibirá el cambio de sistema de particionado.

Estado inicial de oveja_negra

Como primera medida voy a ver cuál es el estado general del volumen y cómo está compuesto.

ubuntu@oveja-negra:~$ sudo parted /dev/xvda
GNU Parted 2.3
Using /dev/xvda
Welcome to GNU Parted! Type 'help' to view a list of commands.
(parted) unit s
(parted) print
Model: Xen Virtual Block Device (xvd)
Disk /dev/xvda: 16777216s
Sector size (logical/physical): 512B/512B
Partition Table: msdos

Number Start   End        Size       Type     File system Flags
1      16065s 16771859s 16755795s primary ext4         boot

(parted) quit
ubuntu@oveja-negra:~$

Vemos que se trata de un disco de 8GB, con tabla de partición msdos y con una sola partición primaria booteable que comienza en el sector 16065 y termina en el sector 16771859. Aquí me voy a detener para hace foco en dos cosas:

La partición comienza en el sector 16065!!! Es decir que los sectores entre el LBA1 y LBA16064 están disponibles (poco menos de 8 Mbytes).
La partición termina en el sector 16771859, mientras que el disco tiene 16777216 sectores... Osea que entre el final de la partición y el del disco hay unos 5357 sectores disponibles (unos 2.5Mbytes).

Si se acuerdan, GPT utliza bastante mas espacio que el sistema convencional de particiones, por lo tanto es importante saber que se cuenta con ese espacio disponible. Habiendo confirmado que todo está en orden para continuar, lancé shutdown a la instancia para comenzar.

NOTA: este es el momento donde deberías tomar un snapshot del disco raiz en caso de que algo salga mal!!!

Que comience la cirugía

Una vez que la instancia se encuentre detenida, es necesario desconectar el disco y conectar a la instancia auxiliar. Con el disco conectado a la instancia auxiliar vemos que fue agregado como /dev/xvdf:

ubuntu@auxiliar:~$ sudo lsblk
NAME    MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
xvda    202:0    0   8G 0 disk
`-xvda1 202:1    0   8G 0 part /
xvdf    202:80   0   8G 0 disk
`-xvdf1 202:81   0   8G 0 part
ubuntu@auxiliar:~$

Damos una última mirada a la tabla de particiones de nuevo

ubuntu@auxiliar:~$ sudo parted /dev/xvdf
GNU Parted 2.3
Using /dev/xvdf
Welcome to GNU Parted! Type 'help' to view a list of commands.
(parted)unit s
(parted)print
Model: Xen Virtual Block Device (xvd)
Disk /dev/xvdf: 16777216s
Sector size (logical/physical): 512B/512B
Partition Table: msdos

Number Start   End        Size       Type     File system Flags
1      16065s 16771859s 16755795s primary ext4         boot

(parted)

Ahora en un acto de casi locura procedemos a eliminar la tabla de particiones

(parted)mklabel
New disk label type? gpt
Warning: Partition(s) on /dev/xvdf are being used.
Ignore/Cancel? Ignore
Warning: The existing disk label on /dev/xvdf will be destroyed and all data on
this disk will be lost. Do you want to continue?
Yes/No? Yes
(parted) print
Model: Xen Virtual Block Device (xvd)
Disk /dev/xvdf: 16777216s
Sector size (logical/physical): 512B/512B
Partition Table: gpt

Number Start End Size File system Name Flags

(parted)

Este es el momento donde nuestra información se encuentra en lo que yo llamaría el limbo informático. hemos perdido toda referencia e información de la misma, ya que hemos reemplazada la tabla de particiones msdos por una gpt. De hecho si cerramos parted podemos corroborar que ya no existe /dev/xvdf1:

ubuntu@auxiliar:~$ sudo lsblk
NAME    MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
xvda    202:0    0   8G 0 disk
`-xvda1 202:1    0   8G 0 part /
xvdf    202:80   0   8G 0 disk
ubuntu@auxiliar:~$

Lo bueno de todo esto es que nada está perdido! Ahora hay que reconstruir la tabla de particiones con la información que teníamos previamente:

ubuntu@auxiliar:~$ sudo parted /dev/xvdf
GNU Parted 2.3
Using /dev/xvdf
Welcome to GNU Parted! Type 'help' to view a list of commands.
(parted)unit s
(parted)mkpart
Partition name? []?
File system type? [ext2]? ext4
Start? 16065
End? 16771859
Warning: The resulting partition is not properly aligned for best performance.
Ignore/Cancel? Ignore
(parted) print
Model: Xen Virtual Block Device (xvd)
Disk /dev/xvdf: 16777216s
Sector size (logical/physical): 512B/512B
Partition Table: gpt

Number Start   End        Size       File system Name Flags
1      16065s 16771859s 16755795s ext4

(parted)

Sencillamente creamos una entra en la tabla de particiones GPT que indique donde se encontraba nuestra partición previamente. Ahora ya deberíamos ser capaces de ver la partición y montarla perfectamente de nuevo:

ubuntu@auxiliar:~$ sudo lsblk
NAME    MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
xvda    202:0    0   8G 0 disk
`-xvda1 202:1    0   8G 0 part /
xvdf    202:80   0   8G 0 disk
`-xvdf1 202:81   0   8G 0 part
ubuntu@auxiliar:~$ sudo fsck.ext4 -f /dev/xvdf1
e2fsck 1.42.9 (4-Feb-2014)
Pass 1: Checking inodes, blocks, and sizes
Pass 2: Checking directory structure
Pass 3: Checking directory connectivity
Pass 4: Checking reference counts
Pass 5: Checking group summary information
cloudimg-rootfs: 58327/524288 files (0.2% non-contiguous), 265348/2094474 blocks
ubuntu@auxiliar:~$ sudo mount /dev/xvdf1 /mnt/
ubuntu@auxiliar:~$ ls /mnt/
bin   dev home        lib    lost+found mnt proc run   srv tmp var
boot etc initrd.img lib64 media       opt root sbin sys usr vmlinuz
ubuntu@auxiliar:~$

En este punto ya está casi todo terminado, de hecho si no se tratara del volumen principal del sistema podríamos terminar acá. Pero si volviésemos a poner el volumen en la instancia oveja-negra notaríamos que la instancia no arranca y jamás lo volverá a hacer en esas condiciones. ¿Por qué? Básicamente porque hemos jugado con la tabla de particiones y los sectores de arranque del sistema. Para arreglar esto re-instalamos GRUB para que repare cualquier situación extraña (/dev/xvdf1 está montado en /mnt)

ubuntu@auxiliar:~$ sudo grub-install --boot-directory=/mnt/boot /dev/xvdf
Installing for i386-pc platform.
grub-install: warning: this GPT partition label contains no BIOS Boot Partition; embedding won't be possible.
grub-install: warning: Embedding is not possible. GRUB can only be installed in this setup by using blocklists. However, blocklists are UNRELIABLE and their use is discouraged..
grub-install: error: will not proceed with blocklists.
ubuntu@auxiliar:~$

WTF!!! Si, si bien GRUB 2 permite bootear de particiones GPT, en sistemas BIOS requiere de algo llamado BIOS Boot Partition donde aloja la segunda etapa de su código (NO necesario en sistemas UEFI). Esto se debe a que al utilizar GPT los bloques que se encuentran a continuación del sector LBA0 (MBR) están ocupados por el encabezado GPT y el arreglo de particiones. Teniendo esta partición GRUB 2 se asegura de tener espacio suficiente donde poner el código necesario, la partición no requiere mucho espacio unos 2MB son mas que suficiente.

Creando la partición "BIOS boot partition"

Crearemos una partición de aproximadamente 2MB entre los sectores 2048 y 6144, esto nos debería garantizar que no estamos sobre escribiendo nada que no debamos:

(parted)mkpart
Partition name? []?
File system type? [ext2]?
Start?2048
End?6144
(parted)print
Model: Xen Virtual Block Device (xvd)
Disk /dev/xvdf: 16777216s
Sector size (logical/physical): 512B/512B
Partition Table: gpt

Number Start   End        Size       File system Name Flags
2      2048s   6144s      4097s
1      16065s 16771859s 16755795s ext4               boot

(parted)

un detalle mas es que debemos marcar la partición con el flag bios_grub para que GRUB sepa que es allí donde debe buscar el código:

(parted) set 2 bios_grub on
(parted)print
Model: Xen Virtual Block Device (xvd)
Disk /dev/xvdf: 16777216s
Sector size (logical/physical): 512B/512B
Partition Table: gpt

Number Start   End        Size       File system Name Flags
2      2048s   6144s      4097s                        bios_grub
1      16065s 16771859s 16755795s ext4               boot

(parted)

Ahora deberíamos poder instalar grub perfectamente:

ubuntu@auxiliar:~$ sudo mount /dev/xvdf1 /mnt/
ubuntu@auxiliar:~$ sudo grub-install --boot-directory=/mnt/boot /dev/xvdf
Installing for i386-pc platform.
Installation finished. No error reported.ubuntu@auxiliar:~$ sudo umount /mnt
ubuntu@auxiliar:~$ lsblk
NAME    MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
xvda    202:0    0   8G 0 disk
`-xvda1 202:1    0   8G 0 part /
xvdf    202:80   0   8G 0 disk
|-xvdf1 202:81   0   8G 0 part
`-xvdf2 202:82   0   2M 0 part
ubuntu@auxiliar:~$

Podemos ver que si intentamos montar la partición resulta complicado:

ubuntu@auxiliar:~$ sudo mount /dev/xvdf2 /mnt/
mount: block device /dev/xvdf2 is write-protected, mounting read-only
mount: you must specify the filesystem typeubuntu@auxiliar:~$

Si bien no tengo certezas es bastante probable que esta partición no tenga ningún formato conocido sino que sea solamente una reserva de espacio donde hay código binario ejecutable correspondiente a la etapa 2 de GRUB.

Ahora llegó el momento de la verdad, volvemos el disco a oveja-negra y le damos start a la instancia:

ubuntu@oveja-negra:~$ sudo parted /dev/xvda
GNU Parted 2.3
Using /dev/xvda
Welcome to GNU Parted! Type 'help' to view a list of commands.
(parted) print
Model: Xen Virtual Block Device (xvd)
Disk /dev/xvda: 8590MB
Sector size (logical/physical): 512B/512B
Partition Table: gpt

Number Start   End     Size    File system Name Flags
2      1049kB 3146kB 2098kB                   bios_grub
1      8225kB 8587MB 8579MB ext4               boot

(parted)   quit
ubuntu@oveja-negra:~$

Sin un raspón, sana, salva y con GPT!!!

miércoles, 29 de julio de 2015

Una instancia a la deriva III: El porque de las cosas

Después de un fin de semana de paseo hoy toca encarar la tercera parte de la saga "Una instancia a la deriva" e intentar descubrir qué pasó a partir de las 2:32 del 23 de Julio y por qué se apagó la instancia 2 horas después.

Para tener un poco mas de contexto si todavía no los leíste, deberías pasar por los posts Una instancia a la deriva I y Una instancia a la deriva II. Acá va un resumen:

A las 3:33 (02:33 UTC) de la mañana del 23 de Julio recibí 2 emails que indicaban autenticaciones exitosas en la instancia.
A partir de ese momento, en los gráficos de consumo de recursos provistos por AWS, se puede ver claramente que el comportamiento de la instancia cambió drásticamente. Consumo de CPU, red y acceso a disco se incrementaron.
A partir del análisis de algunas de las capturas de tcpdump se puede ver un número importante de conexiones SSH iniciadas por la instancia contra direcciones IP de terceros. Esto daría a entender que la instancia fue infectada y ahora se encontraba atacando otras direcciones para propagar el problema.
Cerca de las 04:40 (UTC) la instancia inicio la secuencia de shutdown. A este punto no está claro qué lo desencadenó si audtitd por espacio insuficiente o el cronjob que controlaba la ejecución de tcpdump.

Analizando el disco y los archivos de la instancia

Dado que la instancia se encuentra apagada le quité el volumen raíz, y lo asocié a otra instancia recién lanzada. A continuación se puede ver el disco /dev/xvdf de 10GB

root@ip-172-31-56-203:/home/ubuntu# lsblk
NAME    MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
xvda    202:0    0   8G 0 disk
`-xvda1 202:1    0   8G 0 part /
xvdf    202:80   0 10G 0 disk
`-xvdf1 202:81   0 10G 0 part
root@ip-172-31-56-203:/home/ubuntu#

Monté el disco en modo solo lectura para evitar modificar o eliminar archivos por error.

root@ip-172-31-56-203:/home/ubuntu# mount -o ro /dev/xvdf1 /mnt/
root@ip-172-31-56-203:/home/ubuntu# mount
/dev/xvda1 on / type ext4 (rw,discard)
...
/dev/xvdf1 on /mnt type ext4 (ro)
root@ip-172-31-56-203:/home/ubuntu#

y lo primero que observé es el espacio de almacenamiento disponible...

root@ip-172-31-56-203:/home/ubuntu# df -h
Filesystem      Size Used Avail Use% Mounted on
/dev/xvda1      7.8G 782M 6.6G 11% /
none            4.0K     0 4.0K   0% /sys/fs/cgroup
udev            492M   12K 492M   1% /dev
tmpfs           100M 336K   99M   1% /run
none            5.0M     0 5.0M   0% /run/lock
none            497M     0 497M   0% /run/shm
none            100M     0 100M   0% /run/user
/dev/xvdf1      9.8G 9.2G   62M 100% /mnt
root@ip-172-31-56-203:/home/ubuntu#

exacto! 100% utilizado (a penas 62 MB libres) esto parecería tirar por el suelo mi idea de que habían detenido el proceso tcpdump y refuerza a su vez la teoría de auditd deteniendo la instancia por imposibilidad de escribir logs.

No hay archivos creados en el directorio home del usuario comprometido, esto me llamó un poco la atención, esperaba al menos encontrar algo ahí

root@ip-172-31-56-203:~/restored# ls -lah /mnt/home/ubuntu/
total 32K
drwxr-xr-x 4 ubuntu ubuntu 4.0K Jul 19 20:49 .
drwxr-xr-x 3 root   root   4.0K Jul 6 20:42 ..
-rw------- 1 ubuntu ubuntu    9 Jul 19 20:49 .bash_history
-rw-r--r-- 1 ubuntu ubuntu 220 Apr 9 2014 .bash_logout
-rw-r--r-- 1 ubuntu ubuntu 3.6K Apr 9 2014 .bashrc
drwx------ 2 ubuntu ubuntu 4.0K Jul 6 20:43 .cache
-rw-rw-r-- 1 ubuntu ubuntu    0 Jul 6 20:43 .cloud-locale-test.skip
-rw-r--r-- 1 ubuntu ubuntu 675 Apr 9 2014 .profile
drwx------ 2 ubuntu ubuntu 4.0K Jul 21 07:19 .ssh
root@ip-172-31-56-203:~/restored#
En el directorio home de root, donde se guardaban las capturas, podemos ver que las mismas ocuparon del orden de 5GB

root@ip-172-31-56-203:~/restored# du -sch /mnt/root/
5.0G    /mnt/root/
5.0G    total
root@ip-172-31-56-203:~/restored#

y que tenemos 1062 capturas

root@ip-172-31-56-203:~/restored# ls /mnt/root/sample*|wc -l
1062
root@ip-172-31-56-203:~/restored#

para bien o para mal, parece no faltar ninguna.

En cuanto a los archivos de logs parecen estar intactos y en su lugar. Lo mas llamativo es la cantidad de logs generados por auditd:

root@ip-172-31-56-203:~/restored# ls /mnt/var/log/audit/
audit.log     audit.log.16 audit.log.23 audit.log.30 audit.log.38 audit.log.45 audit.log.52 audit.log.6   audit.log.67 audit.log.74
audit.log.1   audit.log.17 audit.log.24 audit.log.31 audit.log.39 audit.log.46 audit.log.53 audit.log.60 audit.log.68 audit.log.75
audit.log.10 audit.log.18 audit.log.25 audit.log.32 audit.log.4   audit.log.47 audit.log.54 audit.log.61 audit.log.69 audit.log.76
audit.log.11 audit.log.19 audit.log.26 audit.log.33 audit.log.40 audit.log.48 audit.log.55 audit.log.62 audit.log.7   audit.log.77
audit.log.12 audit.log.2   audit.log.27 audit.log.34 audit.log.41 audit.log.49 audit.log.56 audit.log.63 audit.log.70 audit.log.78
audit.log.13 audit.log.20 audit.log.28 audit.log.35 audit.log.42 audit.log.5   audit.log.57 audit.log.64 audit.log.71 audit.log.79
audit.log.14 audit.log.21 audit.log.29 audit.log.36 audit.log.43 audit.log.50 audit.log.58 audit.log.65 audit.log.72 audit.log.8
audit.log.15 audit.log.22 audit.log.3   audit.log.37 audit.log.44 audit.log.51 audit.log.59 audit.log.66 audit.log.73 audit.log.9
root@ip-172-31-56-203:~/restored#

esto es un gran problema. El número de rotaciones de logs de audit es de 80, lo que significa que es MUY probable que los primeros logs hayan sido desechados... Una miradita rápida al log mas viejo nos confirma esto

root@ip-172-31-56-203:~/restored# aureport -t -if /mnt/var/log/audit/audit.log.79

Log Time Range Report
=====================
/mnt/var/log/audit/audit.log.79: 07/23/15 03:15:20.105 - 07/23/15 03:17:17.037
root@ip-172-31-56-203:~/restored#

El log mas viejo contempla los registros entre las 03:15 y las 03:17 del 23 de Julio. Lo cuál significa que NO vamos a tener información de los primero minutos posteriores a las 02:33 ya que por el número de eventos y la cantidad de rotaciones esos logs fueron perdidos.

Analizando un poco los logs:

El primer paso fue incluir los últimos logs de autenticaciones (/var/log/auth.log) en la BD para poder contabilizarlos de manera mas sencilla. De este paso obtuve la siguiente información:

54.196.232.229 realizó 38 intentos fallidos de autenticación entre las 02:32:08 y las 02:33:28.
59.188.237.12 no realizó intentos fallidos.

Viendo mas de cerca los logs podemos ver que:

Jul 23 02:33:28 ip-172-31-54-250 sshd[32683]: Accepted password for ubuntu from 54.196.232.229 port 37470 ssh2
Jul 23 02:33:28 ip-172-31-54-250 sshd[32683]: pam_unix(sshd:session): session opened for user ubuntu by (uid=0)
Jul 23 02:33:29 ip-172-31-54-250 sshd[32683]: pam_unix(sshd:session): session closed for user ubuntu
Jul 23 02:33:30 ip-172-31-54-250 sshd[316]: error: Could not load host key: /etc/ssh/ssh_host_ed25519_key
Jul 23 02:33:32 ip-172-31-54-250 sshd[316]: Accepted password for ubuntu from 59.188.237.12 port 2693 ssh2
Jul 23 02:33:32 ip-172-31-54-250 sshd[316]: pam_unix(sshd:session): session opened for user ubuntu by (uid=0)
Jul 23 02:33:33 ip-172-31-54-250 sshd[370]: Received disconnect from 59.188.237.12: 11: Shutdown.
Jul 23 02:33:33 ip-172-31-54-250 sshd[316]: pam_unix(sshd:session): session closed for user ubuntu
Jul 23 02:33:35 ip-172-31-54-250 sshd[380]: error: Could not load host key: /etc/ssh/ssh_host_ed25519_key
Jul 23 02:33:35 ip-172-31-54-250 sshd[381]: error: Could not load host key: /etc/ssh/ssh_host_ed25519_key
Jul 23 02:33:37 ip-172-31-54-250 sshd[380]: Accepted password for ubuntu from 59.188.237.12 port 2697 ssh2
Jul 23 02:33:37 ip-172-31-54-250 sshd[380]: pam_unix(sshd:session): session opened for user ubuntu by (uid=0)
Jul 23 02:33:37 ip-172-31-54-250 sshd[381]: Accepted password for ubuntu from 59.188.237.12 port 2696 ssh2
Jul 23 02:33:37 ip-172-31-54-250 sshd[381]: pam_unix(sshd:session): session opened for user ubuntu by (uid=0)
Jul 23 02:33:41 ip-172-31-54-250 chpasswd[504]: pam_unix(chpasswd:chauthtok): user "butter" does not exist in /etc/passwd
Jul 23 02:33:41 ip-172-31-54-250 sshd[489]: Received disconnect from 59.188.237.12: 11: Shutdown.
Jul 23 02:33:41 ip-172-31-54-250 sshd[381]: pam_unix(sshd:session): session closed for user ubuntu
Jul 23 02:34:44 ip-172-31-54-250 sshd[488]: Received disconnect from 59.188.237.12: 11: Shutdown.
Jul 23 02:34:44 ip-172-31-54-250 sshd[380]: pam_unix(sshd:session): session closed for user ubuntu

A las 02:33:28 el host 54.196.232.229 dio con el password correcto para el usuario ubuntu.
4 segundos después a las 02:33:32 el host 59.188.237.12 inicia una sesión con el usuario y password correcto. Posiblemente para corroborar que sean válidos, dado que la sesión es terminada al segundo.
A las 02:33:37 se inician dos sesiones desde la IP 59.188.237.12, esta vez duran unos segundos mas. Una de ellas es terminada a las 02:33:41 (4 segundos después de iniciar), mientras que la otra termina a las 02:34:44 (1 minuto y 7 segundos después de iniciar).
A las 02:33:41 se ejecutó el comando chpasswd, básicamente es utilizado para cambiar passwords en batch. No entiendo para qué harían esto. De hecho el error saltó porque el usuario butter no existe en el sistema.

Los logs de auditd

De los logs de auditd, lamentablemente no hay mucho para decir ya que la parte más importante (los minutos correspondientes a las sesiones SSH) se perdió por la rotación. A pesar de esto, acá va lo que pude encontrar a partir de los logs que quedaron:

Analizando el archivo mas viejo

El reporte general a priori no dice demasiado, salvo por el hecho de haber registrado 11314 eventos en casi 2 minutos:

root@ip-172-31-56-203:/home/ubuntu# aureport -i -if /mnt/var/log/audit/audit.log.79

Summary Report
======================
Range of time in logs: 07/23/15 03:15:20.105 - 07/23/15 03:17:17.037
Selected time for report: 07/23/15 03:15:20 - 07/23/15 03:17:17.037
Number of changes in configuration: 0
Number of changes to accounts, groups, or roles: 0
Number of logins: 0
Number of failed logins: 0
Number of authentications: 0
Number of failed authentications: 0
Number of users: 3
Number of terminals: 2
Number of host names: 1
Number of executables: 5
Number of files: 26
Number of AVC's: 0
Number of MAC events: 0
Number of failed syscalls: 0
Number of anomaly events: 0
Number of responses to anomaly events: 0
Number of crypto events: 0
Number of keys: 1
Number of process IDs: 226
Number of events: 11314

root@ip-172-31-56-203:/home/ubuntu#

Podemos identificar esos 5 ejecutables que se mencionan en el reporte general con el flag -x de la siguiente manera:

root@ip-172-31-56-203:/home/ubuntu# aureport -x --summary -if /mnt/var/log/audit/audit.log.79

Executable Summary Report
=================================
total file
=================================
11264 /tmp/squid64 (deleted)
15 /usr/sbin/cron
12 /bin/rm
11 /usr/sbin/tcpdump (deleted)
11 /bin/tar
root@ip-172-31-56-203:/home/ubuntu#

De los 5 ejecutables solo uno me resulta sospechoso y claramente es /tmp/squid64. Lamentablemente el archivo ya no se encuentra en /tmp, debe haber sido eliminado después de lanzarse el proceso probablemente, y no logré recuperarlo. Los otros ejecutables son parte de los procesos de control y monitoreo explicados en el primer post.

Podemos ver también cuáles fueron los archivos mas utilizados en estos eventos:

root@ip-172-31-56-203:/home/ubuntu# aureport -f --summary -if /mnt/var/log/audit/audit.log.79

File Summary Report
===========================
total file
===========================
11264 /etc/passwd
23 /root/
11 /root
2 /root/sample295.jpg
2 /root/sample296.jpg
2 /root/sample297.jpg
2 /root/sample298.jpg
2 /root/sample299.jpg
2 /root/sample300.jpg
2 /root/sample301.jpg
2 /root/sample302.jpg
2 /root/sample303.jpg
2 /root/sample304.jpg
2 /root/sample305.jpg
1 /root/sample294.jpg
1 sample296
1 sample297
1 sample298
1 sample299
1 sample300
1 sample301
1 sample302
1 sample303
1 sample304
1 sample305
1 sample306
root@ip-172-31-56-203:/home/ubuntu#

Parece mucha coincidencia que el proceso /tmp/squid64 y el archivo /etc/passwd se hayan registrado en la misma cantidad de eventos.

De hecho si filtramos el reporte por eventos vemos:

root@ip-172-31-56-203:/home/ubuntu# aureport -e -i --summary -if /mnt/var/log/audit/audit.log.79

Event Summary Report
======================
total type
======================
11298 SYSCALL
3 USER_END
3 USER_START
3 CRED_DISP
3 CRED_ACQ
3 USER_ACCT
1 CWD
root@ip-172-31-56-203:/home/ubuntu#

El evento SYSCALL (tipo 1300) se registró 11298 veces. A partir del reporte de las syscalls utilizadas vemos que la mas registrada fue open (syscall 2):

root@ip-172-31-56-203:/home/ubuntu# aureport -s -i --summary -if /mnt/var/log/audit/audit.log.79

Syscall Summary Report
==========================
total syscall
==========================
11275 open
12 unlinkat
11 creat
root@ip-172-31-56-203:/home/ubuntu#

De las 11275 llamadas a open, 11264 fueron para el archivo /etc/passwd, y llamada por el binario /tmp/squid64.

Por último miramos el registro de eventos por usuario y vemos claramente que la mayoría de los eventos fueron generados por el usuario comprometido (ubuntu):

root@ip-172-31-56-203:/home/ubuntu# aureport -u --summary -i -if /mnt/var/log/audit/audit.log.79

User Summary Report
===========================
total auid
===========================
11264 ubuntu
34 root
15 unset
root@ip-172-31-56-203:/home/ubuntu#

Analizando un evento particular

A modo de ejemplo tomé uno de los 11264 eventos que implicaron el archivo /etc/passwd y el binario /tmp/squid64, se puede ver a continuación:

root@ip-172-31-56-203:/home/ubuntu# ausearch -a "513448" -i -if /mnt/var/log/audit/audit.log.79
----
type=PATH msg=audit(07/23/15 03:15:20.113:513448) : item=0 name=/etc/passwd inode=397875 dev=ca:01 mode=file,644 ouid=root ogid=root rdev=00:00 nametype=NORMAL
type=CWD msg=audit(07/23/15 03:15:20.113:513448) : cwd=/home/ubuntu
type=SYSCALL msg=audit(07/23/15 03:15:20.113:513448) : arch=x86_64 syscall=open success=yes exit=26 a0=0x7f0beb4fd35c a1=O_RDONLY|O_CLOEXEC a2=0x1b6 a3=0x7f0bd0000078 items=1 ppid=1 pid=1588 auid=ubuntu uid=ubuntu gid=ubuntu euid=ubuntu suid=ubuntu fsuid=ubuntu egid=ubuntu sgid=ubuntu fsgid=ubuntu tty=(none) ses=30 comm=squid64 exe=/tmp/squid64 (deleted) key=(null)
root@ip-172-31-56-203:/home/ubuntu#

En esencia, el proceso PID 1588 ejecutado del binario /tmp/squid64 abre el archivo /etc/passwd en modo lectura (no entiendo con qué objetivo hace eso...). El hecho de que el PPID del proceso sea 1 (init) significa que el proceso padre fue terminado e init pasó a ser el padre del mismo. Muy probablemente el proceso padre original fue la shell abierta por SSH.

El verdadero porque del shutdown

Aquí se devela de manera concreta el shutdown!!! A las 04:40:21 el demonio de audit decidió apagar el distema por la falta de espacio libre para poder escribir los eventos, esto quedó registrado en la ĺtima linea del log mas reciente de audit

root@ip-172-31-56-203:/mnt# ausearch -a "1708" -i -if /mnt/var/log/audit/audit.log
----
type=DAEMON_END msg=audit(07/23/15 04:40:21.000:1708) : auditd normal halt, sending auid=root pid=13214 subj=l=3.13.0-48-generic auid=root pid=18333 subj=unconfined res=success res=success
root@ip-172-31-56-203:/mnt#

También se puede ver el reflejo de esto en /var/log/syslog, a las 04:39:56 se registró el primer mensaje indicando poco espacio disponible en el disco:

root@ip-172-31-56-203:/mnt# grep auditd var/log/syslog
Jul 23 04:39:04 ip-172-31-54-250 auditd[18333]: message repeated 108 times: [ Audit daemon rotating log files]
Jul 23 04:39:56 ip-172-31-54-250 auditd[18333]: Audit daemon is low on disk space for logging
Jul 23 04:40:01 ip-172-31-54-250 auditd[18333]: Audit daemon is low on disk space for logging
Jul 23 04:40:03 ip-172-31-54-250 auditd[18333]: Audit daemon rotating log files
Jul 23 04:40:05 ip-172-31-54-250 auditd[18333]: Audit daemon is low on disk space for logging
Jul 23 04:40:19 ip-172-31-54-250 auditd[18333]: The audit daemon is now halting the system
root@ip-172-31-56-203:/mnt#

Analizando un poco las capturas de red

Como mencioné antes, las capturas de red se encuentran totalmente disponibles y aparentemente intactas dentro del directorio home del usuario root. En el post anterior, me había quedado mucha intriga con respecto a la captura número 105, ya que no había sido enviada por email y era la que debería haber capturado toda la actividad de los dos hosts mencionados. Utilizando wireshark y su análisis de conversaciones podemos ver lo siguiente

Las muchas intervenciones hechas por la dirección 54.196.232.229:

Se puede apreciar la similitud de todas las conversaciones TCP siempre con la misma cantidad de paquetes y bytes transferidos, estas conexiones son los intentos fallidos de login. La excepción es la última conexión que intercambió 6 paquetes mas y unos bytes mas también.
La última conexión es la última actividad registrada para esta IP y muy probablemente se trate de la conexión con que se adivinó el password del usuario.

Las 3 intervenciones hechas por la dirección 59.188.237.12:

En la primer conexión apenas se intercambiaron unos 7758 bytes, esta es la conexión que podría haber sido para comprobar la tupla ip, usuario, password
La segunda conexión ya tuvo bastante mas tráfico 2.3MB aproximadamente, de los cuales 2.24 MB se movieron desde 59.188.237.12 a la instancia. Esto indica la subida de uno o mas archivos.
No hay mucho para suponer de la 3er conexión, es significativamente mas chica que la segunda, pero el doble de la primera. Posiblemente para recolectar alguna información del host infectado.

Técnicamente las conexiones 2 y 3 se inician con una diferencia de milisegundos entre ellas.

Un dato muy interesante es que no todo en las capturas resulta ser tráfico SSH encriptado!!! Escripteando un poco con tcpdump, encontré tráfico HTTP entre la instancia y el host 59.188.237.12. Y adivinen qué se envía por este medio? sin cifrado y con un simple HTTP POST!!!!

Si... nada mas y nada menos que las tuplas ip, usuario, passowrd encontradas y de hecho con mi instancia encontraron varias xD. Se puede ver claramente como mediante una petición POST desde la intancia se cargan los valores en cuestión. Esto refuerza mas aún la hipótesis de que el host 59.188.237.12 se encarga de recolectar e infectar constantemente.

Intenté encontrar llamadas a curl o wget que se pudieran estar usando para este paso, pero no logré encontrar nada en los logs de audit, así que al parecer esta operación debe estar manejado por el mismo binario squid64.

Y /tmp/squid64 dónde está?

Después de tanto revuelo, wireshark, tcpdump y demás hierbas no pude encontrar el archivo que subieron y ejecutaron en la instancia, el famoso squid64. Así que con buena parte del misterio resuelto me puso a invertir unas horas mas en intentar saber algo mas sobre el archivo.

Haciendo uso de autopsy pude obtener una lista de Orphan files del volumen y uno de ellos me resultó muy interesante:

Inode: 13931   Type: regular    Mode: 0755   Flags: 0x80000
Generation: 3210820034    Version: 0x00000000:00000001
User: 1000   Group: 1000   Size: 0
File ACL: 0    Directory ACL: 0
Links: 0   Blockcount: 0
Fragment: Address: 0    Number: 0    Size: 0
ctime: 0x55b07036:ba627a40 -- Thu Jul 23 04:40:22 2015
atime: 0x55b052ba:5086de40 -- Thu Jul 23 02:34:34 2015
mtime: 0x55b07036:ba627a40 -- Thu Jul 23 04:40:22 2015
crtime: 0x55b05286:a843ce40 -- Thu Jul 23 02:33:42 2015
dtime: 0x55b07036 -- Thu Jul 23 04:40:22 2015
Size of extra inode fields: 28
EXTENTS:
(END)
A pesar de que los bloques ya no se encuentran asoaciados al inodo 13931, podemos ver los metadatos

Usuario 1000 (ubuntu)
Fecha de creación: 02:33:42 del 23 de Juli
Fecha de última modificación 04:40:22 del 23 de Julio

y todo indica que se trata de un archivo creado por el mismo usuario comprometido justo después de haberse iniciado una sessión SSH desde el host 59.188.237.12 y que casualmente fue eliminado a la misma hora en que fue apagado el sistema. Es mucha casualidad! Potencialmente el inodo 13931 perteneció al archivo squid64.

Yendo un poco mas profundo y buscando cadenas (strings) dentro de los bloques de disco no asignados encontré algunas cosas interesantes:

[-] ERROR: could not create SSH session
SUXX
/dev/urandom
/dev/random
socket error:
POST %s HTTP/1.1
Host: %s
Host: %s:%d
Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.1.3) Gecko/20090913 Firefox/3.5
.3
User-Agent: %s
Content-Length: %d
zhangyan7tian
data=%s %s %s
/stat.asp
59.188.237.12
ask_userauth
entering function %s line %d in /root/sshcrack/libssh-0.5.3/src/auth.c
ssh-userauth
leaving function %s line %d in /root/sshcrack/libssh-0.5.3/src/auth.c
...
Receiving banner: too large banner
ssh_send_banner
SSH-1.5-libssh-0.5.2
SSH-2.0-libssh-0.5.2
Received SSH_KEXDH_REPLY

Entre tantas cadenas podemos ver

El banner SSH-2.0-libssh-0.5.2 con que se identifica el cliente SSH que realiza las conexiones de manera masiva.
Un path de archivos fuente /root/sshcrack/libssh-0.5.3/src/auth.c parece tratarse del path the compilación de la aplicación sshcrack. Lo raro es que utiliza libssh-0.5.3 en lugar del 0.5.2.
Vemos el encabezado HTTP con la llamada POST completa e incluso pareciera estar hardcodeada la IP de recolección e infección (59.188.237.12).

y un poco mas adelante lo que parece ser un diccionario de usuarios/passwords, si prestan atención se darán cuenta que los usuarios probados son los que mencioné cerca del final del primer post:

zhangyan
zhangyan7tian
3rddf
root
12345
root
admin
root
password
root
123muie123
root
root
root
1234
root
root123
root
123456
root
...
qwerty123
root
qwerty
root
pa55w0rd
root
1qaz2wsx
root
root
toor
...
root
^%$#@!
root
^&*()
root
5mmQ

En fin, no pude obtener el archivo, pero quedaron muchos rastros que podrían formar parte del mismo. Desafortunadamente no contemplé en ningún momento la posibilidad de perder logs de auditd, incluso sabiendo de la rotación, creí que 80 era un número mas que suficiente.

Resumen

Hasta aquí llegó mi amor! A modo de resumen para cerrar la saga es dejo los siguientes puntos:

Está claro que hay al menos 2 tipos de nodos en este proceso. Los nodos (tipo A) como 54.196.232.229 que buscan usuarios con passwords triviales y nodos como 59.188.237.12 (tipo B) que se encargan de infectar y recolectar las tuplas obtenidas por los nodos tipo A.
Cuando un nodo tipo A consigue un usuario y password lo reporta instantaneamente al nodo tipo B, mediante un mensaje POST HTTP.
El nodo tipo B se conecta al host y realiza una serie de operaciones que no pudieron ser determinadas con precisión, pero que convierten al host en un nodo tipo A.

En los próximos días iniciaré la instancia por primera vez luego de la infección para corroborar si hay algún mecanismo que haga persistir la infección.