angle-uparrow-clockwisearrow-counterclockwisearrow-down-uparrow-leftatcalendarcard-listchatcheckenvelopefolderhouseinfo-circlepencilpeoplepersonperson-fillperson-plusphoneplusquestion-circlesearchtagtrashx

Python toepassingsregistratie met Docker

Docker best practices suggereren logging naar stdout , maar er zijn enkele gotchas.

5 december 2022
post main image
https://unsplash.com/@agk42

Wanneer je een softwaretoepassing ontwikkelt, is het eerste wat je gaat instellen waarschijnlijk loggen. Eerst alleen naar de console, maar al snel zul je logbestanden toevoegen.

Enkele jaren geleden begon ik Docker te gebruiken voor ontwikkeling en productie. Ik heb niet veel veranderd toen ik overstapte op Docker. De applicatie logbestanden staan nog steeds in een log directory op een Docker Volume. Dit betekent dat de logbestanden deel uitmaken van de toepassing framework.

Best practices op het internet stellen voor om Docker logging te gebruiken. Dit betekent dat onze Docker applicatie logrecords moet afdrukken naar stdout (en/of sterr), in plaats van ze naar onze applicatie logbestanden te schrijven. Wanneer we onze logboekrecords naar stdout sturen in Docker, kunnen we een logboekstuurprogramma opgeven om ze te exporteren naar een externe tool zoals Syslog, met behulp van door Docker geleverde logboekstuurprogramma's of logboekstuurprogramma's van derden. Ik begrijp dat dit voordelen kan hebben, of zelfs essentieel is.

Nogmaals, ik wil niet te veel veranderen en vasthouden aan het standaard logboekstuurprogramma in Docker: json-file. Onze logboekrecords zullen in de bestanden aanwezig zijn:

/var/lib/docker/containers/<container id>/<container id>-json.log

Een van mijn huidige Python projecten is een applicatie die bestaat uit een heleboel (micro) services. Een dienst wordt vertegenwoordigd door een container met logbestanden nog steeds in de context / framework van de dienst. In deze post converteer ik mijn bestaande applicatie logging methode naar Docker logging.

De loggingmodule wijzigen

Voor mijn applicaties heb ik een aangepaste logging module ontwikkeld, binnen deze module zitten de standaard Python logging methoden, wat betekent dat mijn applicatie code regels heeft als:

logger.debug(...)
logger.info(...)
logger.error(...)

Ik gebruik deze logging module overal. Dit betekent dat ik alleen een nieuwe loggingmodus hoefde toe te voegen, met een variabele, use_docker_logging=True, die aangeeft om loggegevens naar stdout te schrijven in plaats van naar een bestand.

Wij kunnen dit heel eenvoudig doen met behulp van logging.StreamHandler(stdout). Bij gebruik van de loggingmodule Python worden de gegevens na elk record doorgespoeld. Dit betekent dat het niet nodig is Python te starten als 'python -u' of de omgevingsvariabele PYTHONUNBUFFERED te gebruiken.

Docker Exec, problemen, waar zijn mijn logbestanden?

Helaas, we zijn nog niet klaar, er is een probleem. Ik weet niet hoe het met u zit, maar ik doe al mijn ontwikkeling met behulp van Docker containers vandaag. In veel gevallen heb ik het commando in het docker-compose.yml bestand zoals:

command: tail -f /dev/null

Dit betekent, start de container en houdt deze in leven. Dan 'Docker Exec' in de container (shell), en voer de Python scripts uit. Toen ik dit deed, verschenen de logrecords van de 'Docker Exec' sessie niet in de Docker logs.

Na zoeken op internet vond ik deze (Docker problemen) pagina 'Proposal: additional logging options for docker exec', zie onderstaande links.

Het blijkt dat wanneer je 'Docker Exec' in een container plaatst, de stdout van deze sessie niet de stdout van de initiële sessie is. Daar zullen redenen voor zijn, die we niet kunnen veranderen, en daar moeten we mee omgaan.

De oplossing is om logboekrecords om te leiden naar:

/proc/1/fd/1

Toen vond ik een andere (Docker issues) pagina op het internet 'Echoing to /dev/stdout does not appear in docker logs', zie links hieronder. Een van de suggesties is om te loggen naar een sym-linked bestand. Wij maken de symlink in de Dockerfile:

RUN ln -sf /proc/1/fd/1 /var/log/test.log

Terug naar de oplossing die we tot nu toe hadden, vervangen we de logging.StreamHandler door de logging.FileHandler:

logging.FileHandler('/var/log/test.log')

Nu verschijnen de log records van Python scripts die draaien in de 'Docker Exec' sessie, in de Docker logs.

Docker Exec-sessie, geen console logging

Helaas zijn we nog niet klaar, er is nog een probleem. Omdat we de logging.FileHandler gebruikten, loggen we alleen naar een bestand, stdout, zijnde de Docker logs. Om de log records op het scherm te zien in de "Docker Exec" sessie, moeten we de logging.StreamHandler weer toevoegen.

Maar wacht, we moeten dit alleen doen voor de 'Docker Exec' sessie, anders zien we dubbele log records in de Docker logs.

Ik heb dit opgelost op een manier die een beetje hackish is, door de bovenste bovenliggende procesnaam te vinden. Als deze procesnaam 'sh' of 'bash' is, neem ik aan dat we Docker Exec hebben gebruikt om de container binnen te gaan.

import psutil

    ...
    # get 'top' parent process of this docker exec session
    parent_process_pid = os.getpid()
    parent_process_name = None
    while True:
        #print('parent_process_pid = {}'.format(parent_process_pid))
        parent_process = psutil.Process(parent_process_pid)
        pid = parent_process.ppid()
        parent_process_name = parent_process.name()
        if pid == 0:
            break
        parent_process_pid = pid

    if parent_name in ['sh', 'bash']:
        # add console logging
        ...
    else:
        # no console logging
        ...
    ...

Logregels met extra velden

Alle logregels van een container staan nu in een enkel logbestand. Als u meerdere diensten (processen) in een container hebt draaien, wilt u waarschijnlijk extra velden toevoegen aan de logregels die de dienst (het proces) identificeren. Dit naast het veld logging.DEBUG, logging.ERROR enz. dat we in de logregels invoegen.

In Python logging kunnen we een extra veld toevoegen aan een logregel met de methode logging.setLogRecordFactory() . Een voorbeeld wordt gegeven op de pagina 'Using LogRecordFactory in python to add custom fields for logging', zie onderstaande links.

Andere wijzigingen

Merk op dat we met de standaard Docker logging driver alleen een string naar stdout kunnen schrijven, het schrijven van een JSON-object (woordenboek) is niet mogelijk. Een ernstige beperking, maar we moeten ermee leven.

Als we tags willen toevoegen aan alle (!) logrecords, kunnen we labels gebruiken in Docker-Compose:

Voorbeeld:

  some-service:
    image: ...
    ports:
      - "8082:8000"
    labels:
      log_for_application: "myapp"

Bij het loggen naar Docker wordt de tijdstempel automatisch toegevoegd door Docker. Dit betekent dat we het moeten verwijderen uit onze Python logregel. Mijn uiteindelijke loggerformatteringstekenreeks ziet er als volgt uit:

'%(proc_id)-15.15s %(levelname)-8.8s [%(filename)-30s%(funcName)20s():%(lineno)03s] %(message)s'

De Docker logs van alle containers met Dozzle bekijken.

Er zijn veel oplossingen om de Docker logs van alle containers te bekijken. Ik heb er een paar geprobeerd, en het gemakkelijkst in te stellen en te gebruiken was Dozzle. Dozzle is een real-time log viewer voor docker containers, zie onderstaande links. Om het uit te voeren, trek je gewoon de container, en je bent klaar om te gaan. Dozzle lijkt op Logs Explorer, een uitbreiding voor Docker Desktop, zie onderstaande links.

Wees voorzichtig, standaard verbindt Dozzle je met Google Analytics, zorg ervoor dat je Dozzle start met de '--no-analytics' vlag:

docker run --name dozzle -d --volume=/var/run/docker.sock:/var/run/docker.sock -p 8888:8080 amir20/dozzle:latest --no-analytics

Eenmaal gestart, wijs uw browser naar:

http://127.0.0.1:8888

Met Dozzle is het heel eenvoudig om uw Docker logs te bekijken.

Zoeken maakt gebruik van regex, wat betekent dat als je bijvoorbeeld wilt filteren op twee termen, 'Term1' en 'Term2',
je in het zoekvak kunt typen:

Term1.*?Term2

Een ander aardig ding met Dozzle is dat we het ook kunnen starten voor een enkele container, of een paar containers. Wat echt ontbreekt, is een manier om je zoekopdrachten op te slaan en opnieuw te selecteren. Maar ik klaag niet. Geweldig hulpmiddel!

Samenvatting

Dit kostte veel meer tijd dan ik had verwacht. Het was veel meer dan alleen printen naar stdout. Is het de moeite waard? Voor de huidige toepassing, die bestaat uit vele diensten vertegenwoordigd door containers, denk ik van wel.

Nu het loggen gebeurt via Docker, kan ik kijken naar andere manieren om de logs te bekijken, waarschuwingen te genereren, enz.

Links / credits

Docker - Configure logging drivers
https://docs.docker.com/config/containers/logging/configure

Dozzle, a real-time log viewer for docker containers
https://dozzle.dev

Echoing to /dev/stdout does not appear in 'docker logs' #19616
https://github.com/moby/moby/issues/19616

Proposal: additional logging options for docker exec #8662
https://github.com/moby/moby/issues/8662

Using LogRecordFactory in python to add custom fields for logging
https://stackoverflow.com/questions/59585861/using-logrecordfactory-in-python-to-add-custom-fields-for-logging

Laat een reactie achter

Reageer anoniem of log in om commentaar te geven.

Opmerkingen

Laat een antwoord achter

Antwoord anoniem of log in om te antwoorden.