Saturday, February 8, 2014

Selectively log http transactions


    Just as in software development, development of a performance test script may require debugging or trouble-shooting.  One of the common debugging techniques in software development is "printf".  For performance testing,  it's the logging of messages.  We don't want to log all messages in a test, it will impact the performance of the platform and make it harder to do debugging.

    Recently I saw a question by ShurupuS  about only logging request data when there is an error and it makes me realize that it may not be easy to log only relevant messages on many test platforms.    In this blog, we will show how easy it is to do so on NetGend platform.

   Our flexibility comes from the design that all the per-instance/per-VUser variables are easily accessible and also from the function "writeFile".  This function took two parameters, the first parameter is the name of a file, the second parameter is the data to be logged.   Here is a quick example on logging the HTTP requests that caused server to give response codes equal to 500 or other response codes that are not 200.

 function VUSER() {  
      id = randNumber(1,100000);
      action(http, "http://www.example.com/viewproducts/${id}");  
      if (http.respCode == 500) {
           writeFile("criticalerror.log", http.request); 
      } else if (http.respCode != 200) {  
           writeFile("error.log", http.request);  
      }  
 }  
     Of course,  the HTTP request can be much more dynamic and complex,  logging only the requests that cause error can save a lot of debugging time.  
     What if you want to check whether a response contains certain pattern (a string), you can do it using match function.  In the following example, we check if the server reply contains the string "success".
 function VUSER() {  
      //create a POST message
      action(http, "http://www.example.com/add2cart");  
      if (!match(http.replyBody, /success/) ) {  
           writeFile("error.log", http.replyBody);  
      }  
 }  
     This function helped me a lot when I was testing an e-commerce site, guess what was the reason for the failure?  this product was sold out :-)  You may be laughing at me,  I was scratching my head before I found the cause.

    What if you need to log multiple piece of data in a file?  like HTTP request, reply body or the reply header.   writeFile() function has a hidden third parameter called "append", when it's present, this function will append the data to the file rather than overwriting the existing file.
 writeFile("tmp.html", http.replyBody);  
 writeFile("tmp.html", http.request, "append);  
 writeFile("tmp.html", http.replyHeader, "append");  

    Since this happens so often, we created a new function logHtml() that will log the reply, request and reply header.
 logHtml("1.html");  
On the UI, you can quickly view the logs in a browser and/or plain text edior.

    You may wonder if it works for HTTPS?   Absolutely!  Everything remains the same except for the action statement uses https instead of http.
 //...  
 action(http, "https://www.example.com/viewproducts");  
 if (http.respCode == 500) {  
    logHtml("tmp.html");  
 }  
   This makes it handy to trouble-shoot HTTPS transactions which typically can't be done with network sniffers!

   In my experience, being able to get relevant logs can cut the time spent on debugging scripts by half.  Hope your favorite test platform also supports the flexible logging as on the NetGend platform.
 

No comments:

Post a Comment