Skip to content
This repository has been archived by the owner on Jan 7, 2018. It is now read-only.

Commit

Permalink
Fix logging of request scheme (http vs https) when behind load balancer.
Browse files Browse the repository at this point in the history 
If API Umbrella was sitting behind an SSL terminator (like an ELB), then
we weren't properly logging the original protocol of the request from
the X-Forwarded-Proto header.

This has been fixed and tests surrounding this, as well as a sanity
check on the logging of the Host header have been added.
  • Loading branch information
@GUI
GUI committed Mar 26, 2015
1 parent 5b8ae1a commit b989713
Show file tree
Hide file tree
Showing 3 changed files with 78 additions and 2 deletions.
4 changes: 2 additions & 2 deletions templates/etc/nginx/router.conf.hbs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -50,9 +50,9 @@ http {
'"req_ip":"$remote_addr",'
'"req_method":"$request_method",'
'"req_origin":"$http_origin",'
'"req_port":"$server_port",'
'"req_port":"$real_port",'
'"req_referer":"$http_referer",'
'"req_scheme":"$scheme",'
'"req_scheme":"$real_scheme",'
'"req_size":"$request_length",'
'"req_uri":"$request_uri",'
'"req_user_agent":"$http_user_agent",'
Expand Down
9 changes: 9 additions & 0 deletions test/config/test.yml
View file
Original file line number Diff line number Diff line change
Expand Up @@ -203,6 +203,15 @@ apis:
url_matches:
- frontend_prefix: /
backend_prefix: /
- _id: wildcard-frontend-host
frontend_host: "*"
backend_host: localhost
servers:
- host: 127.0.0.1
port: 9444
url_matches:
- frontend_prefix: /wildcard-info/
backend_prefix: /info/
dns_resolver:
minimum_ttl: 1
reload_buffer_time: 1
67 changes: 67 additions & 0 deletions test/integration/logging.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -186,6 +186,7 @@ describe('logging', function() {

var requestUrl = 'http://localhost:9080/logging-example/foo/bar/?unique_query_id=' + this.uniqueQueryId + '&url1=http%3A%2F%2Fexample.com%2F%3Ffoo%3Dbar%26foo%3Dbar%20more+stuff&url2=%ED%A1%BC&url3=https%3A//example.com/foo/%D6%D0%B9%FA%BD%AD%CB%D5%CA%A1%B8%D3%D3%DC%CF%D8%D2%BB%C2%A5%C5%CC%CA%C0%BD%F5%BB%AA%B3%C7200%D3%E0%D2%B5%D6%F7%B9%BA%C2%F2%B5%C4%C9%CC%C6%B7%B7%BF%A3%AC%D2%F2%BF%AA%B7%A2%C9%CC%C5%DC%C2%B7%D2%D1%CD%A3%B9%A420%B8%F6%D4%C2%A3%AC%D2%B5%D6%F7%C4%C3%B7%BF%CE%DE%CD%FB%C8%B4%D0%E8%BC%CC%D0%F8%B3%A5%BB%B9%D2%F8%D0%D0%B4%FB%BF%EE%A1%A3%CF%F2%CA%A1%CA%D0%CF%D8%B9%FA%BC%D2%D0%C5%B7%C3%BE%D6%B7%B4%D3%B3%BD%FC2%C4%EA%CE%DE%C8%CB%B4%A6%C0%ED%A1%A3%D4%DA%B4%CB%B0%B8%D6%D0%A3%AC%CE%D2%C3%C7%BB%B3%D2%C9%D3%D0%C8%CB%CA%A7%D6%B0%E4%C2%D6%B0/sites/default/files/googleanalytics/ga.js';
request.get(requestUrl, options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(200);

waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
Expand Down Expand Up @@ -304,6 +305,7 @@ describe('logging', function() {
});

request.get('http://localhost:9080/compressible-delayed-chunked/5', options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(200);

waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
Expand All @@ -325,6 +327,7 @@ describe('logging', function() {
});

request.get('http://localhost:9080/info/', options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(200);
waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
should.not.exist(error);
Expand All @@ -343,6 +346,7 @@ describe('logging', function() {
});

request.get('http://localhost:9080/info/', options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(200);
waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
should.not.exist(error);
Expand All @@ -352,6 +356,61 @@ describe('logging', function() {
}.bind(this));
});

it('logs the host used to access the site for a wildcard api', function(done) {
this.timeout(4500);
var options = _.merge({}, this.options, {
headers: {
'Host': 'unknown.foo',
},
});

request.get('http://localhost:9080/wildcard-info/', options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(200);
waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
should.not.exist(error);
record.request_host.should.eql('unknown.foo');
done();
}.bind(this));
}.bind(this));
});

it('logs request scheme when hit directly', function(done) {
this.timeout(4500);
var options = _.merge({}, this.options, {
strictSSL: false,
});

request.get('https://localhost:9081/info/', options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(200);
waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
should.not.exist(error);
record.request_scheme.should.eql('https');
done();
}.bind(this));
}.bind(this));
});

it('logs request scheme when forwarded from an external load balancer via X-Forwarded-Proto', function(done) {
this.timeout(4500);
var options = _.merge({}, this.options, {
headers: {
'X-Forwarded-Proto': 'https',
},
});

request.get('http://localhost:9080/info/', options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(200);
waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
should.not.exist(error);
record.request_scheme.should.eql('https');
done();
}.bind(this));
}.bind(this));
});

it('logs headers that contain quotes (to account for json escaping in nginx logs)', function(done) {
this.timeout(4500);
var options = _.merge({}, this.options, {
Expand All @@ -366,6 +425,7 @@ describe('logging', function() {
});

request.get('http://localhost:9080/info/', options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(200);
waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
should.not.exist(error);
Expand All @@ -386,6 +446,7 @@ describe('logging', function() {
});

request.get('http://localhost:9080/info/', options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(200);
waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
should.not.exist(error);
Expand All @@ -406,6 +467,7 @@ describe('logging', function() {
method: 'GET',
url: 'http://localhost:9080/info/utf8/✓/encoded_utf8/%E2%9C%93/?api_key=' + this.apiKey + '&unique_query_id=' + this.uniqueQueryId + '&utf8=✓&utf8_url_encoded=%E2%9C%93&more_utf8=¬¶ªþ¤l&more_utf8_hex=\xAC\xB6\xAA\xFE\xA4l&more_utf8_hex_lowercase=\xac\xb6\xaa\xfe\xa4l&actual_backslash_x=\\xAC\\xB6\\xAA\\xFE\\xA4l',
}, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(200);
waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
should.not.exist(error);
Expand Down Expand Up @@ -434,6 +496,7 @@ describe('logging', function() {
method: 'GET',
url: 'http://localhost:9080/info/extra//slash/some\\backslash/encoded%5Cbackslash/encoded%2Fslash?api_key=' + this.apiKey + '&unique_query_id=' + this.uniqueQueryId + '&forward_slash=/slash&encoded_forward_slash=%2F&back_slash=\\&encoded_back_slash=%5C',
}, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(200);
waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
should.not.exist(error);
Expand Down Expand Up @@ -485,6 +548,7 @@ describe('logging', function() {
it('logs requests that time out before responding', function(done) {
this.timeout(90000);
request.get('http://localhost:9080/delay/65000', this.options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(504);

waitForLog(this.uniqueQueryId, { timeout: 10000 }, function(error, response, hit, record) {
Expand Down Expand Up @@ -553,6 +617,7 @@ describe('logging', function() {
});

request.get('http://localhost:9080/info/', options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(403);

waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
Expand All @@ -573,6 +638,7 @@ describe('logging', function() {
it('logs requests when the api backend is down', function(done) {
this.timeout(4500);
request.get('http://localhost:9080/down', this.options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(502);

waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
Expand Down Expand Up @@ -621,6 +687,7 @@ describe('logging', function() {
it('still logs failed requests', function(done) {
this.timeout(4500);
request.get('http://localhost:9080/info/', this.options, function(error, response) {
should.not.exist(error);
response.statusCode.should.eql(502);

waitForLog(this.uniqueQueryId, function(error, response, hit, record) {
Expand Down

0 comments on commit b989713

Please sign in to comment.