Informe de rechazos y logging

import logging
import sys

# format y level se configuran UNA vez, al arrancar el programa.
logging.basicConfig(
    level=logging.INFO,
    format="%(levelname)-8s %(message)s",
    stream=sys.stdout,
)

log = logging.getLogger("ventas")

log.debug("leyendo la fila 47 del archivo")
log.info("archivo leido: 500 filas")
log.warning("3 filas sin costo: se descartan")
log.error("no se pudo escribir el informe")
log.critical("la carpeta de salida no existe: no hay nada que hacer")

print()
print("El DEBUG no aparecio: level=INFO define el piso.")
print("Cambiar ese unico valor apaga o enciende toda la traza fina,")
print("sin tocar ni borrar una sola linea de codigo.")

print()
print("Y esa es la diferencia con print():")
print("  - print va siempre; el nivel se decide una vez y afecta a todo")
print("  - el mensaje trae nivel, y despues fecha, modulo, linea")
print("  - se puede mandar a un archivo sin tocar el codigo que lo emite")
print("  - una biblioteca que hace print le ensucia la salida al que la usa")

print()
# El nivel tambien se puede consultar, para no armar mensajes caros.
print("nivel efectivo:", logging.getLevelName(log.getEffectiveLevel()))
print("¿vale la pena armar el mensaje de debug?", log.isEnabledFor(logging.DEBUG))

import collections
import csv
import logging
import sys

logging.basicConfig(level=logging.INFO, format="%(levelname)-7s %(message)s",
                    stream=sys.stdout)
log = logging.getLogger("ventas")

NULOS = {"", "-", "N/A", "NaN", "null"}

with open("dw_hecho_ventas.csv", encoding="utf-8", newline="") as f:
    filas = list(csv.DictReader(f))


def defectos(fila):
    """Los motivos por los que la fila no sirve."""
    fallas = []
    for columna in ("fecha", "cantidad", "costo", "ingreso"):
        if fila[columna].strip() in NULOS:
            fallas.append(("ausente", columna))
    for columna in ("cantidad", "ingreso", "costo"):
        crudo = fila[columna].strip()
        if crudo in NULOS:
            continue
        try:
            if float(crudo) < 0:
                fallas.append(("negativo_incoherente", columna))
        except ValueError:
            fallas.append(("no_numerico", columna))
    return fallas


# ANTIPATRON 1: no informar nada.
buenas = [x for x in filas if not defectos(x)]
print("1. sin informe:", len(buenas), "filas procesadas")
print("   (el que lee esto no tiene forma de saber que faltan",
      len(filas) - len(buenas), "filas)")
print()

# ANTIPATRON 2: una linea de log por fila mala.
print(f"2. una linea por rechazo (las primeras 5 de {len(filas) - len(buenas)}):")
mostradas = 0
for fila in filas:
    for motivo, columna in defectos(fila):
        if mostradas < 5:
            log.warning("venta %s: %s en %s", fila["venta_id"], motivo, columna)
            mostradas += 1
print("   (con 500 filas y un archivo grande esto son miles de lineas:")
print("    nadie las lee, y las importantes quedan enterradas)")
print()

# LA FORMA QUE SIRVE: agregado al final + el detalle a un archivo.
print("3. resumen agregado:")
conteo = collections.Counter()
rechazadas = []
for fila in filas:
    fallas = defectos(fila)
    if fallas:
        rechazadas.append(fila)
        for motivo, columna in fallas:
            conteo[(motivo, columna)] += 1

log.info("leidas %d filas de dw_hecho_ventas.csv", len(filas))
log.info("validas %d | rechazadas %d", len(buenas), len(rechazadas))
for (motivo, columna), cuantos in sorted(conteo.items()):
    log.warning("  %-22s %-9s %3d", motivo, columna, cuantos)
log.info("el detalle fila por fila va a ventas_rechazadas.csv")

print()
print("El log dice CUANTOS y de que tipo; el archivo de rechazos dice")
print("CUALES. Son dos cosas distintas y ninguna reemplaza a la otra.")

import logging
import re
import sys
import tempfile
from pathlib import Path

carpeta = Path(tempfile.mkdtemp())
archivo = carpeta / "proceso.log"

log = logging.getLogger("ventas")
log.setLevel(logging.DEBUG)          # el logger deja pasar todo...

consola = logging.StreamHandler(sys.stdout)
consola.setLevel(logging.WARNING)    # ...y cada destino filtra lo suyo
consola.setFormatter(logging.Formatter("consola | %(levelname)-8s %(message)s"))

disco = logging.FileHandler(archivo, encoding="utf-8")
disco.setLevel(logging.DEBUG)
disco.setFormatter(logging.Formatter(
    "%(asctime)s %(name)s %(levelname)-8s %(message)s",
    datefmt="%H:%M:%S"))

log.addHandler(consola)
log.addHandler(disco)

log.debug("abriendo dw_hecho_ventas.csv")
log.info("500 filas leidas")
log.warning("6 filas rechazadas")
log.error("no se pudo convertir el costo de la venta 213")

# exception() = error() + el traceback completo. Solo tiene sentido
# adentro de un except. Lo mandamos solo al archivo: un traceback en la
# consola asusta al que mira, y en el archivo es justo lo que se busca.
log.removeHandler(consola)
try:
    int("N/A")
except ValueError:
    log.exception("fallo la conversion de la venta 213")
log.addHandler(consola)

print()
print("Arriba salio la consola: solo WARNING y peores, sin traceback.")
print()
print("Y esto es lo que quedo en", archivo.name, "(hora y rutas tapadas")
print("para que la salida de esta pagina no cambie en cada corrida):")
print("-" * 62)
texto = archivo.read_text(encoding="utf-8")
texto = re.sub(r"^\d\d:\d\d:\d\d", "HH:MM:SS", texto, flags=re.M)
texto = re.sub(r'File "[^"]*[\\/]([^"\\/]+)"', r'File ".../\1"', texto)
for linea in texto.splitlines():
    print(linea)
print("-" * 62)

print()
print("El mismo codigo produjo las dos salidas. La consola es para la")
print("persona que esta mirando; el archivo, para cuando algo salio mal")
print("y hay que reconstruir que paso una semana despues.")

print()
print("Detalle que ahorra tiempo: los argumentos van SEPARADOS por coma,")
print("no interpolados en la cadena.")
log.warning("venta %s rechazada por %s", 213, "costo ausente")
print("  con %s : el mensaje se arma solo si el nivel lo deja pasar")
print("  con f-string: se arma siempre, aunque despues se descarte")

for h in list(log.handlers):
    h.close()
    log.removeHandler(h)

import collections
import csv
import logging
import sys
import tempfile
from pathlib import Path

logging.basicConfig(level=logging.INFO, format="%(levelname)-7s %(message)s",
                    stream=sys.stdout)
log = logging.getLogger("ventas")

NULOS = {"", "-", "N/A", "NaN", "null"}
with open("dw_hecho_ventas.csv", encoding="utf-8", newline="") as f:
    filas = list(csv.DictReader(f))

print("ANTIPATRON 1: except: pass")
total = 0.0
for fila in filas:
    try:
        total += float(fila["costo"])
    except ValueError:
        pass
print("   costo total:", round(total, 2))
print("   ¿sobre cuantas filas? No hay forma de saberlo desde el resultado.")
print()

print("ANTIPATRON 2: print(error) sin decir donde")
mostrados = 0
for fila in filas:
    try:
        float(fila["costo"])
    except ValueError as error:
        if mostrados < 3:
            print("  ", error)
            mostrados += 1
print("   El mensaje no dice que fila ni que columna: con 500 filas y")
print("   siete columnas, encontrarla es trabajo manual.")
print()

print("ANTIPATRON 3: nivel equivocado")
log.error("costo ausente en la venta 213")
print("   ERROR es 'el programa no pudo seguir'. Un dato sucio en un")
print("   archivo sucio es lo esperable: eso es WARNING.")
print("   Si todo es ERROR, nadie mira los ERROR.")
print()

print("ANTIPATRON 4: informar sin el denominador")
log.warning("6 filas rechazadas")
print("   ¿6 de 10 o 6 de 500? Es la diferencia entre tirar el archivo")
print("   y seguir adelante. Un conteo sin total no informa nada.")
print()

print("=" * 62)
print("EL INFORME QUE SI SIRVE")
print("=" * 62)


def defectos(fila):
    fallas = []
    for columna in ("fecha", "cantidad", "costo", "ingreso"):
        if fila[columna].strip() in NULOS:
            fallas.append(("ausente", columna))
    for columna in ("cantidad", "ingreso", "costo"):
        crudo = fila[columna].strip()
        if crudo not in NULOS:
            try:
                if float(crudo) < 0:
                    fallas.append(("negativo_incoherente", columna))
            except ValueError:
                fallas.append(("no_numerico", columna))
    return fallas


conteo = collections.Counter()
buenas, rechazadas, malas = [], [], []
for fila in filas:
    fallas = defectos(fila)
    if fallas:
        rechazadas.append(fila)
        for motivo, columna in fallas:
            conteo[(motivo, columna)] += 1
            malas.append({"venta_id": fila["venta_id"], "columna": columna,
                          "motivo": motivo, "valor": fila[columna]})
    else:
        buenas.append(fila)

carpeta = Path(tempfile.mkdtemp())
with open(carpeta / "ventas_rechazadas.csv", "w", encoding="utf-8",
          newline="") as f:
    escritor = csv.DictWriter(
        f, fieldnames=["venta_id", "columna", "motivo", "valor"])
    escritor.writeheader()
    escritor.writerows(malas)

log.info("entrada    : %d filas", len(filas))
log.info("validas    : %d (%.1f%%)", len(buenas), 100 * len(buenas) / len(filas))
log.info("rechazadas : %d", len(rechazadas))
for (motivo, columna), cuantos in sorted(conteo.items()):
    log.warning("   %-22s %-9s %3d", motivo, columna, cuantos)
log.info("detalle    : ventas_rechazadas.csv (%d filas)", len(malas))

# Las dos listas se llenaron por separado: que la suma de es una
# comprobacion de verdad, no una tautologia.
assert len(buenas) + len(rechazadas) == len(filas)
log.info("invariante : validas + rechazadas == entrada  OK")

print()
print("Tiene las cinco cosas: el total de entrada, el de salida, el")
print("desglose por motivo, el archivo con el detalle, y la comprobacion")
print("de que no se perdio ninguna fila por el camino.")