Example: lr_wasted_time and lr_get_transaction_wasted_time

The following segment demonstrates the use of timers to collect wasted time, and the use of lr_wasted_time to remove that wasted time from the transactions. The output log segments below show that the effects are not reported in the Vuser log, but are reported in the Analysis session.

The segment also shows the use of lr_get_transaction_wasted_time.

WasteTime() {
    int i, baseIter = 1000;
    char dude[1000];
    double wasteTime, actualElapsedTime; 
    merc_timer_handle_t MasterT, timer;

    // Examine the total elapsed time of the action
    MasterT = lr_start_timer();

    //Start transaction
    lr_start_transaction("Demo");

    // Create some elapsed time for the transaction
    for (i=0; i< (10 * baseIter); ++i)
            sprintf(dude, "This is the way we create elapsed time artificially = %d", i);            

    // Add some think time
    lr_think_time(0.5);
    // Create some wasted time and record it with timer
    timer = lr_start_timer();

    for (i=0; i< (5 * baseIter); ++i)
            sprintf(dude, "This is the way we waste time in a script = %d", i);

    wasteTime = lr_end_timer(timer);
    lr_output_message("User created waste time = %lf", wasteTime);
    lr_output_message("Before lr_waste_time: Duration = %lf - Waste = %lf",        
        lr_get_transaction_duration("Demo"),
        lr_get_transaction_wasted_time("Demo"));
    /* Convert Timer in seconds to wasted time in milliseconds and add to internally generated waste time */
    wasteTime *= 1000;
    lr_wasted_time(wasteTime);
    lr_output_message("After lr_waste_time: Duration = %lf - Waste = %lf",
            lr_get_transaction_duration("Demo"),
            lr_get_transaction_wasted_time("Demo"));

    lr_output_message("Think time = %lf", 
        lr_get_transaction_think_time("Demo"));

    lr_end_transaction("Demo", LR_AUTO);
    actualElapsedTime = lr_end_timer(MasterT);
    lr_output_message("Total Elapsed time for Action = %lf", actualElapsedTime);
    return 0;
}
Output:
There is no difference between the transaction duration before and after the call to lr_waste_time
WasteTime.c(28): User created waste time = 0.031250    
WasteTime.c(32): Before lr_waste_time: Duration = 0.609375 - Waste = 0.000000    
WasteTime.c(40): After lr_waste_time: Duration = 0.625000 - Waste = 0.031000    
WasteTime.c(44): Think time = 0.500000    
WasteTime.c(47): Notify: Transaction Demo ended with Pass status (Duration: 0.6406 Think Time: 0.5000 Wasted Time: 0.0310).    
WasteTime.c(50): Total Elapsed time for Action = 0.640625    

Analysis: Average Response Time Raw Data

The Transaction Response Time for "Demo" is 0.61. This is the Duration from the Vuser log (0.6406) minus the Wasted Time ( 0.0310).



Transaction End Status
Transaction Father Tree path
Scenario Elapsed Time
Transaction Response Time
Transaction Name
Pass
NONE
4.843
0
vuser_init_Transaction
Pass
WasteTime_Transaction
5.514
0.61
Demo
Pass
NONE
5.53
0.625
WasteTime_Transaction
Pass
NONE
5.53
0
vuser_end_Transaction