From a64ff9e09490b97dcf90800fd59843c588709028 Mon Sep 17 00:00:00 2001 From: vveliev-tc <40637521+vveliev-tc@users.noreply.github.com> Date: Wed, 10 Jul 2019 15:24:47 -0400 Subject: [PATCH] various updates (#23) * Set description to cmd args of parallel_tests process * Fix matcher to detect when start time needs to be updated * Clean up formatting in report.rb * Implement a folder creation lock file to address duplicate folders being created * Delay each process by its ID number to create a staggered start to reporting in Report Portal (addresses load issues) * Formatting and cleanup in parallel_report.rb * Use temporary directory for tracking folder creation * Add commenting around why we are delaying threads * Make sure to use a "full path" for folder creation tracking * fixing report description when run in parallel - refactoring how runner process is detected - added fallback to cucumber if parallel test was not for parallel formatter * - reverting some changes - launch_uuid related fixes * Fix Cucumber parallel formatter * Fix parallel_tests version and possible endless loop * Add debug logging to debug some issue * Add more debug logging * Remove retrying of requests to Report Portal * Set last_used_time to a time of the parent item * Set description to cmd args of parallel_tests process * Fix URLs to include required "filter.eq.launch" parameter * Fix matcher to detect when start time needs to be updated * Clean up formatting in report.rb * Implement a folder creation lock file to address duplicate folders being created * Delay each process by its ID number to create a staggered start to reporting in Report Portal (addresses load issues) * fixing report description when run in parallel - if launch_id or file_with_launch_id is provided launch will not be marked as finished - moved sleep time, since we are waiting for report to be created anyways * - reverting file lock changes for reading the file - moving lock file related functions to private * - fixing temp file path generation - refactoring how runner process is detected - added fallback to cucumber if parallel test was not for parallel formatter * using single formatter for both parallel_cucumber and cucumber * adding logger for report portal * updating readme and adding settings for logging level * updating how response processing is handling * fixing issue with child process not closing the folder's items * fixing value for time, removing cucumber IO as it's no longer needed * - adding logging - when run in parallel, child process should not close items in process(folder) * - adding logging - add exception handling when closing item , if already closed , ignore RP 40018 error code * adding patch for multipart * updating version --- .rubocop_todo.yml | 67 +++++- Gemfile | 9 +- README.md | 46 ++-- lib/report_portal/cucumber/formatter.rb | 10 +- .../cucumber/parallel_formatter.rb | 14 -- lib/report_portal/cucumber/parallel_report.rb | 54 ----- lib/report_portal/cucumber/report.rb | 222 +++++++++++++++--- lib/report_portal/patches/fariday.rb | 17 ++ lib/report_portal/patches/rest_client.rb | 45 ---- lib/report_portal/settings.rb | 3 +- lib/report_portal/version.rb | 2 +- lib/reportportal.rb | 171 ++++++++------ 12 files changed, 409 insertions(+), 251 deletions(-) delete mode 100644 lib/report_portal/cucumber/parallel_formatter.rb delete mode 100644 lib/report_portal/cucumber/parallel_report.rb create mode 100644 lib/report_portal/patches/fariday.rb delete mode 100644 lib/report_portal/patches/rest_client.rb diff --git a/.rubocop_todo.yml b/.rubocop_todo.yml index 6120c8b..61057f4 100644 --- a/.rubocop_todo.yml +++ b/.rubocop_todo.yml @@ -6,6 +6,14 @@ # Note that changes in the inspected code, or installation of new # versions of RuboCop, may require this file to be generated again. +# Offense count: 2 +# Cop supports --auto-correct. +# Configuration parameters: EnforcedStyle, IndentationWidth. +# SupportedStyles: with_first_argument, with_fixed_indentation +Layout/AlignArguments: + Exclude: + - 'lib/report_portal/rspec/formatter.rb' + # Offense count: 2 # Cop supports --auto-correct. Layout/EmptyLineAfterGuardClause: @@ -13,6 +21,60 @@ Layout/EmptyLineAfterGuardClause: - 'lib/report_portal/cucumber/json_slurper.rb' - 'tests/features/step_definitions/steps.rb' +# Offense count: 1 +# Cop supports --auto-correct. +# Configuration parameters: AllowForAlignment, AllowBeforeTrailingComments, ForceEqualSignAlignment. +Layout/ExtraSpacing: + Exclude: + - 'lib/report_portal/logging/logging_appender.rb' + +# Offense count: 1 +# Cop supports --auto-correct. +Layout/LeadingCommentSpace: + Enabled: true + +# Offense count: 2 +# Cop supports --auto-correct. +# Configuration parameters: EnforcedStyle, IndentationWidth. +# SupportedStyles: aligned, indented +Layout/MultilineOperationIndentation: + Exclude: + - 'lib/report_portal/cucumber/report.rb' + +# Offense count: 3 +# Cop supports --auto-correct. +Layout/SpaceAfterComma: + Exclude: + - 'lib/report_portal/cucumber/report.rb' + - 'lib/reportportal.rb' + - 'tests/formatter_spec.rb' + +# Offense count: 1 +# Cop supports --auto-correct. +# Configuration parameters: EnforcedStyle. +# SupportedStyles: space, no_space +Layout/SpaceAroundEqualsInParameterDefault: + Exclude: + - 'lib/reportportal.rb' + +# Offense count: 5 +# Cop supports --auto-correct. +# Configuration parameters: AllowForAlignment. +Layout/SpaceAroundOperators: + Exclude: + - 'lib/report_portal/cucumber/report.rb' + - 'lib/report_portal/logging/logging_appender.rb' + - 'lib/report_portal/rspec/formatter.rb' + +# Offense count: 4 +# Cop supports --auto-correct. +# Configuration parameters: EnforcedStyle, EnforcedStyleForEmptyBraces, SpaceBeforeBlockParameters. +# SupportedStyles: space, no_space +# SupportedStylesForEmptyBraces: space, no_space +Layout/SpaceInsideBlockBraces: + Exclude: + - 'tests/formatter_spec.rb' + # Offense count: 5 # Cop supports --auto-correct. # Configuration parameters: EnforcedStyle, EnforcedStyleForEmptyBraces. @@ -58,7 +120,7 @@ Metrics/BlockLength: # Offense count: 2 # Configuration parameters: CountComments. Metrics/ClassLength: - Max: 169 + Max: 250 # Offense count: 3 Metrics/CyclomaticComplexity: @@ -118,8 +180,6 @@ Style/Documentation: - 'spec/**/*' - 'test/**/*' - 'lib/report_portal/cucumber/formatter.rb' - - 'lib/report_portal/cucumber/parallel_formatter.rb' - - 'lib/report_portal/cucumber/parallel_report.rb' - 'lib/report_portal/logging/logger.rb' - 'lib/report_portal/patches/rest_client.rb' - 'lib/report_portal/rspec/formatter.rb' @@ -174,7 +234,6 @@ Style/GlobalVars: # Configuration parameters: MinBodyLength. Style/GuardClause: Exclude: - - 'lib/report_portal/cucumber/parallel_report.rb' - 'lib/report_portal/cucumber/report.rb' - 'lib/report_portal/rspec/formatter.rb' - 'lib/reportportal.rb' diff --git a/Gemfile b/Gemfile index e45c32c..b78c327 100644 --- a/Gemfile +++ b/Gemfile @@ -2,11 +2,12 @@ source 'https://rubygems.org' gemspec +gem 'faraday' gem 'cucumber', '~> 3' -gem 'parallel_tests' +gem 'log4r' +gem 'logging' +gem 'parallel_tests', '~> 2.15.0' gem 'rake' gem 'rspec' gem 'rubytree', git: 'https://github.com/razboev/RubyTree' - -gem 'log4r' -gem 'logging' +gem 'sys-proctable', '~> 1.1.5' diff --git a/README.md b/README.md index 0de4110..e4eca83 100644 --- a/README.md +++ b/README.md @@ -28,11 +28,11 @@ Add `gem 'reportportal', git: 'https://github.com/reportportal/agent-ruby.git'` * With Cucumber: -```cucumber -f ReportPortal::Cucumber::Formatter``` +```cucumber -f ReportPortal::Cucumber::Formatter -o ''``` * With Cucumber and parallel_tests gem: -```parallel_cucumber -o ' -f ReportPortal::Cucumber::ParallelFormatter'``` +```parallel_cucumber -o ' -f ReportPortal::Cucumber::Formatter'``` * With RSpec: @@ -54,6 +54,7 @@ Supported settings: - launch_id - id of previously created launch (to be used if formatter_modes contains attach_to_launch) - file_with_launch_id - path to file with id of launch (to be used if formatter_modes contains attach_to_launch) - disable_ssl_verification - set to true to disable SSL verification on connect to ReportPortal (potential security hole!). Set `disable_ssl_verification` to `true` if you see the following error: + - log_level - this is log level for report_portal agent (useful for troubleshooting issued when run in parallel mode) ``` Request to https://rp.epam.com/reportportal-ws/api/v1/pass-team/launch//finish produced an exception: RestClient::SSLCertificateNotVerified: SSL_connect returned=1 errno=0 state=SSLv3 read server certificate B: certificate verify failed ``` @@ -75,12 +76,35 @@ WebMock.disable_net_connect!(:net_http_connect_on_start => true, :allow_localhos ## Formatter modes The following modes are supported: - -| Name | Purpose | -| --- | --- | -| attach_to_launch | Do not create a new launch but add executing features/scenarios to an existing launch. Use launch_id or file_with_launch_id settings to configure that. If they are not present client will check rp_launch_id.tmp in `Dir.tmpdir`) -| use_same_thread_for_reporting | Send reporting commands in the same main thread used for running tests. This mode is useful for debugging this Report Portal client. It changes default behavior to send commands in the separate thread. Default behavior is there not to slow test execution. | -| skip_reporting_hierarchy | Do not create items for folders and feature files | + + + + + + + + + + + + + + + +
NamePurpose
attach_to_launch +Add executing features/scenarios to an existing launch. +Use following options to configure that. + + 1. launch_id + 2. file_with_launch_id + 3. rp_launch_id.tmp in `Dir.tmpdir` + + If above options not present client will create new launch +
use_same_thread_for_reporting +Send reporting commands in the same main thread used for running tests. This mode is useful for debugging +Report Portal client. It changes default behavior to send commands in the separate thread. +Default behavior is there not to slow test execution.
skip_reporting_hierarchy +Do not create items for folders and feature files
## Logging Experimental support for three common logging frameworks was added: @@ -91,12 +115,6 @@ Experimental support for three common logging frameworks was added: To use Logger, set use_standard_logger parameter to true (see Configuration chapter). For the other two corresponding appenders/outputters are available under reportportal/logging. -## Parallel formatter - -ReportPortal::Cucumber::ParallelFormatter can be used for tests started via parallel_tests gem. - -Note: Launch id is shared between independent processes (as is the case with parallel_tests gem) via a file in `Dir.tmpdir`. - ## Links - [ReportPortal](https://github.com/reportportal/) diff --git a/lib/report_portal/cucumber/formatter.rb b/lib/report_portal/cucumber/formatter.rb index ac45900..d108b4e 100644 --- a/lib/report_portal/cucumber/formatter.rb +++ b/lib/report_portal/cucumber/formatter.rb @@ -7,12 +7,10 @@ module Cucumber class Formatter # @api private def initialize(config) - ENV['REPORT_PORTAL_USED'] = 'true' - + @logger ||= Logger.new(config.out_stream) + @logger.level = ReportPortal::Settings.instance.log_level || :warn setup_message_processing - @io = config.out_stream - [:test_case_started, :test_case_finished, :test_step_started, :test_step_finished, :test_run_finished].each do |event_name| config.on_event event_name do |event| process_message(event_name, event) @@ -23,8 +21,6 @@ def initialize(config) def puts(message) process_message(:puts, message) - @io.puts(message) - @io.flush end def embed(*args) @@ -34,7 +30,7 @@ def embed(*args) private def report - @report ||= ReportPortal::Cucumber::Report.new + @report ||= ReportPortal::Cucumber::Report.new(@logger) end def setup_message_processing diff --git a/lib/report_portal/cucumber/parallel_formatter.rb b/lib/report_portal/cucumber/parallel_formatter.rb deleted file mode 100644 index a769685..0000000 --- a/lib/report_portal/cucumber/parallel_formatter.rb +++ /dev/null @@ -1,14 +0,0 @@ -require_relative 'formatter' -require_relative 'parallel_report' - -module ReportPortal - module Cucumber - class ParallelFormatter < Formatter - private - - def report - @report ||= ReportPortal::Cucumber::ParallelReport.new - end - end - end -end diff --git a/lib/report_portal/cucumber/parallel_report.rb b/lib/report_portal/cucumber/parallel_report.rb deleted file mode 100644 index f1648e3..0000000 --- a/lib/report_portal/cucumber/parallel_report.rb +++ /dev/null @@ -1,54 +0,0 @@ -require 'parallel_tests' - -require_relative 'report' - -module ReportPortal - module Cucumber - class ParallelReport < Report - FILE_WITH_LAUNCH_ID = Pathname(Dir.tmpdir) + "parallel_launch_id_for_#{Process.ppid}.lck" - - def parallel? - true - end - - def initialize - @root_node = Tree::TreeNode.new('') - @parent_item_node = @root_node - @last_used_time ||= 0 - - if ParallelTests.first_process? - File.open(FILE_WITH_LAUNCH_ID, 'w') do |f| - f.flock(File::LOCK_EX) - start_launch - f.write(ReportPortal.launch_id) - f.flush - f.flock(File::LOCK_UN) - end - else - File.open(FILE_WITH_LAUNCH_ID, 'r') do |f| - f.flock(File::LOCK_SH) - ReportPortal.launch_id = f.read - f.flock(File::LOCK_UN) - end - end - end - - def test_run_finished(_event, desired_time = ReportPortal.now) - end_feature(desired_time) unless @parent_item_node.is_root? - - if ParallelTests.first_process? - ParallelTests.wait_for_other_processes_to_finish - - File.delete(FILE_WITH_LAUNCH_ID) - - unless attach_to_launch? - $stdout.puts "Finishing launch #{ReportPortal.launch_id}" - ReportPortal.close_child_items(nil) - time_to_send = time_to_send(desired_time) - ReportPortal.finish_launch(time_to_send) - end - end - end - end - end -end diff --git a/lib/report_portal/cucumber/report.rb b/lib/report_portal/cucumber/report.rb index c3e6370..98d3965 100644 --- a/lib/report_portal/cucumber/report.rb +++ b/lib/report_portal/cucumber/report.rb @@ -2,6 +2,10 @@ require 'cucumber/formatter/hook_query_visitor' require 'tree' require 'securerandom' +require 'tempfile' +require 'parallel_tests' +require 'sys/proctable' +require 'fileutils' require_relative '../../reportportal' require_relative '../logging/logger' @@ -10,39 +14,90 @@ module ReportPortal module Cucumber # @api private class Report - def parallel? - false - end + attr_accessor :parallel, :started_launch + @folder_creation_tracking_file = Pathname(Dir.tmpdir) + "folder_creation_tracking.lck" def attach_to_launch? ReportPortal::Settings.instance.formatter_modes.include?('attach_to_launch') end - def initialize - @last_used_time = 0 + def initialize(logger) + @logger = logger + ReportPortal.last_used_time = 0 + ReportPortal.logger = logger @root_node = Tree::TreeNode.new('') @parent_item_node = @root_node - start_launch + + set_parallel_tests_vars + + if ParallelTests.first_process? + @logger.debug("First process: #{@pid_of_parallel_tests}") + start_launch(ReportPortal.now) + else + @logger.debug("Child process: #{@pid_of_parallel_tests}") + start_time = monotonic_time + loop do + break if File.exist?(lock_file) + if monotonic_time - start_time > wait_time_for_launch_create + raise "File with launch ID wasn't created after waiting #{wait_time_for_launch_create} seconds" + end + @logger.debug "File with launch ID wasn't created after waiting #{monotonic_time - start_time} seconds" + + sleep 0.5 + end + ReportPortal.launch_id = read_lock_file(lock_file) + @logger.debug "Attaching to launch using lock_file [#{lock_file}], launch_id: [#{ReportPortal.launch_id}] " + add_process_description + end end - def start_launch(desired_time = ReportPortal.now) + + def start_launch(desired_time, cmd_args = ARGV) + # Expected behavior that make sense: + # 1. If launch_id present attach to existing (simple use case) + # 2. If launch_id not present check if exist rp_launch_id.tmp + # 3. [ADDED] If launch_id is not present check if lock exist with launch_uuid if attach_to_launch? ReportPortal.launch_id = if ReportPortal::Settings.instance.launch_id ReportPortal::Settings.instance.launch_id else - file_path = ReportPortal::Settings.instance.file_with_launch_id || (Pathname(Dir.tmpdir) + 'rp_launch_id.tmp') - File.read(file_path) + self.started_launch = true + file_path = lock_file + File.file?(file_path) ? read_lock_file(file_path) : new_launch(desired_time, cmd_args, file_path) end - $stdout.puts "Attaching to launch #{ReportPortal.launch_id}" + @logger.info "Attaching to launch #{ReportPortal.launch_id}" else - description = ReportPortal::Settings.instance.description - description ||= ARGV.map { |arg| arg.gsub(/rp_uuid=.+/, "rp_uuid=[FILTERED]") }.join(' ') - ReportPortal.start_launch(description, time_to_send(desired_time)) + new_launch(desired_time, cmd_args) end end - def test_case_started(event, desired_time = ReportPortal.now) # TODO: time should be a required argument + def new_launch(desired_time, cmd_args = ARGV, lock_file = nil) + @logger.info("Creating new launch at: [#{desired_time}], with cmd: [#{cmd_args}] and file lock: [#{lock_file}]") + ReportPortal.start_launch(description(cmd_args), time_to_send(desired_time)) + set_file_lock_with_launch_id(lock_file, ReportPortal.launch_id) if lock_file + ReportPortal.launch_id + end + + def description(cmd_args = ARGV) + description ||= ReportPortal::Settings.instance.description + description ||= cmd_args.map { |arg| arg.gsub(/rp_uuid=.+/, "rp_uuid=[FILTERED]") }.join(' ') + description + end + + def set_file_lock_with_launch_id(lock_file, launch_id) + FileUtils.mkdir_p File.dirname(lock_file) + File.open(lock_file, 'w') do |f| + f.flock(File::LOCK_EX) + f.write(launch_id) + f.flush + f.flock(File::LOCK_UN) + end + end + + # scenario starts in separate treads + def test_case_started(event, desired_time) + @logger.debug "test_case_started: [#{event}], " test_case = event.test_case feature = test_case.feature if report_hierarchy? && !same_feature_as_previous_test_case?(feature) @@ -61,7 +116,8 @@ def test_case_started(event, desired_time = ReportPortal.now) # TODO: time shoul ReportPortal.current_scenario.id = ReportPortal.start_item(scenario_node) end - def test_case_finished(event, desired_time = ReportPortal.now) + def test_case_finished(event, desired_time) + @logger.debug "test_case_finished: [#{event}], " result = event.result status = result.to_sym issue = nil @@ -73,7 +129,8 @@ def test_case_finished(event, desired_time = ReportPortal.now) ReportPortal.current_scenario = nil end - def test_step_started(event, desired_time = ReportPortal.now) + def test_step_started(event, desired_time) + @logger.debug "test_step_started: [#{event}], " test_step = event.test_step if step?(test_step) # `after_test_step` is also invoked for hooks step_source = test_step.source.last @@ -87,7 +144,7 @@ def test_step_started(event, desired_time = ReportPortal.now) end end - def test_step_finished(event, desired_time = ReportPortal.now) + def test_step_finished(event, desired_time) test_step = event.test_step result = event.result status = result.to_sym @@ -115,26 +172,109 @@ def test_step_finished(event, desired_time = ReportPortal.now) end end - def test_run_finished(_event, desired_time = ReportPortal.now) + def test_run_finished(_event, desired_time) end_feature(desired_time) unless @parent_item_node.is_root? - - unless attach_to_launch? - close_all_children_of(@root_node) # Folder items are closed here as they can't be closed after finishing a feature - time_to_send = time_to_send(desired_time) - ReportPortal.finish_launch(time_to_send) + @logger.info("Test run finish: [#{@parent_item_node}]") + close_all_children_of(@root_node) # Folder items are closed here as they can't be closed after finishing a feature + if parallel + @logger.debug("Parallel process: #{@pid_of_parallel_tests}") + if ParallelTests.first_process? && started_launch + ParallelTests.wait_for_other_processes_to_finish + File.delete(lock_file) + @logger.info("close launch , delete lock") + complete_launch(desired_time) + end + else + complete_launch(desired_time) end end - def puts(message, desired_time = ReportPortal.now) + def add_process_description + description = ReportPortal.remote_launch['description'].split(' ') + description.push(self.description.split(' ')).flatten! + ReportPortal.update_launch(description: description.uniq.join(' ')) + end + + def puts(message, desired_time) ReportPortal.send_log(:info, message, time_to_send(desired_time)) end - def embed(src, mime_type, label, desired_time = ReportPortal.now) + def embed(src, mime_type, label, desired_time) ReportPortal.send_file(:info, src, label, time_to_send(desired_time), mime_type) end private + def complete_launch(desired_time) + if started_launch || !attach_to_launch? + time_to_send = time_to_send(desired_time) + ReportPortal.finish_launch(time_to_send) + end + end + + def lock_file(file_path = nil) + file_path ||= ReportPortal::Settings.instance.file_with_launch_id + @logger.debug("Lock file (RReportPortal::Settings.instance.file_with_launch_id): #{file_path}") if file_path + file_path ||= Dir.tmpdir + "/report_portal_#{ReportPortal::Settings.instance.launch_uuid}.lock" if ReportPortal::Settings.instance.launch_uuid + @logger.debug("Lock file (ReportPortal::Settings.instance.launch_uuid): #{file_path}") if file_path + file_path ||= Dir.tmpdir + "/parallel_launch_id_for_#{@pid_of_parallel_tests}.lock" if @pid_of_parallel_tests + @logger.debug("Lock file (/parallel_launch_id_for_#{@pid_of_parallel_tests}.lock): #{file_path}") if file_path + file_path ||= Dir.tmpdir + '/rp_launch_id.tmp' + @logger.debug("Lock file (/rp_launch_id.tmp): #{file_path}") if file_path + + file_path + end + + def set_parallel_tests_vars + process_list = Sys::ProcTable.ps + @logger.debug("set_test_variables: #{process_list}") + runner_process ||= get_parallel_test_process(process_list) + @logger.debug("Parallel cucumber runner pid: #{runner_process.pid}") if runner_process + runner_process ||= get_cucumber_test_process(process_list) + @logger.debug("Cucumber runner pid: #{runner_process.pid}") if runner_process + raise 'Failed to find any cucumber related test process' if runner_process.nil? + @pid_of_parallel_tests = runner_process.pid + end + + def get_parallel_test_process(process_list) + process_list.each do |process| + if process.cmdline.match(%r{bin(?:\/|\\)parallel_(?:cucumber|test)(.+)}) + @parallel = true + @logger.debug("get_parallel_test_process: #{process.cmdline}") + return process + end + end + nil + end + + def get_cucumber_test_process(process_list) + process_list.each do |process| + if process.cmdline.match(%r{bin(?:\/|\\)(?:cucumber)(.+)}) + @logger.debug("get_cucumber_test_process: #{process.cmdline}") + return process + end + end + nil + end + + def wait_time_for_launch_create + ENV['rp_parallel_launch_wait_time'] || 60 + end + + def monotonic_time + Process.clock_gettime(Process::CLOCK_MONOTONIC) + end + + def read_lock_file(file_path) + content = nil + File.open(file_path, 'r') do |f| + f.flock(File::LOCK_SH) + content = File.read(file_path) + f.flock(File::LOCK_UN) + end + content + end + # Report Portal sorts logs by time. However, several logs might have the same time. # So to get Report Portal sort them properly the time should be different in all logs related to the same item. # And thus it should be stored. @@ -143,10 +283,10 @@ def embed(src, mime_type, label, desired_time = ReportPortal.now) # * that process/thread can't start the next test until it's done with the previous one def time_to_send(desired_time) time_to_send = desired_time - if time_to_send <= @last_used_time - time_to_send = @last_used_time + 1 + if time_to_send <= ReportPortal.last_used_time + time_to_send = ReportPortal.last_used_time + 1 end - @last_used_time = time_to_send + ReportPortal.last_used_time = time_to_send end def same_feature_as_previous_test_case?(feature) @@ -154,6 +294,7 @@ def same_feature_as_previous_test_case?(feature) end def start_feature_with_parentage(feature, desired_time) + @logger.debug("start_feature_with_parentage: [#{feature}], [#{desired_time}]") parent_node = @root_node child_node = nil path_components = feature.location.file.split(File::SEPARATOR) @@ -172,7 +313,7 @@ def start_feature_with_parentage(feature, desired_time) type = :TEST end # TODO: multithreading # Parallel formatter always executes scenarios inside the same feature in the same process - if parallel? && + if parallel && index < path_components.size - 1 && # is folder? (id_of_created_item = ReportPortal.item_id_of(name, parent_node)) # get id for folder from report portal # get child id from other process @@ -200,9 +341,28 @@ def end_feature(desired_time) end def close_all_children_of(root_node) + @logger.debug("close_all_children_of: [#{root_node.children}]") root_node.postordered_each do |node| - if !node.is_root? && !node.content.closed - ReportPortal.finish_item(node.content) + @logger.debug("close_all_children_of:postordered_each [#{node.content}]") + unless node.is_root? || node.content.closed + begin + item = ReportPortal.remote_item(node.content[:id]) + @logger.debug("started_launch?: [#{started_launch}], item details: [#{item}]") + if started_launch + if item.key?('end_time') + @logger.warn("Main process: item already closed skipping.") + else + ReportPortal.close_child_items(node.content[:id]) + ReportPortal.finish_item(node.content) + end + else + if item.key?('end_time') + ReportPortal.finish_item(node.content) + else + @logger.warn("Child process: item in use cannot close it. [#{item}]") + end + end + end end end end diff --git a/lib/report_portal/patches/fariday.rb b/lib/report_portal/patches/fariday.rb new file mode 100644 index 0000000..4a5a67d --- /dev/null +++ b/lib/report_portal/patches/fariday.rb @@ -0,0 +1,17 @@ +class Faraday::Request::Multipart + def create_multipart(env, params) + boundary = env.request.boundary + parts = process_params(params) do |key, value| + if (JSON.parse(value) rescue false) + Faraday::Parts::Part.new(boundary, key, value, 'Content-Type' => 'application/json') + else + Faraday::Parts::Part.new(boundary, key, value) + end + end + parts << Faraday::Parts::EpiloguePart.new(boundary) + + body = Faraday::CompositeReadIO.new(parts) + env.request_headers[Faraday::Env::ContentLength] = body.length.to_s + return body + end +end \ No newline at end of file diff --git a/lib/report_portal/patches/rest_client.rb b/lib/report_portal/patches/rest_client.rb deleted file mode 100644 index 0318c39..0000000 --- a/lib/report_portal/patches/rest_client.rb +++ /dev/null @@ -1,45 +0,0 @@ -# monkey-patch to temporarily solve the issue in https://github.com/rest-client/rest-client/pull/222 -module RestClient - module Payload - extend self - class Multipart < Base - def build_stream(params) - content_type = params.delete(:content_type) - b = '--' + boundary - - @stream = Tempfile.new("RESTClient.Stream.#{rand(1000)}") - @stream.binmode - @stream.write(b + EOL) - - case params - when Hash, ParamsArray - x = Utils.flatten_params(params) - else - x = params - end - - last_index = x.length - 1 - x.each_with_index do |a, index| - k, v = * a - if v.respond_to?(:read) && v.respond_to?(:path) - create_file_field(@stream, k, v) - else - create_regular_field(@stream, k, v, content_type) - end - @stream.write(EOL + b) - @stream.write(EOL) unless last_index == index - end - @stream.write('--') - @stream.write(EOL) - @stream.seek(0) - end - - def create_regular_field(s, k, v, type = nil) - s.write("Content-Disposition: form-data; name=\"#{k}\"") - s.write("#{EOL}Content-Type: #{type}#{EOL}") if type - s.write(EOL) - s.write(v) - end - end - end -end diff --git a/lib/report_portal/settings.rb b/lib/report_portal/settings.rb index a8f48fa..56edb44 100644 --- a/lib/report_portal/settings.rb +++ b/lib/report_portal/settings.rb @@ -24,10 +24,11 @@ def initialize 'tags' => false, 'is_debug' => false, 'disable_ssl_verification' => false, - # for parallel execution only 'use_standard_logger' => false, 'launch_id' => false, 'file_with_launch_id' => false, + 'launch_uuid' => false, + 'log_level' => false } keys.each do |key, is_required| diff --git a/lib/report_portal/version.rb b/lib/report_portal/version.rb index 3d4011d..1194435 100644 --- a/lib/report_portal/version.rb +++ b/lib/report_portal/version.rb @@ -1,3 +1,3 @@ module ReportPortal - VERSION = '0.7' + VERSION = '0.8' end diff --git a/lib/reportportal.rb b/lib/reportportal.rb index b0487b3..1af33c1 100644 --- a/lib/reportportal.rb +++ b/lib/reportportal.rb @@ -1,29 +1,18 @@ require 'json' -require 'rest_client' +require 'faraday' require 'uri' require 'pathname' require 'tempfile' require_relative 'report_portal/settings' -require_relative 'report_portal/patches/rest_client' +require_relative 'report_portal/patches/fariday' module ReportPortal TestItem = Struct.new(:name, :type, :id, :start_time, :description, :closed, :tags) LOG_LEVELS = { error: 'ERROR', warn: 'WARN', info: 'INFO', debug: 'DEBUG', trace: 'TRACE', fatal: 'FATAL', unknown: 'UNKNOWN' } - - @response_handler = proc do |response, request, result, &block| - if (200..207).include? response.code - response - else - p "ReportPortal API returned #{response}" - p "Offending request method/URL: #{request.args[:method].upcase} #{request.args[:url]}" - p "Offending request payload: #{request.args[:payload]}}" - response.return!(request, result, &block) - end - end - class << self - attr_accessor :launch_id, :current_scenario + attr_accessor :launch_id, :current_scenario, :last_used_time, :logger + @verbose = false def now (Time.now.to_f * 1000).to_i @@ -43,35 +32,38 @@ def status_to_level(status) end def start_launch(description, start_time = now) - url = "#{Settings.instance.project_url}/launch" data = { name: Settings.instance.launch, start_time: start_time, tags: Settings.instance.tags, description: description, mode: Settings.instance.launch_mode } - @launch_id = do_request(url) do |resource| - JSON.parse(resource.post(data.to_json, content_type: :json, &@response_handler))['id'] - end + @launch_id = process_request('launch',:post,data.to_json)['id'] + end + + def remote_launch + process_request("launch/#{@launch_id}",:get) + end + + def update_launch(data) + process_request("launch/#{@launch_id}/update",:put, data.to_json) end def finish_launch(end_time = now) - url = "#{Settings.instance.project_url}/launch/#{@launch_id}/finish" + self.logger.debug "finish_launch: [#{end_time}]" data = { end_time: end_time } - do_request(url) do |resource| - resource.put data.to_json, content_type: :json, &@response_handler - end + process_request("launch/#{@launch_id}/finish",:put,data.to_json) end def start_item(item_node) - url = "#{Settings.instance.project_url}/item" - url += "/#{item_node.parent.content.id}" unless item_node.parent && item_node.parent.is_root? item = item_node.content data = { start_time: item.start_time, name: item.name[0, 255], type: item.type.to_s, launch_id: @launch_id, description: item.description } data[:tags] = item.tags unless item.tags.empty? - do_request(url) do |resource| - JSON.parse(resource.post(data.to_json, content_type: :json, &@response_handler))['id'] - end + url = 'item' + url += "/#{item_node.parent.content.id}" unless item_node.parent && item_node.parent.is_root? + process_request(url,:post,data.to_json)['id'] end def finish_item(item, status = nil, end_time = nil, force_issue = nil) - unless item.nil? || item.id.nil? || item.closed - url = "#{Settings.instance.project_url}/item/#{item.id}" + + if item.nil? || item.id.nil? || item.closed + self.logger.debug "finish_item: Item details are missing or already closed" + else data = { end_time: end_time.nil? ? now : end_time } data[:status] = status unless status.nil? if force_issue && status != :passed # TODO: check for :passed status is probably not needed @@ -79,8 +71,14 @@ def finish_item(item, status = nil, end_time = nil, force_issue = nil) elsif status == :skipped data[:issue] = { issue_type: 'NOT_ISSUE' } end - do_request(url) do |resource| - resource.put data.to_json, content_type: :json, &@response_handler + self.logger.debug "finish_item:id[#{item}], data: #{data} " + begin + response = process_request("item/#{item.id}", :put, data.to_json) + self.logger.debug "finish_item: response [#{response}] " + rescue RestClient::Exception => e + response = JSON.parse(e.response) + + raise e unless response['error_code'] == 40018 end item.closed = true end @@ -89,17 +87,14 @@ def finish_item(item, status = nil, end_time = nil, force_issue = nil) # TODO: implement force finish def send_log(status, message, time) + @logger.debug "send_log: [#{status}],[#{message}], #{@current_scenario} " unless @current_scenario.nil? || @current_scenario.closed # it can be nil if scenario outline in expand mode is executed - url = "#{Settings.instance.project_url}/log" data = { item_id: @current_scenario.id, time: time, level: status_to_level(status), message: message.to_s } - do_request(url) do |resource| - resource.post(data.to_json, content_type: :json, &@response_handler) - end + process_request("log",:post,data.to_json) end end def send_file(status, path, label = nil, time = now, mime_type = 'image/png') - url = "#{Settings.instance.project_url}/log" unless File.file?(path) extension = ".#{MIME::Types[mime_type].first.extensions.first}" temp = Tempfile.open(['file', extension]) @@ -108,43 +103,47 @@ def send_file(status, path, label = nil, time = now, mime_type = 'image/png') temp.rewind path = temp end - File.open(File.realpath(path), 'rb') do |file| - label ||= File.basename(file) - json = { level: status_to_level(status), message: label, item_id: @current_scenario.id, time: time, file: { name: File.basename(file) } } - data = { :json_request_part => [json].to_json, label => file, :multipart => true, :content_type => 'application/json' } - do_request(url) do |resource| - resource.post(data, { content_type: 'multipart/form-data' }, &@response_handler) - end - end + file_name = File.basename(path) + label ||= file_name + json = { level: status_to_level(status), message: label, item_id: @current_scenario.id, time: time, file: { name: "#{file_name}" }, "Content-Type": 'application/json' } + headers = {'Content-Type': 'multipart/form-data'} + payload = { :json_request_part => [json].to_json, + file_name => Faraday::UploadIO.new(path, mime_type) } + process_request("log",:post,payload, headers) end - # needed for parallel formatter - def item_id_of(name, parent_node) + def get_item(name, parent_node) if parent_node.is_root? # folder without parent folder - url = "#{Settings.instance.project_url}/item?filter.eq.launch=#{@launch_id}&filter.eq.name=#{URI.escape(name)}&filter.size.path=0" + url = "item?filter.eq.launch=#{@launch_id}&filter.eq.name=#{URI.escape(name)}&filter.size.path=0" else - url = "#{Settings.instance.project_url}/item?filter.eq.parent=#{parent_node.content.id}&filter.eq.name=#{URI.escape(name)}" + url = "item?filter.eq.launch=#{@launch_id}&filter.eq.parent=#{parent_node.content.id}&filter.eq.name=#{URI.escape(name)}" end - do_request(url) do |resource| - data = JSON.parse(resource.get) - if data.key? 'content' - data['content'].empty? ? nil : data['content'][0]['id'] - else - nil # item isn't started yet - end + process_request(url,:get) + end + + def remote_item(item_id) + process_request("item/#{item_id}",:get) + end + + def item_id_of(name, parent_node) + data = get_item(name, parent_node) + if data.key? 'content' + data['content'].empty? ? nil : data['content'][0]['id'] + else + nil # item isn't started yet end end - # needed for parallel formatter def close_child_items(parent_id) + self.logger.debug "closing child items: #{parent_id} " if parent_id.nil? - url = "#{Settings.instance.project_url}/item?filter.eq.launch=#{@launch_id}&filter.size.path=0&page.page=1&page.size=100" + url = "item?filter.eq.launch=#{@launch_id}&filter.size.path=0&page.page=1&page.size=100" else - url = "#{Settings.instance.project_url}/item?filter.eq.parent=#{parent_id}&page.page=1&page.size=100" + url = "item?filter.eq.launch=#{@launch_id}&filter.eq.parent=#{parent_id}&page.page=1&page.size=100" end ids = [] loop do - response = do_request(url) { |r| JSON.parse(r.get) } + response = process_request(url,:get) if response.key?('links') link = response['links'].find { |i| i['rel'] == 'next' } url = link.nil? ? nil : link['href'] @@ -166,25 +165,45 @@ def close_child_items(parent_id) private - def create_resource(url) - props = { :headers => {:Authorization => "Bearer #{Settings.instance.uuid}"}} - verify_ssl = Settings.instance.disable_ssl_verification - props[:verify_ssl] = !verify_ssl unless verify_ssl.nil? - RestClient::Resource.new url, props - end - - def do_request(url) - resource = create_resource(url) - tries = 3 + def process_request(path, method, *options) + tries = 5 begin - yield resource - rescue - p "Request to #{url} produced an exception: #{$!.class}: #{$!}" - $!.backtrace.each { |l| p l } + response = rp_client.send(method, path, *options) + rescue RestClient::Exception => e + self.logger.warn("Exception[#{e}],class:[#{e.class}],class:[#{e.class}], retry_count: [#{tries}]") + self.logger.error("TRACE[#{e.backtrace}]") + response = JSON.parse(e.response) + m = response['message'].match(%r{Start time of child \['(.+)'\] item should be same or later than start time \['(.+)'\] of the parent item\/launch '.+'}) + if m + parent_time = Time.strptime(m[2], '%a %b %d %H:%M:%S %z %Y') + data = JSON.parse(options[0]) + self.logger.warn("RP error : 40025, time of a child: [#{data['start_time']}], paren time: [#{(parent_time.to_f * 1000).to_i}]") + data['start_time'] = (parent_time.to_f * 1000).to_i + 1000 + options[0] = data.to_json + ReportPortal.last_used_time = data['start_time'] + else + self.logger.error("RestClient::Exception -> response: [#{response}]") + self.logger.error("TRACE[#{e.backtrace}]") + raise + end + retry unless (tries -= 1).zero? - p "Failed to execute request to #{url} after 3 attempts." - nil end + JSON.parse(response.body) + end + + + def rp_client + @connection ||= Faraday.new(url: Settings.instance.project_url) do |f| + f.headers={Authorization: "Bearer #{Settings.instance.uuid}", Accept: 'application/json','Content-type': 'application/json'} + verify_ssl = Settings.instance.disable_ssl_verification + f.ssl.verify = !verify_ssl unless verify_ssl.nil? + f.request :multipart + f.request :url_encoded + f.adapter :net_http + end + + @connection end end end