[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

apt-cacher-ng ""500 Bad redirection (path)" - some debugging info



I have been observing intermittent "500 Bad redirection (path)" errors
from apt-cacher-ng. This is something which appears to have been reported
before but not resolved: e.g.
https://lists.debian.org/debian-user/2015/03/msg00877.html

However I have been able to capture some information, including tcpdumps
of traffic in and out of apt-cacher-ng, which might help.

* Client node (10.10.10.18) is Debian Wheezy

Here's what's seen on the client:

root@node18:~# apt-get update
Hit http://security.debian.org wheezy/updates Release.gpg
Ign http://ftp.uk.debian.org wheezy Release.gpg
Hit http://security.debian.org wheezy/updates Release
Ign http://ftp.uk.debian.org wheezy-updates Release.gpg
Hit http://security.debian.org wheezy/updates/main Sources
Ign http://ftp.uk.debian.org wheezy Release
Hit http://security.debian.org wheezy/updates/contrib Sources
Ign http://ftp.uk.debian.org wheezy-updates Release
Hit http://security.debian.org wheezy/updates/non-free Sources
Hit http://security.debian.org wheezy/updates/main amd64 Packages
Hit http://security.debian.org wheezy/updates/contrib amd64 Packages
Hit http://security.debian.org wheezy/updates/non-free amd64 Packages
Hit http://security.debian.org wheezy/updates/contrib Translation-en
Hit http://security.debian.org wheezy/updates/main Translation-en
Hit http://security.debian.org wheezy/updates/non-free Translation-en
Err http://ftp.uk.debian.org wheezy/main Sources
  500  Bad redirection (path)
Err http://ftp.uk.debian.org wheezy/contrib Sources
  500  Bad redirection (path)
Err http://ftp.uk.debian.org wheezy/non-free Sources
  500  Bad redirection (path)
Err http://ftp.uk.debian.org wheezy/main amd64 Packages
  500  Bad redirection (path)
Err http://ftp.uk.debian.org wheezy/contrib amd64 Packages
  500  Bad redirection (path)
Err http://ftp.uk.debian.org wheezy/non-free amd64 Packages
  500  Bad redirection (path)
Ign http://ftp.uk.debian.org wheezy/contrib Translation-en_US
Ign http://ftp.uk.debian.org wheezy/contrib Translation-en
Ign http://ftp.uk.debian.org wheezy/main Translation-en_US
Ign http://ftp.uk.debian.org wheezy/main Translation-en
Ign http://ftp.uk.debian.org wheezy/non-free Translation-en_US
Ign http://ftp.uk.debian.org wheezy/non-free Translation-en
Err http://ftp.uk.debian.org wheezy-updates/main Sources
  500  Bad redirection (path)
Err http://ftp.uk.debian.org wheezy-updates/contrib Sources
  500  Bad redirection (path)
Err http://ftp.uk.debian.org wheezy-updates/non-free Sources
  500  Bad redirection (path)
Err http://ftp.uk.debian.org wheezy-updates/main amd64 Packages
  500  Bad redirection (path)
Err http://ftp.uk.debian.org wheezy-updates/contrib amd64 Packages
  500  Bad redirection (path)
Err http://ftp.uk.debian.org wheezy-updates/non-free amd64 Packages
  500  Bad redirection (path)
Ign http://ftp.uk.debian.org wheezy-updates/contrib Translation-en_US
Ign http://ftp.uk.debian.org wheezy-updates/contrib Translation-en
Ign http://ftp.uk.debian.org wheezy-updates/main Translation-en_US
Ign http://ftp.uk.debian.org wheezy-updates/main Translation-en
Ign http://ftp.uk.debian.org wheezy-updates/non-free Translation-en_US
Ign http://ftp.uk.debian.org wheezy-updates/non-free Translation-en
W: Failed to fetch http://ftp.uk.debian.org/debian/dists/wheezy/main/source/Sources 500 Bad redirection (path)

W: Failed to fetch http://ftp.uk.debian.org/debian/dists/wheezy/contrib/source/Sources 500 Bad redirection (path)

W: Failed to fetch http://ftp.uk.debian.org/debian/dists/wheezy/non-free/source/Sources 500 Bad redirection (path)

W: Failed to fetch http://ftp.uk.debian.org/debian/dists/wheezy/main/binary-amd64/Packages 500 Bad redirection (path)

W: Failed to fetch http://ftp.uk.debian.org/debian/dists/wheezy/contrib/binary-amd64/Packages 500 Bad redirection (path)

W: Failed to fetch http://ftp.uk.debian.org/debian/dists/wheezy/non-free/binary-amd64/Packages 500 Bad redirection (path)

W: Failed to fetch http://ftp.uk.debian.org/debian/dists/wheezy-updates/main/source/Sources 500 Bad redirection (path)

W: Failed to fetch http://ftp.uk.debian.org/debian/dists/wheezy-updates/contrib/source/Sources 500 Bad redirection (path)

W: Failed to fetch http://ftp.uk.debian.org/debian/dists/wheezy-updates/non-free/source/Sources 500 Bad redirection (path)

W: Failed to fetch http://ftp.uk.debian.org/debian/dists/wheezy-updates/main/binary-amd64/Packages 500 Bad redirection (path)

W: Failed to fetch http://ftp.uk.debian.org/debian/dists/wheezy-updates/contrib/binary-amd64/Packages 500 Bad redirection (path)

W: Failed to fetch http://ftp.uk.debian.org/debian/dists/wheezy-updates/non-free/binary-amd64/Packages 500 Bad redirection (path)

E: Some index files failed to download. They have been ignored, or old ones used instead.

* Configuration of the client node

=== /etc/apt/sources.list ===
deb http://ftp.uk.debian.org/debian wheezy main contrib non-free
deb-src http://ftp.uk.debian.org/debian wheezy main contrib non-free

deb http://security.debian.org/ wheezy/updates main contrib non-free
deb-src http://security.debian.org/ wheezy/updates main contrib non-free

# wheezy-updates, previously known as 'volatile'
deb http://ftp.uk.debian.org/debian wheezy-updates main contrib non-free
deb-src http://ftp.uk.debian.org/debian wheezy-updates main contrib non-free

=== /etc/apt/apt.conf ===
Acquire::http::Proxy "http://apt.virt.nsrc.org:3142/";;

(this name resolves via private DNS to 10.10.10.239)

* apt-cacher node is also Debian Wheezy, and running apt-cacher-ng 0.8.0-3~bpo70+1
  from wheezy/backports. It has address 10.10.10.239 on its internal
interface, and has a separate external (public IP) interface, and is also running a
  local instance of bind as a caching resolver.

* I have pcap files from when this happens.

It's hard to be sure what's going on because there are concurrent HTTP requests from the client and from the client to the outside world. However here's an example of what's seen on the client side:

09:01:22.720227 IP 10.10.10.18.36112 > 10.10.10.239.3142: Flags [P.], seq 1:168, ack 1, win 115, options [nop,nop,TS val 498179 ecr 15462960], length 167
        0x0000:  4500 00db f1c2 4000 4006 1f46 0a0a 0a12 E.....@.@..F....
        0x0010:  0a0a 0aef 8d10 0c46 d617 6bc4 84d0 bd3a .......F..k....:
        0x0020:  8018 0073 2019 0000 0101 080a 0007 9a03 ...s............
        0x0030:  00eb f230 4745 5420 6874 7470 3a2f 2f66 ...0GET.http://f
        0x0040:  7470 2e75 6b2e 6465 6269 616e 2e6f 7267 tp.uk.debian.org
        0x0050:  2f64 6562 6961 6e2f 6469 7374 732f 7768 /debian/dists/wh
        0x0060:  6565 7a79 2f52 656c 6561 7365 2e67 7067 eezy/Release.gpg
        0x0070:  2048 5454 502f 312e 310d 0a48 6f73 743a .HTTP/1.1..Host:
        0x0080:  2066 7470 2e75 6b2e 6465 6269 616e 2e6f .ftp.uk.debian.o
        0x0090:  7267 0d0a 4361 6368 652d 436f 6e74 726f rg..Cache-Contro
        0x00a0:  6c3a 206d 6178 2d61 6765 3d30 0d0a 5573 l:.max-age=0..Us
        0x00b0:  6572 2d41 6765 6e74 3a20 4465 6269 616e er-Agent:.Debian
        0x00c0:  2041 5054 2d48 5454 502f 312e 3320 2830 .APT-HTTP/1.3.(0
        0x00d0:  2e39 2e37 2e39 290d 0a0d 0a .9.7.9)....
...
09:01:24.474510 IP 10.10.10.18.36111 > 10.10.10.239.3142: Flags [P.], seq 691:928, ack 669, win 140, opti
ons [nop,nop,TS val 498617 ecr 15463397], length 237
        0x0000:  4500 0121 fa67 4000 4006 165b 0a0a 0a12 E..!.g@.@..[....
        0x0010:  0a0a 0aef 8d0f 0c46 52c0 6315 251f be2e .......FR.c.%...
        0x0020:  8018 008c e120 0000 0101 080a 0007 9bb9 ................
        0x0030:  00eb f3e5 4745 5420 6874 7470 3a2f 2f73 ....GET.http://s
        0x0040:  6563 7572 6974 792e 6465 6269 616e 2e6f ecurity.debian.o
        0x0050:  7267 2f64 6973 7473 2f77 6865 657a 792f rg/dists/wheezy/
        0x0060:  7570 6461 7465 732f 636f 6e74 7269 622f updates/contrib/
        0x0070:  736f 7572 6365 2f53 6f75 7263 6573 2e62 source/Sources.b
        0x0080:  7a32 2048 5454 502f 312e 310d 0a48 6f73 z2.HTTP/1.1..Hos
        0x0090:  743a 2073 6563 7572 6974 792e 6465 6269 t:.security.debi
        0x00a0:  616e 2e6f 7267 0d0a 4361 6368 652d 436f an.org..Cache-Co
        0x00b0:  6e74 726f 6c3a 206d 6178 2d61 6765 3d30 ntrol:.max-age=0
        0x00c0:  0d0a 4966 2d4d 6f64 6966 6965 642d 5369 ..If-Modified-Si
        0x00d0:  6e63 653a 2054 7565 2c20 3139 204a 616e nce:.Tue,.19.Jan
        0x00e0:  2032 3031 3620 3230 3a35 303a 3433 2047 .2016.20:50:43.G
        0x00f0:  4d54 0d0a 5573 6572 2d41 6765 6e74 3a20 MT..User-Agent:.
        0x0100:  4465 6269 616e 2041 5054 2d48 5454 502f Debian.APT-HTTP/
        0x0110:  312e 3320 2830 2e39 2e37 2e39 290d 0a0d 1.3.(0.9.7.9)...
        0x0120:  0a                                       .
09:01:24.474557 IP 10.10.10.239.3142 > 10.10.10.18.36111: Flags [.], ack 928, win 147, options [nop,nop,T
S val 15463399 ecr 498617], length 0
        0x0000:  4500 0034 49a8 4000 4006 c807 0a0a 0aef E..4I.@.@.......
        0x0010:  0a0a 0a12 0c46 8d0f 251f be2e 52c0 6402 .....F..%...R.d.
        0x0020:  8010 0093 293b 0000 0101 080a 00eb f3e7 ....);..........
        0x0030:  0007 9bb9                                ....
09:01:24.825323 IP 10.10.10.239.3142 > 10.10.10.18.36112: Flags [P.], seq 1036:1381, ack 709, win 147, op
tions [nop,nop,TS val 15463487 ecr 498611], length 345
        0x0000:  4500 018d 4f11 4000 4006 c145 0a0a 0aef E...O.@.@..E....
        0x0010:  0a0a 0a12 0c46 8d10 84d0 c145 d617 6e88 .....F.....E..n.
        0x0020:  8018 0093 2a94 0000 0101 080a 00eb f43f ....*..........?
        0x0030:  0007 9bb3 4854 5450 2f31 2e31 2035 3030 ....HTTP/1.1.500
        0x0040:  2042 6164 2072 6564 6972 6563 7469 6f6e .Bad.redirection
        0x0050:  2028 7061 7468 290d 0a43 6f6e 7465 6e74 .(path)..Content
        0x0060:  2d4c 656e 6774 683a 2031 3638 0d0a 436f -Length:.168..Co
        0x0070:  6e74 656e 742d 5479 7065 3a20 7465 7874 ntent-Type:.text
        0x0080:  2f68 746d 6c0d 0a44 6174 653a 2057 6564 /html..Date:.Wed
        0x0090:  204a 616e 2032 3020 3039 3a30 313a 3234 .Jan.20.09:01:24
        0x00a0:  2032 3031 360d 0a53 6572 7665 723a 2044 .2016..Server:.D
        0x00b0:  6562 6961 6e20 4170 742d 4361 6368 6572 ebian.Apt-Cacher
        0x00c0:  204e 472f 302e 382e 300d 0a43 6f6e 6e65 .NG/0.8.0..Conne
        0x00d0:  6374 696f 6e3a 204b 6565 702d 416c 6976 ction:.Keep-Aliv
        0x00e0:  650d 0a0d 0a3c 2144 4f43 5459 5045 2048 e....<!DOCTYPE.H
        0x00f0:  544d 4c20 5055 424c 4943 2022 2d2f 2f49 TML.PUBLIC."-//I
        0x0100:  4554 462f 2f44 5444 2048 544d 4c20 322e ETF//DTD.HTML.2.
        0x0110:  302f 2f45 4e22 3e0a 3c68 746d 6c3e 3c68 0//EN">.<html><h
        0x0120:  6561 643e 3c74 6974 6c65 3e35 3030 2042 ead><title>500.B
        0x0130:  6164 2072 6564 6972 6563 7469 6f6e 2028 ad.redirection.(
        0x0140:  7061 7468 293c 2f74 6974 6c65 3e0a 3c2f path)</title>.</
        0x0150:  6865 6164 3e0a 3c62 6f64 793e 3c68 313e head>.<body><h1>
        0x0160:  3530 3020 4261 6420 7265 6469 7265 6374 500.Bad.redirect
        0x0170:  696f 6e20 2870 6174 6829 3c2f 6831 3e3c ion.(path)</h1><
        0x0180:  2f62 6f64 793e 3c2f 6874 6d6c 3e /body></html>

* And some example of tcpdump seen on the external side:

09:01:22.721838 IP (tos 0x0, ttl 64, id 55046, offset 0, flags [none], proto UDP (17), length 76) XXX.XXX.XXX.123.56656 > 194.177.211.201.53: 2342% [1au] A? security.debian.org. (48) 09:01:22.721955 IP (tos 0x0, ttl 64, id 55047, offset 0, flags [none], proto UDP (17), length 76) XXX.XXX.XXX.123.57004 > 194.177.211.201.53: 39257% [1au] AAAA? security.debian.org. (48) 09:01:22.937099 IP (tos 0x0, ttl 47, id 16641, offset 0, flags [none], proto UDP (17), length 635) 194.177.211.201.53 > XXX.XXX.XXX.123.56656: 2342*- 2/4/1 security.debian.org. A 133.242.99.74, security.debian.org. RRSIG (607) 09:01:22.937131 IP (tos 0x0, ttl 47, id 16642, offset 0, flags [none], proto UDP (17), length 647) 194.177.211.201.53 > XXX.XXX.XXX.123.57004: 39257*- 2/4/1 security.debian.org. AAAA 2401:2500:103:11a::74, security.debian.org. RRSIG (619)
...
09:01:24.474812 IP XXX.XXX.XXX.123.59862 > 133.242.99.74.80: Flags [P.], seq 871:1170, ack 1271, win 140, options [nop,nop,TS val 15463399 ecr 5644001], length 299
        0x0000:  4500 015f 9d26 4000 4006 2714 caa6 c17b E.._.&@.@.'....{
        0x0010:  85f2 634a e9d6 0050 45da 72e0 f419 b889 ..cJ...PE.r.....
        0x0020:  8018 008c 76b0 0000 0101 080a 00eb f3e7 ....v...........
        0x0030:  0056 1ee1 4745 5420 2f64 6973 7473 2f77 .V..GET./dists/w
        0x0040:  6865 657a 792f 7570 6461 7465 732f 636f heezy/updates/co
        0x0050:  6e74 7269 622f 736f 7572 6365 2f53 6f75 ntrib/source/Sou
        0x0060:  7263 6573 2e62 7a32 2048 5454 502f 312e rces.bz2.HTTP/1.
        0x0070:  310d 0a55 7365 722d 4167 656e 743a 2044 1..User-Agent:.D
        0x0080:  6562 6961 6e20 4170 742d 4361 6368 6572 ebian.Apt-Cacher
        0x0090:  2d4e 472f 302e 382e 300d 0a48 6f73 743a -NG/0.8.0..Host:
        0x00a0:  2073 6563 7572 6974 792e 6465 6269 616e .security.debian
        0x00b0:  2e6f 7267 0d0a 5261 6e67 653a 2062 7974 .org..Range:.byt
        0x00c0:  6573 3d31 332d 0d0a 4966 2d52 616e 6765 es=13-..If-Range
        0x00d0:  3a20 5475 652c 2031 3920 4a61 6e20 3230 :.Tue,.19.Jan.20
        0x00e0:  3136 2032 303a 3530 3a34 3320 474d 540d 16.20:50:43.GMT.
        0x00f0:  0a43 6163 6865 2d43 6f6e 7472 6f6c 3a20 .Cache-Control:.
        0x0100:  6e6f 2d73 746f 7265 2c6e 6f2d 6361 6368 no-store,no-cach
        0x0110:  652c 6d61 782d 6167 653d 300d 0a41 6363 e,max-age=0..Acc
        0x0120:  6570 743a 202a 2f2a 0d0a 4163 6365 7074 ept:.*/*..Accept
        0x0130:  2d45 6e63 6f64 696e 673a 2069 6465 6e74 -Encoding:.ident
        0x0140:  6974 790d 0a43 6f6e 6e65 6374 696f 6e3a ity..Connection:
        0x0150:  206b 6565 702d 616c 6976 650d 0a0d 0a .keep-alive....
09:01:24.631914 IP 176.9.184.93.80 > XXX.XXX.XXX.123.51711: Flags [F.], seq 291, ack 280, win 235, options [nop,nop,TS val 1443953956 ecr 15463395], length 0
        0x0000:  4500 0034 e142 4000 3406 70f8 b009 b85d E..4.B@.4.p....]
        0x0010:  caa6 c17b 0050 c9ff 35d7 1ee9 a42b 5160 ...{.P..5....+Q`
        0x0020:  8011 00eb 24a8 0000 0101 080a 5610 fd24 ....$.......V..$
        0x0030:  00eb f3e3                                ....
09:01:24.631949 IP XXX.XXX.XXX.123.51711 > 176.9.184.93.80: Flags [.], ack 292, win 123, options [nop,nop,TS val 15463438 ecr 1443953956], length 0
        0x0000:  4500 0034 a3c9 4000 4006 a271 caa6 c17b E..4..@.@..q...{
        0x0010:  b009 b85d c9ff 0050 a42b 5160 35d7 1eea ...]...P.+Q`5...
        0x0020:  8010 007b f4af 0000 0101 080a 00eb f40e ...{............
        0x0030:  5610 fd24                                V..$
09:01:24.641615 IP 176.9.184.93.80 > XXX.XXX.XXX.123.51712: Flags [S.], seq 64911450, ack 1591232627, win 28960, options [mss 1460,sackOK,TS val 1443953958 ecr 15463395,nop,wscale 7], length 0
        0x0000:  4500 003c 0000 4000 3406 5233 b009 b85d E..<..@.4.R3...]
        0x0010:  caa6 c17b 0050 ca00 03de 785a 5ed8 4873 ...{.P....xZ^.Hs
        0x0020:  a012 7120 ac6b 0000 0204 05b4 0402 080a ..q..k..........
        0x0030:  5610 fd26 00eb f3e3 0103 0307 V..&........
09:01:24.641653 IP XXX.XXX.XXX.123.51712 > 176.9.184.93.80: Flags [.], ack 1, win 115, options [nop,nop,TS val 15463441 ecr 1443953958], length 0
        0x0000:  4500 0034 bb92 4000 4006 8aa8 caa6 c17b E..4..@.@......{
        0x0010:  b009 b85d ca00 0050 5ed8 4873 03de 785b ...]...P^.Hs..x[
        0x0020:  8010 0073 f4af 0000 0101 080a 00eb f411 ...s............
        0x0030:  5610 fd26                                V..&
09:01:24.641736 IP XXX.XXX.XXX.123.51712 > 176.9.184.93.80: Flags [P.], seq 1:287, ack 1, win 115, options [nop,nop,TS val 15463441 ecr 1443953958], length 286
        0x0000:  4500 0152 bb93 4000 4006 8989 caa6 c17b E..R..@.@......{
        0x0010:  b009 b85d ca00 0050 5ed8 4873 03de 785b ...]...P^.Hs..x[
        0x0020:  8018 0073 f5cd 0000 0101 080a 00eb f411 ...s............
        0x0030:  5610 fd26 4745 5420 2f64 6562 6961 6e2f V..&GET./debian/
        0x0040:  6469 7374 732f 7768 6565 7a79 2d75 7064 dists/wheezy-upd
        0x0050:  6174 6573 2f52 656c 6561 7365 2048 5454 ates/Release.HTT
        0x0060:  502f 312e 310d 0a55 7365 722d 4167 656e P/1.1..User-Agen
        0x0070:  743a 2044 6562 6961 6e20 4170 742d 4361 t:.Debian.Apt-Ca
        0x0080:  6368 6572 2d4e 472f 302e 382e 300d 0a48 cher-NG/0.8.0..H
        0x0090:  6f73 743a 2063 646e 2e64 6562 6961 6e2e ost:.cdn.debian.
        0x00a0:  6e65 740d 0a52 616e 6765 3a20 6279 7465 net..Range:.byte
        0x00b0:  733d 3134 3334 3036 2d0d 0a49 662d 5261 s=143406-..If-Ra
        0x00c0:  6e67 653a 2054 7565 2c20 3139 204a 616e nge:.Tue,.19.Jan
        0x00d0:  2032 3031 3620 3231 3a30 373a 3039 2047 .2016.21:07:09.G
        0x00e0:  4d54 0d0a 4361 6368 652d 436f 6e74 726f MT..Cache-Contro
        0x00f0:  6c3a 206e 6f2d 7374 6f72 652c 6e6f 2d63 l:.no-store,no-c
        0x0100:  6163 6865 2c6d 6178 2d61 6765 3d30 0d0a ache,max-age=0..
        0x0110:  4163 6365 7074 3a20 2a2f 2a0d 0a41 6363 Accept:.*/*..Acc
        0x0120:  6570 742d 456e 636f 6469 6e67 3a20 6964 ept-Encoding:.id
        0x0130:  656e 7469 7479 0d0a 436f 6e6e 6563 7469 entity..Connecti
        0x0140:  6f6e 3a20 6b65 6570 2d61 6c69 7665 0d0a on:.keep-alive..
        0x0150:  0d0a                                     ..
09:01:24.690896 IP 133.242.99.74.80 > XXX.XXX.XXX.123.59862: Flags [P.], seq 1271:1704, ack 1170, win 260, options [nop,nop,TS val 5644110 ecr 15463399], length 433
        0x0000:  4500 01e5 ad94 4000 3006 2620 85f2 634a E.....@.0.&...cJ
        0x0010:  caa6 c17b 0050 e9d6 f419 b889 45da 740b ...{.P......E.t.
        0x0020:  8018 0104 ce80 0000 0101 080a 0056 1f4e .............V.N
        0x0030:  00eb f3e7 4854 5450 2f31 2e31 2032 3036 ....HTTP/1.1.206
        0x0040:  2050 6172 7469 616c 2043 6f6e 7465 6e74 .Partial.Content
        0x0050:  0d0a 4461 7465 3a20 5765 642c 2032 3020 ..Date:.Wed,.20.
        0x0060:  4a61 6e20 3230 3136 2030 393a 3031 3a32 Jan.2016.09:01:2
        0x0070:  3420 474d 540d 0a53 6572 7665 723a 2041 4.GMT..Server:.A
        0x0080:  7061 6368 650d 0a4c 6173 742d 4d6f 6469 pache..Last-Modi
        0x0090:  6669 6564 3a20 5475 652c 2031 3920 4a61 fied:.Tue,.19.Ja
        0x00a0:  6e20 3230 3136 2032 303a 3530 3a34 3320 n.2016.20:50:43.
        0x00b0:  474d 540d 0a45 5461 673a 2022 652d 3532 GMT..ETag:."e-52
        0x00c0:  3962 3630 3565 6365 6664 6622 0d0a 4163 9b605ecefdf"..Ac
        0x00d0:  6365 7074 2d52 616e 6765 733a 2062 7974 cept-Ranges:.byt
        0x00e0:  6573 0d0a 436f 6e74 656e 742d 4c65 6e67 es..Content-Leng
        0x00f0:  7468 3a20 310d 0a43 6163 6865 2d43 6f6e th:.1..Cache-Con
        0x0100:  7472 6f6c 3a20 6d61 782d 6167 653d 312c trol:.max-age=1,
        0x0110:  2070 7562 6c69 630d 0a45 7870 6972 6573 .public..Expires
        0x0120:  3a20 5765 642c 2032 3020 4a61 6e20 3230 :.Wed,.20.Jan.20
        0x0130:  3136 2030 393a 3031 3a32 3520 474d 540d 16.09:01:25.GMT.
        0x0140:  0a58 2d43 6c61 636b 732d 4f76 6572 6865 .X-Clacks-Overhe
        0x0150:  6164 3a20 474e 5520 5465 7272 7920 5072 ad:.GNU.Terry.Pr
        0x0160:  6174 6368 6574 740d 0a43 6f6e 7465 6e74 atchett..Content
        0x0170:  2d52 616e 6765 3a20 6279 7465 7320 3133 -Range:.bytes.13
        0x0180:  2d31 332f 3134 0d0a 4b65 6570 2d41 6c69 -13/14..Keep-Ali
        0x0190:  7665 3a20 7469 6d65 6f75 743d 352c 206d ve:.timeout=5,.m
        0x01a0:  6178 3d39 370d 0a43 6f6e 6e65 6374 696f ax=97..Connectio
        0x01b0:  6e3a 204b 6565 702d 416c 6976 650d 0a43 n:.Keep-Alive..C
        0x01c0:  6f6e 7465 6e74 2d54 7970 653a 2061 7070 ontent-Type:.app
        0x01d0:  6c69 6361 7469 6f6e 2f78 2d62 7a69 7032 lication/x-bzip2
        0x01e0:  0d0a 0d0a 00                             .....
09:01:24.690934 IP XXX.XXX.XXX.123.59862 > 133.242.99.74.80: Flags [.], ack 1704, win 148, options [nop,nop,TS val 15463453 ecr 5644110], length 0
        0x0000:  4500 0034 9d27 4000 4006 283e caa6 c17b E..4.'@.@.(>...{
        0x0010:  85f2 634a e9d6 0050 45da 740b f419 ba3a ..cJ...PE.t....:
        0x0020:  8010 0094 7585 0000 0101 080a 00eb f41d ....u...........
        0x0030:  0056 1f4e                                .V.N
09:01:24.823956 IP 176.9.184.93.80 > XXX.XXX.XXX.123.51712: Flags [.], ack 287, win 235, options [nop,nop,TS val 1443954004 ecr 15463441], length 0
        0x0000:  4500 0034 850f 4000 3406 cd2b b009 b85d E..4..@.4..+...]
        0x0010:  caa6 c17b 0050 ca00 03de 785b 5ed8 4991 ...{.P....x[^.I.
        0x0020:  8010 00eb 49f3 0000 0101 080a 5610 fd54 ....I.......V..T
        0x0030:  00eb f411                                ....
09:01:24.825048 IP 176.9.184.93.80 > XXX.XXX.XXX.123.51712: Flags [P.], seq 1:268, ack 287, win 235, options [nop,nop,TS val 1443954004 ecr 15463441], length 267
        0x0000:  4500 013f 8510 4000 3406 cc1f b009 b85d E..?..@.4......]
        0x0010:  caa6 c17b 0050 ca00 03de 785b 5ed8 4991 ...{.P....x[^.I.
        0x0020:  8018 00eb 8958 0000 0101 080a 5610 fd54 .....X......V..T
        0x0030:  00eb f411 4854 5450 2f31 2e31 2033 3032 ....HTTP/1.1.302
        0x0040:  2046 6f75 6e64 0d0a 4461 7465 3a20 5765 .Found..Date:.We
        0x0050:  642c 2032 3020 4a61 6e20 3230 3136 2030 d,.20.Jan.2016.0
        0x0060:  393a 3033 3a32 3620 474d 540d 0a4c 6f63 9:03:26.GMT..Loc
        0x0070:  6174 696f 6e3a 2068 7474 703a 2f2f 6465 ation:.http://de
        0x0080:  6269 616e 6d69 7272 6f72 2e6e 6b6e 2e69 bianmirror.nkn.i
        0x0090:  6e2f 6465 6269 616e 2f64 6973 7473 2f77 n/debian/dists/w
        0x00a0:  6865 657a 792d 7570 6461 7465 732f 5265 heezy-updates/Re
        0x00b0:  6c65 6173 650d 0a43 6f6e 7465 6e74 2d54 lease..Content-T
        0x00c0:  7970 653a 2074 6578 742f 706c 6169 6e0d ype:.text/plain.
        0x00d0:  0a56 6172 793a 2041 6363 6570 742d 456e .Vary:.Accept-En
        0x00e0:  636f 6469 6e67 0d0a 4b65 6570 2d41 6c69 coding..Keep-Ali
        0x00f0:  7665 3a20 7469 6d65 6f75 743d 3130 2c20 ve:.timeout=10,.
        0x0100:  6d61 783d 3230 300d 0a43 6f6e 6e65 6374 max=200..Connect
        0x0110:  696f 6e3a 204b 6565 702d 416c 6976 650d ion:.Keep-Alive.
        0x0120:  0a54 7261 6e73 6665 722d 456e 636f 6469 .Transfer-Encodi
        0x0130:  6e67 3a20 6368 756e 6b65 640d 0a0d 0a ng:.chunked....
09:01:24.825078 IP XXX.XXX.XXX.123.51712 > 176.9.184.93.80: Flags [.], ack 268, win 123, options [nop,nop,TS val 15463487 ecr 1443954004], length 0
        0x0000:  4500 0034 bb94 4000 4006 8aa6 caa6 c17b E..4..@.@......{
        0x0010:  b009 b85d ca00 0050 5ed8 4991 03de 7966 ...]...P^.I...yf
        0x0020:  8010 007b f4af 0000 0101 080a 00eb f43f ...{...........?
        0x0030:  5610 fd54                                V..T

* Logs on apt-cacher are not very useful. Around the time of the tcpdumps above
I see only:

/var/log/apt-cacher-ng/apt-cacher.err

Wed Jan 20 09:01:23 2016|Error resolving debianmirror.nkn.in:80: 503 DNS error for hostname debianmirror.nkn.in: Name or service not known. If debianmirror.nkn.in refers to a configured cache repository, please check the corresponding configuration file.

(see below regarding this DNS error)

/var/log/apt-cacher-ng/apt-cacher.log

1453280483|O|220|10.10.10.18|security.debian.org/dists/wheezy/updates/Release.gpg
1453280484|O|345|10.10.10.18|debrep/dists/wheezy/Release.gpg
1453280484|O|216|10.10.10.18|security.debian.org/dists/wheezy/updates/Release
1453280484|O|345|10.10.10.18|debrep/dists/wheezy-updates/Release.gpg
1453280484|O|232|10.10.10.18|security.debian.org/dists/wheezy/updates/main/source/Sources.bz2
1453280484|O|345|10.10.10.18|debrep/dists/wheezy/Release

* I was using the out-of-the-box configuration of apt-cacher-ng.

In particular, backends_debian points to cdn.debian.net, which via a
chain of CNAMEs points to httpredir.debian.org:

cdn.debian.net.        3600    IN    CNAME    deb.cdn.araki.net.
deb.cdn.araki.net.    30534    IN    CNAME    http.debian.net.
http.debian.net.    3589    IN    CNAME    httpredir.debian.org.

(I am aware of the https://wiki.debian.org/DebianGeoMirror page)

Now, these machines are located in Nepal.  The Debian GeoMirror service
doesn't work particularly well there: it seems to pick countries which are
geographically close, but most likely *not* network-close. If I run

    curl -v http://httpredir.debian.org/debian/

three times at the command line, the results I get are:

Location: http://debian.gnu.gen.tr/debian/    # Turkey
Location: http://debian.spnet.net/debian/     # Bulgaria
Location: http://debianmirror.nkn.in/debian/  # India

The reason I mention this is that there is definitely a separate problem
resolving "debianmirror.nkn.in", as shown in the logs above. These have
also been visible directly at the client on occasion, throwing up errors like:

W:Failed to fetch http://httpredir.debian.org/debian/dists/wheezy/main/source/Sources 503 DNS error for hostname debianmirror.nkn.in: Name or service not known. If debianmirror.nkn.in refers to a configured cache repository, please check the corresponding configuration file.

A brief investigation shows that the DNS for nkn.in is poorly configured.
The glue records match up, but:

- ns1 and ns2 are on the same subnet, and ns3 has only an IPv6 address; this means it's violating RFC2182, and any intermittent connectivity to that subnet will result in
  failures to resolve
- the authoritative zone has a TTL of only 300 on the NS records, meaning that after 5
  minutes all caches will be forced back to query the parent

* My theory is that apt-cacher-ng is giving these "500 Bad redirection (path)" errors when it is unable to resolve the name it has been redirected to by the geo mirror service. "Bad redirection" would make sense here, although the problem would be with the host, not the path! It would also explain why the client seems happy when fetching files from security.debian.org but not from ftp.uk.debian.org [which I believe on the apt-cacher-ng are being mapped to cdn.debian.net from the debian_backends config file]

If so, it should be possible to reproduce this in a lab environment - e.g. set up a 'geomirror' type service which gives redirections to a nonexistent name, or one whose nameservers are blackholed - and see if apt-cacher-ng exhibits this behaviour.

If it does, I think the behaviour could be improved by:

- giving a more helpful error in the response to the client
- retrying the backend (since next time, the httpredir service may give a redirect to a different location) - removing debianmirror.nkn.in from the httpredir service until such time as they make their authoritative DNS more resilient

Given the flakiness of the hosts returned by httpredir, I have now configured /etc/apt-cacher-ng/backends_debian to point statically to a presumed reliable host (ftp.uk.debian.org), and I'm hoping that the 500 errors will be gone. I'll be hitting this cache hard over the next week or so, so I'll find out then.

Anyway, I hope some of the above is helpful. I'm happy to share pcap files off-list.

Regards,

Brian Candler.


Reply to: