Nginx ist ein verbreiteter Webserver, der auch weitere Funktionen anbietet und daher z.B. als Reverse Proxy laufen kann. Gerade da kann es passieren, dass etwas nicht richtig funktioniert – warum ist nicht ersichtlich. Im schlimmsten Falle liefert die hinter dem Reverse Proxy liegende Anwendung keine weitere Informationen und ist gar propriet\u00e4r, sodass man dort wenig bis gar nicht eingreifen kann. Nginx bietet verschiedene M\u00f6glichkeiten zur Fehlersuche, die bedingt durch die Architektur teils etwas komplexer sind.<\/p>\n
Bevor man tiefer gehend mit dem Debug-Protokoll im n\u00e4chsten Abschnitt sucht, w\u00fcrde ich es auf den einfacheren Wegen probieren. Das Access-Log liegt meist unter Sollten die Protokolle nicht existieren oder leer sein, m\u00fcssen sie ggf. zun\u00e4chst aktiviert werden. Daf\u00fcr bietet Nginx die Direktiven Sollte das nicht ausreichen, bietet Nginx Debuglogs. Sie protokollieren zahlreiche zus\u00e4tzliche Informationen. Darunter beispielsweise die HTTP-Header und bei der Verwendung als Reverse Proxy mit dem ngx_http_proxy_module Modul ebenfalls die an das Backend-System weitergeleiteten Header. Es gibt nur einen Haken: Diese Debug-Protokolle k\u00f6nnen nicht ohne weiteres aktiviert werden, wie man es etwa aus (neueren) Apache 2.4 Versionen kennt. Dort l\u00e4sst sich dynamisch das LogLevel f\u00fcr bestimmte Module deutlich feiner setzen, etwa so:<\/p>\n Nginx muss dagegen mit Debug-Flag kompiliert werden, damit das debug<\/em> Level zus\u00e4tzlich zu den oben genannten zur Verf\u00fcgung steht.2<\/a><\/sup> Wie Nginx kompiliert wird, hatte ich in diesem Beitrag bereits gezeigt<\/a>. Allerdings wollte ich die ganzen Abh\u00e4ngigkeiten nicht auf einem produktiven System installieren, nur um dort zeitweise die Debug-Logs nutzen zu k\u00f6nnen. Also habe ich mit folgendem Dockerfile alles in einen Container gepackt:<\/p>\n Passend dazu eine docker-compose.yml:<\/p>\n Sowie die Nginx Konfigurationsdatei:<\/p>\n Das ist bewusst sehr minimalistisch gehalten und verwendet daher HTTP ohne Verschl\u00fcsselung, weil ich zur Eingrenzung des Problems m\u00f6glichst vieles ausschlie\u00dfen wollte. Mit einer eigenen Zertifizierungsstelle signierte TLS-Zertifikate f\u00fcr HTTPS-Verbindungen geh\u00f6rten auch dazu. Au\u00dferdem l\u00e4sst sich dies so f\u00fcr andere Zwecke als Vorlage nutzen, ohne ggf. unn\u00f6tige Module zu enthalten. Wer weitere ben\u00f6tigt, kann diese hinzuf\u00fcgen – etwa das Um das Image mit unserem selbst kompilierten Nginx zu erzeugen und einen Container zu starten, gen\u00fcgen die bekannten Docker Compose Befehle:<\/p>\n Achtung: Das Debug-Protokoll schreibt sehr viele Eintr\u00e4ge! Man sollte dies daher keinesfalls<\/strong> uneingeschr\u00e4nkt auf produktiven Systemen einsetzen. Im besten Falle findet man nichts mehr in den Logs. Im schlimmsten Falle schie\u00dft man es damit ab, weil durch das Protokollieren viel Last generiert wird. Au\u00dferhalb von (kleinen) Testumgebungen sollte daher unbedingt begrenzt werden, f\u00fcr welche Clients Debug-Protokolle angelegt werden. Daf\u00fcr steht die Direktive Anbei ein Beispiel eines HTTP-Aufrufes. Ich habe wegen der L\u00e4nge ein paar Zeilen gek\u00fcrzt. Man sieht wie zuvor angesprochen s\u00e4mtliche eingehende HTTP-Header und die an den Backend-Server weitergeleiteten. W\u00fcrde man beispielsweise mit Nginx ist ein verbreiteter Webserver, der auch weitere Funktionen anbietet und daher z.B. als Reverse Proxy laufen kann. Gerade da kann es passieren, dass etwas nicht richtig funktioniert – warum ist nicht ersichtlich. Im schlimmsten Falle liefert die hinter dem Reverse Proxy liegende Anwendung keine weitere Informationen und ist gar propriet\u00e4r, sodass man dort wenig …<\/p>\n","protected":false},"author":5,"featured_media":11503,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":"[{\"content\":\"https:\/\/docs.nginx.com\/nginx\/admin-guide\/monitoring\/logging\/\",\"id\":\"9cef4e6f-9d7d-4af6-83f0-90c6d2961b83\"},{\"content\":\"https:\/\/nginx.org\/en\/docs\/debugging_log.html\",\"id\":\"51288b85-dd3d-4045-8fb7-43785f6f5129\"},{\"content\":\"https:\/\/nginx.org\/en\/docs\/configure.html\",\"id\":\"142e4bf2-a0aa-48df-9576-f6d7e14c2fa4\"}]"},"categories":[78],"tags":[497,983,541],"class_list":["post-11493","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-software","tag-docker","tag-dockerfile","tag-nginx"],"_links":{"self":[{"href":"https:\/\/u-labs.de\/portal\/wp-json\/wp\/v2\/posts\/11493","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/u-labs.de\/portal\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/u-labs.de\/portal\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/u-labs.de\/portal\/wp-json\/wp\/v2\/users\/5"}],"replies":[{"embeddable":true,"href":"https:\/\/u-labs.de\/portal\/wp-json\/wp\/v2\/comments?post=11493"}],"version-history":[{"count":10,"href":"https:\/\/u-labs.de\/portal\/wp-json\/wp\/v2\/posts\/11493\/revisions"}],"predecessor-version":[{"id":11667,"href":"https:\/\/u-labs.de\/portal\/wp-json\/wp\/v2\/posts\/11493\/revisions\/11667"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/u-labs.de\/portal\/wp-json\/wp\/v2\/media\/11503"}],"wp:attachment":[{"href":"https:\/\/u-labs.de\/portal\/wp-json\/wp\/v2\/media?parent=11493"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/u-labs.de\/portal\/wp-json\/wp\/v2\/categories?post=11493"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/u-labs.de\/portal\/wp-json\/wp\/v2\/tags?post=11493"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}\/var\/log\/nginx\/access.log<\/code>, sofern nicht anders definiert. In Containern wird es auf stdout geschrieben und l\u00e4sst sich bei Docker beispielsweise mit docker logs -f $containerName<\/code> abrufen. Darin werden alle Zugriffe protokolliert, sodass man z.B. den HTTP Statuscode sieht, der zur\u00fcckgesendet wurde. Auch das Fehlerprotokoll (error.log<\/code>) kann hilfreich sein. Nginx protokolliert dort Fehler im Kontext des Webservers, etwa nicht gefundene Dateien. CGI-Programme k\u00f6nnen ihre Logs dort ebenfalls weiterleiten. Je nach Konfiguration befinden die sich in einer anderen Logdatei\/einem anderen Container. Ein Blick in die Protokolle der anderen involvierten Anwendungen schadet nicht, sofern die Anfragen dort ankommen – etwa der Anwendung, die hinter Nginx l\u00e4uft.<\/p>\naccess_log<\/code> und error_log<\/code>. Bei Letzterem unterteilt der Webserver die Ereignisse in warn, error, crit, alert, emerg<\/em>.1<\/a><\/sup><\/p>\nerror_log \/var\/logs\/nginx\/error.log warn;<\/code><\/pre>\nDebuglogs in Nginx<\/h2>\n
LogLevel error proxy:trace5<\/code><\/pre>\nFROM debian:stable-slim\nRUN apt-get update \\\n && apt-get install -y gcc build-essential libpcre3-dev zlib1g-dev wget\n\nWORKDIR \/tmp\nRUN wget -O nginx.tar.gz https:\/\/nginx.org\/download\/nginx-1.24.0.tar.gz \\\n && mkdir \/opt\/nginx-src \\\n && tar xf nginx.tar.gz -C \/opt\/nginx-src --strip-components=1\n\nWORKDIR \/opt\/nginx-src\nRUN .\/configure --prefix=\/opt\/nginx --with-debug\nRUN make install\n\nENTRYPOINT ["\/opt\/nginx\/sbin\/nginx", "-g", "daemon off;"]<\/code><\/pre>\nservices:\n nginx-debug:\n build: .\n mem_limit: 1G\n volumes:\n - .\/nginx.conf:\/opt\/nginx\/conf\/nginx.conf\n ports:\n - 80:80<\/code><\/pre>\n#user nobody;\nworker_processes 1;\n\nerror_log \/dev\/stdout debug;\n\nevents {\n worker_connections 1024;\n}\n\nhttp {\n include mime.types;\n default_type application\/octet-stream;\n\n log_format main '$remote_addr - $remote_user [$time_local] "$request" '\n '$status $body_bytes_sent "$http_referer" '\n '"$http_user_agent" "$http_x_forwarded_for"';\n # alternativ \/proc\/1\/fd\/1\n access_log \/dev\/stdout main;\n\n sendfile on;\n keepalive_timeout 65;\n\n server {\n listen 80;\n server_name localhost;\n\n location \/ {\n proxy_pass http:\/\/backend-server;\n }\n }\n}<\/code><\/pre>\nhttp_ssl_module<\/code> f\u00fcr TLS-Verbindungen. Eine Liste aller Module mit ihrem jeweiligen Argument, das zu Aktivierung an den configure<\/code> Befehl \u00fcbergeben werden muss, steht unter nginx.org bereit.3<\/a><\/sup><\/p>\nDOCKER_BUILDKIT=0 docker compose up --build<\/code><\/pre>\nDOCKER_BUILDKIT<\/code> verwende ich gerne, um die vollst\u00e4ndige Ausgabe zu erhalten. Docker Compose ab V2 versucht Platz zu sparen, in dem l\u00e4ngere Ausgaben nicht vollst\u00e4ndig angezeigt werden. Das mag in Ordnung sein, wenn alles funktioniert. Gibt es jedoch Probleme, finde ich das \u00e4u\u00dferst ungeschickt, wenn nur Teile der Fehlermeldungen sichtbar sind. Vor allem wenn das nicht der urs\u00e4chliche Fehler war, sondern ein Folgefehler, sodass die relevanten Meldungen nicht zu sehen sind.<\/p>\nEinschr\u00e4nkungen<\/h2>\n
debug_connection<\/code> bereit:<\/p>\nevents {\n debug_connection 192.168.1.1;\n}<\/code><\/pre>\nWas wird protokolliert?<\/h2>\n
proxy_set_header<\/code> einen Header nur f\u00fcr das Backend setzen, so erscheint dieser nicht bei http header<\/em> – dies sind die vom Client eingehenden. Sondern weiter unten bei http proxy header<\/em>.<\/p>\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http request line: "GET \/login?reqUrl=%2F HTTP\/1.1"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http uri: "\/login"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http args: "reqUrl=%2F"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http exten: ""\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 posix_memalign: 0000556B725264E0:4096 @16\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http process request header line\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header: "Host: localhost"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header: "User-Agent: Mozilla\/5.0 (X11; Linux x86_64; rv:109.0) Gecko\/20100101 Firefox\/119.0"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header: "Accept: text\/html,application\/xhtml+xml,application\/xml;q=0.9,image\/avif,image\/webp,*\/*;q=0.8"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header: "Accept-Language: de,en-US;q=0.7,en;q=0.3"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header: "Accept-Encoding: gzip, deflate, br"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header: "Connection: keep-alive"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header: "Cookie: LAVAGNA_SESSION_ID=xyz"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header: "Upgrade-Insecure-Requests: 1"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header: "Sec-Fetch-Dest: document"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header: "Sec-Fetch-Mode: navigate"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header: "Sec-Fetch-Site: none"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header: "Sec-Fetch-User: ?1"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http header done\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 event timer del: 3: 266058067\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 rewrite phase: 0\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 test location: "\/"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 using configuration "\/"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http cl:-1 max:1048576\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 rewrite phase: 2\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 post rewrite phase: 3\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 generic phase: 4\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 generic phase: 5\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 access phase: 6\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 access phase: 7\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 post access phase: 8\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 generic phase: 9\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 generic phase: 10\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http init upstream, client timer: 0\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 epoll add event: fd:3 op:3 ev:80002005\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http script copy: "Host"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http script var: "backend-server"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http script copy: "Connection"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http script copy: "close"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http script copy: ""\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http script copy: ""\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http proxy header: "User-Agent: Mozilla\/5.0 (X11; Linux x86_64; rv:109.0) Gecko\/20100101 Firefox\/119.0"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http proxy header: "Accept: text\/html,application\/xhtml+xml,application\/xml;q=0.9,image\/avif,image\/webp,*\/*;q=0.8"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http proxy header: "Accept-Language: de,en-US;q=0.7,en;q=0.3"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http proxy header: "Accept-Encoding: gzip, deflate, br"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http proxy header: "Upgrade-Insecure-Requests: 1"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http proxy header: "Sec-Fetch-Dest: document"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http proxy header: "Sec-Fetch-Mode: navigate"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http proxy header: "Sec-Fetch-Site: none"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http proxy header: "Sec-Fetch-User: ?1"\nnginx-debug-1 | 2023\/11\/01 17:46:14 [debug] 7#0: *1 http proxy header:\nnginx-debug-1 | "GET \/login?reqUrl=%2F HTTP\/1.0\nnginx-debug-1 | Host: backend-server\nnginx-debug-1 | Connection: close\nnginx-debug-1 | User-Agent: Mozilla\/5.0 (X11; Linux x86_64; rv:109.0) Gecko\/20100101 Firefox\/119.0\nnginx-debug-1 | Accept: text\/html,application\/xhtml+xml,application\/xml;q=0.9,image\/avif,image\/webp,*\/*;q=0.8\nnginx-debug-1 | Accept-Language: de,en-US;q=0.7,en;q=0.3\nnginx-debug-1 | Accept-Encoding: gzip, deflate, br\nnginx-debug-1 | Upgrade-Insecure-Requests: 1\nnginx-debug-1 | Sec-Fetch-Dest: document\nnginx-debug-1 | Sec-Fetch-Mode: navigate\nnginx-debug-1 | Sec-Fetch-Site: none\nnginx-debug-1 | Sec-Fetch-User: ?1\nnginx-debug-1 | \nnginx-debug-1 | "<\/code><\/pre>\nQuellen<\/h2>\n
\n