Por: Yuri Diógenes / Diana Hernandez

 

1. Introducción

 

El artículo de esta semana esta basado en un incidente de soporte que trabajé aqui en Microsoft en donde el cliente tenía un escenario semejante al mostrado abajo:

 

 

Figura 1 – En el escenario de la figura apenas una sucursal esta siendo representada, sin embargo exiten otras.

 

En este escenario los servidores de RRAS de las sucursales se conectaban com el servidor RRAS de la matriz através de una conexión en demanda (DOD - Dial on Demand) de un único camino, o sea, siempre la sucursal es la que va a discar para la principal. Esta conexión  DOD es usada para fines de gerenciamiento, teniendo en cuenta que la conexión principal entre el escritorio remoto y la principal es hecha através de una conexión dedicada en esta red de Frame Relay.

 

 

En este escenario las conexiones DOD utilizan direccionamiento IP dinámico asignado por el servidor principal. Sin embargo, en este caso el cliente estaba utilizando mapeamiento estático através de los atributos de cuenta de usuario, con esto cada sucursal tenia su usuario adecuado que a su vez tenia una direccion IP como un atributo definido en las propiedades de la cuenta.

 

Durante el gerenciamiento de estos servidores remotos fue detectado que habia un problema com el direccionamiento IP, ya que al accesar un determinado IP el mismo apuntaba para otro servidor. La solución alterna era desconectar y conectar  nuevamente, de esta forma el IP correcto era adquirido.  Fue através de la detección de este problema que vino entonces la pregunta: por que con el mapeamiento de IP siendo utilizada la cuenta de usuario de la sucursal se obtiene una IP diferente de la que fué estrablecida?

 

 

 

2. Preparando el Ambiente

 

 

Para preparar el ambiente para obtener la información necesaria para iniciar la resolución del problema fue necesario realizar los siguientes pasos en los servidores RRAS de la sede principal y de la sucursal:

 

1. Habilitar todos los logs de RRAS através del comando netsh ras set tracing * enable. Estos logs serán almacenados en el folder %windir%\tracing.

2. Iniciar el “Network Monitor” para realizar la captura de los datos.

 

Después de realizar esto fue necesario esperar a que el problema ocurriese, ya que el hecho de ser un comportamiento aleatorio fue algo que dificultó la captura de los datos sincronizados.

 

3. Análisis de los Datos

 

 

Después de tener capturados los datos en el momento exacto en que el problema ocurrió fue posible determinar básicamente lo que aconteció.  Es importante antes de iniciar la lectura de los logs entender los siguientes parametros configurados en el servidor RRAS de la sucursual, en el servidor que inicia la conexión:

 

 

 

Figura 2 – Propiedades de la conexión DOD en el servidor RRAS de la sucursal.

 

Através de este parámetro podemos entonces concluir que en el lado de la sucursal el RRAS va a esperar tres segundos y entonces va a interntar conectarse nuevamente.

 

Para tener certeza de lo que esta ocurriendo con la sucursal Madri es necesario verificar las propiedades de la cuenta de este usuario y revisar cual IP esta de hecho siendo asignada para el RRAS de esta sucursal:

 

 

Figura 3 – Propriedades del usuario Madri.

 

Conforme es posible verificar en la ventana de arriba, la dirección IP que debe ser asignada automaticamente para el usuario Madri es 192.168.5.100.

 

Sabiendo esto entonces nos enfocamos a analizar una ocurrencia de las 7:12 que acontecio cuando la sucursal “Madri” perdió la conexión por algun motivo y espero 3 segundos para marcar nuevamente.

 

En el lado del servidor RRAS es posible verificar através del archivo RASIPHLP.LOG el momento exacto en que el usuario Madri intenta reconectarse.

 

[2384] 02-20 07:15:09:506: RasSrvrAcquireAddress(hPort: 0x82, IP address: 0x6405a8c0, UserName: Madri, PortName: VPN4-126)

[2384] 02-20 07:15:09:506: rasSrvrGetAddressForServerAdapter

[2384] 02-20 07:15:09:506: Address 0x6405a8c0 is already in use

[2384] 02-20 07:15:09:506: RasDhcpAcquireAddress

[2384] 02-20 07:15:09:516: RasSrvrActivateIp(IpAddr = 0x6505a8c0, dwUsage = 0)

[2384] 02-20 07:15:09:516: RasTcpSetProxyArp(IP Addr: 0x6505a8c0, fAddAddress: TRUE)

[2384] 02-20 07:15:09:516: rasSrvrGetAddressForServerAdapter

 

La dirección IP que aparece en rojo es justamente la dirección IP 192.168.5.100, la forma de encontrarlo es usando la siguiente regla:

 

  • Dirección en hexadecimal que aparece en el log = 0x6405a8c0
  • Direccion en hexadecimal invertido y separado cada dos dígitos = c0 a8 05 64
  • Convirtiendo esta dirección en hexadecimal tenemos = 192.168.5.100

 

Notese que a las 7:15:09 tenemos un evento diciendo que la dirección IP 192.168.5.100 ya está en uso y con esto la IP 192.168.5.151 (0x6505a8c0) es asignada al cliente (Madri).  Ahora veamos porque el servidor RRAS de la sede principal piensa que la dirección IP esta aun en uso...

 

 

3.1. Conclusión

 

La conclusión de este escenario es que el RRAS de la sucursal va a marcar más rapidamente de lo que servidor RRAS toma para entender que la conexión cayó del lado remoto y desconecte al usuario. Con las configuraciones estandard de RRAS este tiempo puede variar entre 2 a 3 minutos (mas información sobre este comportamiento ver el articulo KB262990), o sea, a si mismo con la asignación manual de IP en las propiedades de la cuenta, el RRAS necesita verificar si este IP esta en uso y en ese caso será necesario asignar otro IP disponible del banco de datos de DHCP.

 

De esta manera cuando vemos en RASIPHLP.LOG el evento diciendo que la IP estava en uso es justamente por el hecho que el servidor RRAS aún tiene la conexión activa con la sucursal y por lo tanto la IP aún no es liberada.

 

4.  Pero por que la conexión se cayó?

 

Después de tener identificado el motivo por el cual la dirección IP era asignada incorrectamente entonces fué cuestionado el motivo por el cual varias veces durante el dia la conexión habia sido perdida, ocasionando que la sucursal tuviera que marcar para el servidor central de RRAS.

 

Usando una captura de ejemplo de la ocurrencia cerca de las 8:20, es posible notar que un poco antes de este evento tenemos los dos servidores intercambiando información de control PPTP normalmente, conforme es posible verificar en el trafico capturado. Estos paquetes de control PPTP son enviados cada 60 segundos:

 

8:19  192.168.3.2 192.168.3.1 PPTP  PPTP: Control Message , Echo Request

8:19  192.168.3.1 192.168.3.2 PPTP  PPTP: Control Message , Echo Reply

 

 

A las 8:20 tenemos el siguiente evento en el archivo RASMAN.LOG:

 

[1992] 02-20 08:20:43:284: d:\nt\net\rras\ras\rasman\rasman\util.c 1997: Disconnected Port 252, reason 1. rc=0x0

 

Luego tenemos el siguiente evento en el archivo RASTAPI.LOG:

 

[1992] 02-20 08:20:43:284: PortTestSignalState: DisconnectReason = 2

 

 

En el archivo RASMAN.LOG se muestra que la razón de la desconexión fue igual a 1 (HARDWAREFAILURE) y el archivo RASTAPI.LOG la razón fue igual a 2 (LINKDROPPED). Con esto podemos verificar que ocurrió un problema en los niveles de enlace físico. Es possible con esto deducir que hubo un problema en la portadora, sea esta la tarjeta de red o el equipo activo que esta al frente de este servidor RRAS.

En la captura de red es posible verificar que estuvimos un poco mas de un segundo sin conectividad de red total y a las 8:21 comenzamos nuevamente el proceso através de un ARP request:

 

8:21  192.168.3.1 192.168.3.1       ARP   ARP: Request, 192.168.3.1 asks for 192.168.3.1

8:21  192.168.3.1 192.168.3.2       ARP   ARP: Request, 192.168.3.1 asks for 192.168.3.2

8:21  192.168.3.2 192.168.3.1       ARP   ARP: Response, 192.168.3.2 at 00-03-FF-0F-2B-29

 

En seguida tenemos un TCP 3 Way Handshake de PPTP (TCP 1723):

 

8:21  192.168.3.1 192.168.3.2       TCP   TCP: Flags=.S......, SrcPort=1149, DstPort=1723, Len=0, Seq=3777429460, Ack=0, Win=65535 (scale factor 0) = 65535

 

8:21  192.168.3.2 192.168.3.1       TCP   TCP: Flags=.S..A..., SrcPort=1723, DstPort=1149, Len=0, Seq=1936732946, Ack=3777429461, Win=16384 (scale factor 0) = 16384

 

8:21  192.168.3.2 192.168.3.1       TCP   TCP: Flags=....A..., SrcPort=1723, DstPort=1149, Len=0, Seq=1936733135, Ack=3777429809, Win=65187 (scale factor 0) = 65187

 

Posteriormente tenemos una creación de la conexión PPTP:

 

8:21  192.168.3.1 192.168.3.2       PPTP  PPTP: Control Message , Start Control Connection Request

8:21  192.168.3.2 192.168.3.1       PPTP  PPTP: Control Message , Start Control Connection Reply

8:21  192.168.3.1 192.168.3.2       PPTP  PPTP: Control Message , Outgoing Call Request

8:21  192.168.3.2 192.168.3.1       PPTP  PPTP: Control Message , Outgoing Call Reply

8:21  192.168.3.1 192.168.3.2       PPTP  PPTP: Control Message , Set Link Info

 

Después de esto la comunicación continua sin mayores problemas.

 

 

5. Conclusão

 

Conforme fue mencionado antes en la referencia del artículo KB262990, es posible hacer algunos ajustes en el control de la inactividad del link. El servidor RRAS puede quedarse verificando si un link esta inactivo através del ajuste del parametro InactivityIdleSeconds en la llave:

 

HKEY_LOCAL_MACHINE\SYSTEM\CCS\Control\Class\{4d36E972-....}\instanceid

 

El valor estandard es de 60 segundos, si este valor fuera reducido para 1, el servicio de RRAS podria llevar de 30 a 45 segundos para detectar la caida del link PPTP.

 

Otro parámetro que puede ser usado es DefaultIdleTimeout en la llave:

 

HKLM\SYSTEM\CurrentControlSet\Services\RasMan\PPP

 

Este es un parámetro global que afecta todas las conexiones PPP, o sea , que el servidor RRAS va verificar si la conexión esta inactiva y en caso que asi sea entonces va a desconectarla.

 

Una solución alterna para esta necesidad seria:

 

  • Configurar por ejemplo el servidor RRAS para desconectar después de 6 segundos sin tráfico alterando el DefaultIdleTimeout;
  • Configurar el RRAS de la sucursal para mantener siempre algun tipo de tráfico por este link, por ejemplo un archivo BAT con un ping –t para la dirección interna del servidor RRAS de la principal.
  • Configurar el servidor RRAS remoto para marcar nuevamente en 10 segundos en caso que la conexión haya sido interrumpida.

 

Con este tipo de solución alterna, al final lo que tendríamos sería el siguiente comportamiento:

 

  • Se la conexión cae por completo del lado del cleinte remoto el va a contar 10 segundos antes de llamar nuevamente, y el servidor RRAS va a ver que la conexión esta inactiva por 6 segundos y la va a desconectar.
  • El resultado seria que cuando el cliente remoto intenta reconectarse el no debería tener problema de tomar otra IP, teniendo en cuenta que la conexión anterior ya fue liberada y con esto la dirección IP no estaría en uso.