661258 - Cached video of 0-length served from videos-cdn

Status: RESOLVED FIXED

(mozilla.org Graveyard :: Server Operations, task)

Description

[Ed Lee :Mardak]

Some reason the original upload is hitting in the cache and reporting 0-length from my home connection, my web server, people.mo, stage. zandr reports that he is able to get the correct content.

For now I've uploaded a second copy and used that from the blog.

Below are the headers for the broken cache version the new upload. Main difference are the last 4 lines.

~$ curl -I http://videos-cdn.mozilla.net/serv/labs/prospector/twitterAddressBarSearchIntro.webm
HTTP/1.1 200 OK
Accept-Ranges: bytes
Content-Type: video/webm
Date: Wed, 01 Jun 2011 16:03:32 GMT
ETag: "1bcc007-0-ef37a7c0"
Last-Modified: Wed, 01 Jun 2011 05:38:47 GMT
Server: ECAcc (lax/282A)
X-Backend-Server: dm-download02
X-Cache: HIT
Content-Length: 0

~$ curl -I http://videos-cdn.mozilla.net/serv/labs/prospector/twitterAddressBarSearchIntro2.webm
HTTP/1.1 200 OK
Accept-Ranges: bytes
Content-Type: video/webm
Date: Wed, 01 Jun 2011 16:03:35 GMT
ETag: "1bcc002-3c2c38-91b71b40"
Last-Modified: Wed, 01 Jun 2011 15:56:53 GMT
Server: Apache
X-Backend-Server: dm-download02
Content-Length: 3943480

Comment 1

[Ed Lee :Mardak]

Of course the caching problem is now fixed ;)

~$ curl -I http://videos-cdn.mozilla.net/serv/labs/prospector/twitterAddressBarSearchIntro.webm
HTTP/1.1 200 OK
Accept-Ranges: bytes
Content-Type: video/webm
Date: Wed, 01 Jun 2011 23:57:45 GMT
ETag: "1bcc007-3c2c38-f2acaa40"
Last-Modified: Wed, 01 Jun 2011 05:39:45 GMT
Server: ECAcc (sjo/525E)
X-Backend-Server: dm-download02
X-Cache: HIT
Content-Length: 3943480

Comment 2

[Ed Lee :Mardak]

I have a guess to what might have happened. I had a <video> tag pointing to the .webm as a placeholder before I actually created the video. So the cache noticed it didn't exist.

Some reason it just took a while for the cache to notice it was no longer 404.

Although the cache originally reported 200 per comment 0...

Comment 3

[Jake Maul [:jakem]]

It's hard to say what could cause this (especially the 404->200 thing), but I'm inclined to treat this as a one-off. I believe it would have been solvable by a simple cache flush on the Edgecast CDN. You can see that they considered it a "HIT" in the first request. You can also see that the ETag and Last-Modified timestamp have both changed between the first (broken) hit and the second (successful) hit.

It seems like something on the server-side was broken for a bit, and that's what got cached. Possibly when a video is uploaded, it's first created as a 0-byte file and the upload goes to a temp file, then is moved into place? This is a common pattern with some file transfer programs, because it means the content is never "partially" available, and there's no chance the filename will be "stolen" by some other uploader during your upload. It makes the upload atomic.

However, if the CDN happens to make a request during the upload, that would cause this scenario. Our servers would return a 200-OK, with a zero-byte file. The CDN would cache this. Then when the upload finishes, the ETag and Last-Modified time would be changed. By then though, the CDN has cached the wrong version.

zandr was unaffected possibly because he's hitting a different CDN node... one that didn't have the file cached yet, and so when *he* goes to get it, the CDN pulls the correct copy rather than serving from cache.

I'm going to mark this as resolved. If you see the same type of issue in the future (in a way that isn't explained by the above scenario), please reopen or make a new bug so we can investigate.

Thanks!