gauge: Test fails with Error `Error Message: Connection closed [127.0.0.1:50992] cause: EOF`

Expected behavior

Test should complete successfully

Actual behavior

Test fails intermittently with exception as Error Message: Connection closed [127.0.0.1:50992] cause: EOF

Tests are run with command gauge --tags 'regression' -n 15 -g 1 run specs

Steps to reproduce

On build.gocd.org environment functional tests run using gauge-ruby plugin are failing intermittently, not sure if its plugin or gauge core issue. Not observed it so far in the gauge-java tests that we have. However will update this issue if see similar failure on gauge-java tests.

here is the gauge log during failure,

23:45:44.651 Compatible version of plugin ruby not found. Installing plugin ruby...
23:45:44.651 Gathering metadata for ruby
23:45:44.863 Downloading gauge-ruby-0.5.1-linux.x86_64.zip
23:45:46.659 Installing plugin ruby 0.5.1
23:45:46.664 Successfully installed plugin 'ruby'.
23:45:46.664 Compatible version of plugin html-report not found. Installing plugin html-report...
23:45:46.664 Gathering metadata for html-report
23:45:46.712 Downloading html-report-4.0.5-linux.x86_64.zip
23:45:47.994 Installing plugin html-report 4.0.5
23:45:48.008 Successfully installed plugin 'html-report'.
23:45:48.008 Installing required plugins.
23:45:48.008 Installing plugin 'screenshot'
23:45:48.008 Gathering metadata for screenshot
23:45:48.032 Downloading screenshot-0.0.1-linux.x86_64.zip
23:45:48.056 Checking updates...
23:45:48.484 Installing plugin screenshot 0.0.1
23:45:48.487 Successfully installed plugin 'screenshot'.
23:45:48.775 Using the -g flag will make the distribution strategy 'eager'. The --strategy setting will be overridden.
23:45:48.775 The following specifications satisfy filter criteria:
23:45:48.775 specs/BasicDependencyWalkInPipelineCompare.spec
23:45:48.775 specs/ConfigRepoEnvironmentMerge.spec
23:45:48.775 specs/EditExistingEnvironment.spec
23:45:48.775 specs/OverrideEnvironmentVariableDuringTrigger.spec
23:45:48.775 specs/PipelineLockingBehavior.spec
23:46:39.815 # BasicDependencyWalkInPipelineCompare
23:46:39.816 ## BasicDependencyWalkInPipelineCompare
23:46:39.816 * Basic Configuration - setup
23:46:40.097 * Using pipeline "up, down, child-of-down" - setup
23:46:40.670 * With "1" live agents - setup
23:46:57.700 * Capture go state "BasicDependencyWalkInPipelineCompare" - setup

####### More steps here........


23:53:28.407 Failed Step: Verify pipeline "pipeline-unlock-onComplete" is locked and not schedulable - Using api
23:53:28.407 Error Message: Connection closed [127.0.0.1:50992] cause: EOF
23:53:28.407 Specification: specs/PipelineLockingBehavior.spec:19
23:53:28.407 Stacktrace: 
23:53:28.407 Error Message: write tcp 127.0.0.1:35415->127.0.0.1:50992: use of closed network connection
23:53:28.407 Stacktrace: 
23:53:28.407 * Capture go state "PipelineLockingBehavior" - teardown
23:53:28.407 Error Message: write tcp 127.0.0.1:35415->127.0.0.1:50992: use of closed network connection
23:53:28.407 Stacktrace: 
23:53:28.407 Error Message: write tcp 127.0.0.1:35415->127.0.0.1:50992: use of closed network connection
23:53:28.407 Stacktrace: 
23:53:28.407 Error Message: write tcp 127.0.0.1:35415->127.0.0.1:50992: use of closed network connection
23:53:28.407 Stacktrace: 
23:53:28.407 Error Message: write tcp 127.0.0.1:35415->127.0.0.1:50992: use of closed network connection
23:53:28.407 Stacktrace: 
23:53:28.407 Error Message: write tcp 127.0.0.1:35415->127.0.0.1:50992: use of closed network connection
23:53:28.407 Stacktrace: 
23:53:28.508 Plugin [Html Report] with pid [10922] has exited
23:53:28.508 Specifications:	5 executed	4 passed	1 failed	0 skipped
23:53:28.508 Scenarios:	5 executed	4 passed	1 failed	0 skipped
23:53:28.508 
Total time taken: 7m38.719s

More logs from the console

/go/pipelines/regression-SPAs/vendor/bundle/ruby/2.3.0/gems/gauge-ruby-0.5.1/lib/method_cache.rb:79:in `recoverable?': undefined method `[]' for nil:NilClass (NoMethodError)
	from /go/pipelines/regression-SPAs/vendor/bundle/ruby/2.3.0/gems/gauge-ruby-0.5.1/lib/processors/execute_step_request_processor.rb:32:in `rescue in process_execute_step_request'
	from /go/pipelines/regression-SPAs/vendor/bundle/ruby/2.3.0/gems/gauge-ruby-0.5.1/lib/processors/execute_step_request_processor.rb:29:in `process_execute_step_request'
	from /go/pipelines/regression-SPAs/vendor/bundle/ruby/2.3.0/gems/gauge-ruby-0.5.1/lib/message_processor.rb:58:in `call'
	from /go/pipelines/regression-SPAs/vendor/bundle/ruby/2.3.0/gems/gauge-ruby-0.5.1/lib/message_processor.rb:58:in `process_message'
	from /go/pipelines/regression-SPAs/vendor/bundle/ruby/2.3.0/gems/gauge-ruby-0.5.1/lib/gauge_runtime.rb:56:in `handle_message'
	from /go/pipelines/regression-SPAs/vendor/bundle/ruby/2.3.0/gems/gauge-ruby-0.5.1/lib/gauge_runtime.rb:41:in `dispatch_messages'
	from /go/pipelines/regression-SPAs/vendor/bundle/ruby/2.3.0/gems/gauge-ruby-0.5.1/lib/gauge_runtime.rb:85:in `<module:Runtime>'
	from /go/pipelines/regression-SPAs/vendor/bundle/ruby/2.3.0/gems/gauge-ruby-0.5.1/lib/gauge_runtime.rb:33:in `<module:Gauge>'
	from /go/pipelines/regression-SPAs/vendor/bundle/ruby/2.3.0/gems/gauge-ruby-0.5.1/lib/gauge_runtime.rb:31:in `<top (required)>'
	from -e:1:in `require'
	from -e:1:in `<main>'
        Error Message: write tcp 127.0.0.1:37463->127.0.0.1:45238: use of closed network connection
        Stacktrace: 

        Error Message: write tcp 127.0.0.1:37463->127.0.0.1:45238: use of closed network connection
        Stacktrace: 

        Error Message: write tcp 127.0.0.1:37463->127.0.0.1:45238: use of closed network connection
        Stacktrace: 

        Failed Step: Create artifact store "A1"
        Specification: specs/ArtifactStoreAPI.spec:14
        Error Message: Connection closed [127.0.0.1:45238] cause: EOF
        Stacktrace: 

    Error Message: write tcp 127.0.0.1:37463->127.0.0.1:45238: use of closed network connection
    Stacktrace: 

  Error Message: write tcp 127.0.0.1:37463->127.0.0.1:45238: use of closed network connection
  Stacktrace: 

Failed to initialize spec datastore. Error: write tcp 127.0.0.1:37463->127.0.0.1:45238: use of closed network connection
Failed to initialize spec datastore. Error: write tcp 127.0.0.1:37463->127.0.0.1:45238: use of closed network connection
# ConfigReposPipeline
Failed to initialize spec datastore. Error: write tcp 127.0.0.1:37463->127.0.0.1:45238: use of closed network connection
Failed to initialize spec datastore. Error: write tcp 127.0.0.1:37463->127.0.0.1:45238: use of closed network connection
# PipelineHistoryPagination
Failed to initialize spec datastore. Error: write tcp 127.0.0.1:37463->127.0.0.1:45238: use of closed network connection
# TemplatesAPI
  Error Message: write tcp 127.0.0.1:37463->127.0.0.1:45238: use of closed network connection
  Stacktrace: 

Ruby runner Failed. Reason: exit status 1

Gauge version

Gauge version: 1.0.0
gauge-ruby - 0.5.1

About this issue

Original URL
State: closed
Created 6 years ago
Reactions: 1
Comments: 15 (9 by maintainers)

Commits related to this issue

bubble up exit codes properly, getgauge/gauge#1158 — committed to getgauge/gauge-java by sriv 6 years ago
break execution when runner crashes, #1158 eliminates noise in console logs — committed to getgauge/gauge by sriv 6 years ago
check for null messages before adding, getgauge/gauge#1158 — committed to getgauge/gauge-java by sriv 6 years ago
1158 exit on runner crash (#1235) * break execution when runner crashes, #1158 eliminates noise in console logs * refactoring, add log on connection closed * log connection failure only on e... — committed to getgauge/gauge by sriv 6 years ago
check for all errors, not just io.EOF when ensuring runner connection, #1158 — committed to getgauge/gauge by sriv 6 years ago
Revert "check for all errors, not just io.EOF when ensuring runner connection, #1158" This reverts commit 130472f9fa38e8b1cc1a3dea9bf4ea5064e174bf. — committed to getgauge/gauge by deleted user 6 years ago
1158 exit on runner crash (#1247) * break execution when runner crashes, #1158 eliminates noise in console logs * refactoring, add log on connection closed * fine grained error check to ensu... — committed to getgauge/gauge by sriv 6 years ago
1158 exit on runner crash (#1247) * break execution when runner crashes, #1158 eliminates noise in console logs * refactoring, add log on connection closed * fine grained error check to ensu... — committed to getgauge/gauge by sriv 6 years ago

Most upvoted comments

An update: @jonathangiber’s example helped narrow down one case, i.e. if there is a null value added to Gauge.writeMessage then it crashes the gauge-java runner, causing the use of closed network connection errors.

As a principle we would like to have the runners not crash because of test code, however in this case, it was clearly the runner not handling the case. Have a fix for this issue, and will raise a PR.

Steps to replicate:

gauge init java
Edit StepImplementation.java, add Gauge.writeMessage(null) in context step implementation.
gauge run specs

Changes include:

gauge will try to assess health of the runner by checking the connection before trying to execute a step, and if it detects that the runner died, it will break execution, giving faster feedback.
this particular issue is to be fixed in gauge-java, i.e. ignore null messages.

@rajiesh 's problem report is with the ruby runner, where I see the same issue, nil value passed to Gauge.write_message crashes the runner.

Protobuf asserts the values before building the message, and nil is not a valid String value. So all runners need to check for nil/null before adding it to the proto object.

sriv on Oct 24, 2018

It’s happening sometimes also to me when performing the following code:

  private void printBrowserConsole() {
    LogEntries logEntries = webDriverHolder.getWebDriver().manage().logs().get(LogType.BROWSER);
    String logs = null;

    for (LogEntry entry : logEntries) {
      logs = logs + entry.getMessage();
    }

    Gauge.writeMessage(logs);
  }

Java Gauge version: 1.0.2 Commit Hash: b4288bb

jonathangiber on Oct 7, 2018