TeamCity — rake runner aborts early

How to run TeamCity rakerunner locally

It is important to get the working directory right, otherwise you’ll get a bunch of require errors, for example:

C:\ruby\bin/ruby.exe C:\BuildAgent\plugins\rake-runner\lib\rb\runner\rakerunner.rb

Fails with error:

C:/ruby/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:31:in `gem_original_require’: no such file to load — teamcity/rakerunner_consts (LoadError)

from C:/ruby/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:31:in `require’

from C:/BuildAgent/plugins/rake-runner/lib/rb/runner/rake_ext.rb:20

no such file to load -- teamcity/rakerunner_consts (LoadError)

from C:/ruby/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:31:in `require'

from C:/BuildAgent/plugins/rake-runner/lib/rb/runner/rake_ext.rb:20

rake_ext is including a file with path:

require 'teamcity/rakerunner_consts'

And we know require works relative to the working directory which means our working directory must be set to:

C:\BuildAgent\plugins\rake-runner\lib\rb\patch

Rake abort

TeamCity rakerunner exits with message “Rake aborted!” as soon as it encounters a non-zero exit code from any task. Any subsequent tasks are therefore skipped.

This is not desirable behaviour for us because we have reporting tasks that must run always.

Stack trace showing the overridden members:

C:/BuildAgent/plugins/rake-runner/lib/rb/runner/rake_ext.rb:158:in 'process_exception'
C:/BuildAgent/plugins/rake-runner/lib/rb/runner/rake_ext.rb:95:in 'target_exception_handling'
C:/BuildAgent/plugins/rake-runner/lib/rb/runner/rake_ext.rb:266:in 'execute'
C:/ruby/lib/ruby/gems/1.8/gems/rake-0.8.4/lib/rake.rb:578:in 'invoke_with_call_chain'
C:/ruby/lib/ruby/1.8/monitor.rb:242:in 'synchronize'
C:/ruby/lib/ruby/gems/1.8/gems/rake-0.8.4/lib/rake.rb:571:in 'invoke_with_call_chain'
C:/ruby/lib/ruby/gems/1.8/gems/rake-0.8.4/lib/rake.rb:564:in 'standard_invoke_with_call_chain'
C:/BuildAgent/plugins/rake-runner/lib/rb/runner/rake_ext.rb:235:in 'invoke'
C:/BuildAgent/plugins/rake-runner/lib/rb/runner/rake_ext.rb:90:in 'target_exception_handling'
C:/BuildAgent/plugins/rake-runner/lib/rb/runner/rake_ext.rb:234:in 'invoke'
C:/ruby/lib/ruby/gems/1.8/gems/rake-0.8.4/lib/rake.rb:2027:in 'invoke_task'
C:/ruby/lib/ruby/gems/1.8/gems/rake-0.8.4/lib/rake.rb:2005:in 'top_level'
C:/ruby/lib/ruby/gems/1.8/gems/rake-0.8.4/lib/rake.rb:2005:in 'each'
C:/ruby/lib/ruby/gems/1.8/gems/rake-0.8.4/lib/rake.rb:2005:in 'top_level'
C:/BuildAgent/plugins/rake-runner/lib/rb/runner/rake_ext.rb:311:in 'standard_exception_handling'
C:/ruby/lib/ruby/gems/1.8/gems/rake-0.8.4/lib/rake.rb:1999:in 'top_level'
C:/ruby/lib/ruby/gems/1.8/gems/rake-0.8.4/lib/rake.rb:1977:in 'run'
C:/BuildAgent/plugins/rake-runner/lib/rb/runner/rake_ext.rb:311:in 'standard_exception_handling'
C:/ruby/lib/ruby/gems/1.8/gems/rake-0.8.4/lib/rake.rb:1974:in 'run'
C:/BuildAgent/plugins/rake-runner/lib/rb/runner/rake_ext.rb:179:in 'run'
C:/BuildAgent/plugins/rake-runner/lib/rb/runner/rakerunner.rb:40

Here’s what rake Application.top_level looks like:

# Rake lib
def top_level
    standard_exception_handling do
        if options.show_tasks
            display_tasks_and_comments
        elsif options.show_prereqs
            display_prerequisites
        else
            top_level_tasks.each { |task_name| invoke_task(task_name) }
        end
    end
end

The TeamCity version has overridden standard_exception_handling:

# TeamCity Rakerunner
def standard_exception_handling
    begin
        yield
    rescue Rake::ApplicationAbortedException => app_e
        raise
    rescue Exception => exc
        Rake::TeamCityApplication.process_exception(exc)
    end
end

So the yield there is yielding to the result of executing each top level task. The rake task implementation has an execute method like:

# TeamCity Rakerunner
def execute(*args, &block)
    standard_execute_block = Proc.new do
        standard_execute(*args, &block)
    end

    if application.options.dryrun
        Rake::TeamCityApplication.target_exception_handling(
            name, true, "(dry run)", &standard_execute_block)
    else
        Rake::TeamCityApplication.target_exception_handling(
            name, true, &standard_execute_block)
    end
end

Where Rake::TeamCityApplication.target_exception_handling raises Rake::ApplicationAbortedException. We can disable this behaviour by commenting it out.

Solution

The Quick solution is to comment out the line that raises the exception:

# rake_ext line 158, method TeamCityApplication.process_exception

raise Rake::ApplicationAbortedException, exc

The problem now though, is that a failing task will not be reported automatically.

In this project that’s fine because we’re doing this ourselves in a subsequent step, but for other projects using the rakerunner this may prove confusing.

Rake — shell task failure

For my current project, we’re running cucumber as one of our tasks. Our report generation runs afterwards — which we need to happen regardless of cucumber’s exit code (cucumber exits with code 1 when any tests fail).

Handling shell task failure

We noticed that if cucumber fails, rake exits immediately — without running our subsequent report tasks.

We’re running cucumber with rake’s ruby function — which runs the ruby interpreter in its own process by invoking a shell command.

Pseudo-stacktrace (irrelevant source lines omitted):

Shell::CommandProcessor.system(command, *opts)
Rake::Win32.rake_system(*cmd)
FileUtils.sh(*args, &block)
FileUtils.ruby(*args, &block)

The key to this is the behaviour of rake’s FileUtils.sh. Examining the source shows:

If it is not supplied a block, and the shell command fails, and rake exits with error status.

Aside: For some reason, Kernel.system echoes errors.

Example

This task will cause rake to exit immediately with status 1:

task 'this-one-fails' do
    ruby("xxx")
end

while the following task does not cause rake to terminate  normally, any subsequent task will still run:

path = File.expand_path(File.dirname(__FILE__) + ‘/output/cucumber-manual.txt’)

cuke_path = ‘C:/ruby/lib/ruby/gems/1.8/gems/cucumber-0.3.3/bin/cucumber’

ruby(“#{cuke_path} -h > ‘#{path}'”) do |success, exit_code|

puts “Exited with code: #{exit_code}” if !success

end

task 'this-one-succeeds' do
    ruby("xxx") do |success, exit_code|
        puts "Exited with code: #{exit_code.exitstatus}" unless success
    end
end

Getting the last exit status

The $? variable contains the status of the last child process to terminate. This may be useful if steps subsequent to the failed one require this information.

Cucumber — ANSI formatting

When cucumber output is piped to file on disk, it may contain non-printable characters and markup, for example:

[32m6 passed steps

Actually looks like this when output to console:

6 passed steps

This is due to cucumber emitting Ansi formatting.

[ANSI escape sequences] are used to control text formatting and other output options on text terminals.

Most of these escape sequences start with the characters ESC (ASCII decimal 27/hex 0x1B/octal 033) and [ (left bracket). This sequence is called CSI for Control Sequence Introducer(or Control Sequence Initiator). There is a single-character CSI (155/0x9B/0233) as well.

The ESC+[ two-character sequence is more often used than the single-character alternative, for details see C0 and C1 control codes. Devices supporting only ASCII (7-bits), or which implement 8-bit code pages which use the 0x80–0x9F control character range for other purposes will recognize only the two-character sequence. Though some encodings use multiple bytes per character, in this topic all characters are single-byte…

This formatting can be suppressed using the:

--[no-]color

switch.

TeamCity build agents and FireWatir

We have had some issues lately getting our automated acceptance tests running in TeamCity on Firefox.

Our failing tests could open browser windows, but not interact with them — the same behaviour exhibited when the JSSH plugin is missing. And the error reported in TeamCity is like:

Unable to connect to machine : 127.0.0.1 on port 9997.
Make sure that JSSh is properly installed and
Firefox is running with '-jssh' option
(Watir::Exception::UnableToStartJSShException)

This was puzzling because we knew we had installed JSSH.

The problem amounts to ensuring the Firefox JSSH extension is enabled for the correct account.

Build agents, user accounts and desktop (GUI) interaction

Only when Local System Account is selected can you also select the Allow service to interact with the desktop option. The “this account” method does not even allow selection of the checkbox (watch carefully, the checkbox is unchecked when you press apply).

Running without GUI does not prevent these types of things happening — they’re just not painted on the screen — so to diagnose issues like these it’s preferable to allow interaction with desktop.

This means running build agents as Local System account.

Solution

Firefox allows adding extensions via command line. So, to enable JSSH for every user on your build agent, download the extension, and then run something like:

$ "C:\Program Files\Mozilla Firefox\firefox -install-global-extension 'path\to\extension'"

You can then run Team City Build Agent Service as Local System user and enable desktop interaction.

References

• [Windows Local System account] The LocalSystem account is a predefined local account used by the service control manager. This account is not recognized by the security subsystem, so you cannot specify its name in a call to the LookupAccountName function. It has extensive privileges on the local computer, and acts as the computer on the network.
• [Firefox command line options] Various command line options are be available to perform advanced, troubleshooting or system administration tasks. Installation into the application directory is possible from the command line, intended to be used by administrators on multi-user systems.
• [How does JSSH work?] FireWatir uses JSSh (TCP/IP JavaScript Shell Server for Mozilla) to drive the FireFox browser. JSSh allows other programs (like telnet) to establish JavaScript shell connections to a running Mozilla process. Once that connection is made, we can send JavaScript commands over the connection, which are executed against the DOM of the page loaded in the browser. JSSh listens on port 9997 by default.

Ruby require

While diagnosing problems with a ruby application, we discovered we had to move certain folders around so the interpreter could find them. Clearly we were missing something fundamental.

Require: definition

Inspecting the source (v1.9) for require shows:

Ruby tries to load the library named _string_, returning
 *  +true+ if successful. If the filename does not resolve to
 *  an absolute path, it will be searched for in the directories listed
 *  in <code>$:</code>. If the file has the extension ``.rb'', it is
 *  loaded as a source file; if the extension is ``.so'', ``.o'', or
 *  ``.dll'', or whatever the default shared library extension is on
 *  the current platform, Ruby loads the shared library as a Ruby
 *  extension. Otherwise, Ruby tries adding ``.rb'', ``.so'', and so on
 *  to the name. The name of the loaded feature is added to the array in
 *  <code>$"</code>. A feature will not be loaded if it's name already
 *  appears in <code>$"</code>. However, the file name is not converted
 *  to an absolute path, so that ``<code>require 'a';require
 *  './a'</code>'' will load <code>a.rb</code> twice.

Require does not canonicalize paths

Here’s the relevant part of the comment:

However, the file name is not converted
to an absolute path, so that
require 'a';
require './a'
will load a.rb twice.

So, as described, ruby treats require statements literally: a different path is a different file, even if it’s a different path to the same file. And this may result in a file being loaded twice.

This can have confusing side effects. We encountered this in one of our cucumber projects — after scenario handlers were firing twice and we didn’t know why.

Require does not expand paths

Another implication of this behaviour is that an application may not run as expected unless the correct working directory is used.

Adding to the $” list does not work

I thought another option may be adding items directly to the $” list. I guess this shows that require is doing more than just inserting an item in a list.

Adding to $” is in fact not enough, demonstrated by the fact that this works:

require file_to_include

$”.unshift(file_to_include)

require file_to_include
$".unshift(file_to_include)

While the reverse order does not:

$".unshift(file_to_include)
require file_to_include

This proves that require has exited early because the file already exists in $” – and hence the include fails.

Solution

Fortunately there is a way around both of these problems.

Rather than require relative paths:

require '../lib/application'

absolute paths may be specified:

File.expand_path(File.dirname(__FILE__) + '/../lib/application')

This means that:

1. Working directory is no longer relevant. The second example ensures that the required path is relative the the file that requires it.
2. Duplicate requires are not possible

EDIT, 2009-05-12: Also consider require_relative, added in v1.9