Parsing massive test case file takes lot of time

[mkorpela]

Parsing massive test case file takes lot of time

[mkorpela]

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

[vkosuri]

Yes I tested with RF 3.0

[mkorpela]

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

[mkorpela]

python pabotprofile.py generated

[vkosuri]

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]

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

[mkorpela]

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]

@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]

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]

Thanks for pointin that out. I fixed the import.

[mkorpela]

Should be fixed in 0.25