Missing country code for some users

[DFurnes]

Some users don't seem to be getting their country code applied correctly (being shown "global" experience, even from the US) and getting null saved to their country code field.

Not able to consistently reproduce, and continuing to investigate. 🔍

[DFurnes]

This isn't happening on Cats Gone Good (which is roughly the exact same codebase):

mysql> SELECT id, first_name, email, country_code FROM `users` WHERE `country_code`='' OR `country_code` IS NULL;
+--------+------------+------------------------------+--------------+
| id     | first_name | email                        | country_code |
+--------+------------+------------------------------+--------------+
|      1 | Dave       | dfurnes@dosomething.org      |              |
|      2 | Andrea     | agaither@dosomething.org     |              |
|      4 | Naomi      | nhirabayashi@dosomething.org |              |
| 107370 | Diane      | dzmirich@dosomething.org     | NULL         |
+--------+------------+------------------------------+--------------+
4 rows in set (0.00 sec)

Admittedly, Cats Gone Good only has 71 test users. But perhaps an indication that it could be a server or Fastly configuration issue?

[DFurnes]

Running the same query on Athletes Gone Good shows only 145 (of 53,924) users without a country_code set on their record.

[DFurnes]

And logs are coming in after deploying #486 to production:

2015-12-02 18:02:23] production.DEBUG: Received request with country header "BR". {"HTTP_X_FASTLY_COUNTRY_CODE":"BR","IP":"10.100.60.224","url":"https://www.celebsgonegood.com/candidates/jared-leto","method":"GET"} 
[2015-12-02 18:02:24] production.DEBUG: Received request with country header "". {"HTTP_X_FASTLY_COUNTRY_CODE":null,"IP":"10.100.60.224","url":"https://celebsgonegood.com/votes","method":"POST"} 
[2015-12-02 18:02:24] production.DEBUG: Received request with country header "". {"HTTP_X_FASTLY_COUNTRY_CODE":null,"IP":"10.100.60.224","url":"https://celebsgonegood.com/candidates/justin-bieber","method":"GET"} 
[2015-12-02 18:02:25] production.DEBUG: Received request with country header "US". {"HTTP_X_FASTLY_COUNTRY_CODE":"US","IP":"10.100.60.224","url":"https://www.celebsgonegood.com/candidates/shawn-mendes","method":"GET"} 
[2015-12-02 18:02:25] production.DEBUG: Received request with country header "RU". {"HTTP_X_FASTLY_COUNTRY_CODE":"RU","IP":"10.100.60.224","url":"https://www.celebsgonegood.com/candidates/jared-leto","method":"GET"} 
[2015-12-02 18:02:31] production.DEBUG: Received request with country header "US". {"HTTP_X_FASTLY_COUNTRY_CODE":"US","IP":"10.100.60.224","url":"https://www.celebsgonegood.com/candidates/jared-leto","method":"GET"} 
[2015-12-02 18:02:31] production.DEBUG: Received request with country header "IT". {"HTTP_X_FASTLY_COUNTRY_CODE":"IT","IP":"10.100.60.224","url":"https://www.celebsgonegood.com/votes","method":"POST"} 
[2015-12-02 18:02:31] production.DEBUG: Received request with country header "US". {"HTTP_X_FASTLY_COUNTRY_CODE":"US","IP":"10.100.60.224","url":"https://www.celebsgonegood.com/candidates/jared-leto","method":"GET"} 
[2015-12-02 18:02:31] production.DEBUG: Received request with country header "US". {"HTTP_X_FASTLY_COUNTRY_CODE":"US","IP":"10.100.60.224","url":"https://www.celebsgonegood.com","method":"GET"} 
[2015-12-02 18:02:31] production.DEBUG: Received request with country header "US". {"HTTP_X_FASTLY_COUNTRY_CODE":"US","IP":"10.100.60.224","url":"https://www.celebsgonegood.com/candidates/madison-beer","method":"GET"} 
[2015-12-02 18:02:32] production.DEBUG: Received request with country header "IT". {"HTTP_X_FASTLY_COUNTRY_CODE":"IT","IP":"10.100.60.224","url":"https://www.celebsgonegood.com/candidates/bella-thorne","method":"GET"} 
[2015-12-02 18:02:32] production.DEBUG: Received request with country header "". {"HTTP_X_FASTLY_COUNTRY_CODE":null,"IP":"10.100.60.224","url":"https://celebsgonegood.com/candidates/rooster-teeth","method":"GET"}
[2015-12-02 18:02:32] production.DEBUG: Received request with country header "US". {"HTTP_X_FASTLY_COUNTRY_CODE":"US","IP":"10.100.60.224","url":"https://www.celebsgonegood.com/candidates/jared-leto","method":"GET"}
[2015-12-02 18:02:32] production.DEBUG: Received request with country header "US". {"HTTP_X_FASTLY_COUNTRY_CODE":"US","IP":"10.100.60.224","url":"https://www.celebsgonegood.com/candidates/jared-leto","method":"GET"}
[2015-12-02 18:02:32] production.DEBUG: Received request with country header "US". {"HTTP_X_FASTLY_COUNTRY_CODE":"US","IP":"10.100.60.224","url":"https://www.celebsgonegood.com/candidates/jared-leto","method":"GET"}
[2015-12-02 18:02:32] production.DEBUG: Received request with country header "US". {"HTTP_X_FASTLY_COUNTRY_CODE":"US","IP":"10.100.60.224","url":"https://www.celebsgonegood.com/candidates/jared-leto","method":"GET"}
[2015-12-02 18:02:35] production.DEBUG: Received request with country header "". {"HTTP_X_FASTLY_COUNTRY_CODE":null,"IP":"10.100.60.224","url":"https://celebsgonegood.com/votes","method":"POST"}

Not seeing any patterns so far... but it's definitely still having trouble.

[DFurnes]

For anyone following along, @sheyd is checking in with Fastly support now. ☎️

[DFurnes]

Just to be extra sure that this isn't due to a bug in the application, I tried adding some logging directly to the top of public/index.php (so before sessions are initiated, before Laravel even bootstraps, or a single other line of code runs):

error_log($_SERVER['HTTP_X_FASTLY_COUNTRY_CODE'].', ', 3, '/home/dosomething/test.log');

Here’s the logged country codes over the course of roughly 5 minutes:

US, US, US, , US, US, , , US, US, , , , , , , , , US, US, US, US, , , , , , , CN, , , US, US, , , CN, , , FR, FR, FR, FR, FR, FR, , , RU, , , , , US, US, , , , , , , US, NL, US, US, , , US, , , , US, , , , US, , NL, US, CN, , , , US, US, , , DE, US, , US, US, US, IE, , , , NL, , US, , , , MM, , US, US, US, MM, US, ES, US, US, US, US,

My best guess (and I believe @sheyd's as well) is that Fastly just plain isn’t sending those country codes for a random selection of requests, perhaps due to a misconfigured server somewhere in their network.

[DFurnes]

Another interesting thing, which may be a clue to what's going on... request logs on Cats Gone Good show what seems to be the individual request's IP address whereas Celebs Gone Good consistently shows the exact same (internal?) IP address for every single request: 10.100.60.224

Perhaps something in between (HAProxy, Varnish, ...?) is stripping out the header from time to time?

/cc @sheyd

[DFurnes]

For what it's worth, there's still no instances of a missing country code on Cats Gone Good (although of course it gets drastically less traffic). Just for fun, I tried targeting a loader.io test at Cats Gone Good, and all requests properly logged their country code.