Forum Discussion

scottb's avatar
scottb
Contributor
11 years ago

Testcomplete runs impressively slow after upgrade to 10.4 Enterprise

Last week I upgraded my test system from 10.3 standard to 10.4 Enterprise.  After the upgrade Testcomplete runs extremely slow.  At this time TC is unusable.  Fortunately this is only a development system and we don't have a hot project right now.  



When walking through JScripts in debug mode I notice that writes to Log.Message() take a few seconds per write.  



I monitored the system activity using Sysinternal's Process Monitor utility.  Process Monitor show a lot of delays from an operation with hasplms.exe.  It is trying to create file <C:\Program Files (x86)\Common Files\SafeNet Sentinel\Sentinel LDK\installed> and getting a results "NAME NOT FOUND".  It only takes about three or four tenths of a second when it does this, but it does this once every second or two.  That seems like a lot of work to make sure TC is licensed.



I also noticed a lot of activity with TCHookX64, but it seems to run quite fast. 



I can provide the Smartbear staff with a Process Monitor dump while a delay is occuring when writing to Log.Message if requested, but I will not post the dump here.



Do I need to change permissions for TC perhaps?  Or did the licensing configuration change in a bad way between 10.3 and 10.4 Enterprise? 



My SUT is Windows 7 Professional with service pack 1. 

My hardware is a slightly beefy Intell i7-2600K CPU @ 3.4-GHz 3.4 GHz.  8GB RAM.  64 bit O/S.  1TB hard disk with about 390GB free space.



The Windows task manager > Resource Monitor show about 1.1GB free space in RAM while TC is running.  



I don't believe the hardware and O/S resources are an issue, especially since everything worked fine before the upgrade.



  • mtsmith's avatar
    mtsmith
    11 years ago
    Scott,

          Creating performance counters and then running that project on a different machine can also lead to dramatic increases in test execution time. In some cases, tests ran 10-20 times longer on a VM than developer box.  Process Monitor revealed that a large number of TCP Reconnect operations were made to the developer box, due to including performance counters in the project. Removing the counters restored the performance.  
  • mtsmith's avatar
    mtsmith
    Contributor
    11 years ago
    Scott,

          Creating performance counters and then running that project on a different machine can also lead to dramatic increases in test execution time. In some cases, tests ran 10-20 times longer on a VM than developer box.  Process Monitor revealed that a large number of TCP Reconnect operations were made to the developer box, due to including performance counters in the project. Removing the counters restored the performance.  
  • simon_glet's avatar
    simon_glet
    Regular Contributor
    11 years ago
    Even if we are still running TC 9.20.2460.7, I ran your function that took 1 (one) second to complete.



    1 - No, taking that long to write a log is not normal at all.



    2 - If the licence validation algorithm as changed since 9.20 (on startup only) and that your are using a floating licence, checking against the licence server much more might just reveal a network performance issue.





    Sincerely

  • simon_glet's avatar
    simon_glet
    Regular Contributor
    11 years ago
    Hi Scott,



    Glad to see that you are narrowing on the issue !



    Does the "bad" project have Performance Counters in the project's properties ? That can slow down the execution, especially for remote counters.



    Sincerely
  • mtsmith's avatar
    mtsmith
    Contributor
    11 years ago
    Here's a shot from Process Monitor that helped identify the Performance Counter problems here. The blacked out workstation is where the test is running and the blue out workstation is the developer box where it was trying to access the counters.
  • scottb's avatar
    scottb
    Contributor
    11 years ago
    I'm not using Performance Counters, so I can rule that out.  



    I made a copy of the "bad" project start stripped out all of the Project componets except the one test script.  The behavior reproduced.  



    As far as I can tell the project settings in the "bad" Suite are the same as the settings in the "good" Suites.  



    I zipped up the stripped down project and submitted it to Smartbear Support so they can look at it.  I'm guessing the project configurations are somehow corrupt.  



    I'll let you know something when I know something.  Thanks again for your help.



  • scottb's avatar
    scottb
    Contributor
    11 years ago
    Someone had put performance counters into the project for a machine that does not exist on my network and forgot to remove them before checking the project into Subversion.  That caused the 7 second hang time.  If I had worked with performance counters before, I might have recognized what was going on.



    It looks like Mark Smith gets the prize for best answer. 



    Thank you everyone for your help!



    -- Scott



  • joseph_michaud's avatar
    joseph_michaud
    Moderator
    11 years ago
    I think the attempted access by hasplms to that directory is a red herring.  My similar system (Windows 7 Professional SP1 64-bit  with Intel Core i7-2640M CPU @ 2.80 GHz  with 8 GB) shows similar activity (attempted open of "C:\Program Files (x86)\Common Files\SafeNet Sentinel\Sentinel LDK\installed" every 500 milliseconds) but with no appreciable slowdown.



    I don't think what the license service (hasplms) is doing is affecting your performance (although I will later investigate why it is trying to access that directory).





    What do you mean by "10.3 standard" and "10.4 Enterprise"?  Do you mean that you installed the Web module when you installed 10.4?





    What happens if you go back to TC 10.30?
  • simon_glet's avatar
    simon_glet
    Regular Contributor
    11 years ago
    Hi Scott,



    Based on Joseph's input I would suggest looking at your antivirus application. We have had performance issues that were solved by excluding files and directories from the antivirus's realtime scanning.



    Best Regards
  • scottb's avatar
    scottb
    Contributor
    11 years ago

    The system was upgraded last week by uninstalling TC 10.30 and installing TC 10.40 with a license to add Web testing.  


     


    Today I uninstalled 10.40 and installed 10.30. The performance is the same.  


     


    The CPU usage as reported in Windows Task Manager stays between about 0 - 3% while TC is running, expect when rending forms. 


     


    I'm coming into this after someone did the upgrade last week.  I haven't used my TC system in about nine months. 


     


    The bottleneck seems to be with the Log.Message statements.  Each statement takes about three to five seconds to execute.  In the last nine months someone added a lot of Log.Message statements to our scripts, many of them inside of loops.  They probably did this to sort of "pre-debug" the scripts. 


     


    There are no logging events set up, so that is not the source of the slowness. 


     


    I changed the log folder to a different location and that did not change the behavior. 




    It could be that 10.30 exhibited the same behavior and my less technical testers did not consider it an issue.   I am going to run a test project that is known to take 5 hours to run on 10.30 to see if it still takes five hours on 10.40.  If the time stays the same I have some training issues here.  Meanwhile, three to five seconds is too long to write a message string to the log.


     

  • scottb's avatar
    scottb
    Contributor
    11 years ago
    Thanks for the feedback Simon and Mark.  I don't think outside operations are the problem here.  



    This is a test script I ran: 






    function yyy()


    {


    var y = "yyy";


    var startTime = aqDateTime.Time();


    var endTime;


    var ctWrites=10;


    for (var i=0; i < ctWrites; i++) 


    {


      Log.Message(y);


    }


    endTime = aqDateTime.Time();


    Log.Message(aqDateTime.TimeInterval(startTime, endTime));


    }






    The last log message says "12:01:09 AM".  In other words it takes one minute and nine seconds to write 10 log messages.  That's a problem.  I have a lot of Log.Message() statements.



    I have two questions. 



    1.  Is this slowness normal for TC? 



    2.  If it isn't normal how do I track down the cause of the slowness?  I don't see anything odd in the Process Monitor output, except the constant 0.2 second stalls from haspmls.exe.  Could this be a thread blocking issue?  How would I track that down?  



    I shut down everything on my SUT that looked like it might cause a problem.