Creo que solemos tener tendencia a pensar en las root cause de los incidentes como factores aislados (o el código estaba mal, o alguien ejecutó algo mal, o la configuración estaba mal, etc…) Aún conociendo la teoría, si hemos leido decenas de artículos sobre cómo normalmente se trata de una combinación de factores (errores) nuestra tendencia automática es la de buscar un único culpable, incluso el propio concepto “root cause” asume una fuente monolítica desde la que se propagan el resto de consecuencias hasta generar el problema que estábamos tratando de resolver.

El siguiente issue es una prueba de que esto no siempre es así, y no deberíamos emplear ese atajo mental sin un poco de visión crítica: Tuvimos un error operativo que, por si solo, no habría causado incidente y descubrí un error de código en un módulo de la collection community.windowsde Ansible que, por si sólo, no habría causado un incidente. ¿Que ocurrió cuándo coincidieron?

La fuente de este artículo es un conjunto de notas que siempre me gusta tomar cuando me enfrento a troubleshootings interesantes. Además ha sido mi primera contribución open source a un proyecto tan grande como es Ansible.

El error: probablemente estemos haciendo algo mal

El error ocurrió en nuestra pipeline de deployment principal, durante la release de una nueva versión. Como siempre, los FQDN, hostnames y el output en general han sido editados para proteger a los respectivos clientes.

failed: [host-2.domain.com] (item=CUSTOMER_WEBSITE) => 
{     
    "ansible_loop_var": "item",     
    "application_pool": "CUSTOMER-1",     
    "changed": false,    
    "physical_path": "G:\\WEBAPP\\22.2.0.0\\CUSTOMER-1" } 
    MSG: Cannot find path 'G:\\WEBAPP\\22.1.0.0\\CUSTOMER-1' because it does not exist.

¿No existe el physical_path? Ya hay un sospechoso, haciendo gala de otro shortcut mental lo primero que pensamos fue “Si siempre ha funcionado, y ahora no, algo debemos haber cambiado que causa el error. Hemos roto ese path” (y esto es un atajo mental, sin duda, que haya funcionado en el pasado no garantiza que vaya a funcionar en el presente). Era un buen comienzo.

El path de la 22.2existía, pero el de la 22.1 no. Vale, error operativo, durante ese momento del deployment el anterior path, como es el de la versión previa, siempre existe en caso de necesitarse para un rollback. En el momento, durante el deployment, resolvimos el problema restaurando el path perdido y continuamos.

Durante la ejecución me anoté mirar esto para más adelante: ¿Qué importaba el path de la versión anterior si lo que estabamos era mapeando al de la versión actual, que sí existía? ¿Habíamos cometido realmente un error operativo? ¿o el código estaba imponiendo unas condiciones innecesariamente restrictivas? El problema pasó de sospechoso de error operativo a convertirse en algo más interesante. Lo primero que necesitaba saber era de dónde venía ese error. Ansible es Python, pero en hosts Windows Ansible es PowerShell y aquel string tenía una pinta muy pwsh-ish. En otro shortcut mental, elaboré una teoría escasa de pruebas y basada en instinto y lo que me inspiraban los limitados datos disponibles. Esto, que puede llamarse “especular”, en la ingeniería del conocimiento lo llaman heurística.

La teoría

El error “Cannot find path $path” no venía ni de Ansible, ni del módulo de pwsh. Venía de PowerShell en sí. Pero primero tenía que entender un poco mejor lo que había pasado. Para no alargarme, lo voy a poner a modo de lista:

  • El path que se estaba intentando mappear (Versión 22.2) existía durante la ejecución.
  • El path de la versión anterior (22.1) se había borrado antes de lo esperado, aquí hubo un error operativo.
    • Esto fue posible porque en otro paso de nuestra automation se detienen los IIS y se borran todas las n versiones anteriores exceptuando n (es decir, borramos n-1versiones para asegurarnos de que no hay folders de versiones más viejas que la inmediatamente anterior y que no tienen valor para hacer un rollback)
  • La APP Pool de IIS aún tenía mapeado el path de la versión anterior (G:\\WEBAPP\\22.1.0.0\\CUSTOMER-1), ya que nunca se llegó a actualizar.

Después de esto estaba bastante claro que habíamos hecho mal en nuestro lado (borrar la última versión antes de tiempo), pero no por qué daba error de “Cannot find path 'G:\\WEBAPP\\22.1.0.0\\CUSTOMER-1' because it does not exist.” cuando en el módulo estabamos mapeando el 'G:\\WEBAPP\\22.2.0.0\\CUSTOMER-1', que sí existía.

La ventaja más importante, en mi opinión, del Open Source y lo que le ha permitido convertirse en el estandar de facto para muchas partes de la industria, es que puedes echar un vistazo al código para hacerte una idea mejor de qué está pasando.

El bug en el código: Una validación implícita

Al echar un vistazo al source de win_iis_webapplication me encontré con una línea muy interesante, previa a hacer una comprobación entre el Physical Path actual del webapp y el recibido como parámetro ($folder.FullName), para ver si debe modificarse y cumplir la condición de idempotencia (no actúar si el estado deseado y el estado actual son el mismo).

$app_folder = Get-Item -LiteralPath $application.PhysicalPath
            $folder = Get-Item -LiteralPath $physical_path
            if ($folder.FullName -ne $app_folder.FullName) {
                Set-ItemProperty -LiteralPath "IIS:\Sites\$($site)\$($name)" -name physicalPath -value $physical_path -WhatIf:$check_mode
                $result.changed = $true
            }

Ahí estaba el error. En el if, el módulo compara entre el path actual y el path recibido (if ($folder.FullName -ne $app_folder.FullName)), sin embargo, para obtener el path actual hacía algo un poco extraño: $app_folder = Get-Item -LiteralPath $application.PhysicalPath. Si haces Get-Item de algo que no existe, tienes el descriptivo mensaje de error del tipo Cannot find path 'X' because it does not exist. Una App Pool de IIS puede tener en su PhysicalPath cualquier path, incluso uno que no exista si nos las hemos arreglado para borrarlo mientras estaba detenida. Por supuesto fallará en cuánto vuelva a iniciar, pero por poder, puede tener un path que no exista en el filesystem.

Ya estaba claro lo que había pasado, al intentar hacer ese Get-Item con el PhysicalPath anterior que habíamos borrado (error operativo) PowerShell daba un error irrecuperable (le estas pidiendo hacer Get de algo inexistente, al fin y al cabo). Misterio resuelto, ¡yay!

Pero, ¿debería el módulo de Ansible hacer una comprobación del path anterior, y no del proporcionado?. Si atendemos a la lógica de que en Ansible lo que definimos es el estado final en el que queremos dejar a nuestros hosts, no tiene demasiado sentido validar el estado anterior. ¿Y si de hecho estoy lanzando mi playbook para corregir algo que actualmente está mal? ¿Y si alguien o algo desconfigura mis App Pools? Lo lógico sería lanzar el playbook para corregirlo, y no es muy útil que en ese momento Ansible falle porque la configuración actual (no a la que quiero llegar) no sea correcta. Es más, en este caso concreto ni siquiera parecía una comprobación explícita, sino una comprobación implícita derivada de la manera en la que el código estaba intentando obtener el PhysicalPath existente.

El fix: Una mejora para no ser innecesariamente restrictivo

Al módulo no le tiene que importar si el PhysicalPath actual es válido, o si existe. Como si es ILoveYou, sólo si el proporcionado es válido y no es el mismo que el actual. Ese es su call to action. Con este planteamiento, aplicar el fix es bastante sencillo: Eliminar la validación implícita. Y es exactamente lo que hice en este PR

$app_folder = Get-Item -LiteralPath $application.PhysicalPath
            if ($folder.FullName -ne $application.PhysicalPath) {
                Set-ItemProperty -LiteralPath "IIS:\Sites\$($site)\$($name)" -name physicalPath -value $physical_path -WhatIf:$check_mode
                $result.changed = $true
            }

Kudos

Documentación oficial del módulo win?iis?webapplication