{"id":1902,"date":"2012-02-02T11:43:37","date_gmt":"2012-02-02T19:43:37","guid":{"rendered":"http:\/\/onehub.com\/blog\/?p=1902"},"modified":"2016-02-02T08:21:21","modified_gmt":"2016-02-02T16:21:21","slug":"finding-and-fixing-a-long-standing-bug-in-the-ruby-amazon-s3-library","status":"publish","type":"post","link":"https:\/\/www.onehub.com\/blog\/2012\/02\/02\/finding-and-fixing-a-long-standing-bug-in-the-ruby-amazon-s3-library\/","title":{"rendered":"Fixing a long standing bug in the Ruby Amazon S3 Library"},"content":{"rendered":"<p>The <a href=\"http:\/\/rubygems.org\/gems\/aws-s3\">AWS::S3 library for Ruby<\/a> has been around since the release of <a href=\"http:\/\/aws.amazon.com\/s3\/\">Amazon S3<\/a> in 2006; hundreds, if not thousands, of applications use it. Consequently, it is not usually <em>&#8220;the suspect&#8221;<\/em> when looking for the cause of intermittent access errors to S3. However, we recently found and fixed an error that has been present in the signature calculation method since the library was first released.<\/p>\n<p>We use S3 as the backing store for <a href=\"https:\/\/onehub.com\/\">Onehub Workspaces<\/a>, and we do a <strong>lot<\/strong> of S3 operations. During routine log monitoring we noticed a slow, but persistent, stream of HTTP 403 (Unauthorized Access) errors from S3. These errors were not frequent enough to cause problems for our customers; applications using S3 should be designed anticipate errors, and retry. Still, we felt that further investigation was warranted.<\/p>\n<p>To manage the logs generated by all of the Onehub services, we use <a href=\"http:\/\/papertrailapp.com\">Papertrail<\/a>. Papertrail allows us to run a real-time search against our production logs, showing us requests to S3 like this:<\/p>\n<pre class=\"brush: plain; light: true; title: ; notranslate\" title=\"\">\r\nhttps:\/\/s3.amazonaws.com\/&lt;bucket&gt;\/&lt;object&gt;?AWSAccessKeyId=&lt;ouraccesskey&gt;&Expires=1328127911&Signature=l74ewTX9hh0s2oiLoIY83V%2BlLuM%3D\r\n<\/pre>\n<p>The components used to calculate the signature are <a href=\"http:\/\/aws.amazon.com\/documentation\/s3\/\">well documented by Amazon<\/a>. When a signature fails, S3 will provide the components it attempted to use in the XML returned with the error message. We noticed that the signatures in these errors were different than those that should have been calculated for the provided Expires time. We monkey-patched the <code>#canonical_signature<\/code> method of <code>AWS::S3::Authentication::Signature<\/code> to handle a closure.<\/p>\n<pre class=\"brush: ruby; light: true; title: ; notranslate\" title=\"\">\r\nmodule AWS\r\n  module S3\r\n    class Authentication\r\n      class Signature\r\n        private\r\n        def encoded_canonical\r\n          digest = OpenSSL::Digest::Digest.new('sha1')\r\n          b64_hmac = [OpenSSL::HMAC.digest(digest, secret_access_key, canonical_string)].pack(&quot;m&quot;).strip\r\n          if options[:debug_proc]\r\n            options[:debug_proc].call(sprintf(&quot;AWS::S3::Authentication::Signature - request %s encoded canonical: %s %s  canonical: [%s]&quot;, @request.path, b64_hmac, CGI.escape(b64_hmac), canonical_string))\r\n          end\r\n          url_encode? ? CGI.escape(b64_hmac) : b64_hmac\r\n        end\r\n      end\r\n    end\r\n  end\r\nend\r\n<\/pre>\n<p>This enabled us to pass in an option to <code>AWS::S3#url_for<\/code> containing a closure with our debugging method.<\/p>\n<pre class=\"brush: ruby; light: true; title: ; notranslate\" title=\"\">\r\noptions = options.merge({:debug_proc =&gt; lambda{|x| logger.warn(x)}})\r\nthe_url = AssetStore.url_for(key_name, options)\r\n<\/pre>\n<p>We put this through testing, and into production, then waited for the next error to appear.<\/p>\n<pre class=\"brush: plain; light: true; title: ; notranslate\" title=\"\">\r\nAWS::S3::Authentication::Signature - request \/&lt;bucket&gt;\/&lt;keyname&gt; encoded canonical: l74ewTX9hh0s2oiLoIY83V+lLuM= l74ewTX9hh0s2oiLoIY83V%2BlLuM%3D canonical: [GET#012#012#0121328127912#012\/&lt;bucket&gt;\/&lt;keyname&gt;]\r\nhttps:\/\/s3.amazonaws.com\/&lt;bucket&gt;\/&lt;object&gt;?AWSAccessKeyId=&lt;OURACCESSKEY&gt;&Expires=1328127911&Signature=l74ewTX9hh0s2oiLoIY83V%2BlLuM%3D\r\n<\/pre>\n<p>From here we could see the error. The <code>Expires<\/code> time used to calculate the signature was different that the time provided in the URL. The value <code>1328127911<\/code> is in the URL, while <code>1328127912<\/code> was used to calculate the signature!<\/p>\n<p>But why?<\/p>\n<p>It took a bit of digging through the <code>AWS::S3<\/code> source, but we found the culprit. When generating these S3 URLs, we pass an <code>expires_in<\/code> option to <code>AWS::S3#url_for<\/code>.<\/p>\n<pre class=\"brush: ruby; light: true; title: ; notranslate\" title=\"\">\r\n# Signature is the abstract super class for the Header and QueryString authentication methods. It does the job\r\n# of computing the canonical_string using the CanonicalString class as well as encoding the canonical string. The subclasses\r\n# parameterize these computations and arrange them in a string form appropriate to how they are used, in one case a http request\r\n# header value, and in the other case key\/value query string parameter pairs.\r\nclass Signature &lt; String #:nodoc:\r\n  attr_reader :request, :access_key_id, :secret_access_key, :options\r\n\r\n  def initialize(request, access_key_id, secret_access_key, options = {})\r\n    super()\r\n    @request, @access_key_id, @secret_access_key = request, access_key_id, secret_access_key\r\n    @options = options\r\n  end\r\n\r\n  private\r\n\r\n    def canonical_string\r\n      options = {}\r\n      options[:expires] = expires if expires?\r\n      CanonicalString.new(request, options)\r\n    end\r\n    memoized :canonical_string\r\n\r\n    def encoded_canonical\r\n      digest   = OpenSSL::Digest::Digest.new('sha1')\r\n      b64_hmac = [OpenSSL::HMAC.digest(digest, secret_access_key, canonical_string)].pack(&quot;m&quot;).strip\r\n      url_encode? ? CGI.escape(b64_hmac) : b64_hmac\r\n    end\r\n\r\n    def url_encode?\r\n      !@options[:url_encode].nil?\r\n    end\r\n\r\n    def expires?\r\n      is_a? QueryString\r\n    end\r\n\r\n    def date\r\n      request['date'].to_s.strip.empty? ? Time.now : Time.parse(request['date'])\r\n    end\r\nend\r\n\r\n# Provides query string authentication by computing the three authorization parameters: AWSAccessKeyId, Expires and Signature.\r\n# More details about the various authentication schemes can be found in the docs for its containing module, Authentication.\r\nclass QueryString &lt; Signature #:nodoc:\r\n  constant :DEFAULT_EXPIRY, 300 # 5 minutes\r\n  def initialize(*args)\r\n    super\r\n    options[:url_encode] = true\r\n    self &lt;&lt; build\r\n  end\r\n\r\n  private\r\n\r\n    # Will return one of three values, in the following order of precedence:\r\n    #\r\n    #   1) Seconds since the epoch explicitly passed in the +:expires+ option\r\n    #   2) The current time in seconds since the epoch plus the number of seconds passed in\r\n    #      the +:expires_in+ option\r\n    #   3) The current time in seconds since the epoch plus the default number of seconds (60 seconds)\r\n    def expires\r\n      return options[:expires] if options[:expires]\r\n      date.to_i + expires_in\r\n    end\r\n\r\n    def expires_in\r\n      options.has_key?(:expires_in) ? Integer(options[:expires_in]) : DEFAULT_EXPIRY\r\n    end\r\n\r\n    # Keep in alphabetical order\r\n    def build\r\n      &quot;AWSAccessKeyId=#{access_key_id}&amp;Expires=#{expires}&amp;Signature=#{encoded_canonical}&quot;\r\n    end\r\nend\r\n<\/pre>\n<p>The <code>#initialize<\/code> method is the entry point, but most of the work is done by <code>#build<\/code>. The bug was immediately apparent once we looked at <code>#expires<\/code>. Because <code>#build<\/code> calls <code>#expires<\/code>, and then <code>#encoded_canonical<\/code> calls it later, the date used can change. The <code>#date<\/code> method uses <code>Time.now<\/code>, if these calls happened on different seconds, they would result in different values. The solution is to memoize the time; it could be done in <code>#expires<\/code> or <code>#date<\/code>.<\/p>\n<pre class=\"brush: ruby; light: true; title: ; notranslate\" title=\"\">\r\ndef expires\r\n  return options[:expires] if options[:expires]\r\n  @expires ||= date.to_i + expires_in\r\nend\r\n<\/pre>\n<p>Interestingly, this error is only possible if the <code>expires_in<\/code> option is used. We suspect most people either use the library&#8217;s <code>DEFAULT_EXPIRY<\/code> or pass in an <code>expires<\/code> option, both of which cause <code>#expires<\/code> to avoid the call to <code>#date<\/code>.<\/p>\n<p>After a bit of testing we put this code into production and have eliminated these errors, resulting in better performance for our customers. We have also submitted a <a href=\"https:\/\/github.com\/marcel\/aws-s3\/pull\/54\">pull request<\/a> to the library maintainer.<\/p>\n","protected":false},"excerpt":{"rendered":"<p>The AWS::S3 library for Ruby has been around since the release of Amazon S3 in 2006; hundreds, if not thousands, of applications use it. Consequently, it is not usually &#8220;the suspect&#8221; when looking for the cause of intermittent access errors [&hellip;]<\/p>\n","protected":false},"author":8,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"_themeisle_gutenberg_block_has_review":false},"categories":[1],"tags":[],"_links":{"self":[{"href":"https:\/\/www.onehub.com\/blog\/wp-json\/wp\/v2\/posts\/1902"}],"collection":[{"href":"https:\/\/www.onehub.com\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.onehub.com\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.onehub.com\/blog\/wp-json\/wp\/v2\/users\/8"}],"replies":[{"embeddable":true,"href":"https:\/\/www.onehub.com\/blog\/wp-json\/wp\/v2\/comments?post=1902"}],"version-history":[{"count":0,"href":"https:\/\/www.onehub.com\/blog\/wp-json\/wp\/v2\/posts\/1902\/revisions"}],"wp:attachment":[{"href":"https:\/\/www.onehub.com\/blog\/wp-json\/wp\/v2\/media?parent=1902"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.onehub.com\/blog\/wp-json\/wp\/v2\/categories?post=1902"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.onehub.com\/blog\/wp-json\/wp\/v2\/tags?post=1902"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}