Monday, December 10, 2012

Loadrunner How to Download an Image

Usually images such as jpg, gif, png, etc., will be downloaded automatically as extra resources.  However, occasionally it is necessary to download images directly.  Downloading an image directly can be done easily as follows:
  • make web_url call requesting jpg, gif, png, etc.
  • Set Resource=1 indicating the the downloaded item is a resource
  • Use content type/mime type "image/jpg", "image/gif", "image/png", etc.
The following script illustrates this method as follows:
  • Image of type png is downloaded
  • Downloaded image file size is retrieved and checked that it is as expected.
  • Script writes an error message is the downloaded size is not as expected.

Script


Action()
{
long imgSize=0;

web_url("test pdf download",    
"URL=http://www.google.com/images/nav_logo114.png",
"Resource=1",
"RecContentType=image/png",
"Snapshot=t1.inf",
LAST);

    // Save pdf file size
imgSize = web_get_int_property(HTTP_INFO_DOWNLOAD_SIZE);

// Verify size is as expected (~28765 bytes 321 header bytes)
if (imgSize < 28765 ) {
lr_error_message("File download error, expected ~247,800 bytes but got %d", imgSize);
} else {
lr_output_message("File downloaded size okay, expected ~247,800 bytes and got %d", imgSize);
}

return 0;
}

Console Output


Running Vuser...
Starting iteration 1.
Starting action Action.
Action.c(6): web_url("test pdf download") was successful, 28765 body bytes, 321 header bytes   [MsgId: MMSG-26386]
Action.c(14): web_get_int_property was successful   [MsgId: MMSG-26392]
Action.c(20): File downloaded size okay, expected ~247,800 bytes and got 29086
Ending action Action.
Ending iteration 1.
Ending Vuser...

Friday, December 7, 2012

Loadrunner How to Download PDF File

A pdf file can be downloaded in loadrunner as follows:

  • make web_url call requesting pdf
  • Set Resource=1 indicating the the downloaded item is a resource
  • Use content type/mime type "application/pdf"
The following script illustrates this method as follows:
  • Pdf is downloaded
  • Downloaded pdf file size is retrieved and checked that it is as expected.
  • Pdf file contents is saved to a parameter

Script

Action()
{
long pdfSize=0;

web_reg_save_param("pdfContent", 
"LB=", 
"RB=", 
LAST );

web_url("test pdf download",    
"URL=http://research.google.com/archive/disk_failures.pdf",
"Resource=1",
"RecContentType=application/pdf",
"Snapshot=t1.inf",
LAST);

    // Save pdf file size
pdfSize = web_get_int_property(HTTP_INFO_DOWNLOAD_SIZE);

// Verify size is as expected (~247808 bytes)
if (pdfSize < 247000) {
//End the transaction
lr_error_message("File download error, expected ~247,800 bytes but got %d", pdfSize);
} else {
lr_output_message("File downloaded size okay, expected ~247,800 bytes and got %d", pdfSize);
}


lr_output_message("pdfContent=%s", lr_eval_string("{pdfContent}"));

return 0;
}

Console Output

Starting action Action.
Action.c(6): Registering web_reg_save_param was successful   [MsgId: MMSG-26390]
Action.c(11): Redirecting "http://research.google.com/archive/disk_failures.pdf" (redirection depth is 0)   [MsgId: MMSG-26694]
Action.c(11): To location "http://static.googleusercontent.com/external_content/untrusted_dlcp/research.google.com/en/us/archive/disk_failures.pdf"   [MsgId: MMSG-26693]
Action.c(11): web_url("test pdf download") was successful, 247808 body bytes, 715 header bytes   [MsgId: MMSG-26386]
Action.c(19): web_get_int_property was successful   [MsgId: MMSG-26392]
Action.c(26): File downloaded size okay, expected ~247,800 bytes and got 248523
Action.c(30): pdfContent=HTTP/1.0 302 Found
Location: http://static.googleusercontent.com/external_content/untrusted_dlcp/research.google.com/en/us/archive/disk_failures.pdf
Cache-Control: private
Content-Type: text/html; charset=UTF-8

Wednesday, November 21, 2012

Mysql Performance Monitoring - Script


The following provides a linux shell script that provides some basic mysql performance monitoring.  It reports the following metrics every N seconds based on the parameter passed in:
  • timestamp
  • queries per second
  • threads connected
  • connections
  • slow queries per second
  • rows read per second
  • rows inserted per second
  • rows updated per second
  • rows deleted per second
The results are written into a csv output file mysql-stats.csv.

Script


# mysql-stats.sh
# mysql stats sampled every $1 seconds until stopped
#

if [ "$1" == "" ] ; then
  echo "syntax= ./mysql-stats.sh <intervalSeconds>"
  exit
fi

time=$1
origqps=`mysql -u username -p password "show status" | awk '{if ($1 == "Queries") print $2}'`
origconn=`mysql -u username -p password "show status" | awk '{if ($1 == "Threads_connected") print $2}'`
origconnattempt=`mysql -u username -p password "show status" | awk '{if ($1 == "Connections") print $2}'`
origslowqry=`mysql -u username -p password "show status" | awk '{if ($1 == "Slow_queries") print $2}'`
origrowsread=`mysql -u username -p password "show status" | awk '{if ($1 == "Innodb_rows_read") print $2}'`
originserted=`mysql -u username -p password "show status" | awk '{if ($1 == "Innodb_rows_inserted") print $2}'`
origupdated=`mysql -u username -p password "show status" | awk '{if ($1 == "Innodb_rows_updated") print $2}'`
origdeleted=`mysql -u username -p password "show status" | awk '{if ($1 == "Innodb_rows_deleted") print $2}'`

echo "Stats (show status) sampled every $time seconds" > mysql-stats.csv
echo "Time , Queries , Threads_connected , Connections , Slow_queries , Innodb_rows_read , inserted , updated , deleted" >> mysql-stats.csv

x=1
while :
do

sleep $time
lastqps=`mysql -u username -p password "show status" | awk '{if ($1 == "Queries") print $2}'`
lastconn=`mysql -u username -p password "show status" | awk '{if ($1 == "Threads_connected") print $2}'`
lastconnattempt=`mysql -u username -p password "show status" | awk '{if ($1 == "Connections") print $2}'`
lastslowqry=`mysql -u username -p password "show status" | awk '{if ($1 == "Slow_queries") print $2}'`
lastrowsread=`mysql -u username -p password "show status" | awk '{if ($1 == "Innodb_rows_read") print $2}'`
lastinserted=`mysql -u username -p password "show status" | awk '{if ($1 == "Innodb_rows_inserted") print $2}'`
lastupdated=`mysql -u username -p password "show status" | awk '{if ($1 == "Innodb_rows_updated") print $2}'`
lastdeleted=`mysql -u username -p password "show status" | awk '{if ($1 == "Innodb_rows_deleted") print $2}'`

diffqps=`expr $lastqps - $origqps`
#diffconn=`expr $lastconn - $origconn`
diffconnattempt=`expr $lastconnattempt - $origconnattempt`
diffslowqry=`expr $lastslowqry - $origslowqry`
diffrowsread=`expr $lastrowsread - $origrowsread`
diffinserted=`expr $lastinserted - $originserted`
diffupdated=`expr $lastupdated - $origupdated`
diffdeleted=`expr $lastdeleted - $origdeleted`

avgqps=`expr $diffqps / $time`
#avgconn=`expr $diffconn / $time`
avgconnattempt=`expr $diffconnattempt / $time`
avgslowqry=`expr $diffslowqry / $time`
avgrowsread=`expr $diffrowsread / $time`
avginserted=`expr $diffinserted / $time`
avgupdated=`expr $diffupdated / $time`
avgdeleted=`expr $diffdeleted / $time`

#echo "$avgqps"
date=`date`
echo "$date , $avgqps , $lastconn , $avgconnattempt , $avgslowqry , $avgrowsread , $avginserted , $avgupdated , $avgdeleted" >> mysql-stats.csv

origqps=$lastqps
origconn=$lastconn
origconnattempt=$lastconnattempt
origslowqry=$lastslowqry
origrowsread=$lastrowsread
originserted=$lastinserted
origupdated=$lastupdated
origdeleted=$lastdeleted

done



Output


Stats (show status) sampled every 10 seconds
Time , Queries , Threads_connected , Connections , Slow_queries , Innodb_rows_read , inserted , updated , deleted
Tue Sep 18 14:32:37 PDT 2012 , 13 , 5 , 0 , 0 , 45 , 0 , 0 , 0
Tue Sep 18 14:32:47 PDT 2012 , 13 , 5 , 0 , 0 , 45 , 0 , 0 , 0
Tue Sep 18 14:32:57 PDT 2012 , 1374 , 5 , 0 , 0 , 258 , 352 , 0 , 153
Tue Sep 18 14:33:07 PDT 2012 , 4061 , 26 , 2 , 0 , 907 , 976 , 28 , 83
Tue Sep 18 14:33:17 PDT 2012 , 12122 , 26 , 0 , 0 , 374 , 3026 , 0 , 89
Tue Sep 18 14:33:27 PDT 2012 , 9714 , 26 , 0 , 0 , 45 , 2412 , 0 , 0
Tue Sep 18 14:33:37 PDT 2012 , 8694 , 26 , 0 , 0 , 45 , 2162 , 0 , 0
Tue Sep 18 14:33:47 PDT 2012 , 4659 , 26 , 0 , 0 , 45 , 1153 , 0 , 0
Tue Sep 18 14:33:57 PDT 2012 , 4237 , 26 , 0 , 0 , 45 , 1053 , 0 , 0
Tue Sep 18 14:34:07 PDT 2012 , 3668 , 26 , 0 , 0 , 332 , 921 , 0 , 108
Tue Sep 18 14:34:17 PDT 2012 , 3739 , 26 , 0 , 0 , 45 , 928 , 0 , 0
Tue Sep 18 14:34:27 PDT 2012 , 3636 , 26 , 0 , 0 , 45 , 902 , 0 , 0
Tue Sep 18 14:34:38 PDT 2012 , 4526 , 26 , 0 , 0 , 45 , 1125 , 0 , 0
Tue Sep 18 14:34:48 PDT 2012 , 3734 , 26 , 0 , 0 , 45 , 927 , 0 , 0
Tue Sep 18 14:34:58 PDT 2012 , 3678 , 26 , 0 , 0 , 45 , 912 , 0 , 0



Monday, November 19, 2012

Mysql Performance Monitoring - Graphical Tool

One simple method of mysql performance monitoring is using the free tool MysqlMonitorTool.  It allows you to connect to a set of mysql instances and view charts showing some basic performance information including the following:

  • connections
  • inserted rows per second
  • updated rows per second
  • deleted rows per second
  • read rows per second
  • slow queries per second
  • queries per second
The following shows the display:

The tool is fairly easy to use as follows:
  • Download and unzip from http://sourceforge.net/projects/mysqlmt/
  • Create a batch or executable script that points to the tool's jar file:  java -jar MysqlMonitorTool.jar
  • Run the batch script
  • Click server configuration, then click "add new server", then enter your server configuration (servername, host, port, username, password) for one or more mysql instances.
  • Click "add new server group" and create a server group and add the servers you created to the group.
  • Connect and the app will connect to your instances and provide the following tabs:
    • ProcessList
    • charts
    • Status Vars
    • Server Vars
    • Recording (to record chart output)

Loadrunner Check for Substring in Response

The following describes one method for checking a response for a specific substring.  The method is:

  • Use web_reg_find to search the response to the next request for the specified substring, saving the count in a parameter
  • Make the request
  • Check the count parameter for the number of occurrences of the substring

The following script illustrates the method, searching for the substrings "Google" and "Microsoft" in an http request to http://www.google.com, printing out the results.

Script


Action()
{
char *response;

// save response
        web_reg_save_param("responseParam", 
       "LB=", 
       "RB=", 
       LAST ); 

        // check response for substrings "Google" and "Microsoft"
web_reg_find("Text=Microsoft", "SaveCount=microsoft_count", LAST );
web_reg_find("Text=Google", "SaveCount=google_count", LAST );

// send request
web_url("test", 
"URL=http://www.google.com", 
"Resource=1", 
"RecContentType=text/plain", 
"Referer=http://www.google.com/", 
"Snapshot=t12.inf", 
LAST);

// Save respone to string
//response = lr_eval_string(lr_eval_string("{responseParam}"));
//lr_message("response = %s", response);

// check whether substring "Google" was found
if (strcmp(lr_eval_string("{google_count}"), "0") > 0) {
lr_output_message("Found %s occurrences of substring \"Google\" in response", lr_eval_string("{google_count}"));
} else {
lr_output_message("Did not find substring \"Google\" in response");
}

// check whether substring "Microsoft" was found
if (strcmp(lr_eval_string("{microsoft_count}"), "0") > 0) {
lr_output_message("Found %s occurrences of \"Microsoft\" in response", lr_eval_string("{search_count}"));
} else {
lr_output_message("Did not find substring \"Microsoft\" in response");
}

return 0;
}


Console Output


Starting iteration 1.
Starting action Action.
Action.c(7): Registering web_reg_save_param was successful   [MsgId: MMSG-26390]
Action.c(13): Registering web_reg_find was successful   [MsgId: MMSG-26390]
Action.c(14): Registering web_reg_find was successful   [MsgId: MMSG-26390]
Action.c(17): Registered web_reg_find successful for "Text=Microsoft"   [MsgId: MMSG-26362]
Action.c(17): Registered web_reg_find successful for "Text=Google" (count=7)   [MsgId: MMSG-26364]
Action.c(17): web_url("test") was successful, 5034 body bytes, 736 header bytes   [MsgId: MMSG-26386]
Action.c(31): Found 7 occurrences of substring "Google" in response
Action.c(40): Did not find substring "Microsoft" in response
Ending action Action.
Ending iteration 1.

Wednesday, November 7, 2012

Loadrunner Logging Options

There are a number of different functions provided by Loadrunner for logging, including:

  • lr_message
  • lr_output_message
  • lr_error_message
  • lr_log_message
  • lr_debug_message
  • lr_vuser_status_message
This post provides a script illustrating each of these logging methods, and a description of the differences.

lr_message
The limitation of lr_message is that no source file (such as Action.c) or line number is provided.

lr_output_message
lr_output_message includes source file and line number information which is useful for debugging issues.

lr_error_message
lr_error_message flags the message as an error rather than informational.

lr_log_message
lr_log_message can reduce some network traffic during load tests by not sending messages to the load test output window.

lr_debug_message
lr_debug_message can write message conditionally on certain logging settings being enabled

lr_vuser_status_message
lr_vuser_status_message updates the vuser status field during load tests


The following script illustrates the various logging methods.

Script


Action()
{
// setup test message data
int msgLevel;
char *message = "This is a test message.";
        // save string to a parameter
        lr_save_string(message, "messageParam");

// lr_message test
lr_message("---------------------- lr_message --------------------------");
lr_message("--- lr_message does not show the source file and line number");
lr_message("--- lr_message: %s", message);
lr_message("----------------- end lr_message ---------------------");

// lr_output_message test
lr_message("------------------- lr_output_message -----------------------");
lr_message("--- lr_output_message does show the source file and line number");
lr_output_message("--- lr_output_message: %s", message);
lr_message("----------------- end lr_output_message ---------------------");

        // lr_error_message test
lr_message("------------------- lr_error_message -----------------------");
lr_message("--- lr_error_message writes a message with an Error log level");
lr_error_message("--- lr_error_message: %s", message);
lr_message("----------------- end lr_error_message ---------------------");

// lr_log_message test
lr_message("------------------- lr_log_message ------------------------");
lr_message("--- lr_log_message does not send messages to the output window and could therefore reduce network traffic between agent and load generator in some situations");
lr_log_message("--- lr_log_message: %s", message);
lr_message("----------------- end lr_log_message ---------------------");

// lr_debug_message test
lr_message("------------------- lr_debug_message -----------------------");
lr_message("--- lr_debug_message writes a message if the specified log settings are set");
    msgLevel=lr_get_debug_message();
if (msgLevel & LR_MSG_CLASS_BRIEF_LOG  ) {
lr_message("standard log is enabled");
} else if (msgLevel & LR_MSG_CLASS_EXTENDED_LOG  ) {
lr_message("extended log is enabled");
} else if (msgLevel & LR_MSG_CLASS_DISABLE_LOG  ) {
lr_message("log is disabled");


// log message if brief or extended log are enabled
lr_debug_message(LR_MSG_CLASS_BRIEF_LOG | LR_MSG_CLASS_EXTENDED_LOG, "--- lr_debug_message: %s", "This is written if brief or extended log is enabled");

// disable  brief and extended log
        lr_set_debug_message(LR_MSG_CLASS_BRIEF_LOG, LR_SWITCH_OFF); 
        lr_set_debug_message(LR_MSG_CLASS_EXTENDED_LOG, LR_SWITCH_OFF);

// now the debug message should not be written
lr_debug_message(LR_MSG_CLASS_BRIEF_LOG | LR_MSG_CLASS_EXTENDED_LOG, "This should not be written to log because brief and extended log are both disabled");

// re-enable extended log
        lr_set_debug_message(LR_MSG_CLASS_EXTENDED_LOG, LR_SWITCH_ON);

lr_message("----------------- end lr_debug_message ---------------------");

// lr_vuser_status_message
// lr_log_message test
lr_message("------------------- lr_vuser_status_message ------------------------");
lr_message("--- lr_vuser_status_message updates the status field of the vuser status area.  It does not write to the log");
lr_vuser_status_message("--- lr_vuser_status_message: %s", message);
lr_message("----------------- end lr_vuser_status_message ---------------------");

return 0;
}



Output

Running Vuser...
Starting iteration 1.
Starting action Action.
---------------------- lr_message --------------------------
--- lr_message does not show the source file and line number
--- lr_message: This is a test message.
----------------- end lr_message ---------------------
------------------- lr_output_message -----------------------
--- lr_output_message does show the source file and line number
Action.c(19): --- lr_output_message: This is a test message.
----------------- end lr_output_message ---------------------
------------------- lr_error_message -----------------------
--- lr_error_message writes a message with an Error log level
Action.c(25): Error: --- lr_error_message: This is a test message.
----------------- end lr_error_message ---------------------
------------------- lr_log_message ------------------------
--- lr_log_message does not send messages to the output window and could therefore reduce network traffic between agent and load generator in some situations
--- lr_log_message: This is a test message.
----------------- end lr_log_message ---------------------
------------------- lr_debug_message -----------------------
--- lr_debug_message writes a message if the specified log settings are set
extended log is enabled
--- lr_debug_message: This is written if brief or extended log is enabled
----------------- end lr_debug_message ---------------------
------------------- lr_vuser_status_message ------------------------
--- lr_vuser_status_message updates the status field of the vuser status area.  It does not write to the log
----------------- end lr_vuser_status_message ---------------------
Ending action Action.
Ending iteration 1.
Ending Vuser...
Starting action vuser_end.
Ending action vuser_end.
Vuser Terminated.

Thursday, November 1, 2012

Loadrunner Asynchronous Results Polling Using 11.5 Web Async


Some user action trigger asynchronous server-side operations.  The user can then be forced to check for results periodically by polling the server.  Loadrunner 11.5 provides asynchronous logic allowing callback functions to be specified which are called when the async call finally returns.  The following example gives one example of using the asynchronous callbacks as follows:

  • Include web_api.h to load some needed symbols
  • To capture the time it takes for the async response to come back, specify a global variable showing done state
  • Before the async call, set async polling properties using web_reg_async_attributes such as how often to poll, which callback functions to use, etc.
  • Define the callback functions to be called when the async response is returned and update the done state variable in the callback
  • Make the async call
  • To get the response time, wait until the callback has updated the global state variable
  • End the transaction
  • Stop the async polling

The following shows an example of a script doing this, and the next section shows the script's vugen console output.

Script

// Specify include files
#ifndef _GLOBALS_H
#define _GLOBALS_H

#include "web_api.h"
#endif // _GLOBALS_H
// End include files

// Define a global variable holding done state
int done;

Action()
{
    web_url("wiki",
        "URL=http://ajaxify.com/run/wiki",
        "Resource=0",
        "RecContentType=text/html",
        "Referer=",
        "Snapshot=t37.inf",
        "Mode=HTML",
        LAST);

    // Initialize the global done state variable, and start the async transaction variable
    done = 0;
    lr_start_transaction("async-call");

   // Define the request to be handled asynchronously, in this case a "?messages" call
   // Specify the polling interval of 5 seconds
   // Specify the callback functions that will be called when the response is returned.
   // The callback functions are defined below.     web_reg_async_attributes("ID=Poll_0",
        "URL=http://ajaxify.com/run/wiki/content.php?messages",
        "Pattern=Poll",
        "PollIntervalMs=5000",
        "RequestCB=Poll_0_RequestCB",
        "ResponseBodyBufferCB=Poll_0_ResponseBodyBufferCB",
        "ResponseCB=Poll_0_ResponseCB",
        LAST);

    // now make the async call.
    // note that the script will not block on this call.  processing will continue on past this step while the request is handles asynchronously
    web_url("content.php",
        "URL=http://ajaxify.com/run/wiki/content.php?messages",
        "Resource=0",
        "RecContentType=text/xml",
        "Referer=http://{host_ajaxify_com}/run/wiki/",
        "Snapshot=t38.inf",
        "Mode=HTML",
        LAST);


    // To capture the response time of the async call, wait until the callback is called.
    // Without this, the script would move past and complete the iteration before the callback is called.     while (done==0)
    {
        lr_think_time(1);
    }

    // once the callback has been called, end the transaction to get the response time.
     lr_end_transaction("async-call"LR_AUTO);
     
   // stop the polling
   web_stop_async("ID=Poll_0",
        LAST);

    return 0;
}



/*
*    Callback Implementation
*
*
*/

int Poll_0_RequestCB()
{
    //enter your implementation for RequestCB() here

    return WEB_ASYNC_CB_RC_OK;
}

int Poll_0_ResponseBodyBufferCB(
    const char *    aLastBufferStr,
    int                aLastBufferLen,
    const char *    aAccumulatedStr,
    int                aHttpStatusCode)
{
    //enter your implementation for ResponseBodyBufferCB() here

    // when the response is received, update the global variable
    done = 1;
    // print out the response body and length
    lr_message("in Poll_0_ResponseBodyBufferCB response body callback");
    lr_message("in Poll_0_ResponseBodyBufferCB response body callback, lastBufferLen=%d", aLastBufferLen);
 
    return WEB_ASYNC_CB_RC_OK;
}

int Poll_0_ResponseCB(
    const char *    aResponseHeadersStr,
    int                aResponseHeadersLen,
    const char *    aResponseBodyStr,
    int                aResponseBodyLen,
    int                aHttpStatusCode)
{
    //enter your implementation for ResponseCB() here
 
    lr_message("in Poll_0_ResponseCB response callback, headerLen=%d, bodyLen=%d", aResponseHeadersLen, aResponseBodyLen);
    lr_message("in Poll_0_ResponseCB response callback, header=%s", aResponseHeadersStr);
    lr_message("in Poll_0_ResponseCB response callback, body=%s", aResponseBodyStr);
 
    return WEB_ASYNC_CB_RC_OK;
}


Console Output

Running Vuser...
Starting iteration 1.
Notify: max connections per server : 6
Starting action Action.
Action.c(16): web_url("wiki") started      [MsgId: MMSG-26355]
Action.c(16): Redirecting "http://ajaxify.com/run/wiki" (redirection depth is 0)       [MsgId: MMSG-26694]
Action.c(16): To location "http://ajaxify.com/run/wiki/"  [MsgId: MMSG-26693]
Action.c(16): Found resource "http://ajaxify.com/run/Lib/css/demo.css" in HTML "http://ajaxify.com/run/wiki/"       [MsgId: MMSG-26659]
Action.c(16): Found resource "http://ajaxify.com/run/wiki/wiki.css" in HTML "http://ajaxify.com/run/wiki/"       [MsgId: MMSG-26659]
Action.c(16): Found resource "http://ajaxify.com/run/Lib/js/util.js" in HTML "http://ajaxify.com/run/wiki/"       [MsgId: MMSG-26659]
Action.c(16): Found resource "http://ajaxify.com/run/Lib/js/ajaxCaller.js" in HTML "http://ajaxify.com/run/wiki/"       [MsgId: MMSG-26659]
Action.c(16): Found resource "http://ajaxify.com/run/wiki/wiki.js" in HTML "http://ajaxify.com/run/wiki/"       [MsgId: MMSG-26659]
Action.c(16): Found resource "http://ajaxify.com/favicon.ico" in HTML "http://ajaxify.com/run/wiki/"       [MsgId: MMSG-26659]
Action.c(16): Found resource "http://ajaxify.com/run/Lib/php/button.php" in HTML "http://ajaxify.com/run/wiki/"       [MsgId: MMSG-26659]
Action.c(16): web_url("wiki") was successful, 22491 body bytes, 2152 header bytes, 24 chunking overhead bytes      [MsgId: MMSG-26385]
Action.c(26): Notify: Transaction "polling" started.
Action.c(41): web_reg_async_attributes started       [MsgId: MMSG-26355]
Action.c(41): web_reg_async_attributes was successful      [MsgId: MMSG-26392]
Action.c(50): web_url("content.php") started    [MsgId: MMSG-26355]
Action.c(50): "ID=poll_0" && "Pattern=Poll" && "PollIntervalMs=5000" now applied to URL="http://ajaxify.com/run/wiki/content.php?messages" (RelFrameId=1, Internal ID=10)     [MsgId: MMSG-35172]
Action.c(50): Retaining cross-step download of URL="http://ajaxify.com/run/wiki/content.php?messages" (RelFrameId=1, Internal ID=10)     [MsgId: MMSG-27658]
Action.c(50): web_url("content.php") was successful, 0 body bytes, 0 header bytes       [MsgId: MMSG-26386]
Action.c(62): lr_think_time: 1.00 seconds.
in Poll_0_ResponseBodyBufferCB response body callback
in Poll_0_ResponseBodyBufferCB response body callback, lastBufferLen=928
in Poll_0_ResponseBodyBufferCB response body callback
in Poll_0_ResponseBodyBufferCB response body callback, lastBufferLen=0
in Poll_0_ResponseCB response callback, headerLen=319, bodyLen=928
in Poll_0_ResponseCB response callback, header=HTTP/1.1 200 OK
Server: nginx/0.8.53
Date: Thu, 01 Nov 2012 21:18:42 GMT
Content-Type: text/xml
Transfer-Encoding: chunked
Connection: keep-alive
X-Powered-By: PHP/5.3.5-1ubuntu7.11
Expires: 0
Last-Modified: Thu, 01 Nov 2012 21:18:42 GMT
cache-control: no-store, no-cache, must-revalidate
Pragma: no-cache


in Poll_0_ResponseCB response callback, body=<messages>  <message>
      <id>10</id>
      <lastAuthor>lastAuthor</lastAuthor>
      <ranking>100</ranking>
      <content>Wonder%20Wonder%20ffff%0AStuff%20here%20for%20123fdsfd%0Atest%0Avbnvytytry%0Aokadfasdf%0Artyry%0Artyryry%0Arytry%0Adfgvdfg%0A%0Asdfsad%0A%0Asdfsd%0A%0Aghghhgggh%0A%0Atesteste%0A%0AZe%20woiauha%0A%20df%0A%0Axcvx%0AHello%20friends%21%0Ahello%20folks%0Ahi%0Ajiadsasd%0A%0A%0Azzz</content>
  </message>  <message>
      <id>2</id>
      <lastAuthor>lastAuthor</lastAuthor>
      <ranking>200</ranking>
      <content>ABC%0Aklljljl%0Ak%3Bk%3B%3Bk%3B%0Aggugj%0A%0Affff%0A%0Aasdf%0A%0Abla%0Aqwe%0Aqweqwe%0Ajnknknkjkvfgh%0A</content>
  </message>  <message>
      <id>3</id>
      <lastAuthor>lastAuthor</lastAuthor>
      <ranking>300</ranking>
      <content>This%20is%20line%201%0AThis%20is%20line%202.%0AEnd%0A.%0Adffdfg123123123%0Aawgaw%0Afsdf%0Atestes%0Aasdfadf%0Aadsasd</content>
  </message></messages>
Action.c(62): Issuing a "POLL" request for conversation with ID="poll_0" and "PollIntervalMs=5000". Scheduling due at t=13494, URL="http://ajaxify.com/run/wiki/content.php?messages"     [MsgId: MMSG-35169]
Action.c(62): "ID=poll_0" && "Pattern=Poll" && "PollIntervalMs=5000" now applied to URL="http://ajaxify.com/run/wiki/content.php?messages" (RelFrameId=, Internal ID=11)     [MsgId: MMSG-35172]
Action.c(67): Notify: Transaction "polling" ended with "Pass" status (Duration: 4.0431 Think Time: 1.8491 Wasted Time: 0.0121).
Action.c(69): web_stop_async started       [MsgId: MMSG-26355]
Action.c(69): Notify: Deleting Conversation Information with ID="poll_0"
Action.c(69): Aborting download of URL "http://ajaxify.com/run/wiki/content.php?messages" (RelFrameId=, Internal ID=11) of conversation with ID="poll_0"  [MsgId: MMSG-35167]
in Poll_0_ResponseBodyBufferCB response body callback
in Poll_0_ResponseBodyBufferCB response body callback, lastBufferLen=0
in Poll_0_ResponseCB response callback, headerLen=0, bodyLen=0
in Poll_0_ResponseCB response callback, header=
in Poll_0_ResponseCB response callback, body=
Action.c(69): web_stop_async was successful     [MsgId: MMSG-26392]
Ending action Action.
Ending iteration 1.
Ending Vuser...
Starting action vuser_end.
Ending action vuser_end.
Vuser Terminated.

Tuesday, October 23, 2012

Loadrunner Asynchronous Results Polling

Some user action trigger asynchronous server-side operations.  The user can then be forced to check for results periodically by polling the server.   The following script gives an example of how to do this as follows:

  • Define variables to specify polling interval and polling timeout.
  • Each polling interval, make the call to the server and check the results.
  • If the server has returned the finished results, end the polling loop and pass the transaction.
  • Otherwise, wait for the next polling interval and repeat.
  • If the timeout is hit, end the polling loop and fail the transaction.

Script

Action()
{
int done = 0;  
int pollIntervalSec = 1;
int timeoutSec = 3;
int secWaited = 0;
char *response, *expectedResponse; 

expectedResponse = "abc";

        lr_start_transaction("wait_for_data");

        // poll the site until expected response is received or timeout is reached
while (done==0)
{
            // capture response information
    web_reg_save_param("responseParam", 
"LB=Control: ", 
"RB=max", 
LAST ); 

            // hit the page to be polled
    web_url("Test", 
"URL=http://www.google.com", 
"Resource=0", 
"RecContentType=text/html", 
"Snapshot=t1.inf",
LAST);

    // Save respone to string
   response = lr_eval_string(lr_eval_string("{responseParam}"));

   // check string contents to see if done
   if(strcmp(response,expectedResponse)==0)
{
     done=1; // set flag to indicate success
 lr_message("Found expected response=%s", response);
     lr_end_transaction("wait_for_data", LR_PASS);
   }

    // increment time waited
   secWaited = secWaited + pollIntervalSec;

    // check for timeout
   if (secWaited > timeoutSec)
   {
    done = 1;
    lr_end_transaction("wait_for_data", LR_FAIL);
    lr_error_message("Wait for data timed out, took longer than %d seconds", timeoutSec);
   }
   lr_think_time(pollIntervalSec);


return 0;
}


Console Output


Starting action Action.
Action.c(11): Notify: Transaction "wait_for_data" started.
Action.c(15): Registering web_reg_save_param was successful   [MsgId: MMSG-26390]
Action.c(20): Found resource "http://www.google.com/intl/en_ALL/images/srpr/logo1w.png" in HTML "http://www.google.com"   [MsgId: MMSG-26659]
Action.c(20): Warning -26376: Requested parameter "responseParam" found in 2 different pages/frames. Use web_reg_save_param with more restrictive LB/RB/RelFrameId   [MsgId: MWAR-26376]
Action.c(20): Warning -26373: Parameter "responseParam" saved from a resource (URL="http://www.google.com/intl/en_ALL/images/srpr/logo1w.png")   [MsgId: MWAR-26373]
Action.c(20): web_url("Test") highest severity level was "warning", 12282 body bytes, 1071 header bytes   [MsgId: MMSG-26388]
Action.c(48): lr_think_time: 1.00 seconds.
Action.c(15): Registering web_reg_save_param was successful   [MsgId: MMSG-26390]
Action.c(20): Resource "http://www.google.com/intl/en_ALL/images/srpr/logo1w.png" is in the cache already and will not be downloaded again   [MsgId: MMSG-26655]
Action.c(20): web_url("Test") was successful, 4952 body bytes, 400 header bytes   [MsgId: MMSG-26386]
Action.c(48): lr_think_time: 1.00 seconds.
Action.c(15): Registering web_reg_save_param was successful   [MsgId: MMSG-26390]
Action.c(20): Resource "http://www.google.com/intl/en_ALL/images/srpr/logo1w.png" is in the cache already and will not be downloaded again   [MsgId: MMSG-26655]
Action.c(20): web_url("Test") was successful, 4952 body bytes, 224 header bytes   [MsgId: MMSG-26386]
Action.c(48): lr_think_time: 1.00 seconds.
Action.c(15): Registering web_reg_save_param was successful   [MsgId: MMSG-26390]
Action.c(20): Resource "http://www.google.com/intl/en_ALL/images/srpr/logo1w.png" is in the cache already and will not be downloaded again   [MsgId: MMSG-26655]
Action.c(20): web_url("Test") was successful, 4952 body bytes, 224 header bytes   [MsgId: MMSG-26386]
Action.c(45): Notify: Transaction "wait_for_data" ended with "Fail" status (Duration: 4.1903 Think Time: 3.0017 Wasted Time: 0.6545).
Action.c(46): Error: Wait for data timed out, took longer than 3 seconds
Action.c(48): lr_think_time: 1.00 seconds.
Ending action Action.