search

lancachenet / monolithic

A monolithic lancache service capable of caching all CDNs in a single instance
https://hub.docker.com/r/lancachenet/monolithic
Other
737 stars 73 forks source link

[Tracking] steamcache not caching steam requests due to HTTPS #28

Closed tn00364361 closed 5 years ago

tn00364361 commented 5 years ago

Describe the issue you are having

Downloading Steam games does not write cache data to the disk. I can see the traffic is going through my lancache server, but nothing is being written to the disk. Strangely enough, this only happens to Steam. Caching Uplay and Microsoft work just fine.

How are you running the container(s)?

docker run --detach \
  --restart unless-stopped \
  --name steamcache-dns \
  -p 192.168.1.10:53:53/udp \
  -e USE_GENERIC_CACHE=true \
  -e LANCACHE_IP=192.168.1.10 \
  -e UPSTREAM_DNS=192.168.1.1 \
  steamcache/steamcache-dns:latest

docker run --detach \
  --restart unless-stopped \
  --name lancache \
  -v $HOME/lancache-data/cache:/data/cache \
  -v $HOME/lancache-data/logs:/data/logs \
  -p 80:80 \
  -e CACHE_MEM_SIZE=512m \
  -e CACHE_DISK_SIZE=180g \
  steamcache/monolithic:latest

docker run --detach \
  --restart unless-stopped \
  --name sniproxy \
  -p 443:443 \
  steamcache/sniproxy:latest

DNS Configuration

UPSTREAM_DNS is pointed to my router, which is redirected to a VM running pi-hole. I suspected this might be the reason, but I was wrong. The same problem persists even when I set UPSTREAM_DNS to Google DNS.

Output of container(s)

 $ docker exec -it lancache tail -f /data/logs/access.log
[uplay] 192.168.1.174 / - - - [27/Apr/2019:06:14:55 +0000] "GET /uplaypc/downloads/720/slices/7B5A972296D93C2133FA8C85EFCE91B5A26FED25?_tkn_=exp=1556349271~acl=%2fuplaypc%2fdownloads%2f720%2fslices%2f7B5A972296D93C2133FA8C85EFCE91B5A26FED25~data=2e2896c5-91f8-4451-8bb8-80e24eb51b39~hmac=5801f66a896378f8ddd707a5189796701a80e290337d445287373909e5a82dfd HTTP/1.1" 200 2097152 "-" "Massgate" "MISS" "uplaypc-s-ubisoft.cdn.ubi.com" "-"
[uplay] 192.168.1.174 / - - - [27/Apr/2019:06:14:56 +0000] "GET /uplaypc/downloads/720/slices/4EFF1460A3AEE2D5E65A9DA7A38EE0958E760C5E?_tkn_=exp=1556349267~acl=%2fuplaypc%2fdownloads%2f720%2fslices%2f4EFF1460A3AEE2D5E65A9DA7A38EE0958E760C5E~data=2e2896c5-91f8-4451-8bb8-80e24eb51b39~hmac=d673b1cd71e26f20429bde9aa2a9816fb14c450139838ce9b78feeb90658f356 HTTP/1.1" 200 1256701 "-" "Massgate" "MISS" "uplaypc-s-ubisoft.cdn.ubi.com" "-"
[uplay] 192.168.1.174 / - - - [27/Apr/2019:06:14:56 +0000] "GET /uplaypc/downloads/720/slices/86B18AF05CE886B8D9F1B3174517BA2EF6C2D953?_tkn_=exp=1556349266~acl=%2fuplaypc%2fdownloads%2f720%2fslices%2f86B18AF05CE886B8D9F1B3174517BA2EF6C2D953~data=2e2896c5-91f8-4451-8bb8-80e24eb51b39~hmac=fbdfed378cf04fb62bc24f01c41dd3488a03266d46240c1ccc615efb3e84d835 HTTP/1.1" 200 1236221 "-" "Massgate" "MISS" "uplaypc-s-ubisoft.cdn.ubi.com" "-"
[uplay] 192.168.1.174 / - - - [27/Apr/2019:06:14:56 +0000] "GET /uplaypc/downloads/720/slices/6B04FC3FB1DED37559DEF38735091881317BADAB?_tkn_=exp=1556349273~acl=%2fuplaypc%2fdownloads%2f720%2fslices%2f6B04FC3FB1DED37559DEF38735091881317BADAB~data=2e2896c5-91f8-4451-8bb8-80e24eb51b39~hmac=9e31c87cf69f7a88b4abd9c64264bbc9e192f27978dc4a45f2709d43e75c763f HTTP/1.1" 200 670985 "-" "Massgate" "MISS" "uplaypc-s-ubisoft.cdn.ubi.com" "-"
[uplay] 192.168.1.174 / - - - [27/Apr/2019:06:14:56 +0000] "GET /uplaypc/downloads/720/slices/A74C9A8C2CE6364B5259D1556027DE82832EF3B8?_tkn_=exp=1556349271~acl=%2fuplaypc%2fdownloads%2f720%2fslices%2fA74C9A8C2CE6364B5259D1556027DE82832EF3B8~data=2e2896c5-91f8-4451-8bb8-80e24eb51b39~hmac=0061c05a81078c9ead96618d3370617b46c7d728ae6e666b86283e739c50228e HTTP/1.1" 200 1715453 "-" "Massgate" "MISS" "uplaypc-s-ubisoft.cdn.ubi.com" "-"
[uplay] 192.168.1.174 / - - - [27/Apr/2019:06:14:56 +0000] "GET /uplaypc/downloads/720/slices/BC5E963BC134EC261B6FEB47B44FC60EB8A2BC4E?_tkn_=exp=1556349267~acl=%2fuplaypc%2fdownloads%2f720%2fslices%2fBC5E963BC134EC261B6FEB47B44FC60EB8A2BC4E~data=2e2896c5-91f8-4451-8bb8-80e24eb51b39~hmac=28b8671eef4f1c3f340c4e6959e464baf8fff33ff1a0043dc36750280cc52b09 HTTP/1.1" 200 1649917 "-" "Massgate" "MISS" "uplaypc-s-ubisoft.cdn.ubi.com" "-"
[uplay] 192.168.1.174 / - - - [27/Apr/2019:06:14:56 +0000] "GET /uplaypc/downloads/720/slices/F1FD766104F2F807F7C0308501FA58DDCB565F97?_tkn_=exp=1556349273~acl=%2fuplaypc%2fdownloads%2f720%2fslices%2fF1FD766104F2F807F7C0308501FA58DDCB565F97~data=2e2896c5-91f8-4451-8bb8-80e24eb51b39~hmac=cbc563d1fb72590248b8881aa98d0187ca6027a985431ce7599abf692768293a HTTP/1.1" 200 720137 "-" "Massgate" "MISS" "uplaypc-s-ubisoft.cdn.ubi.com" "-"
[uplay] 192.168.1.174 / - - - [27/Apr/2019:06:14:56 +0000] "GET /uplaypc/downloads/720/slices/EC8FBF7A0D6E9EF8692E46DDF251331C91652CB5?_tkn_=exp=1556349272~acl=%2fuplaypc%2fdownloads%2f720%2fslices%2fEC8FBF7A0D6E9EF8692E46DDF251331C91652CB5~data=2e2896c5-91f8-4451-8bb8-80e24eb51b39~hmac=8c5499fe882b3fe8c76c2c2f2f8179f6c0d1c3b208d6734ae9a33616cd396940 HTTP/1.1" 200 691465 "-" "Massgate" "MISS" "uplaypc-s-ubisoft.cdn.ubi.com" "-"
[uplay] 192.168.1.174 / - - - [27/Apr/2019:06:14:56 +0000] "GET /uplaypc/downloads/720/slices/41AC96F16F89C71F750D19808332B97C54E5A0FA?_tkn_=exp=1556349272~acl=%2fuplaypc%2fdownloads%2f720%2fslices%2f41AC96F16F89C71F750D19808332B97C54E5A0FA~data=2e2896c5-91f8-4451-8bb8-80e24eb51b39~hmac=8db46d446aa8136dc932016f75c82b6741c27f58a8078027c3599324575b0f29 HTTP/1.1" 200 1064189 "-" "Massgate" "MISS" "uplaypc-s-ubisoft.cdn.ubi.com" "-"
[steam] 192.168.1.174 / - - - [27/Apr/2019:06:15:04 +0000] "GET /client/steam_client_win32 HTTP/1.1" 302 0 "-" "Valve/Steam HTTP Client 1.0 (client;windows;16;1555457005)" "MISS" "client-download.steampowered.com" "-"

I expected new lines when downlowing Steam games, but there was none.

mirko911 commented 5 years ago

I think I had the same problem on a LAN-Party yesterday.

When we tested it some days ago, the Cache worked fine. But yesterday it was just a passthrough of the data (for steam games)

I hadn't time to do further investigations yet

VibroAxe commented 5 years ago

@tn00364361 if there were no new log lines this probably means either your DNS is out of date or we are missing some entries over at UK lans

Can you post the contents of your steam content log and the output from the DNS container from a client downloading something?

@mirko911 if you had similar this would be useful

exurgent commented 5 years ago

Bad news, I'm afraid: Running Wireshark on the client shows Steam downloading over HTTPS.

From my server logs, it looks like they switched on Friday (CET)...just to make sure LANs on the weekend have zero time to prepare...

ghost commented 5 years ago

awesome, hosting a LAN in a few hours...cant wait this tank :(

VibroAxe commented 5 years ago

@exurgent can you show a wireshark screen cap please? Any idea what host it's connected on?

exurgent commented 5 years ago

I'm not actually using your containers but slightly different solution I built myself, so these logs will look a bit different but the problem is the same (that's the reason I dropped by here, to see if you guys had figured out a solution already).

Anyway, this is what it looks like now: steam-tls.zip I also tried switching the download region in Steam, but the other regions are also serving HTTPS

And here is nginx happily serving the same cacheNN-fra1.steamcontent.com servers on Thursday. 

HIT: 192.168.10.10 - - [25/Apr/2019:22:58:00 +0200] "GET cache48-fra1.steamcontent.com/depot/218231/chunk/20dd912e84cfa9c5823bfc046d0edc07735f7d25?l=14&e=1556828509&sid=12093647&h=ad41193548f6e500575f6955cf64e3e90b078675" 200 1052304 -
HIT: 192.168.10.10 - - [25/Apr/2019:22:58:00 +0200] "GET cache52-fra1.steamcontent.com/depot/218231/chunk/e40a6b38aadde03b9bc1af1c3c7750e2aa54deb4?l=14&e=1556828509&sid=12093647&h=ad41193548f6e500575f6955cf64e3e90b078675" 200 1051504 -
HIT: 192.168.10.10 - - [25/Apr/2019:22:58:00 +0200] "GET cache54-fra1.steamcontent.com/depot/218231/chunk/e1a34ed92af27ba8490d28039fa0455f3ab5ae83?l=14&e=1556828509&sid=12093647&h=ad41193548f6e500575f6955cf64e3e90b078675" 200 1055472 -
HIT: 192.168.10.10 - - [25/Apr/2019:22:58:00 +0200] "GET cache53-fra1.steamcontent.com/depot/218231/chunk/711e860d35fa417b1a0bce48acb63d33cca0d83e?l=14&e=1556828509&sid=12093647&h=ad41193548f6e500575f6955cf64e3e90b078675" 200 1047344 -
HIT: 192.168.10.10 - - [25/Apr/2019:22:58:00 +0200] "GET cache25-fra1.steamcontent.com/depot/218231/chunk/c75802d5bca6df25fdf89c13f58cf5d562b945e5?l=14&e=1556828509&sid=12093647&h=ad41193548f6e500575f6955cf64e3e90b078675" 200 1049888 -
HIT: 192.168.10.10 - - [25/Apr/2019:22:58:00 +0200] "GET cache48-fra1.steamcontent.com/depot/218231/chunk/9e728aa5f4f56a7bfd2208d7a6252844bfe96256?l=14&e=1556828509&sid=12093647&h=ad41193548f6e500575f6955cf64e3e90b078675" 200 1055552 -
HIT: 192.168.10.10 - - [25/Apr/2019:22:58:00 +0200] "GET cache38-fra1.steamcontent.com/depot/218231/chunk/666d4159e5aac10bf7fd81d2ee20f534b5b075cb?l=14&e=1556828509&sid=12093647&h=ad41193548f6e500575f6955cf64e3e90b078675" 200 1059408 -
HIT: 192.168.10.10 - - [25/Apr/2019:22:58:00 +0200] "GET cache68-fra1.steamcontent.com/depot/218231/chunk/0cd1aa118208e147849c6352130c08b5387afc91?l=14&e=1556828509&sid=12093647&h=ad41193548f6e500575f6955cf64e3e90b078675" 200 1041216 -
HIT: 192.168.10.10 - - [25/Apr/2019:22:58:00 +0200] "GET cache25-fra1.steamcontent.com/depot/218231/chunk/6b19be85f50f50f36fb74c406614b20948917272?l=14&e=1556828509&sid=12093647&h=ad41193548f6e500575f6955cf64e3e90b078675" 200 1047408 -
VibroAxe commented 5 years ago

Anyone else experiencing this issue please let us know. Looking to determine how wide spread the issue is at the moment

exurgent commented 5 years ago

Might be statistical noise or actually relevant: I'm in Germany, @mirko911 also has Germany in his profile, and here is another post reporting a problem, the netstat output shows a German locale.

ghost commented 5 years ago

its down, steam downloads are not caching properly and have poor speeds....blizzard, origin, and uplay appear fine so far

will-janz commented 5 years ago

I'm also experiencing this. I recently set up a steamcache/generic container, which broke a couple days ago catastrophically; steam logins broke, and games simply wouldn't download. After migrating to monolithic, logins worked and games downloaded but never through the cache. Some sample entries from the sniproxy container:

2019-04-27 07:41:03 192.168.0.106:50026 -> 172.17.0.2:443 -> 162.254.195.14:443 [cache3-lax1.steamcontent.com] 4782/4782 bytes tx 933/933 bytes rx 60.417 seconds
2019-04-27 07:41:04 192.168.0.106:50010 -> 172.17.0.2:443 -> 162.254.193.14:443 [cache3-ord1.steamcontent.com] 2490370/2490370 bytes tx 4563/4563 bytes rx 66.290 seconds
2019-04-27 07:41:08 192.168.0.106:50065 -> 172.17.0.2:443 -> 162.254.195.32:443 [cache21-lax1.steamcontent.com] 1660471/1660471 bytes tx 3003/3003 bytes rx 61.604 seconds
2019-04-27 07:41:09 192.168.0.106:50074 -> 172.17.0.2:443 -> 162.254.195.32:443 [cache21-lax1.steamcontent.com] 401697/401697 bytes tx 1449/1449 bytes rx 60.719 seconds
2019-04-27 07:41:13 192.168.0.106:50084 -> 172.17.0.2:443 -> 162.254.195.23:443 [cache12-lax1.steamcontent.com] 275805/275805 bytes tx 2639/2639 bytes rx 62.103 seconds
2019-04-27 07:41:13 192.168.0.106:50081 -> 172.17.0.2:443 -> 162.254.193.48:443 [cache14-ord1.steamcontent.com] 5753930/5753930 bytes tx 9093/9093 bytes rx 64.322 seconds
2019-04-27 07:41:13 192.168.0.106:50080 -> 172.17.0.2:443 -> 162.254.193.48:443 [cache14-ord1.steamcontent.com] 8657899/8657899 bytes tx 10549/10549 bytes rx 64.421 seconds

DNS resolves, Windows updates are cached, but it appears as if steam is now using HTTPS. If you'd like more log data I'd be happy to provide.

lolpota commented 5 years ago

I just set it up and I think I'm having the same issue. It shows the networking peak when i start a downlaod, but it still shows as "MISS" when I uninstall and redownload it.

VibroAxe commented 5 years ago

@lolpota if the monolithic logs are showing a miss this is a different issue. Please post a new issue with full logs

mirko911 commented 5 years ago

Hi, here is my longer answer:

@VibroAxe my DNS entries are ok:

Apr 28 15:12:54 mirko dnsmasq[34367]: query[A] cache67-fra1.steamcontent.com from 10.0.0.15
Apr 28 15:12:54 mirko dnsmasq[34367]: config cache67-fra1.steamcontent.com is 10.0.0.3
Apr 28 15:12:58 mirko dnsmasq[34367]: query[A] cache27-fra1.steamcontent.com from 10.0.0.15
Apr 28 15:12:58 mirko dnsmasq[34367]: config cache27-fra1.steamcontent.com is 10.0.0.3
Apr 28 15:13:02 mirko dnsmasq[34367]: query[A] cache64-fra1.steamcontent.com from 10.0.0.15
Apr 28 15:13:02 mirko dnsmasq[34367]: config cache64-fra1.steamcontent.com is 10.0.0.3
Apr 28 15:13:04 mirko dnsmasq[34367]: query[A] cache27-fra1.steamcontent.com from 10.0.0.15
Apr 28 15:13:04 mirko dnsmasq[34367]: config cache27-fra1.steamcontent.com is 10.0.0.3

there is no DNS Response which doesn't get redirected to my Steam Cache VM. The nginx logs are also nearly empty for steam downloads, but the sniproxy gets some decent load, which shouldn't be if steam just uses HTTP

[steam] 10.0.0.15 / - - - [28/Apr/2019:13:14:21 +0000] "GET /appinfo/17740/sha/dee2dc2720343058fc36cd051c08e8e761228032.txt.gz HTTP/1.1" 200 4649 "-" "Valve/Steam HTTP Client 1.0" "MISS" "clientconfig.akamai.steamstatic.com" "-"
root@server02:/home/mirko911# vnstat -l -i ens33
Monitoring ens33...    (press CTRL-C to stop)

   rx:    66.91 Mbit/s  8413 p/s          tx:    68.90 Mbit/s  6981 p/s
exurgent commented 5 years ago

Some good news I found, Steam will accept a self-signed-certificate for *.steamcontent.com if it's imported as a trusted root in Windows. Not a great solution at all, but it's something and does not require a root certificate...

mirko911 commented 5 years ago

gj. But does that mean, that everyone on a LAN-Party would need this self signed certificate?

mintopia commented 5 years ago

I've reached out to Valve today to try and get an update on this issue.

mintopia commented 5 years ago

Valve got back to me VERY quickly last night. They've disabled HTTPS for content downloads now. I've checked and it's definitely using HTTP again. They do want to switch to HTTPS but will provide a way to use cache servers in future before they do it. We'll update the project with details when we have them.

Before

[2019-05-01 02:03:42] Downloading 13 chunks from depot 1048878
[2019-05-01 02:03:42] HTTP (SteamCache,229) - cache5-lhr1.steamcontent.com (10.10.0.11:443 / 10.10.0.11:443, host: cache5-lhr1.steamcontent.com): AuthenticateDepotID (1048878) - Success!
[2019-05-01 02:03:42] HTTP (SteamCache,39) - cache31-lhr1.steamcontent.com (10.10.0.11:443 / 10.10.0.11:443, host: cache31-lhr1.steamcontent.com): AuthenticateDepotID (1048878) - Success!
[2019-05-01 02:03:42] HTTP (SteamCache,142) - cache8-lhr1.steamcontent.com (10.10.0.11:443 / 10.10.0.11:443, host: cache8-lhr1.steamcontent.com): AuthenticateDepotID (1048878) - Success!
[2019-05-01 02:03:42] HTTP (SteamCache,37) - cache29-lhr1.steamcontent.com (10.10.0.11:443 / 10.10.0.11:443, host: cache29-lhr1.steamcontent.com): AuthenticateDepotID (1048878) - Success!
[2019-05-01 02:03:43] Increasing target number of download connections to 5 (rate was 21.550, now 26.319)
[2019-05-01 02:03:43] Created download interface of type 'SteamCache' (7) to host cache20-lhr1.steamcontent.com (cache20-lhr1.steamcontent.com)
[2019-05-01 02:03:45] HTTP (SteamCache,232) - cache20-lhr1.steamcontent.com (10.10.0.11:443 / 10.10.0.11:443, host: cache20-lhr1.steamcontent.com): CDepotHTTPDownloadInterface::BYldTestConnection - Server response 'OK' (200)
[2019-05-01 02:03:46] Downloading 12 chunks from depot 1048879
[2019-05-01 02:03:46] HTTP (SteamCache,229) - cache5-lhr1.steamcontent.com (10.10.0.11:443 / 10.10.0.11:443, host: cache5-lhr1.steamcontent.com): AuthenticateDepotID (1048879) - Success!
[2019-05-01 02:03:46] HTTP (SteamCache,39) - cache31-lhr1.steamcontent.com (10.10.0.11:443 / 10.10.0.11:443, host: cache31-lhr1.steamcontent.com): AuthenticateDepotID (1048879) - Success!
[2019-05-01 02:03:46] HTTP (SteamCache,37) - cache29-lhr1.steamcontent.com (10.10.0.11:443 / 10.10.0.11:443, host: cache29-lhr1.steamcontent.com): AuthenticateDepotID (1048879) - Success!
[2019-05-01 02:03:46] HTTP (SteamCache,232) - cache20-lhr1.steamcontent.com (10.10.0.11:443 / 10.10.0.11:443, host: cache20-lhr1.steamcontent.com): AuthenticateDepotID (1048879) - Success!
[2019-05-01 02:03:46] HTTP (SteamCache,142) - cache8-lhr1.steamcontent.com (10.10.0.11:443 / 10.10.0.11:443, host: cache8-lhr1.steamcontent.com): AuthenticateDepotID (1048879) - Success!
[2019-05-01 02:03:49] AppID 620980 update changed : Running,
[2019-05-01 02:03:49] AppID 620980 update changed : Running,Committing,
[2019-05-01 02:03:49] AppID 620980 file commit : 313 updated, 0 moved, 0 deleted
[2019-05-01 02:03:49] AppID 620980 state changed : Fully Installed,Update Queued,Update Running,
[2019-05-01 02:03:49] AppID 620980 finished update, mounted depots (BuildID 3708884) : 620981 (6839388023573913446),1048870 (8598310574302776858),1048871 (2294283607926338484),1048872 (7913335308611876022),1048873 (5599303875539812140),1048874 (7018376873649072655),1048875 (3405625299962600753),1048876 (3451346463254839004),1048877 (6162517820281174534),1048878 (4595863642808201239),1048879 (5614874234996355969),
[2019-05-01 02:03:49] AppID 620980 update changed : Running,
[2019-05-01 02:03:49] AppID 620980 update changed : None
[2019-05-01 02:03:49] AppID 620980 state changed : Fully Installed,Update Queued,
[2019-05-01 02:03:49] AppID 620980 state changed : Fully Installed,
[2019-05-01 02:03:49] AppID 620980 scheduler finished : removed from schedule

After

[2019-05-01 08:04:03] AppID 620980 update changed : Running,Downloading,
[2019-05-01 08:04:03] AppID 620980 update changed : Running,Downloading,Staging,
[2019-05-01 08:04:03] Downloading 581 chunks from depot 620981
[2019-05-01 08:04:03] HTTP (SteamCache,43) - cache34-lhr1.steamcontent.com (10.10.0.11:80 / 10.10.0.11:80, host: cache34-lhr1.steamcontent.com): AuthenticateDepotID (620981) - Success!
[2019-05-01 08:04:03] HTTP (SteamCache,238) - cache26-lhr1.steamcontent.com (10.10.0.11:80 / 10.10.0.11:80, host: cache26-lhr1.steamcontent.com): AuthenticateDepotID (620981) - Success!
[2019-05-01 08:04:03] AppID 620980 scheduler update : Priority Last, legacy=no, restore="", timeSinceLastPlayed=-5, appDisableSecondsRemaining=0
[2019-05-01 08:04:15] Increasing target number of download connections to 4 (rate was 0.000, now 55.818)
[2019-05-01 08:04:15] Current download rate: 55.818 Mbps
[2019-05-01 08:04:15] Created download interface of type 'SteamCache' (7) to host cache23-lhr1.steamcontent.com (cache23-lhr1.steamcontent.com)
[2019-05-01 08:04:15] HTTP (SteamCache,235) - cache23-lhr1.steamcontent.com (0.0.0.0:0 / 0.0.0.0:0, host: cache23-lhr1.steamcontent.com): AuthenticateDepotID (620981) - Success!
[2019-05-01 08:04:34] Downloading 12 chunks from depot 1048870
[2019-05-01 08:04:34] HTTP (SteamCache,43) - cache34-lhr1.steamcontent.com (10.10.0.11:80 / 10.10.0.11:80, host: cache34-lhr1.steamcontent.com): AuthenticateDepotID (1048870) - Success!
[2019-05-01 08:04:34] HTTP (SteamCache,235) - cache23-lhr1.steamcontent.com (10.10.0.11:80 / 10.10.0.11:80, host: cache23-lhr1.steamcontent.com): AuthenticateDepotID (1048870) - Success!