Analyze Rails CI

#railsdm2019 Analyze Rails CI
Analyze Rails CI
@mtsmfm
Fumiaki Matsushima
RailsDM 2019 #railsdm2019

View Slide

➔ Web Dev at Quipper
➔ Ruby, Mahjong, Dead by
Daylight
➔ Nishi-nippori.rb organizer
➔ GraphQL Tokyo organizer
@mtsmfm.inspect

View Slide

https://studysapuri.jp/

View Slide


View Slide

https://nishinipporirb.doorkeeper.jp/events/88540
Nishi-nippori.rb meetup #53

View Slide

https://nishinipporirb.doorkeeper.jp/events/88540
Meetup
place
Nishi-
nippori

View Slide

I gave a talk about flaky tests before
https://speakerdeck.com/mtsmfm/how-do-e2e-tests-fail-randomly

View Slide

I’ve been writing flaky tests

View Slide

I’m going to write new
variation of flaky tests

View Slide

“100% is the wrong
reliability target for
basically everything”
Site Reliability Engineering
Edited by Betsy Beyer, Chris Jones, Jennifer Petoff and Niall Richard Murphy
https://landing.google.com/sre/sre-book/chapters/introduction/

View Slide

The same with flaky tests

View Slide

97.3 %

View Slide

The percentage of passed
jobs on master branch
in Feb 2019
in rails/rails repo

View Slide

https://github.com/rails/rails/pull/33829#issuecomment-420586191
Rails also has flaky tests

View Slide


View Slide

https://has-it-failed.herokuapp.com

View Slide

https://has-it-failed.herokuapp.com/?q=test_invoke_when_generator_is_not_found

View Slide

What I’d like to talk
- I’ve published Rails CI result as a public dataset on
BigQuery
https://console.cloud.google.com/bigquery?p=rails-travis
-result&d=rails_travis_result&page=dataset
- You can find the test was failed before or not on Rails
CI via http://has-it-failed.herokuapp.com
- There’s a room for improvement if we have CI result
database
(e.g. Make CI result passed if failed one is a flaky test)

View Slide

Browser
rails-ci-result-importer
BigQuery
PostgreSQL
has-it-failed
TravisCI API
Overview of systems I created for this talk

View Slide

Agenda
1. rails-ci-result-importer
2. has-it-failed app
3. Future work

View Slide

1. rails-ci-result-importer

View Slide

rails-ci-result-importer
BigQuery
TravisCI API

View Slide

https://github.com/mtsmfm/rails-ci-result-importer

View Slide

Heroku
Scheduler
Embulk
BigQuery
Redis
diff.yml
TravisCI API
bin/import
embulk-input-travis
embulk-output-bigquery

View Slide

https://www.embulk.org/docs/

View Slide

Why embulk?
- Just curious
- Embulk plugin can be written in (J)Ruby

View Slide

Heroku
Scheduler
Embulk
BigQuery
Redis
diff.yml
TravisCI API
bin/import
embulk-input-travis
embulk-output-bigquery

View Slide

https://github.com/mtsmfm/embulk-input-travis

View Slide

Resources on TravisCI
Commit
d8d6bd5
Build
59740
Job
59740.1
GEM=railties
Ruby: 2.5.3
$ git push xxx
Repository
rails/rails Job
59740.2
GEM=railties
Ruby: 2.6.0
Job
59740.3
GEM=ap,ac
Ruby: 2.6.0
...

View Slide

Table schema on BigQuery
Field name Type Description
id INTEGER Job id on TravisCI
data STRING Job attributes in JSON
log STRING Job log
started_at TIMESTAMP When this job started
build_number INTEGER Build number job belongs to
build_data STRING Build attributes job belongs to
commit_data STRING Commit attributes job belongs to

View Slide

Important notice
- This dataset doesn’t have all results (for now)
- Some rows don’t have commit_data (for now)
- I paid to store this dataset but you need to
pay money to run query

View Slide

Table schema on BigQuery
Field name Type Description
id INTEGER Job id on TravisCI
data STRING Job attributes in JSON
log STRING Job log
started_at TIMESTAMP When this job started
build_number INTEGER Build number job belongs to
build_data STRING Build attributes job belongs to
commit_data STRING Commit attributes job belongs to
Partitioned by started_at

View Slide

Be sure to query with “WHERE started_at”

View Slide

40 / 1024 * 5 ≒ 0.2 (USD)
https://cloud.google.com/bigquery/pricing

View Slide

Important notice
- This dataset doesn’t have all results (for now)
- Some rows don’t have commit_data (for now)
- I paid to store this dataset but you need to
pay money to run query
- Be sure to query with “WHERE started_at”
- Full scan costs only $0.2 for now but amount of data
keeps increasing

View Slide

2. has-it-failed app

View Slide

https://github.com/mtsmfm/has-it-failed

View Slide

Browser
BigQuery
PostgreSQL
Find all failed tests
via SQL
ImportJob
Store PG
(cache)
Web server

View Slide

It’s just raw log...
/home/travis/.rvm/rubies/ruby-head/bin/ruby -w -Itest -Ilib -I../activesupport/lib -I../actionpack/lib
-I../actionview/lib -I../activemodel/lib test/commands/server_test.rb
Run options: --seed 10052
# Running:
....F
Failure:
Rails::Command::ServerCommandTest#test_using_server_mistype_without_suggestion
[test/commands/server_test.rb:38]:
Expected /Maybe you meant/ to not match "Could not find server \"t\". Maybe you meant \"cgi\"?\nRun
`rails server --help` for more options.\n".
rails test test/commands/server_test.rb:35
.....................
Finished in 0.760100s, 34.2060 runs/s, 71.0433 assertions/s.
26 runs, 54 assertions, 1 failures, 0 errors, 0 skips
^^^ +++
--- test/configuration/middleware_stack_proxy_test.rb

View Slide

It’s just raw log...
# Running:
....F
Failure:
.....................
^^^ +++
Test class,
test method
Failed info

View Slide

Browser
BigQuery
PostgreSQL
via SQL
ImportJob
Store PG
(cache)
Web server

View Slide

SELECT * FROM(
SELECT DISTINCT id, data, build_number, build_data,
extractCiResult(log) AS parse_result
FROM `rails-travis-result.rails_travis_result.jobs`
WHERE "#{from.iso8601}" < started_at
AND started_at < "#{to.iso8601}"
) WHERE parse_result <> "error"
AND JSON_EXTRACT_SCALAR(data, "$.state") = "failed"
AND JSON_ARRAY_LENGTH(
JSON_EXTRACT(parse_result, "$.failedTests")
) > 0

View Slide

CREATE TEMP FUNCTION extractCiResult (log STRING) RETURNS STRING LANGUAGE js AS
"""
try {
const railsCiResult = (TravisResultParser.parse(log)).find(
command => command.includes('[Travis CI]')
);
return JSON.stringify(RailsCiParser.parse(railsCiResult));
} catch {
return 'error';
}
"""
OPTIONS
(
library=[
"gs://rails-travis-result/parser/v0.1.0/rails_ci.js",
"gs://rails-travis-result/parser/v0.1.0/travis_result.js"
]
);

View Slide

BigQuery supports JavaScript UDF
- Let’s write a parser in JavaScript and run on
BigQuery directly!

View Slide

PEG and PEG.js
- Parsing Expression Grammar
- PEG.js is one of the most popular parser
generator
- Export parser from PEG
- Online editor

View Slide

https://pegjs.org/online

View Slide

Result
= (Noise command:Command Noise { return command; })+
Noise
= (!Command .)*
Command
= TimeStart commandBody:CommandBody TimeEnd {
return commandBody;
}
CommandBody
= chars:(!TimeEnd char:. {return char})* {
return chars.join('').replace(/\x1B\[([0-9]{1,2}(;[0-9]{1,2})?)?[mGK]/g, '').replace(/\r\n/g, "\n")
}
TimeStart
= "travis_time:start:" (!"\n" .)+ "\n"
TimeEnd
= "travis_time:end:" (!"\n" .)+ "\n"

View Slide

How to parse Rails CI log
1. Find output from entrypoint (ci/travis.rb)
2. Find test command
e.g. $ ruby foo_test.rb
3. Find finished messages

View Slide

"""
try {
);
} catch {
return 'error';
}
"""
OPTIONS
(
library=[
]
);

View Slide

Log contains infrastructure info
https://api.travis-ci.org/v3/job/505038092/log.txt
...

View Slide

Result
Noise
= (!Command .)*
Command
= TimeStart commandBody:CommandBody TimeEnd {
return commandBody;
}
CommandBody
= chars:(!TimeEnd char:. {return char})* {
return chars.join('').replace(/\x1B\[([0-9]{1,2}(;[0-9]{1,2})?)?[mGK]/g, '').replace(/\r\n/g, "\n")
}
TimeStart
= "travis_time:start:" (!"\n" .)+ "\n"
TimeEnd
= "travis_time:end:" (!"\n" .)+ "\n"

View Slide

travis_fold:start:worker_info
…
travis_fold:end:worker_info
…
travis_time:start:08cc8690
$ bundle install --jobs 3 --retry 3
travis_time:end:08cc8690
…
...
travis_time:start:262254e0
$ ci/travis.rb
[Travis CI] railties
Running command: bundle exec rake test
travis_time:end:262254e0
…
Done. Your build exited with 0.
Result

View Slide

travis_fold:start:worker_info
…
travis_fold:end:worker_info
…
travis_time:start:08cc8690
$ bundle install --jobs 3 --retry 3
travis_time:end:08cc8690
…
...
travis_time:start:262254e0
$ ci/travis.rb
[Travis CI] railties
Running command: bundle exec rake test
travis_time:end:262254e0
…
Done. Your build exited with 0.
Noise
Result
Noise
Command
Noise
Noise
Command

View Slide

"""
try {
);
} catch {
return 'error';
}
"""
OPTIONS
(
library=[
]
);

View Slide

https://github.com/rails/rails/blob/d8d6bd5e63a9a4a6c06a4dde3c7137ee2be105fd/ci/travis.rb#L45

View Slide

"""
try {
);
} catch {
return 'error';
}
"""
OPTIONS
(
library=[
]
);

View Slide

RailsCiResult
= Noise tests:Test+ {
return {
failedTests: tests.filter(t => t.summary).filter(({summary: {failuresCount, errorsCount}}) => failuresCount + errorsCount > 0),
coreDumpedTests: tests.filter(t => t.dump),
noises: tests.filter(t => t.noise)
}
}
Noise
= (!Test .)*
Test
= command:TestCommand
result:(
results:TestFailureOrErrorResult* summary:TestFinished TestOutputNoise { return { summary, results } }
/ results:TestSuccessResult summary:TestFinished TestOutputNoise { return { summary, results } }
/ dump:RubyCoreDump { return { dump } }
/ noise:TestOutputNoise { return { noise } }
) {
return { command, ...result };
}
TestCommand
= command:$("/home/travis/.rvm" $(!("/bin/" "j"? "ruby -w" / "\n") .)* "/bin/" "j"? "ruby -w" $(!"\n" .)*)
"\n" { return command }
TestOutputNoise
= (!TestCommand .)*
TestSuccessResult
= message:$(!TestFinished .)* { return { message } }
TestFailureOrErrorResult
= (!(TestFailureOrErrorResultKeyword / TestFinished) .)* meta:TestFailureOrErrorResultKeyword message:TestFailureMessage {
return { ...meta, message }
}
TestFailureMessage
= $(!(TestFailureOrErrorResultKeyword / TestFinished) .)*
TestFailureOrErrorResultKeyword
= "\n" type:("Failure" / "Error") ":\n" testClass:TestClass "#" method:TestMethod (" [" file:TestFile ":" line:Int "]")? ":\n" {
return { type, testClass, method }
}
TestClass
= $[a-zA-Z:]+
TestMethod
= $[a-zA-Z_]+
TestFile
= $[a-z/\._]+
TestFinished
= "\n" runsCount:Int " runs, " assertionsCount:Int " assertions, " failuresCount:Int " failures, " errorsCount:Int " errors, " skipsCount:Int " skips" "\n" {
return { runsCount, assertionsCount, failuresCount, errorsCount, skipsCount }
}
RubyCoreDump
= $((!RubyCoreDumpNote .)* RubyCoreDumpNote)
RubyCoreDumpNote
= "\n"
"[NOTE]\n"
"You may have encountered a bug in the Ruby interpreter or extension libraries.\n"
"Bug reports are welcome.\n"
"For details: https://www.ruby-lang.org/bugreport.html\n"
"\n"
"Aborted (core dumped)\n"
Int
= chars:$[0-9]+ { return parseInt(chars) }

View Slide

RailsCiResult
= Noise tests:Test+ {
return {
failedTests: tests.filter(t => t.summary).filter(({summary: {failuresCount,
errorsCount}}) => failuresCount + errorsCount > 0),
coreDumpedTests: tests.filter(t => t.dump),
noises: tests.filter(t => t.noise)
}
}

View Slide

Test
= command:TestCommand
result:(
TestFailureOrErrorResult* TestFinished TestOutputNoise
/ TestSuccessResult TestFinished TestOutputNoise
/ RubyCoreDump
/ TestOutputNoise
)

View Slide

TestCommand
= command:$("/home/travis/.rvm" $(!("/bin/" "j"? "ruby -w" / "\n") .)* "/bin/" "j"? "ruby -w" $(!"\n" .)*) "\n"
TestFailureOrErrorResult
= (!(TestFailureOrErrorResultKeyword / TestFinished) .)* TestFailureOrErrorResultKeyword TestFailureMessage
= "\n" type:("Failure" / "Error") ":\n" testClass:TestClass "#" method:TestMethod (" [" file:TestFile ":" line:Int "]")? ":\n"
TestClass
= $[a-zA-Z:]+
TestMethod
= $[a-zA-Z_]+
TestFile
= $[a-z/\._]+
TestFinished
= "\n" runsCount:Int " runs, " assertionsCount:Int " assertions, " failuresCount:Int " failures, " errorsCount:Int " errors, "
skipsCount:Int " skips" "\n"

View Slide

# Running:
....F
Failure:
.....................
^^^ +++
-I../actionview/lib -I../activemodel/lib test/configuration/middleware_stack_proxy_test.rb

View Slide

# Running:
....F
Failure:
.....................
^^^ +++
-I../actionview/lib -I../activemodel/lib test/configuration/middleware_stack_proxy_test.rb
TestCommand
Noise
FailureMessage
TestFinished

View Slide

{
"failedTests": [
{
"command": "/home/travis/.rvm/rubies/ruby-head/bin/ruby -w -Itest -Ilib -I../activesupport/lib -I../actionpack/lib
-I../actionview/lib -I../activemodel/lib test/commands/server_test.rb",
"summary": {
"runsCount": 26,
"assertionsCount": 54,
"failuresCount": 1,
"errorsCount": 0,
"skipsCount": 0
},
"results": [
{
"type": "Failure",
"testClass": "Rails::Command::ServerCommandTest",
"method": "test_using_server_mistype_without_suggestion",
"message": "Expected /Maybe you meant/ to not match \"Could not find server \\\"t\\\". Maybe you meant \\\"cgi\\\"?\\nRun
`rails server --help` for more options.\\n\".\n\nrails test test/commands/server_test.rb:35\n\n.....................\n\nFinished in
0.760100s, 34.2060 runs/s, 71.0433 assertions/s."
} ...

View Slide

Yay!

View Slide

Browser
BigQuery
PostgreSQL
via SQL
ImportJob
Store PG
(cache)
Web server

View Slide

has-it-failed web
- Rails 6.0.0.beta3
- Heroku
- Nothing special

View Slide

3. Future work

View Slide

"""
try {
);
} catch {
return 'error';
}
"""
OPTIONS
(
library=[
]
);

View Slide

This parser is also flaky

View Slide

It’s much better to collect
test report in future

View Slide

https://docs.travis-ci.com/user/uploading-artifacts/
TravisCI doesn’t provide the place to store artifacts

View Slide

Buildkite can store artifacts
https://buildkite.com/pricing

View Slide

https://github.com/rails/rails/pull/35698

View Slide

[Idea] Make CI passed if failed one is flaky
1. Generate JUnit format XML test report
2. Send test report to the service
3. The service collects flaky tests data and
returns 0 or 1
4. Use the value in step 3 as exit code

View Slide

$ bin/ruby -I test || true
Flaky tests
Data
Web server
$ test $(curl --form
"[email protected]" https://server) =
‘0’
result.xml

View Slide

Flaky tests
Data
1. Generate XML and always
returns 0
Web server
‘0’
result.xml

View Slide

Flaky tests
Data
returns 0
Web server
‘0’
result.xml

View Slide

Flaky tests
Data
returns 0
Web server
‘0’
result.xml
3. Service returns 0 or 1

View Slide

Flaky tests
Data
returns 0
Web server
‘0’
result.xml
3. Service returns 0 or 1
4. Verify returned value

View Slide

Conclusion
- I’ve published Rails CI result as a public dataset on
BigQuery
https://console.cloud.google.com/bigquery?p=rails-travis
-result&d=rails_travis_result&page=dataset
- You can find the test was failed before or not on Rails
CI via http://has-it-failed.herokuapp.com
- There’s a room for improvement if we have CI result
database
(e.g. Make CI result passed if failed one is a flaky test)

View Slide

Analyze Rails CI

Analyze Rails CI

Fumiaki MATSUSHIMA

More Decks by Fumiaki MATSUSHIMA

Other Decks in Programming

Featured

Transcript