Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Parsing massive test case file takes lot of time #65

Closed
vkosuri opened this issue Apr 6, 2016 · 11 comments
Closed

Parsing massive test case file takes lot of time #65

vkosuri opened this issue Apr 6, 2016 · 11 comments
Assignees
@mkorpela
Labels
enhancement

Comments

@vkosuri
Copy link

vkosuri commented Apr 6, 2016

We are auto generating robot framework testcase through some automation scripts the generated robot framework testcase size approximately 50 MB, while i used to

pabot --name "Conformance Tests" --doc --timestampoutputs --splitlog --outputdir olt_reports generated

It took around 30 minutes to analyse the testcase after that it started actual execution and completed in 4 minutes

The number of lines in testcase approximately 4,00,000

Is there any methods to find why it took so much time analyse the testcase?

If not are there any methods to solve this issue?

The same issue we raised at robot-framework robotframework/robotframework#2231
@mkorpela
Copy link
Owner

mkorpela commented Apr 6, 2016

Hi,
So I liked to confirm that this happening with the new Robot Framework version that Peke and Jussi made?

@vkosuri
Copy link
Author

vkosuri commented Apr 7, 2016

Yes I tested with RF 3.0

@mkorpela
Copy link
Owner

mkorpela commented Apr 8, 2016

Could you try to run
https://gist.github.com/mkorpela/0e76c48eb6453dc21712
This will give you profiling results

@mkorpela
Copy link
Owner

mkorpela commented Apr 8, 2016

python pabotprofile.py generated

@vkosuri
Copy link
Author

vkosuri commented May 5, 2016

After 26 mins i forcefully stopped execution from console, here are some values i captured from profile

Elapsed time: 26 minutes 4.374 seconds
Thu May  5 13:56:46 2016    ./pybot-profileluxiz9.out

         219346286 function calls (216679489 primitive calls) in 1564.373 seconds

   Ordered by: cumulative time
   List reduced from 2166 to 50 due to restriction <50>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000 1564.375 1564.375 <string>:1(<module>)
        1    0.000    0.000 1564.375 1564.375 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/pabot/pabot.py:352(main)
        2    0.008    0.004 1505.657  752.829 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/utils/application.py:73(execute)
        2    0.000    0.000 1505.647  752.823 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/utils/application.py:78(_execute)
        1    0.000    0.000 1502.106 1502.106 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/pabot/pabot.py:189(solve_suite_names)
        1    0.000    0.000 1502.106 1502.106 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/run.py:469(run)
        1    0.000    0.000 1502.077 1502.077 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/run.py:423(main)
    39/16    0.000    0.000 1260.403   78.775 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/model/testsuite.py:158(visit)
    36/18    0.001    0.000 1260.401   70.022 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/model/visitor.py:76(visit_suite)
  2027/41    0.024    0.000 1260.150   30.735 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/model/itemlist.py:67(visit)
     2035    0.020    0.000 1258.921    0.619 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/model/testcase.py:71(visit)
        1    0.079    0.079 1258.529 1258.529 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/model.py:180(run)
        3    0.035    0.012 1256.931  418.977 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/runner.py:110(visit_test)
 292529/4    4.824    0.000 1237.058  309.264 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/steprunner.py:31(run_steps)
453078/160550    8.774    0.000 1236.124    0.008 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/steprunner.py:48(run_step)
399820/241585   15.908    0.000  915.140    0.004 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/librarykeywordrunner.py:104(dry_run)
    53258    2.445    0.000  882.806    0.017 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/userkeywordrunner.py:185(dry_run)
    53258    1.966    0.000  809.390    0.015 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/userkeywordrunner.py:192(_dry_run)
    53257    2.739    0.000  736.461    0.014 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/userkeywordrunner.py:134(_execute)
239269/107281    5.559    0.000  576.231    0.005 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/librarykeywordrunner.py:146(_dry_run)
   453078    3.522    0.000  363.097    0.001 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/context.py:181(get_runner)
   453078    3.214    0.000  359.576    0.001 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/namespace.py:221(get_runner)
   453078    2.977    0.000  356.362    0.001 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/namespace.py:263(get_runner)
   453078    6.507    0.000  353.385    0.001 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/namespace.py:278(_get_runner)
   453078    6.733    0.000  342.583    0.001 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/namespace.py:302(_get_implicit_runner)
   399820   22.028    0.000  285.989    0.001 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/namespace.py:327(_get_runner_from_library_keywords)
        1    0.000    0.000  243.519  243.519 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/builder.py:49(build)
        1    0.000    0.000  243.519  243.519 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/builder.py:63(_parse_and_build)
  3251818   33.577    0.000  227.829    0.000 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/handlerstore.py:52(__contains__)
  4883386   28.793    0.000  224.612    0.000 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/utils/normalizing.py:61(<lambda>)
   453078   12.021    0.000  213.132    0.000 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/statusreporter.py:28(__enter__)
  4884397   82.617    0.000  195.847    0.000 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/utils/normalizing.py:21(normalize)
  3575492   25.757    0.000  189.402    0.000 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/utils/normalizing.py:111(__contains__)
        1    0.000    0.000  187.444  187.444 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/builder.py:68(_parse)
      6/1    0.000    0.000  187.444  187.444 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/parsing/model.py:31(TestData)
        1    0.000    0.000  187.443  187.443 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/parsing/model.py:217(populate)
        1    0.000    0.000  187.443  187.443 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/parsing/populators.py:106(populate)
        1    0.000    0.000  187.441  187.441 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/parsing/populators.py:124(_populate_children)
        5    0.000    0.000  187.441   37.488 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/parsing/model.py:233(add_child)
        5    0.000    0.000  187.434   37.487 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/parsing/model.py:141(populate)
        5    0.000    0.000  187.433   37.487 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/parsing/populators.py:54(populate)
        5    9.560    1.912  187.412   37.482 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/parsing/tsvreader.py:23(read)
   399820    5.765    0.000  182.808    0.000 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/librarykeywordrunner.py:111(_dry_run)
   453088    5.480    0.000  161.490    0.000 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/arguments/argumentspec.py:41(resolve)
   284832    4.771    0.000  156.485    0.001 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/parsing/populators.py:91(add)
   453078    4.224    0.000  152.277    0.000 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/context.py:171(start_keyword)
   453078    3.394    0.000  148.053    0.000 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/output/output.py:60(start_keyword)
   453078   12.078    0.000  144.659    0.000 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/output/logger.py:184(start_keyword)
   453078   10.186    0.000  135.742    0.000 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/statusreporter.py:40(__exit__)
   453088    8.816    0.000  135.164    0.000 /home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework-3.0-py2.7.egg/robot/running/arguments/argumentresolver.py:32(resolve)

@mkorpela
Copy link
Owner

mkorpela commented May 5, 2016

Thank you! This is very informative. It seems that the time goes in step_runner and userkeywordrunner

@mkorpela
Copy link
Owner

mkorpela commented May 6, 2016

Further investigation shows that surgical attack to
robot/parsing/populators.py:54(populate)
OR robot/parsing/tsvreader.py:23(read)
before executing solve_suite_names should improve the situation.
If steps would be mostly removed during parsing from test cases and keywords.

@mkorpela
Copy link
Owner

mkorpela commented May 6, 2016

@vkosuri Could you try to build pabot from bef36d6
?
sudo python setup.py install

and execute pabot with your test data?

I am trying out experimental way of modifying how Robot Framework works and I need your validation that this is the right direction.

@vkosuri
Copy link
Author

vkosuri commented May 7, 2016

Thanks,

Yes it seems to me working fine, I will let know profile stats also soon

The package decorator not included in my workspace so it failed execution. I solved with pip install decorator

(venv)mkosuri@evolet:~/yang_gen/sdvt-yang-testing$ python pabotprofile.py generated
Traceback (most recent call last):
  File "pabotprofile.py", line 3, in <module>
    from pabot.pabot import main
  File "/home/mkosuri/yang_gen/venv/local/lib/python2.7/site-packages/robotframework_pabot-0.24-py2.7.egg/pabot/pabot.py", line 28, in <module>
    from decorator import contextmanager
ImportError: No module named decorator

@mkorpela mkorpela mentioned this issue May 7, 2016
Closed
@mkorpela
Copy link
Owner

mkorpela commented May 7, 2016

Thanks for pointin that out. I fixed the import.

@mkorpela mkorpela self-assigned this May 7, 2016
@mkorpela
Copy link
Owner

mkorpela commented May 7, 2016

Should be fixed in 0.25

@mkorpela mkorpela closed this as completed May 7, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@mkorpela mkorpela

Labels
enhancement
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@mkorpela @vkosuri