Python toepassingsregistratie met Docker
Docker best practices suggereren logging naar stdout , maar er zijn enkele gotchas.
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
Lees meer
Docker Docker-compose Log file Logging
Recent
- Database UUID primaire sleutels van je webapplicatie verbergen
- Don't Repeat Yourself (DRY) met Jinja2
- SQLAlchemy, PostgreSQL, maximum aantal rijen per user
- Toon de waarden in SQLAlchemy dynamische filters
- Veilige gegevensoverdracht met Public Key versleuteling en pyNaCl
- rqlite: een alternatief voor SQLite met hoge beschikbaarheid en distributed
Meest bekeken
- Met behulp van Python's pyOpenSSL om SSL-certificaten die van een host zijn gedownload te controleren
- Gebruik van UUIDs in plaats van Integer Autoincrement Primary Keys met SQLAlchemy en MariaDb
- Maak verbinding met een dienst op een Docker host vanaf een Docker container
- PyInstaller en Cython gebruiken om een Python executable te maken
- SQLAlchemy: Gebruik van Cascade Deletes om verwante objecten te verwijderen
- Flask RESTful API verzoekparametervalidatie met Marshmallow-schema's