diff --git a/.github/workflows/rubocop.yml b/.github/workflows/rubocop.yml index 85a7f74..e4713d0 100644 --- a/.github/workflows/rubocop.yml +++ b/.github/workflows/rubocop.yml @@ -6,7 +6,7 @@ jobs: rubocop: runs-on: ubuntu-latest steps: - - uses: actions/checkout@v2 + - uses: actions/checkout@v3 - name: Set up Ruby uses: ruby/setup-ruby@v1 with: diff --git a/.github/workflows/unit-tests.yml b/.github/workflows/unit-tests.yml index 958debf..0dfa8ff 100644 --- a/.github/workflows/unit-tests.yml +++ b/.github/workflows/unit-tests.yml @@ -6,7 +6,7 @@ jobs: test: runs-on: ubuntu-latest steps: - - uses: actions/checkout@v2 + - uses: actions/checkout@v3 - name: Set up Ruby uses: ruby/setup-ruby@v1 with: diff --git a/CHANGELOG.md b/CHANGELOG.md index 7e7b81e..3a221b0 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,9 +1,34 @@ # Changelog for DS API rubygem +## 1.3.3- 2023-01 + +- (Jon) Refactors the elapsed time calculated for API requests to be resolved as + microseconds rather than milliseconds. This is to improve the reporting of the + elapsed time in the system tooling logs. +- (Jon) Resolves failing tests due to the improper invocation of mock objects + without the correct arguments. +- (Jon) Minor text changes to the .gemspec file to update the description and + summary of the gem as well as the name and email address for the maintainer. +- (Jon) Includes multiple updates and fixes to the codebase to resolve the + majority of the Rubocop warnings. +- (Jon) Updated CI/CD workflows to use latest Epimorphics GitHub Actions + versions. +- (Jon) Updated System test to include a test for the new elapsed time metric. +- (Jon) Refactored the linting settings to include lessons learned in other + projects thereby improving the opinionated results from RuboCop to ensure the + codebase adheres to current best practices. +- (Jon) Refactored the version cadence creation to include a SUFFIX value if + provided; otherwise no SUFFIX is included in the version number. +- (Jon) Includes initial steps for better logging of API requests and responses + to the system logs. +- (Jon) As part of the better logging updates the error message returned to the + requesting app has been refactored to be more concise as well the failed + connection error status has been set specifically to `503 Service Unavailable`. + ## 1.3.2 - 2022-04-01 -- (Ian) Remove use of automated Faraday logging of API calls. Add manual - logging of API calls, to conform to local best practice +- (Ian) Remove use of automated Faraday logging of API calls. Add manual logging + of API calls, to conform to local best practice ## 1.3.1 - 2022-03-28 @@ -19,8 +44,8 @@ ## 1.2.0 - 2022-01-27 -- (Ian) Added `ActiveSupport` instrumentation calls to allow collecting - of metrics on API calls +- (Ian) Added `ActiveSupport` instrumentation calls to allow collecting of + metrics on API calls ## 1.1.1 - 2022-01-21 @@ -32,8 +57,8 @@ ## 1.0.0 - 2021-06-14 (Bogdan) -- Added a DSAPI to SapiNT converter, which converts all DSAPI queries - to SapiNT queries and then sends them to a SapiNT backend +- Added a DSAPI to SapiNT converter, which converts all DSAPI queries to SapiNT + queries and then sends them to a SapiNT backend ## 0.4.5 - 2019-11-11 diff --git a/README.md b/README.md index 6def07a..13ec39c 100644 --- a/README.md +++ b/README.md @@ -16,16 +16,16 @@ returned to the caller in a compact JSON format. In 2021, we took the decision to retire the DsAPI codebase, which has not been actively maintained for some time. In its place, we now expect to use -[SapiNT](https://github.com/epimorphics/sapi-nt). SapiNT performs a similar +[Sapi-NT](https://github.com/epimorphics/sapi-nt). Sapi-NT performs a similar function, in that it provides a RESTful API in which compact queries are translated into SPARQL expressions, and the results are available in (amongst other formats) -JSON encoding. However, the input to SapiNT, in which we articulate the projection +JSON encoding. However, the input to Sapi-NT, in which we articulate the projection of the underlying hypercube that we require is encoded as URL parameters in an HTTP GET request. DsAPI, in contrast, expects the input query to be POSTed as a JSON expression. To minimise changes to the client applications in which this gem is used, we have -implemented a shim layer that accepts DsAPI expressions and re-codes them as SapiNT +implemented a shim layer that accepts DsAPI expressions and re-codes them as Sapi-NT URLs. Similarly, differences in the returned JSON results formats are also ironed out by this shim layer. It is possible to do this because, once the designs of the applications had settled, the HMLR apps only use a subset of the expressive power @@ -50,8 +50,8 @@ source 'https://rubygems.pkg.github.com/epimorphics' do end ``` -An API URL needs to be provided for the `Service` class in order for the gem -to work. +_N.B. An API URL needs to be provided by that project for the `Service` class in +order for the gem to work._ --- @@ -71,14 +71,25 @@ Inspecting 21 files ### Tests -To run the tests you must set the environment variable `API_URL` to point to a -running instance of a valid SAPINT API and run `rake test`: +You will need to have started the [HMLR Data API](https://github.com/epimorphics/lr-data-api) +locally. To do so follow the instructions in the repository's [README](https://github.com/epimorphics/lr-data-api#run) + +Once the API is started you can invoke the tests with the simple command below[^1]: + +```sh +rake test +``` + +You can also set the environment variable `API_URL` to point to a running +instance of the HMLR Data API from a non-default port: ```sh API_URL=http://localhost:8080 rake test ``` -If `API_URL` is not set it will default to `http://localhost:8888` +_N.B If `API_URL` environment variable is not set it will default to `http://localhost:8888`_ + +--- ### Publishing the gem to the GitHub Package Registry @@ -113,3 +124,6 @@ This gem integrates with Prometheus monitoring by emitting the following - `response.api` - API response, including status code and duration - `connection_failure.api` - failure to connect to the API, with exception detail - `service_exception.api` - failure to process the API response + +[^1]: You may need to preface the `rake test` command with `bundle exec` if you + are using a Ruby version manager such as `rbenv` or `rvm`. diff --git a/Rakefile b/Rakefile index 75f3fc0..421eb2f 100644 --- a/Rakefile +++ b/Rakefile @@ -1,10 +1,11 @@ -# frozen-string-literal: true +# frozen_string_literal: true require 'bundler/gem_tasks' require 'rake/testtask' Rake::TestTask.new(:test) do |t| t.test_files = FileList['test/**/*_test.rb'] + t.warning = false end task default: :test diff --git a/data_services_api.gemspec b/data_services_api.gemspec index 088592f..7126210 100644 --- a/data_services_api.gemspec +++ b/data_services_api.gemspec @@ -1,4 +1,4 @@ -# frozen-string-literal: true +# frozen_string_literal: true lib = File.expand_path('lib', __dir__) $LOAD_PATH.unshift(lib) unless $LOAD_PATH.include?(lib) @@ -10,7 +10,8 @@ Gem::Specification.new do |spec| spec.version = DataServicesApi::VERSION spec.authors = ['Epimorphics Ltd'] spec.email = ['info@epimorphics.com'] - spec.summary = 'Ruby wrapper for Epimorphics data service API' + spec.summary = 'Data Services API' + spec.description = 'Ruby wrapper for Epimorphics Data Services API' spec.homepage = 'https://github.com/epimorphics/data-API-ruby' spec.license = 'MIT' spec.required_ruby_version = '>= 2.6' @@ -26,7 +27,7 @@ Gem::Specification.new do |spec| spec.add_runtime_dependency 'json', '~> 2.6.1' spec.add_runtime_dependency 'yajl-ruby', '~> 1.4.1' - spec.add_development_dependency 'bundler', '~> 2.3.5' + spec.add_development_dependency 'bundler', '~> 2.4' spec.add_development_dependency 'byebug', '~> 11.1.3' spec.add_development_dependency 'excon', '~> 0.90.0' spec.add_development_dependency 'json_expressions', '~> 0.9.0' diff --git a/fixtures/vcr_cassettes/test_0007_should_also_instrument_a_failed_API_call.yml b/fixtures/vcr_cassettes/test_0007_should_also_instrument_a_failed_API_call.yml new file mode 100644 index 0000000..8cc9347 --- /dev/null +++ b/fixtures/vcr_cassettes/test_0007_should_also_instrument_a_failed_API_call.yml @@ -0,0 +1,95 @@ +--- +http_interactions: +- request: + method: get + uri: http://localhost:8888/ceci/nest/pas/une/page?_limit=1 + body: + encoding: US-ASCII + string: '' + headers: + User-Agent: + - Faraday v1.10.2 + Accept: + - application/json + Accept-Encoding: + - gzip;q=1.0,deflate;q=0.6,identity;q=0.3 + response: + status: + code: 404 + message: '' + headers: + Sleuth-Trace-Id: + - 1ad8bb4208736675 + Sleuth-Span-Id: + - 1ad8bb4208736675 + Vary: + - Accept + - Access-Control-Request-Headers + - Access-Control-Request-Method + - Origin + Cache-Control: + - max-age=0 + Content-Type: + - application/json;charset=UTF-8 + Content-Length: + - '183' + Date: + - Thu, 05 Jan 2023 16:33:00 GMT + body: + encoding: UTF-8 + string: |- + { + "timestamp" : "Thu Jan 05 16:33:00 GMT 2023", + "status" : "404", + "error" : "Not Found", + "message" : "Requested endpoint doesn't exist", + "path" : "/ceci/nest/pas/une/page" + } + recorded_at: Thu, 05 Jan 2023 16:33:00 GMT +- request: + method: get + uri: http://localhost:8080/ceci/nest/pas/une/page?_limit=1 + body: + encoding: US-ASCII + string: '' + headers: + User-Agent: + - Faraday v1.10.2 + Accept: + - application/json + Accept-Encoding: + - gzip;q=1.0,deflate;q=0.6,identity;q=0.3 + response: + status: + code: 404 + message: '' + headers: + Sleuth-Trace-Id: + - a96c3b47516a2a5d + Sleuth-Span-Id: + - a96c3b47516a2a5d + Vary: + - Accept + - Access-Control-Request-Headers + - Access-Control-Request-Method + - Origin + Cache-Control: + - max-age=0 + Content-Type: + - application/json;charset=UTF-8 + Content-Length: + - '183' + Date: + - Mon, 16 Jan 2023 21:26:29 GMT + body: + encoding: UTF-8 + string: |- + { + "timestamp" : "Mon Jan 16 21:26:29 GMT 2023", + "status" : "404", + "error" : "Not Found", + "message" : "Requested endpoint doesn't exist", + "path" : "/ceci/nest/pas/une/page" + } + recorded_at: Mon, 16 Jan 2023 21:26:29 GMT +recorded_with: VCR 6.1.0 diff --git a/fixtures/vcr_cassettes/test_0009_should_correctly_receive_a_duration_in_microseconds.yml b/fixtures/vcr_cassettes/test_0009_should_correctly_receive_a_duration_in_microseconds.yml new file mode 100644 index 0000000..bd170ec --- /dev/null +++ b/fixtures/vcr_cassettes/test_0009_should_correctly_receive_a_duration_in_microseconds.yml @@ -0,0 +1,75 @@ +--- +http_interactions: +- request: + method: get + uri: http://localhost:8080/landregistry/id/ukhpi?_limit=1 + body: + encoding: US-ASCII + string: '' + headers: + User-Agent: + - Faraday v1.10.2 + Accept: + - application/json + Accept-Encoding: + - gzip;q=1.0,deflate;q=0.6,identity;q=0.3 + response: + status: + code: 200 + message: '' + headers: + Sleuth-Trace-Id: + - 9da7c5677828fe61 + Sleuth-Span-Id: + - 9da7c5677828fe61 + Vary: + - Accept + Cache-Control: + - max-age=0 + Content-Type: + - application/json + Content-Length: + - '1771' + Date: + - Mon, 16 Jan 2023 21:26:37 GMT + body: + encoding: UTF-8 + string: '{"meta":{"@id":"http://localhost//landregistry/id/ukhpi?_limit=1","publisher":"","license":"","licenseName":"","comment":"","version":"0.1","hasFormat":["http://localhost//landregistry/id/ukhpi.html?_limit=1","http://localhost//landregistry/id/ukhpi.geojson?_limit=1","http://localhost//landregistry/id/ukhpi.rdf?_limit=1","http://localhost//landregistry/id/ukhpi.json?_limit=1","http://localhost//landregistry/id/ukhpi.csv?_limit=1","http://localhost//landregistry/id/ukhpi.ttl?_limit=1"],"limit":1},"items":[{"@id":"http://landregistry.data.gov.uk/data/ukhpi/region/rutland/month/1999-05","refRegion":{"@id":"http://landregistry.data.gov.uk/id/region/rutland"},"refMonth":"1999-05","averagePrice":86936,"housePriceIndex":34.68,"percentageAnnualChange":7.75,"percentageChange":3.35,"salesVolume":77,"averagePriceDetached":118808,"housePriceIndexDetached":35.49,"percentageChangeDetached":3.21,"percentageAnnualChangeDetached":7.56,"averagePriceSemiDetached":71348,"housePriceIndexSemiDetached":34.29,"percentageChangeSemiDetached":3.42,"percentageAnnualChangeSemiDetached":7.91,"averagePriceTerraced":61817,"housePriceIndexTerraced":33.79,"percentageChangeTerraced":3.60,"percentageAnnualChangeTerraced":7.55,"averagePriceFlatMaisonette":42370,"housePriceIndexFlatMaisonette":34.70,"percentageChangeFlatMaisonette":3.61,"percentageAnnualChangeFlatMaisonette":9.47,"averagePriceNewBuild":99439,"housePriceIndexNewBuild":33.50,"percentageChangeNewBuild":3.17,"percentageAnnualChangeNewBuild":8.12,"salesVolumeNewBuild":21,"averagePriceExistingProperty":85036,"housePriceIndexExistingProperty":34.89,"percentageChangeExistingProperty":3.38,"percentageAnnualChangeExistingProperty":7.88,"salesVolumeExistingProperty":56,"refPeriodStart":"1999-05-01","refPeriodDuration":1}]}' + recorded_at: Mon, 16 Jan 2023 21:26:37 GMT +- request: + method: get + uri: http://localhost:8888/landregistry/id/ukhpi?_limit=1 + body: + encoding: US-ASCII + string: '' + headers: + User-Agent: + - Faraday v1.10.2 + Accept: + - application/json + Accept-Encoding: + - gzip;q=1.0,deflate;q=0.6,identity;q=0.3 + response: + status: + code: 200 + message: '' + headers: + Sleuth-Trace-Id: + - dae267f30f82ee41 + Sleuth-Span-Id: + - dae267f30f82ee41 + Vary: + - Accept + Cache-Control: + - max-age=0 + Content-Type: + - application/json + Content-Length: + - '1771' + Date: + - Wed, 25 Jan 2023 16:37:39 GMT + body: + encoding: UTF-8 + string: '{"meta":{"@id":"http://localhost//landregistry/id/ukhpi?_limit=1","publisher":"","license":"","licenseName":"","comment":"","version":"0.1","hasFormat":["http://localhost//landregistry/id/ukhpi.html?_limit=1","http://localhost//landregistry/id/ukhpi.geojson?_limit=1","http://localhost//landregistry/id/ukhpi.rdf?_limit=1","http://localhost//landregistry/id/ukhpi.json?_limit=1","http://localhost//landregistry/id/ukhpi.csv?_limit=1","http://localhost//landregistry/id/ukhpi.ttl?_limit=1"],"limit":1},"items":[{"@id":"http://landregistry.data.gov.uk/data/ukhpi/region/rutland/month/1999-05","refRegion":{"@id":"http://landregistry.data.gov.uk/id/region/rutland"},"refMonth":"1999-05","averagePrice":86936,"housePriceIndex":34.68,"percentageAnnualChange":7.75,"percentageChange":3.35,"salesVolume":77,"averagePriceDetached":118808,"housePriceIndexDetached":35.49,"percentageChangeDetached":3.21,"percentageAnnualChangeDetached":7.56,"averagePriceSemiDetached":71348,"housePriceIndexSemiDetached":34.29,"percentageChangeSemiDetached":3.42,"percentageAnnualChangeSemiDetached":7.91,"averagePriceTerraced":61817,"housePriceIndexTerraced":33.79,"percentageChangeTerraced":3.60,"percentageAnnualChangeTerraced":7.55,"averagePriceFlatMaisonette":42370,"housePriceIndexFlatMaisonette":34.70,"percentageChangeFlatMaisonette":3.61,"percentageAnnualChangeFlatMaisonette":9.47,"averagePriceNewBuild":99439,"housePriceIndexNewBuild":33.50,"percentageChangeNewBuild":3.17,"percentageAnnualChangeNewBuild":8.12,"salesVolumeNewBuild":21,"averagePriceExistingProperty":85036,"housePriceIndexExistingProperty":34.89,"percentageChangeExistingProperty":3.38,"percentageAnnualChangeExistingProperty":7.88,"salesVolumeExistingProperty":56,"refPeriodStart":"1999-05-01","refPeriodDuration":1}]}' + recorded_at: Wed, 25 Jan 2023 16:37:39 GMT +recorded_with: VCR 6.1.0 diff --git a/lib/data_services_api/dataset.rb b/lib/data_services_api/dataset.rb index 8140254..33d4804 100644 --- a/lib/data_services_api/dataset.rb +++ b/lib/data_services_api/dataset.rb @@ -39,7 +39,7 @@ def describe_api end def explain_api - # There should be a HATEOS-style reference to this endpoint + # TODO: There should be a HATEOS-style reference to this endpoint # https://github.com/epimorphics/ds-api-ruby/issues/1 structure_api.gsub(/structure$/, 'explain') end diff --git a/lib/data_services_api/service.rb b/lib/data_services_api/service.rb index 500f8d2..7b19fe9 100644 --- a/lib/data_services_api/service.rb +++ b/lib/data_services_api/service.rb @@ -43,7 +43,7 @@ def get_json(http_url, params, options) end def get_from_api(http_url, accept_headers, params, options) # rubocop:disable Metrics/MethodLength, Metrics/AbcSize - start_time = Time.now + start_time = Process.clock_gettime(Process::CLOCK_MONOTONIC, :microsecond) conn = set_connection_timeout(create_http_connection(http_url)) response = conn.get do |req| @@ -115,7 +115,11 @@ def set_connection_timeout(conn) # rubocop:disable Naming/AccessorMethodName def ok?(response, http_url) unless (200..207).cover?(response.status) - msg = "Failed to read from #{http_url}: #{response.status.inspect}" + response_body = JSON.parse(response.body, symbolize_names: true) + response_message = response_body[:message] + response_error = response_body[:error] + msg = "#{response_error}: #{response_message}" + raise ServiceException.new(msg, response.status, http_url, response.body) end @@ -137,31 +141,36 @@ def report_json_failure(json) end def instrument_response(response, start_time) - log_api_response(response, start_time: start_time) - - instrumenter&.instrument('response.api', response: response, duration: Time.now - start_time) + log_api_response(response, start_time) + end_time = Process.clock_gettime(Process::CLOCK_MONOTONIC, :microsecond) + elapsed_time = end_time - start_time + instrumenter&.instrument( + 'response.api', + response: response, + duration: elapsed_time + ) end def instrument_connection_failure(http_url, exception, start_time) log_api_response( nil, - start_time: start_time, + start_time, message: exception.message, - status: 'connection fail', + status: 503, # Service Unavailable status code (see https://httpstatuses.com/503) url: http_url ) - instrumenter&.instrument('connection_failure.api', exception: exception) + instrumenter&.instrument('connection_failure.api', exception) end def instrument_service_exception(http_url, exception, start_time) log_api_response( nil, - start_time: start_time, + start_time, message: exception.message, - status: 'service exception', + status: exception.status, url: http_url ) - instrumenter&.instrument('service_exception.api', exception: exception) + instrumenter&.instrument('service_exception.api', exception) end # Return true if we're currently running in a Rails environment @@ -169,11 +178,13 @@ def in_rails? defined?(Rails) end - def log_api_response(response, start_time:, url: nil, status: nil, message: 'GET from API') + def log_api_response(response, start_time, url: nil, status: nil, message: 'GET from API') + end_time = Process.clock_gettime(Process::CLOCK_MONOTONIC, :microsecond) + elapsed_time = end_time - start_time logger.info( url: response ? response.env[:url].to_s : url, status: status || response.status, - duration: Time.now - start_time, + duration: elapsed_time, message: message ) end diff --git a/lib/data_services_api/version.rb b/lib/data_services_api/version.rb index 576185d..8910030 100644 --- a/lib/data_services_api/version.rb +++ b/lib/data_services_api/version.rb @@ -4,6 +4,7 @@ module DataServicesApi MAJOR = 1 MINOR = 3 - PATCH = 2 - VERSION = "#{MAJOR}.#{MINOR}.#{PATCH}" + PATCH = 3 + SUFFIX = nil + VERSION = "#{MAJOR}.#{MINOR}.#{PATCH}#{SUFFIX && ".#{SUFFIX}"}" end diff --git a/test/data_services_api/data_services_api_test.rb b/test/data_services_api/data_services_api_test.rb index 05ccfea..9fe6fa3 100644 --- a/test/data_services_api/data_services_api_test.rb +++ b/test/data_services_api/data_services_api_test.rb @@ -8,7 +8,13 @@ end it 'should be constructable with a given URL' do - dsapi = DataServicesApi::Service.new(url: 'foo/bar') + mock_logger = mock('logger') + mock_logger.expects(:info).at_least(0) + + @service = DataServicesApi::Service.new + + dsapi = DataServicesApi::Service.new(url: 'foo/bar', logger: mock_logger) + _(dsapi.url).must_match(%r{foo/bar}) end end diff --git a/test/data_services_api/dataset_test.rb b/test/data_services_api/dataset_test.rb index 983627d..b7d1f58 100644 --- a/test/data_services_api/dataset_test.rb +++ b/test/data_services_api/dataset_test.rb @@ -5,7 +5,7 @@ describe 'DataServiceApi::Dataset' do before do VCR.insert_cassette name, record: :new_episodes - api_url = ENV['API_URL'] || 'http://localhost:8888' + api_url = ENV.fetch('API_URL', 'http://localhost:8888') mock_logger = mock('logger') mock_logger.expects(:info).at_least(0) diff --git a/test/data_services_api/service_test.rb b/test/data_services_api/service_test.rb index 13571b2..53e42e2 100644 --- a/test/data_services_api/service_test.rb +++ b/test/data_services_api/service_test.rb @@ -28,12 +28,16 @@ def info(message, &block) describe 'DataServicesAPI::Service', vcr: true do let(:api_url) do - ENV['API_URL'] || 'http://localhost:8888' + ENV.fetch('API_URL', 'http://localhost:8888') + end + + let :mock_logger do + MockLogger.new end before do VCR.insert_cassette(name, record: :new_episodes) - @service = DataServicesApi::Service.new + @service = DataServicesApi::Service.new(url: api_url, logger: mock_logger) end after do @@ -57,8 +61,7 @@ def info(message, &block) end it 'should retrieve JSON with HTTP GET' do - mock_logger = MockLogger.new - service = DataServicesApi::Service.new(url: 'http://localhost:8080', logger: mock_logger) + service = DataServicesApi::Service.new(url: api_url, logger: mock_logger) json = service.api_get_json("#{api_url}/landregistry/id/ukhpi", { '_limit' => 1 }) _(json).wont_be_nil _(json['meta']).wont_be_nil @@ -66,7 +69,6 @@ def info(message, &block) it 'should instrument an API call' do instrumenter = MockNotifications.new - mock_logger = MockLogger.new DataServicesApi::Service .new(url: api_url, instrumenter: instrumenter, logger: mock_logger) @@ -79,7 +81,6 @@ def info(message, &block) it 'should instrument a failed API call' do instrumenter = MockNotifications.new - mock_logger = MockLogger.new _ do DataServicesApi::Service @@ -92,9 +93,8 @@ def info(message, &block) _(instrumentations.first.first).must_equal 'connection_failure.api' end - it 'should instrument a failed API call' do + it 'should also instrument a failed API call' do instrumenter = MockNotifications.new - mock_logger = MockLogger.new _ do DataServicesApi::Service @@ -118,4 +118,26 @@ def info(message, &block) # @TODO: add specific constraints on received log messages _(logger.messages).wont_be_empty end + + it 'should correctly receive a duration in microseconds' do + new_logger = MockLogger.new + + DataServicesApi::Service + .new(url: api_url, logger: new_logger) + .api_get_json("#{api_url}/landregistry/id/ukhpi", { '_limit' => 1 }) + + _(new_logger).wont_be_nil + + msg_log = new_logger.messages[:info].first + + _(msg_log).wont_be_nil + _(msg_log.size).must_equal 2 + + json = msg_log.first + + _(json).wont_be_nil + _(json[:duration]).wont_be_nil + _(json[:duration]).must_be :>, 0 + assert_kind_of(Integer, json[:duration]) + end end