search

sillygod / cdp-cache

a caddy 2 proxy cache plugin
MIT License
119 stars 17 forks source link

Something since v0.3.2 caused intermittent timeouts #24

Closed Silver-Golden closed 4 years ago

Silver-Golden commented 4 years ago

I had an issue earlier.
I use uptimerobot to monitor my uptime and to notify me if stuff goes fubar.

Today I had this. image

(Sorry the numbers are a tad small, my paint skills arent the best)

  1. Caddy died, looking at the logs it said that http_cache was not a directive.
    • I thought that was strange so I recompiled with
    • xcaddy build v2.1.0-beta.1 --with github.com/caddy-dns/cloudflare --with github.com/sillygod/cdp-cache
    • which I had used before back when you fixed #9
  2. This began uptime robot paniking, sending me alert that connection timed out folloed by a perfect connection
    • Logs are below, the middle segment is from one of the timeout periods. Uptimerobot sends secondary requests to check if its only a localised error which should explain te 3 requests within a few seconds.
    • I cant see anything wrong in teh responses myself.
  3. I recompiled using
    • xcaddy build v2.1.0-beta.1 --with github.com/caddy-dns/cloudflare --with github.com/sillygod/cdp-cache@v0.3.2
    • and it went back to normal.

Because compiling to v0.3.2 worked and v0.3.8 didnt I presume something between the two is causing issues.

Now that I am awake again I will do some further testing to hone in on which version introduced the issue.

Logs

Jul 06 10:21:48 Debian-102-buster-64-minimal caddy[9348]: {"level":"debug","ts":1594023708.335256,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"localhost:8085","request":{"method":"GET","uri":"/gw2/v1/status?misc=uptime1","proto":"HTTP/1.1","remote_addr":"69.162.124.237:33240","host":"api.silveress.ie","headers":{"X-Forwarded-Proto":["https"],"Cache-Control":["no-cache"],"Accept-Charset":["ISO-8859-1,UTF-8;q=0.7,*;q=0.7"],"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"Accept-Language":["en-US,en;q=0.8"],"Referer":["https://api.silveress.ie/gw2/v1/status?misc=uptime1"],"X-Forwarded-For":["69.162.124.237"],"Accept-Encoding":["gzip, deflate"],"User-Agent":["Mozilla/5.0+(compatible; UptimeRobot/2.0; http://www.uptimerobot.com/)"]},"tls":{"resumed":false,"version":772,"ciphersuite":4865,"proto":"","proto_mutual":true,"server_name":"api.silveress.ie"}},"duration":0.002780804,"headers":{"Content-Type":["application/json; charset=utf-8"],"Connection":["Keep-Alive"],"Content-Md5":["kHSaUAGaJ+HzLOvbqnobwQ=="],"Date":["Mon, 06 Jul 2020 08:21:48 GMT"],"Api-Version":["2.2.3"],"Request-Id":["cea55763-f38b-448e-ab3c-da9d8bfa8355"],"Response-Time":["2"],"Vary":["origin,access-control-request-method,access-control-request-headers"],"Server":["gw2_api_market_data"]},"status":200}
Jul 06 10:21:48 Debian-102-buster-64-minimal caddy[9348]: {"level":"debug","ts":1594023708.3355274,"logger":"http.handlers.http_cache","msg":"cache handler","host":"api.silveress.ie","method":"GET","uri":"/gw2/v1/status?misc=uptime1","request time":0.003200192,"upstream request time":0.002944886}
Jul 06 10:21:48 Debian-102-buster-64-minimal caddy[9348]: {"level":"info","ts":1594023708.3356032,"logger":"http.log.access.log3","msg":"handled request","request":{"method":"GET","uri":"/gw2/v1/status?misc=uptime1","proto":"HTTP/1.1","remote_addr":"69.162.124.237:33240","host":"api.silveress.ie","headers":{"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"Accept-Language":["en-US,en;q=0.8"],"Referer":["https://api.silveress.ie/gw2/v1/status?misc=uptime1"],"Accept-Encoding":["gzip, deflate"],"User-Agent":["Mozilla/5.0+(compatible; UptimeRobot/2.0; http://www.uptimerobot.com/)"],"Connection":["close"],"Cache-Control":["no-cache"],"Accept-Charset":["ISO-8859-1,UTF-8;q=0.7,*;q=0.7"]},"tls":{"resumed":false,"version":772,"ciphersuite":4865,"proto":"","proto_mutual":true,"server_name":"api.silveress.ie"}},"common_log":"69.162.124.237 - - [06/Jul/2020:10:21:48 +0200] \"GET /gw2/v1/status?misc=uptime1 HTTP/1.1\" 200 0","duration":0.003278651,"size":0,"status":200,"resp_headers":{"X-Cache-Status":["miss"],"Api-Version":["2.2.3"],"Response-Time":["2"],"Vary":["origin,access-control-request-method,access-control-request-headers"],"Access-Control-Allow-Origin":["*"],"Content-Length":["0"],"Content-Type":["application/json; charset=utf-8"],"Content-Md5":["kHSaUAGaJ+HzLOvbqnobwQ=="],"Request-Id":["cea55763-f38b-448e-ab3c-da9d8bfa8355"],"Date":["Mon, 06 Jul 2020 08:21:48 GMT"]}}
Jul 06 10:26:48 Debian-102-buster-64-minimal caddy[9348]: {"level":"debug","ts":1594024008.3852909,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"localhost:8085","request":{"method":"GET","uri":"/gw2/v1/status?misc=uptime1","proto":"HTTP/1.1","remote_addr":"69.162.124.237:47342","host":"api.silveress.ie","headers":{"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"Accept-Charset":["ISO-8859-1,UTF-8;q=0.7,*;q=0.7"],"Accept-Encoding":["gzip, deflate"],"X-Forwarded-Proto":["https"],"User-Agent":["Mozilla/5.0+(compatible; UptimeRobot/2.0; http://www.uptimerobot.com/)"],"X-Forwarded-For":["69.162.124.237"],"Cache-Control":["no-cache"],"Referer":["https://api.silveress.ie/gw2/v1/status?misc=uptime1"],"Accept-Language":["en-US,en;q=0.8"]},"tls":{"resumed":false,"version":772,"ciphersuite":4865,"proto":"","proto_mutual":true,"server_name":"api.silveress.ie"}},"duration":0.001367914,"headers":{"Content-Md5":["kHSaUAGaJ+HzLOvbqnobwQ=="],"Api-Version":["2.2.3"],"Connection":["Keep-Alive"],"Date":["Mon, 06 Jul 2020 08:26:48 GMT"],"Request-Id":["dc727677-1275-413b-b5a4-d42ab988622b"],"Response-Time":["1"],"Server":["gw2_api_market_data"],"Vary":["origin,access-control-request-method,access-control-request-headers"],"Content-Type":["application/json; charset=utf-8"]},"status":200}
Jul 06 10:26:48 Debian-102-buster-64-minimal caddy[9348]: {"level":"debug","ts":1594024008.3855257,"logger":"http.handlers.http_cache","msg":"cache handler","host":"api.silveress.ie","method":"GET","uri":"/gw2/v1/status?misc=uptime1","request time":0.001665571,"upstream request time":0.00153932}
Jul 06 10:26:48 Debian-102-buster-64-minimal caddy[9348]: {"level":"info","ts":1594024008.385569,"logger":"http.log.access.log3","msg":"handled request","request":{"method":"GET","uri":"/gw2/v1/status?misc=uptime1","proto":"HTTP/1.1","remote_addr":"69.162.124.237:47342","host":"api.silveress.ie","headers":{"User-Agent":["Mozilla/5.0+(compatible; UptimeRobot/2.0; http://www.uptimerobot.com/)"],"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"Accept-Charset":["ISO-8859-1,UTF-8;q=0.7,*;q=0.7"],"Accept-Encoding":["gzip, deflate"],"Accept-Language":["en-US,en;q=0.8"],"Connection":["close"],"Cache-Control":["no-cache"],"Referer":["https://api.silveress.ie/gw2/v1/status?misc=uptime1"]},"tls":{"resumed":false,"version":772,"ciphersuite":4865,"proto":"","proto_mutual":true,"server_name":"api.silveress.ie"}},"common_log":"69.162.124.237 - - [06/Jul/2020:10:26:48 +0200] \"GET /gw2/v1/status?misc=uptime1 HTTP/1.1\" 200 0","duration":0.001728661,"size":0,"status":200,"resp_headers":{"Api-Version":["2.2.3"],"Content-Md5":["kHSaUAGaJ+HzLOvbqnobwQ=="],"Vary":["origin,access-control-request-method,access-control-request-headers"],"Content-Length":["0"],"Access-Control-Allow-Origin":["*"],"X-Cache-Status":["miss"],"Content-Type":["application/json; charset=utf-8"],"Date":["Mon, 06 Jul 2020 08:26:48 GMT"],"Request-Id":["dc727677-1275-413b-b5a4-d42ab988622b"],"Response-Time":["1"]}}

Jul 06 10:27:08 Debian-102-buster-64-minimal caddy[9348]: {"level":"debug","ts":1594024028.7672164,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"localhost:8085","request":{"method":"GET","uri":"/gw2/v1/status?misc=uptime1","proto":"HTTP/1.1","remote_addr":"69.162.124.237:51554","host":"api.silveress.ie","headers":{"User-Agent":["Mozilla/5.0+(compatible; UptimeRobot/2.0; http://www.uptimerobot.com/)"],"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"Accept-Charset":["ISO-8859-1,UTF-8;q=0.7,*;q=0.7"],"X-Forwarded-Proto":["https"],"Referer":["https://api.silveress.ie/gw2/v1/status?misc=uptime1"],"Accept-Language":["en-US,en;q=0.8"],"Cache-Control":["no-cache"],"Accept-Encoding":["gzip, deflate"],"X-Forwarded-For":["69.162.124.237"]},"tls":{"resumed":false,"version":772,"ciphersuite":4865,"proto":"","proto_mutual":true,"server_name":"api.silveress.ie"}},"duration":0.000857493,"headers":{"Vary":["origin,access-control-request-method,access-control-request-headers"],"Content-Type":["application/json; charset=utf-8"],"Request-Id":["02849b94-4cb4-4184-ad33-d5487cd67325"],"Response-Time":["0"],"Server":["gw2_api_market_data"],"Content-Md5":["kHSaUAGaJ+HzLOvbqnobwQ=="],"Date":["Mon, 06 Jul 2020 08:27:08 GMT"],"Api-Version":["2.2.3"],"Connection":["Keep-Alive"]},"status":200}
Jul 06 10:27:08 Debian-102-buster-64-minimal caddy[9348]: {"level":"debug","ts":1594024028.767438,"logger":"http.handlers.http_cache","msg":"cache handler","host":"api.silveress.ie","method":"GET","uri":"/gw2/v1/status?misc=uptime1","request time":0.001218159,"upstream request time":0.001005734}
Jul 06 10:27:08 Debian-102-buster-64-minimal caddy[9348]: {"level":"info","ts":1594024028.7675006,"logger":"http.log.access.log3","msg":"handled request","request":{"method":"GET","uri":"/gw2/v1/status?misc=uptime1","proto":"HTTP/1.1","remote_addr":"69.162.124.237:51554","host":"api.silveress.ie","headers":{"Accept-Language":["en-US,en;q=0.8"],"Cache-Control":["no-cache"],"Accept-Encoding":["gzip, deflate"],"User-Agent":["Mozilla/5.0+(compatible; UptimeRobot/2.0; http://www.uptimerobot.com/)"],"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"Accept-Charset":["ISO-8859-1,UTF-8;q=0.7,*;q=0.7"],"Connection":["close"],"Referer":["https://api.silveress.ie/gw2/v1/status?misc=uptime1"]},"tls":{"resumed":false,"version":772,"ciphersuite":4865,"proto":"","proto_mutual":true,"server_name":"api.silveress.ie"}},"common_log":"69.162.124.237 - - [06/Jul/2020:10:27:08 +0200] \"GET /gw2/v1/status?misc=uptime1 HTTP/1.1\" 200 0","duration":0.001292381,"size":0,"status":200,"resp_headers":{"Api-Version":["2.2.3"],"Content-Md5":["kHSaUAGaJ+HzLOvbqnobwQ=="],"Date":["Mon, 06 Jul 2020 08:27:08 GMT"],"Request-Id":["02849b94-4cb4-4184-ad33-d5487cd67325"],"X-Cache-Status":["miss"],"Vary":["origin,access-control-request-method,access-control-request-headers"],"Content-Type":["application/json; charset=utf-8"],"Response-Time":["0"],"Content-Length":["0"],"Access-Control-Allow-Origin":["*"]}}
Jul 06 10:27:12 Debian-102-buster-64-minimal caddy[9348]: {"level":"debug","ts":1594024032.87792,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"localhost:8085","request":{"method":"GET","uri":"/gw2/v1/status?misc=uptime1","proto":"HTTP/1.1","remote_addr":"122.248.234.23:41896","host":"api.silveress.ie","headers":{"Accept-Charset":["ISO-8859-1,UTF-8;q=0.7,*;q=0.7"],"X-Forwarded-For":["122.248.234.23"],"User-Agent":["Mozilla/5.0+(compatible; UptimeRobot/2.0; http://www.uptimerobot.com/)"],"Accept-Language":["en-US,en;q=0.8"],"Referer":["https://api.silveress.ie/gw2/v1/status?misc=uptime1"],"Accept-Encoding":["gzip, deflate"],"X-Forwarded-Proto":["https"],"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"Cache-Control":["no-cache"]},"tls":{"resumed":false,"version":772,"ciphersuite":4865,"proto":"","proto_mutual":true,"server_name":"api.silveress.ie"}},"duration":0.000846973,"headers":{"Server":["gw2_api_market_data"],"Connection":["Keep-Alive"],"Date":["Mon, 06 Jul 2020 08:27:12 GMT"],"Api-Version":["2.2.3"],"Response-Time":["0"],"Vary":["origin,access-control-request-method,access-control-request-headers"],"Content-Type":["application/json; charset=utf-8"],"Content-Md5":["kHSaUAGaJ+HzLOvbqnobwQ=="],"Request-Id":["6f2a95d6-6b32-45d8-a7e5-4e2bca73aead"]},"status":200}
Jul 06 10:27:12 Debian-102-buster-64-minimal caddy[9348]: {"level":"debug","ts":1594024032.8781872,"logger":"http.handlers.http_cache","msg":"cache handler","host":"api.silveress.ie","method":"GET","uri":"/gw2/v1/status?misc=uptime1","request time":0.00125563,"upstream request time":0.001006536}
Jul 06 10:27:12 Debian-102-buster-64-minimal caddy[9348]: {"level":"info","ts":1594024032.878272,"logger":"http.log.access.log3","msg":"handled request","request":{"method":"GET","uri":"/gw2/v1/status?misc=uptime1","proto":"HTTP/1.1","remote_addr":"122.248.234.23:41896","host":"api.silveress.ie","headers":{"User-Agent":["Mozilla/5.0+(compatible; UptimeRobot/2.0; http://www.uptimerobot.com/)"],"Accept-Language":["en-US,en;q=0.8"],"Accept-Charset":["ISO-8859-1,UTF-8;q=0.7,*;q=0.7"],"Connection":["close"],"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"Cache-Control":["no-cache"],"Referer":["https://api.silveress.ie/gw2/v1/status?misc=uptime1"],"Accept-Encoding":["gzip, deflate"]},"tls":{"resumed":false,"version":772,"ciphersuite":4865,"proto":"","proto_mutual":true,"server_name":"api.silveress.ie"}},"common_log":"122.248.234.23 - - [06/Jul/2020:10:27:12 +0200] \"GET /gw2/v1/status?misc=uptime1 HTTP/1.1\" 200 0","duration":0.001335692,"size":0,"status":200,"resp_headers":{"Vary":["origin,access-control-request-method,access-control-request-headers"],"Access-Control-Allow-Origin":["*"],"Date":["Mon, 06 Jul 2020 08:27:12 GMT"],"Api-Version":["2.2.3"],"Content-Type":["application/json; charset=utf-8"],"Request-Id":["6f2a95d6-6b32-45d8-a7e5-4e2bca73aead"],"Content-Length":["0"],"X-Cache-Status":["miss"],"Response-Time":["0"],"Content-Md5":["kHSaUAGaJ+HzLOvbqnobwQ=="]}}
Jul 06 10:27:13 Debian-102-buster-64-minimal caddy[9348]: {"level":"debug","ts":1594024033.3108592,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"localhost:8085","request":{"method":"GET","uri":"/gw2/v1/status?misc=uptime1","proto":"HTTP/1.1","remote_addr":"46.101.250.135:36965","host":"api.silveress.ie","headers":{"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"Accept-Language":["en-US,en;q=0.8"],"Referer":["https://api.silveress.ie/gw2/v1/status?misc=uptime1"],"Accept-Encoding":["gzip, deflate"],"User-Agent":["Mozilla/5.0+(compatible; UptimeRobot/2.0; http://www.uptimerobot.com/)"],"Accept-Charset":["ISO-8859-1,UTF-8;q=0.7,*;q=0.7"],"Cache-Control":["no-cache"],"X-Forwarded-For":["46.101.250.135"],"X-Forwarded-Proto":["https"]},"tls":{"resumed":true,"version":772,"ciphersuite":4865,"proto":"","proto_mutual":true,"server_name":"api.silveress.ie"}},"duration":0.001216025,"headers":{"Vary":["origin,access-control-request-method,access-control-request-headers"],"Content-Type":["application/json; charset=utf-8"],"Api-Version":["2.2.3"],"Server":["gw2_api_market_data"],"Connection":["Keep-Alive"],"Content-Md5":["kHSaUAGaJ+HzLOvbqnobwQ=="],"Date":["Mon, 06 Jul 2020 08:27:13 GMT"],"Request-Id":["70f5a9fe-e529-409f-90e3-f94b19073d62"],"Response-Time":["0"]},"status":200}
Jul 06 10:27:13 Debian-102-buster-64-minimal caddy[9348]: {"level":"debug","ts":1594024033.3111043,"logger":"http.handlers.http_cache","msg":"cache handler","host":"api.silveress.ie","method":"GET","uri":"/gw2/v1/status?misc=uptime1","request time":0.001591921,"upstream request time":0.001366732}
Jul 06 10:27:13 Debian-102-buster-64-minimal caddy[9348]: {"level":"info","ts":1594024033.3111575,"logger":"http.log.access.log3","msg":"handled request","request":{"method":"GET","uri":"/gw2/v1/status?misc=uptime1","proto":"HTTP/1.1","remote_addr":"46.101.250.135:36965","host":"api.silveress.ie","headers":{"Connection":["close"],"Referer":["https://api.silveress.ie/gw2/v1/status?misc=uptime1"],"Accept-Encoding":["gzip, deflate"],"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"Accept-Language":["en-US,en;q=0.8"],"Cache-Control":["no-cache"],"User-Agent":["Mozilla/5.0+(compatible; UptimeRobot/2.0; http://www.uptimerobot.com/)"],"Accept-Charset":["ISO-8859-1,UTF-8;q=0.7,*;q=0.7"]},"tls":{"resumed":true,"version":772,"ciphersuite":4865,"proto":"","proto_mutual":true,"server_name":"api.silveress.ie"}},"common_log":"46.101.250.135 - - [06/Jul/2020:10:27:13 +0200] \"GET /gw2/v1/status?misc=uptime1 HTTP/1.1\" 200 0","duration":0.001660932,"size":0,"status":200,"resp_headers":{"X-Cache-Status":["miss"],"Content-Type":["application/json; charset=utf-8"],"Request-Id":["70f5a9fe-e529-409f-90e3-f94b19073d62"],"Access-Control-Allow-Origin":["*"],"Content-Length":["0"],"Date":["Mon, 06 Jul 2020 08:27:13 GMT"],"Api-Version":["2.2.3"],"Response-Time":["0"],"Vary":["origin,access-control-request-method,access-control-request-headers"],"Content-Md5":["kHSaUAGaJ+HzLOvbqnobwQ=="]}}

Jul 06 10:32:08 Debian-102-buster-64-minimal caddy[9348]: {"level":"debug","ts":1594024328.3454297,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"localhost:8085","request":{"method":"GET","uri":"/gw2/v1/status?misc=uptime1","proto":"HTTP/1.1","remote_addr":"69.162.124.237:38050","host":"api.silveress.ie","headers":{"Accept-Language":["en-US,en;q=0.8"],"Accept-Encoding":["gzip, deflate"],"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"Accept-Charset":["ISO-8859-1,UTF-8;q=0.7,*;q=0.7"],"X-Forwarded-For":["69.162.124.237"],"Cache-Control":["no-cache"],"Referer":["https://api.silveress.ie/gw2/v1/status?misc=uptime1"],"X-Forwarded-Proto":["https"],"User-Agent":["Mozilla/5.0+(compatible; UptimeRobot/2.0; http://www.uptimerobot.com/)"]},"tls":{"resumed":false,"version":772,"ciphersuite":4865,"proto":"","proto_mutual":true,"server_name":"api.silveress.ie"}},"duration":0.002288225,"headers":{"Server":["gw2_api_market_data"],"Vary":["origin,access-control-request-method,access-control-request-headers"],"Content-Type":["application/json; charset=utf-8"],"Connection":["Keep-Alive"],"Content-Md5":["kHSaUAGaJ+HzLOvbqnobwQ=="],"Api-Version":["2.2.3"],"Request-Id":["de7638e0-0148-4b19-8a64-86bf9d297882"],"Date":["Mon, 06 Jul 2020 08:32:08 GMT"],"Response-Time":["1"]},"status":200}
Jul 06 10:32:08 Debian-102-buster-64-minimal caddy[9348]: {"level":"debug","ts":1594024328.345701,"logger":"http.handlers.http_cache","msg":"cache handler","host":"api.silveress.ie","method":"GET","uri":"/gw2/v1/status?misc=uptime1","request time":0.002699277,"upstream request time":0.002442248}
Jul 06 10:32:08 Debian-102-buster-64-minimal caddy[9348]: {"level":"info","ts":1594024328.3457546,"logger":"http.log.access.log3","msg":"handled request","request":{"method":"GET","uri":"/gw2/v1/status?misc=uptime1","proto":"HTTP/1.1","remote_addr":"69.162.124.237:38050","host":"api.silveress.ie","headers":{"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"Accept-Language":["en-US,en;q=0.8"],"Accept-Encoding":["gzip, deflate"],"Referer":["https://api.silveress.ie/gw2/v1/status?misc=uptime1"],"User-Agent":["Mozilla/5.0+(compatible; UptimeRobot/2.0; http://www.uptimerobot.com/)"],"Accept-Charset":["ISO-8859-1,UTF-8;q=0.7,*;q=0.7"],"Connection":["close"],"Cache-Control":["no-cache"]},"tls":{"resumed":false,"version":772,"ciphersuite":4865,"proto":"","proto_mutual":true,"server_name":"api.silveress.ie"}},"common_log":"69.162.124.237 - - [06/Jul/2020:10:32:08 +0200] \"GET /gw2/v1/status?misc=uptime1 HTTP/1.1\" 200 0","duration":0.002769841,"size":0,"status":200,"resp_headers":{"Request-Id":["de7638e0-0148-4b19-8a64-86bf9d297882"],"Response-Time":["1"],"X-Cache-Status":["miss"],"Content-Type":["application/json; charset=utf-8"],"Content-Md5":["kHSaUAGaJ+HzLOvbqnobwQ=="],"Access-Control-Allow-Origin":["*"],"Api-Version":["2.2.3"],"Vary":["origin,access-control-request-method,access-control-request-headers"],"Date":["Mon, 06 Jul 2020 08:32:08 GMT"],"Content-Length":["0"]}}
sillygod commented 4 years ago

Hi @Silver-Golden ,

It seems that it is a little hard to find the root cause. Maybe we should try more tests to dig it out. May I know how your Caddyfile looks like?

sillygod commented 4 years ago

Hi @Silver-Golden ,

The following image is the health check for the cache server (which is built on version v0.3.8)

image

I don't encounter the situation you mentioned. There are just fewer picks because of the latency from far region.

In addition, I've also registered the monitor service (which you used)

image

This also looks good.

I think the problem is not related to the cache server.

Silver-Golden commented 4 years ago

I completely forgot to follow this up, I was busy with a rust project and lost track of time.

I'll dig in a bit deeper today, to see if I can recreate it and if I can when the problem arose.

sillygod commented 4 years ago

@Silver-Golden ,

Never mind, I just curious about what happened. BTW, I think the uptimerobot's health check is not stable. I will show you what I find. Go to see the following two images.

it shows a high pick below. image

However, there is not such high pick in the google's uptime check. image

PS: In order to compare, both of the time zones are set on UTC+8.

So if you configure the timeout(maybe 1 second) in the uptimerobot, it will judge the cache server is down when the peak appears.

Maybe, you can use another solution to monitor the cache server. Ex. google's uptime checks. It's so steady :) (you can see that from the above image).

Silver-Golden commented 4 years ago

So I used 0.3.7 to compile it.
I then waited about an hour before enabling teh cache for this endpoint.
When I did enable it the periodic timeout and access started happening.

xcaddy build v2.1.0-beta.1 --with github.com/caddy-dns/cloudflare --with github.com/sillygod/cdp-cache@v0.3.7

image

I'll do 0.3.6 next

Silver-Golden commented 4 years ago

Update

image

Same procedure as above:

  1. Disable cache for the endpoint
  2. Compile and install next version
  3. Wait about 10 min so tehre is a gap in the data
  4. Enable cache in config and restart caddy
  5. Wait anoterh 10 min or so to see the result

The red sections in order are 0.3.7 (as above), 0.3.6, 0.3.5 and 0.3.4 which has no red/timeouts.

I suspect that something changed between 0.3.4 and 0.3.5 that is giving this behaviour.
I am still not sure if its actually impacting users but it is spamming my inbox

Silver-Golden commented 4 years ago

Ugh as soon as I posted that I refreshed the monitor and seems like 0.3.4 is giving a timeout now, back to testing

Silver-Golden commented 4 years ago

0.3.3 gaves timeouts as well and now back to 0.3.2 which is not giving the timeouts.

Looking back I probally should have started with 0.3.2 and gone up

sillygod commented 4 years ago

I consider closing this issue if there is no example to reproduce this bug. Until now, I still can not find a way to reproduce this one.