Aws::CloudSearchDomain::Errors::SignatureDoesNotMatch when using :expr argument

[traviskroberts]

I get the following error when I try to create and sort using expressions.

Aws::CloudSearchDomain::Errors::SignatureDoesNotMatch (The request signature we calculated does not match the signature you provided. Check your AWS Secret Access Key and signing method. Consult the service documentation for details.
The Canonical String for this request should have been
'GET
/2013-01-01/search
expr=%7B%22distance%22%3A%22haversin%2835.8456%2C-86.3903%2Clocation.latitude%2Clocation.longitude%29%22%2C%22myrank%22%3A%22_score%2Flog%28distance%29%22%7D&format=sdk&pretty=true&q=%28or%20%28phrase%20field%3D%27name%27%20boost%3D100%20%27test%27%29%20%28prefix%20field%3D%27name%27%20boost%3D10%20%27test%27%29%20%28phrase%20field%3D%27street_address%27%20boost%3D0.5%20%27test%27%29%20%28phrase%20field%3D%27city%27%20boost%3D1.0%20%27test%27%29%20%28phrase%20field%3D%27state_abbr%27%20boost%3D1.0%20%27test%27%29%20%28phrase%20field%3D%27zip_code%27%20boost%3D1.0%20%27test%27%29%29&q.parser=structured&size=200&sort=myrank%20desc
content-length:
host:my-cloudsearch-domain.us-east-1.cloudsearch.amazonaws.com
user-agent:aws-sdk-ruby2/2.2.1 ruby/2.0.0 x86_64-darwin14.0.0
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20151123T221827Z

content-length;host;user-agent;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855'

The String-to-Sign should have been
'AWS4-HMAC-SHA256
20151123T221827Z
20151123/us-east-1/cloudsearch/aws4_request
1877a2c2717aa27f5cf6a08c7163e98e11c3a6ec37f58eec097a89827c78eae8'

The decoded request looks like this:

expr={"distance":"haversin(35.8456,-86.3903,location.latitude,location.longitude)","myrank":"_score/log(distance)"}&format=sdk&pretty=true&q=(or (phrase field='name' boost=100 'test') (prefix field='name' boost=10 'test') (phrase field='street_address' boost=0.5 'test') (phrase field='city' boost=1.0 'test') (phrase field='state_abbr' boost=1.0 'test') (phrase field='zip_code' boost=1.0 'test'))&q.parser=structured&size=200&sort=myrank desc

If I remove the myrank expression, the request completes.

Extra details:

• ruby 2.0.0p576
• rails 3.2.18
• aws-sdk 2.2.1

If you need any other information, let me know.

[awood45]

Looks potentially related to #929 - I'll try and reproduce with this, it could help to get a wire trace as well by adding http_wire_trace: true to your client construction.

[traviskroberts]

@awood45 Thanks for the quick reply. Here's the wire trace from the call:

opening connection to cloudsearch-domain-id.us-east-1.cloudsearch.amazonaws.com:443...
opened
starting SSL for cloudsearch-domain-id.us-east-1.cloudsearch.amazonaws.com:443...
SSL established
<- "GET /2013-01-01/search?format=sdk&pretty=true&expr=%7B%22distance%22%3A%22haversin%2835.8456%2C-86.3903%2Clocation.latitude%2Clocation.longitude%29%22%2C%22myrank%22%3A%22_score%2Flog%28distance%29%22%7D&q=%28or%20%28phrase%20field%3D%27name%27%20boost%3D100%20%27test%27%29%20%28prefix%20field%3D%27name%27%20bo
ost%3D10%20%27test%27%29%20%28phrase%20field%3D%27street_address%27%20boost%3D0.5%20%27test%27%29%20%28phrase%20field%3D%27city%27%20boost%3D1.0%20%27test%27%29%20%28phrase%20field%3D%27state_abbr%27%20boost%3D1.0%20%27test%27%29%20%28phrase%20field%3D%27zip_code%27%20boost%3D1.0%20%27test%27%29%29&q.parser=structu
red&size=200&sort=myrank%20desc HTTP/1.1\r\nContent-Type: \r\nAccept-Encoding: \r\nUser-Agent: aws-sdk-ruby2/2.2.1 ruby/2.0.0 x86_64-darwin14.0.0\r\nX-Amz-Date: 20151123T225907Z\r\nHost: cloudsearch-domain-id.us-east-1.cloudsearch.amazonaws.com\r\nX-Amz-Content-Sha256: e3b0c44298fc
1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855\r\nAuthorization: AWS4-HMAC-SHA256 Credential=AKIAJY7R7EQZLEQWMQTA/20151123/us-east-1/cloudsearch/aws4_request, SignedHeaders=host;user-agent;x-amz-content-sha256;x-amz-date, Signature=70127d7857fd688fb8e04a28fdbf872e5ae49075e4be76b5608add1a7274f6c0\r\nContent-Le
ngth: 0\r\nAccept: */*\r\n\r\n"
-> "HTTP/1.1 500 Server Error\r\n"
-> "Content-Type: application/json; charset=UTF-8\r\n"
-> "ETag: \"YzAwMDAwMDAwMDAwMDAwMFNvbHI=\"\r\n"
-> "Last-Modified: Fri, 20 Nov 2015 16:32:56 GMT\r\n"
-> "Content-Length: 196\r\n"
-> "Connection: keep-alive\r\n"
-> "\r\n"
reading 196 bytes...
-> "{\"error\":{\"rid\":\"y/LJtJMquiUKmIIQ\",\"message\":\"[*Deprecated*: Use the outer message field] Unrecognized method call (log).\"},\"message\":\"Unrecognized method call (log).\",\"__type\":\"#SearchException\"}"
read 196 bytes
Conn keep-alive
opening connection to cloudsearch-domain-id.us-east-1.cloudsearch.amazonaws.com:443...
opened
starting SSL for cloudsearch-domain-id.us-east-1.cloudsearch.amazonaws.com:443...
SSL established
<- "GET /2013-01-01/search?format=sdk&pretty=true&expr=%7B%22distance%22%3A%22haversin%2835.8456%2C-86.3903%2Clocation.latitude%2Clocation.longitude%29%22%2C%22myrank%22%3A%22_score%2Flog%28distance%29%22%7D&q=%28or%20%28phrase%20field%3D%27name%27%20boost%3D100%20%27test%27%29%20%28prefix%20field%3D%27name%27%20b$ost%3D10%20%27test%27%29%20%28phrase%20field%3D%27street_address%27%20boost%3D0.5%20%27test%27%29%20%28phrase%20field%3D%27city%27%20boost%3D1.0%20%27test%27%29%20%28phrase%20field%3D%27state_abbr%27%20boost%3D1.0%20%27test%27%29%20%28phrase%20field%3D%27zip_code%27%20boost%3D1.0%20%27test%27%29%29&q.parser=struct$red&size=200&sort=myrank%20desc HTTP/1.1\r\nContent-Type: \r\nAccept-Encoding: \r\nUser-Agent: aws-sdk-ruby2/2.2.1 ruby/2.0.0 x86_64-darwin14.0.0\r\nX-Amz-Date: 20151123T225908Z\r\nHost: cloudsearch-domain-id.us-east-1.cloudsearch.amazonaws.com\r\nX-Amz-Content-Sha256: e3b0c44298f$1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855\r\nAuthorization: AWS4-HMAC-SHA256 Credential=AKIAJY7R7EQZLEQWMQTA/20151123/us-east-1/cloudsearch/aws4_request, SignedHeaders=content-length;host;user-agent;x-amz-content-sha256;x-amz-date, Signature=4ed8cf8e7e207419edc888669cdf3cf0727e08b5b8bf10f59706c45631357b$c\r\nContent-Length: 0\r\nAccept: */*\r\n\r\n"
-> "HTTP/1.1 403 Forbidden\r\n"
-> "Content-Type: application/json\r\n"
-> "x-amzn-RequestId: cd6ad2f0-9235-11e5-a368-f51d032365ca\r\n"
-> "Content-Length: 3149\r\n"
-> "Connection: keep-alive\r\n"
-> "\r\n"
reading 3149 bytes...
-> "{\"__type\":\"#SignatureDoesNotMatch\",\"error\":{\"message\":\"[*Deprecated*: Use the outer message field] The request signature we calculated does not match the signature you provided. Check your AWS Secret Access Key and signing method. Consult the service documentation for details.\\n\\nThe Canonical Strin$ for this request should have been\\n'GET\\n/2013-01-01/search\\nexpr=%7B%22distance%22%3A%22haversin%2835.8456%2C-86.3903%2Clocation.latitude%2Clocation.longitude%29%22%2C%22myrank%22%3A%22_score%2Flog%28distance%29%22%7D&format=sdk&pretty=true&q=%28or%20%28phrase%20field%3D%27name%27%20boost%3D100%20%27test%27%2$%20%28prefix%20field%3D%27name%27%20boost%3D10%20%27test%27%29%20%28phrase%20field%3D%27street_address%27%20boost%3D0.5%20%27test%27%29%20%28phrase%20field%3D%27city%27%20boost%3D1.0%20%27test%27%29%20%28phrase%20field%3D%27state_abbr%27%20boost%3D1.0%20%27test%27%29%20%28phrase%20field%3D%27zip_code%27%20boost%3D$.0%20%27test%27%29%29&q.parser=structured&size=200&sort=myrank%20desc\\ncontent-length:\\nhost:cloudsearch-domain-id.us-east-1.cloudsearch.amazonaws.com\\nuser-agent:aws-sdk-ruby2/2.2.1 ruby/2.0.0 x86_64-darwin14.0.0\\nx-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e46$9b934ca495991b7852b855\\nx-amz-date:20151123T225908Z\\n\\ncontent-length;"
-> "host;user-agent;x-amz-content-sha256;x-amz-date\\ne3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855'\\n\\nThe String-to-Sign should have been\\n'AWS4-HMAC-SHA256\\n20151123T225908Z\\n20151123/us-east-1/cloudsearch/aws4_request\\nc9a079251f7b1d5277864df1f2de97fbb331dc78d41998eac2a7761cd724cfad'\\$\"},\"message\":\"The request signature we calculated does not match the signature you provided. Check your AWS Secret Access Key and signing method. Consult the service documentation for details.\\n\\nThe Canonical String for this request should have been\\n'GET\\n/2013-01-01/search\\nexpr=%7B%22distance%22%3A%22$aversin%2835.8456%2C-86.3903%2Clocation.latitude%2Clocation.longitude%29%22%2C%22myrank%22%3A%22_score%2Flog%28distance%29%22%7D&format=sdk&pretty=true&q=%28or%20%28phrase%20field%3D%27name%27%20boost%3D100%20%27test%27%29%20%28prefix%20field%3D%27name%27%20boost%3D10%20%27test%27%29%20%28phrase%20field%3D%27stree$_address%27%20boost%3D0.5%20%27test%27%29%20%28phrase%20field%3D%27city%27%20boost%3D1.0%20%27test%27%29%20%28phrase%20field%3D%27state_abbr%27%20boost%3D1.0%20%27test%27%29%20%28phrase%20field%3D%27zip_code%27%20boost%3D1.0%20%27test%27%29%29&q.parser=structured&size=200&sort=myrank%20desc\\ncontent-length:\\nhos$:cloudsearch-domain-id.us-east-1.cloudsearch.amazonaws.com\\nuser-agent:aws-sdk-ruby2/2.2.1 ruby/2.0.0 x86_64-darwin14.0.0\\nx-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855\\nx-amz-date:20151123T225908Z\\n\\ncontent-length;host;user-agent;x-am$-content-sha256;x-amz-date\\ne3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855'\\n\\nThe String-to-Sign should have been\\n'AWS4-HMAC-SHA256\\n20151123T225908Z\\n20151123/us-east-1/cloudsearch/aws4_request\\nc9a079251f7b1d5277864df1f2de97fbb331dc78d41998eac2a7761cd724cfad'\\n\"}"
read 3149 bytes
Conn keep-alive

[awood45]

Thanks, that's very helpful. I'm communicating with the service team to see why we're calculating signatures differently, and I'll add this in. I'm not sure it's a client issue yet, but either the client or the service is making signature mistakes here.

[awood45]

I'm having trouble reproducing this on my end though, can you show me a bit more about the request you're making?

[traviskroberts]

@awood45 Thanks so much for looking into this.

Here is a gist of my "search" class as well as a simplified controller that calls it: https://gist.github.com/traviskroberts/8b99cfdcc6bf441b2769

[awood45]

So, if content-length is added after signing, then your request should work. Locally, my default handler order has content-length headers added after signing, which is why I can't recreate this locally.

What I'd like to see is your handler ordering and priority, to see if your handler order differs from mine. Can you give me the output of:

client = Aws::CloudSearchDomain::Client.new(opts) # However you normally construct it.
client.handlers.entries.each { |h| puts "#{h.class}: #{h.step} #{h.priority}" }; nil
client.handlers.to_a

This will help me debug.

[traviskroberts]

@awood45 Of course!

Here is the output of each command:

@client.handlers.entries.each { |h| puts "#{h.class}: #{h.step} #{h.priority}" }

Seahorse::Client::HandlerListEntry: build 90
Seahorse::Client::HandlerListEntry: send 50
Seahorse::Client::HandlerListEntry: validate 95
Seahorse::Client::HandlerListEntry: initialize 90
Seahorse::Client::HandlerListEntry: sign 0
Seahorse::Client::HandlerListEntry: initialize 50
Seahorse::Client::HandlerListEntry: validate 50
Seahorse::Client::HandlerListEntry: build 50
Seahorse::Client::HandlerListEntry: sign 99
Seahorse::Client::HandlerListEntry: sign 50
Seahorse::Client::HandlerListEntry: initialize 90
Seahorse::Client::HandlerListEntry: build 50
Seahorse::Client::HandlerListEntry: sign 50

@client.handlers.to_a

[
  Seahorse::Client::NetHttp::Handler,
  Seahorse::Client::Plugins::ContentLength::Handler,
  Aws::Json::ErrorHandler,
  Aws::Plugins::RequestSigner::Handler,
  Aws::Plugins::RetryErrors::Handler,
  Aws::Rest::Handler,
  Aws::Plugins::UserAgent::Handler,
  Seahorse::Client::Plugins::Endpoint::Handler,
  Aws::Plugins::ParamValidator::Handler,
  Seahorse::Client::Plugins::RaiseResponseErrors::Handler,
  Aws::Plugins::ParamConverter::Handler,
  Seahorse::Client::Plugins::ResponseTarget::Handler
]

[awood45]

Sorry, I had a bug in one line:

client.handlers.entries.each { |h| puts "#{h.handler_class}: #{h.step} #{h.priority}" }; nil

[traviskroberts]

No problem, here's the updated output:

Seahorse::Client::Plugins::Endpoint::Handler: build 90
Seahorse::Client::NetHttp::Handler: send 50
Seahorse::Client::Plugins::RaiseResponseErrors::Handler: validate 95
Seahorse::Client::Plugins::ResponseTarget::Handler: initialize 90
Seahorse::Client::Plugins::ContentLength::Handler: sign 0
Aws::Plugins::ParamConverter::Handler: initialize 50
Aws::Plugins::ParamValidator::Handler: validate 50
Aws::Plugins::UserAgent::Handler: build 50
Aws::Plugins::RetryErrors::Handler: sign 99
Aws::Plugins::RequestSigner::Handler: sign 50
Aws::Plugins::ResponsePaging::Handler: initialize 90
Aws::Rest::Handler: build 50
Aws::Json::ErrorHandler: sign 50

[awood45]

Thanks - this is curious because by this ordering, content-length should strictly be added after signing, which is the workaround for this issue. Looking more in to this.

[awood45]

Okay, I have some more clarity on this issue.

What you're seeing is a two-stage error:

1. Your initial request generates a 500 Error, for whatever reason. The SDK recognizes this and attempts to retry.
2. On the second request only, we additionally sign the content-length header, which generates the signature error. We believe this to be a server-side issue.

What is curious to me is that you're seeing consistent 500 errors, despite adding retries around the second error. That indicates to me a second issue, which I can only speculate on, around your use or the server's reading of your expr param. I'm going to see if I can recreate that.

I'd encourage you, separately, to reach out to the service team via AWS Support to see why you're getting persistent 500 errors.

[awood45]

@traviskroberts I'm working on the signature error still, but I have some more information for you.

That 500 Error you're getting should actually be a 400 Error - it looks like the function "log" is not supported, only "ln", "logn", or "log10". This is why you're getting this error consistently rather than intermittently.

Once the service fixes the signature problem, you'll still see 500 errors. Once this is correctly translated to a 400 error, the request still won't work as-is.

Let me know if this workaround helps you use expr without errors.

[awood45]

I have some examples for you, using the IMDB sample data. Let me know if this helps you avoid the 500 that causes this:

# 500 Error
client.search(query: "star", return: "title", expr: "{ 'score': 'log(_score)' }", sort: "score asc")

# Success
client.search(query: "star", return: "title", expr: "{ 'score': 'log10(_score)' }", sort: "score asc")
client.search(query: "star", return: "title", expr: "{ 'score': 'ln(_score)' }", sort: "score asc")

[traviskroberts]

@awood45 I can confirm that I get the following signing error with the first query, but the other two work just fine.

Aws::CloudSearchDomain::Errors::SignatureDoesNotMatch: The request signature we calculated does not match the signature you provided. Check your AWS Secret Access Key and signing method. Consult the service documentation for details.

The Canonical String for this request should have been
'GET
/2013-01-01/search
expr=%7B%20%27score%27%3A%20%27log%28_score%29%27%20%7D&format=sdk&pretty=true&q=star&return=name&sort=score%20asc
content-length:
host:my-cloudsearch-domain.us-east-1.cloudsearch.amazonaws.com
user-agent:aws-sdk-ruby2/2.2.1 ruby/2.0.0 x86_64-darwin14.0.0
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20151125T213051Z

content-length;host;user-agent;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855'

The String-to-Sign should have been
'AWS4-HMAC-SHA256
20151125T213051Z
20151125/us-east-1/cloudsearch/aws4_request
bac396d5a1f08025bc89aaed949fbe87b32d3361d84ae1b377b9f597f2a4fb47'

[awood45]

Right, the signing error comes on the retry. If you look at the wire trace, a 500 Error (which really should be a 400 Bad Request, but that's a fix in progress) happens first.

So, if you can replace "log" in your call with "ln", "logn", or "log10" as appropriate, you should no longer have this issue.

[awood45]

Referring to the "log distance" bit in your request above.

[traviskroberts]

@awood45 Thanks so much for your help in diagnosing what's going on here. I've tried to change my query to use log10 instead of log and now I'm getting a Aws::CloudSearchDomain::Errors::SearchException error that says undefined field: "distance" in the myrank expression.

It appears that the definition of myrank doesn't have access to the previously defined distance expression. If I sort by distance desc it works just fine.

Any ideas what might be causing this?

Thanks again for all your help!

[awood45]

I'm not sure what would be causing that, as that goes well into the service usage domain.

Hopefully this will help: http://docs.aws.amazon.com/cloudsearch/latest/developerguide/defining-expressions-in-requests.html

I can try to dig around, but admittedly this is past my knowledge of CloudSearch's internal workings.

[traviskroberts]

I was finally able to get around the errors by just combining the two expressions into one.

Instead of:

expr = {
  "distance": "haversin(35.8456,-86.3903,location.latitude,location.longitude)",
  "myrank": "_score/log10(distance)"
}

I changed it to:

expr = { 
  "myrank": "_score/log10(haversin(35.8456,-86.3903,location.latitude,location.longitude))" 
}