There are some log entries in the caddy logs that are reported on level error although they are induced by client behavior and nothing can be done about them on there server side. I believe this class of log messages should only be logged with a level of warning instead of error to make them easier to filter out. My logs are collected via Google Cloud Stackdriver logging, so my examples below might include some unfamiliar login fields, but this is probably not relevant for this discussion.
The first very common error occurs SSE event streams, every time a client closes something like this is logged:
{
"insertId": "1snph9if65spv4",
"jsonPayload": {
"logger": "http.handlers.reverse_proxy",
"upstream": "unix//run/containers/gitea.sock",
"container": {
"created": "2024-07-12T07:15:05.531024115Z",
"name": "/caddy",
"imageId": "sha256:fb9248311f17dbb180b45470385f05e1d1ed030ed1242445310158743a2844e2",
"id": "d59dde84b3df95a0205884d70734da984df160fa007cc641aae337d5b904b8f9",
"imageName": "jumager/caddy:develop"
},
"duration": 0.004181822,
"message": "aborting with incomplete response",
"instance": {
"zone": "iad",
"id": "redacted_instance"
},
"request": {
"proto": "HTTP/2.0",
"uri": "/user/events",
"host": "gitea.redacted.org",
"remote_ip": "redacted_ip",
"remote_port": "62847",
"tls": {
"server_name": "gitea.redacted.org",
"cipher_suite": 4865,
"resumed": false,
"proto": "h2",
"version": 772
},
"method": "GET",
"headers": {
"X-Forwarded-For": [
"redacted_ip"
],
"User-Agent": [
"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.5 Safari/605.1.15"
],
"X-Forwarded-Proto": [
"https"
],
"Accept-Encoding": [
"gzip, deflate, br"
],
"Sec-Fetch-Dest": [
"empty"
],
"Pragma": [
"no-cache"
],
"Cookie": [
"REDACTED"
],
"Sec-Fetch-Site": [
"same-origin"
],
"Accept": [
"text/event-stream"
],
"Cache-Control": [
"no-cache"
],
"X-Forwarded-Host": [
"gitea.redacted.org"
],
"Accept-Language": [
"de-DE,de;q=0.9"
],
"Traceparent": [
"00-f8cdce6ba6e56a86b393a41b98b5fde9-4863285a2948ba15-01"
],
"Sec-Fetch-Mode": [
"cors"
]
},
"client_ip": "redacted_ip"
},
"error": "reading: context canceled"
},
"httpRequest": {
"requestMethod": "GET",
"requestUrl": "https://gitea.redacted.org/user/events",
"userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.5 Safari/605.1.15",
"remoteIp": "redacted_ip:62847",
"latency": "0.004181822s",
"protocol": "HTTP/2.0"
},
"resource": {
"type": "gce_instance",
"labels": {
"project_id": "hosting-349701",
"instance_id": "redacted_instance",
"zone": "iad"
}
},
"timestamp": "2024-07-13T15:00:10.895007426Z",
"severity": "ERROR",
"logName": "projects/hosting-349701/logs/ngcplogs-docker-driver",
"trace": "projects/hosting-349701/traces/f8cdce6ba6e56a86b393a41b98b5fde9",
"receiveTimestamp": "2024-07-13T15:00:11.914164155Z",
"spanId": "4863285a2948ba15"
}
A similar problem might happen if HTTP/2 or HTTP/3 streams are closed by the client, nothing that the server can do about this (example for h2):
{
"insertId": "t51k1ofjvgp4e",
"jsonPayload": {
"duration": 0.146122205,
"upstream": "nextcloud:9000",
"instance": {
"id": "redacted_instance",
"zone": "eu-frankfurt-1"
},
"request": {
"uri": "/ocs/v2.php?lastCommonReadId=0&lastKnownMessageId=3476&includeLastKnown=1&limit=100&setReadMarker=0&timeout=0&lookIntoFuture=0",
"host": "nextcloud.redacted.org",
"tls": {
"cipher_suite": 4865,
"proto": "h2",
"resumed": true,
"server_name": "nextcloud.redacted.org",
"version": 772
},
"client_ip": "172.18.0.1",
"remote_ip": "172.18.0.1",
"method": "GET",
"proto": "HTTP/2.0",
"headers": {
"User-Agent": [
"Mozilla/5.0 (Android) Nextcloud-Talk v19.0.1"
],
"Accept": [
"application/json"
],
"Accept-Encoding": [
"gzip"
],
"Authorization": [
"REDACTED"
],
"X-Forwarded-For": [
"172.18.0.1"
],
"X-Forwarded-Host": [
"nextcloud.redacted.org"
],
"Ocs-Apirequest": [
"true"
],
"Ngrok-Skip-Browser-Warning": [
"true"
],
"X-Forwarded-Proto": [
"https"
],
"Cookie": [
"REDACTED"
]
},
"remote_port": "41468"
},
"container": {
"created": "2024-07-11T12:34:01.089956605Z",
"imageId": "sha256:fb9248311f17dbb180b45470385f05e1d1ed030ed1242445310158743a2844e2",
"imageName": "jumager/caddy:develop",
"name": "/caddy",
"id": "900a956692593a737ae46e7963d9d3eb24de31f34dcb75e9d8cdfef2a98b61d6"
},
"error": "writing: http2: stream closed",
"logger": "http.handlers.reverse_proxy",
"message": "aborting with incomplete response"
},
"httpRequest": {
"requestMethod": "GET",
"requestUrl": "https://nextcloud.redacted.org/ocs/v2.php%3FlastCommonReadId=0&lastKnownMessageId=3476&includeLastKnown=1&limit=100&setReadMarker=0&timeout=0&lookIntoFuture=0",
"userAgent": "Mozilla/5.0 (Android) Nextcloud-Talk v19.0.1",
"remoteIp": "172.18.0.1:41468",
"latency": "0.146122205s",
"protocol": "HTTP/2.0"
},
"resource": {
"type": "gce_instance",
"labels": {
"project_id": "hosting-349701",
"zone": "eu-frankfurt-1",
"instance_id": "redacted_instance"
}
},
"timestamp": "2024-07-12T10:15:47.195211569Z",
"severity": "ERROR",
"logName": "projects/hosting-349701/logs/ngcplogs-docker-driver",
"receiveTimestamp": "2024-07-12T10:15:48.139349424Z"
}
And this is an example for h3:
{
"insertId": "134my6sfx5ktzv",
"jsonPayload": {
"logger": "http.handlers.reverse_proxy",
"duration": 27.564383584,
"container": {
"name": "/caddy",
"created": "2024-07-12T07:15:05.531024115Z",
"imageId": "sha256:fb9248311f17dbb180b45470385f05e1d1ed030ed1242445310158743a2844e2",
"imageName": "jumager/caddy:develop",
"id": "d59dde84b3df95a0205884d70734da984df160fa007cc641aae337d5b904b8f9"
},
"instance": {
"zone": "iad",
"id": "redacted_instance"
},
"message": "aborting with incomplete response",
"upstream": "unix//run/containers/redacted.sock",
"error": "writing: H3 error (0x0)",
"request": {
"remote_ip": "redacted_ip",
"headers": {
"Cookie": [
"REDACTED"
],
"X-Forwarded-For": [
"redacted_ip"
],
"Accept-Language": [
"it-IT,it;q=0.9"
],
"Accept-Encoding": [
"gzip, deflate, br"
],
"Accept": [
"*/*"
],
"Traceparent": [
"00-6d4184543ce8227db97f7cd8028534ab-c05cd4e9cd17a8fb-01"
],
"X-Forwarded-Host": [
"redacted.app"
],
"Priority": [
"u=3"
],
"X-Forwarded-Proto": [
"https"
],
"User-Agent": [
"Redacted/147 CFNetwork/1496.0.7 Darwin/23.5.0"
]
},
"remote_port": "18677",
"uri": "/redacted_req",
"tls": {
"resumed": false,
"proto": "h3",
"version": 772,
"server_name": "redacted.app",
"cipher_suite": 4865
},
"proto": "HTTP/3.0",
"host": "redacted.app",
"client_ip": "redacted_ip",
"method": "GET"
}
},
"httpRequest": {
"requestMethod": "GET",
"requestUrl": "https://redacted.app/redacted_req",
"userAgent": "Redacted/147 CFNetwork/1496.0.7 Darwin/23.5.0",
"remoteIp": "redacted_ip:18677",
"latency": "27.564383584s",
"protocol": "HTTP/3.0"
},
"resource": {
"type": "gce_instance",
"labels": {
"instance_id": "redacted_instance",
"zone": "iad",
"project_id": "hosting-349701"
}
},
"timestamp": "2024-07-12T07:31:44.900229430Z",
"severity": "ERROR",
"logName": "projects/hosting-349701/logs/ngcplogs-docker-driver",
"trace": "projects/hosting-349701/traces/6d4184543ce8227db97f7cd8028534ab",
"receiveTimestamp": "2024-07-12T07:31:45.918433209Z",
"spanId": "c05cd4e9cd17a8fb"
}
In all of these cases I think the log level should be warning and not error, otherwise it is difficult to find real errors where one should be looking at.