[RUBY]how to measure steps' execution time
347 views
Skip to first unread message
Oleg Sukhodolsky
May 15, 2012, 6:24:32 AM5/15/12
to cu...@googlegroups.com
Hi,
I need to implement formatter which will report step's execution time.
At Cucumber's wiki I've found cucumber_timing_presenter formatter which starts timer in before_step and stops it in before_step_result
but this approach doesn't work when I have a scenario with examples table.
For this example I see the following call sequence for step definition:
before_step
before_step-result
step_name
after_step_result
after_step
And only before_step_result +step_name +after_step_result for step execution. And all these three calls are executed after the test code, so I can not measure execution time :(
After that I've tries to run cucumber with debug formatter (cucumber --format debug) and it produce very unexpected (for me) sequence of calls:
before_features
before_feature
before_comment
comment_line
after_comment
before_tags
after_tags
feature_name
before_feature_element
before_tags
after_tags
scenario_name
before_steps
before_step
before_step_result
step_name
after_step_result
after_step
before_step
before_step_result
step_name
after_step_result
after_step
before_step
before_step_result
step_name
after_step_result
after_step
before_step
before_step_result
step_name
after_step_result
after_step
after_steps
before_examples_array
before_examples
examples_name
before_outline_table
before_table_row
before_table_cell
table_cell_value
after_table_cell
before_table_cell
table_cell_value
after_table_cell
before_table_cell
table_cell_value
after_table_cell
before_table_cell
table_cell_value
after_table_cell
after_table_row
before_table_row
before_table_cell
table_cell_value
after_table_cell
before_table_cell
table_cell_value
after_table_cell
before_table_cell
table_cell_value
after_table_cell
before_table_cell
table_cell_value
after_table_cell
after_table_row
before_table_row
before_table_cell
table_cell_value
after_table_cell
before_table_cell
table_cell_value
after_table_cell
before_table_cell
table_cell_value
after_table_cell
before_table_cell
table_cell_value
after_table_cell
after_table_row
before_table_row
before_table_cell
table_cell_value
after_table_cell
before_table_cell
table_cell_value
after_table_cell
before_table_cell
table_cell_value
after_table_cell
before_table_cell
table_cell_value
after_table_cell
after_table_row
after_outline_table
after_examples
after_examples_array
after_feature_element
after_feature
after_features
It is unexpected because I do not see no xxx_table_cell calls in my formatter.
So, I have two questions:
1. why debug formatter produces such a different output?
2. what formatter's methods I should use to measure step execution time in for steps executed for tables?
Thanks In advance, Oleg.
P.S. just to clarify I do use cucumber 1.2.0
aslak hellesoy
May 15, 2012, 6:35:12 AM5/15/12
to cu...@googlegroups.com
On Tue, May 15, 2012 at 11:24 AM, Oleg Sukhodolsky <os9...@gmail.com> wrote:
> Hi,
>
> I need to implement formatter which will report step's execution time.
> Hi,
>
> I need to implement formatter which will report step's execution time.
That already exists. --format usage
Aslak
> -- There are two rules:
>
> 1) Please prefix the subject with [Ruby], [JVM] or [JS]. This allows people
> to filter messages.
> 2) Please use interleaved answers
> http://en.wikipedia.org/wiki/Posting_style#Interleaved_style
>
> You received this message because you are subscribed to the Google Groups
> Cukes group. To post to this group, send email to cu...@googlegroups.com. To
> unsubscribe from this group, send email to
> cukes+un...@googlegroups.com. For more options, visit this group at
> https://groups.google.com/d/forum/cukes?hl=en
Oleg Sukhodolsky
May 15, 2012, 7:03:04 AM5/15/12
to cu...@googlegroups.com
On Tue, May 15, 2012 at 2:35 PM, aslak hellesoy
<aslak.h...@gmail.com> wrote:
> On Tue, May 15, 2012 at 11:24 AM, Oleg Sukhodolsky <os9...@gmail.com> wrote:
>> Hi,
>>
>> I need to implement formatter which will report step's execution time.
>
> That already exists. --format usage
It looks like it doesn't work with examples :( For regular scenario
<aslak.h...@gmail.com> wrote:
> On Tue, May 15, 2012 at 11:24 AM, Oleg Sukhodolsky <os9...@gmail.com> wrote:
>> Hi,
>>
>> I need to implement formatter which will report step's execution time.
>
> That already exists. --format usage
it reports time for every step,
but for scenario with example it just prints total time.
I've modified step definitions for
https://github.com/cucumber/cucumber/blob/master/examples/i18n/en/features/addition.feature
to sleep for some time (to make execution time visible). And also add
one regular scenario:
Scenario: Add two numbers (simple)
Given I have entered 20 into the calculator
And I have entered 30 into the calculator
When I press add
Then the result should be 50 on the screen
>cucumber --format usage addition.feature
----................
1.0005000 /I have entered (\d+) into the calculator/ #
step_definitons/calculator_steps.rb:14
1.0000000 Given I have entered 20 into the calculator # addition.feature:20
1.0010000 And I have entered 30 into the calculator # addition.feature:21
0.5010000 /I press (\w+)/ #
step_definitons/calculator_steps.rb:19
0.5010000 When I press add # addition.feature:22
0.3010000 /the result should be (.*) on the screen/ #
step_definitons/calculator_steps.rb:24
0.3010000 Then the result should be 50 on the screen # addition.feature:23
4 scenarios (4 passed)
16 steps (16 passed)
0m11.212s
as you can see total time is about 11 seconds, but statistic it
provided for 2.8seconds (one run of simple scenario)
Oleg.
Oleg Sukhodolsky
May 16, 2012, 5:20:33 AM5/16/12
to cu...@googlegroups.com
So, does current behavior of usage formatter is a bug in cucumber?
Should it before|after_step() before|after every execution of step.
Or there are some other places which the formatter should use to
calculate execution time for scenario with table?
Thanks in advance, Oleg.
Should it before|after_step() before|after every execution of step.
Or there are some other places which the formatter should use to
calculate execution time for scenario with table?
Thanks in advance, Oleg.
aslak hellesoy
May 16, 2012, 5:35:11 AM5/16/12
to cu...@googlegroups.com
On Wed, May 16, 2012 at 10:20 AM, Oleg Sukhodolsky <os9...@gmail.com> wrote:
> So, does current behavior of usage formatter is a bug in cucumber?
Yes, it sounds like a bug if Example scenarios don't behave the same
> So, does current behavior of usage formatter is a bug in cucumber?
as regular Scenarios.
Aslak
Oleg Sukhodolsky
May 16, 2012, 5:38:25 AM5/16/12
to cu...@googlegroups.com
On Wed, May 16, 2012 at 1:35 PM, aslak hellesoy
<aslak.h...@gmail.com> wrote:
> On Wed, May 16, 2012 at 10:20 AM, Oleg Sukhodolsky <os9...@gmail.com> wrote:
>> So, does current behavior of usage formatter is a bug in cucumber?
>
> Yes, it sounds like a bug if Example scenarios don't behave the same
> as regular Scenarios.
Great, at least now I know that I should fix this ;)
<aslak.h...@gmail.com> wrote:
> On Wed, May 16, 2012 at 10:20 AM, Oleg Sukhodolsky <os9...@gmail.com> wrote:
>> So, does current behavior of usage formatter is a bug in cucumber?
>
> Yes, it sounds like a bug if Example scenarios don't behave the same
> as regular Scenarios.
Thanks, Oleg.
Reply all
Reply to author
Forward
0 new messages