Viewing VU Event Logs
Reading the Log
You open a VU event log in Test Controller's main window just like you would any table or chart. To open the event log viewer for a specific VU, navigate to the VU in the Current test runs section of the left sidebar, then double-click the VU (or right-click the VU and select Open).
The virtual user event log viewer in Eggplant Performance Test Controller
Following is an explanation of how to read logs in the event log viewer, by column:
Time: The elapsed time since the test run started. Every entry written to the event log is labeled with a timestamp that specifies when the engine encountered the event, so you can tell how far into the test run the event occurred. This is written to the nearest millisecond in the format HH:MM:SS:MSS.
Type: Events are grouped according to their log type. Following is a list of common groups. See Common Groups and Events below for more information about each of them.
- Test initialization & progression
- Transactions
- Timings
- VU status & information
- Check / progress point
ID: Information specific to the event type.
Info: Detailed information about the event.
Thread ID: Indicates whether events were written by the main script or a background script.
Log Filtering Options
The event log viewer lets you filter the information you see in the log. It provides several filter options for you to choose from: Default, All (shows all entries in the log), or Custom. When you select, Custom you can select or deselect to filter Transactions, Timings, Requests, Errors, Warnings, Messages, Metrics, and Progress Points.
Common Log Groups and Events
Following is a list of common log type groups and their events.
Log Type Group | Description | ID | Info |
---|---|---|---|
Test Initialization and Progression Log Group | Start: The time of test run initialization. This event is written in all logs. A VU will be in a Pending state until the Start activity event. The Pending state between Start and Start activity is usually because of VU "ramp up" or group start delay. | Empty | Empty |
Start Activity: When the VU progresses from a Pending to a Running state on commencement of script code execution. | Empty | Empty | |
Current Script: Shows the time of script execution where the name of the executed script appears in the ID column. If the script was executed in the repeated section of a workflow the iteration index will be shown in the Info column. If in the initial or final section no index will be given, the iteration count will start at 0. | <script_name> | Iteration index (if possible) | |
End activity: When the VU progresses from a Running to a Completed state. | Empty | Empty | |
End: Test run completion. If the VU completed naturally then Completed will appear in the Info column. If the VU exited the run In Error, which is usually the result of an exception being raised and not handled in the script code, then Error will appear in the Info column of the VU event log. Programmed Exit will be written to the Info column if a VU is made to exit programmatically using exitVU (C++, Java, ExitVU for C#). | Empty | Completed, Error, or Programmed Exit | |
Transactions | Start transaction: Written to the event log when a startTransaction (C++, Java, StartTransaction for C#) call is made in the VU script. A startTransactioncall can be passed one or two string parameters. The first is the <Transaction_Name> (or id) and it appears in the ID field. The second is a tag, which will appear in the Info column of the event log. The tag field does not have to be matched in the corresponding endTransaction. | <transaction_name> | tag (if applicable) |
Suspend transaction: suspendTransaction (C++, Java, SuspendTransaction for C#) can be used to suspend the current transaction timing. This often provides a way of excluding any lengthy script routines from transaction timings. | <transaction_name> | Empty | |
Fail transaction: Used to exclude a transaction from analysis or increase the failed transaction count for the group. A transaction can be failed by explicitly calling failTransaction in the script (C++, Java, FailTransaction for C#) or by setting the second (Boolean) parameter of endTransaction to false. This is particularly useful when there is a necessity to work with nested/overlapping transactions for applications that use asynchronous messaging. | <transaction_name> | tag (if applicable) | |
Resume transaction: resumeTransaction (C++, Java, ResumeTransaction for C#) is used to restart a transaction timing after suspension (using suspendTransaction). | <transaction_name> | Empty | |
End transaction: The transaction end time written to the VU event log using endTransaction (C++, Java, EndTransaction for C#). If the second parameter passed to endTransaction is false this will be logged as a Fail transaction event and not an End transaction. | <transaction_name> | tag (if applicable) | |
Timings | Start timing: Timing events can be logged explicitly or by enabling HTTP request timings in the runtime settings (Web VU groups only). Timings are started from the script using startTiming (C++, Java, StartTiming for C#). | <Timing_Name> | Empty |
Fail timing: Used to exclude a timing from analysis by flagging it as a failure. This is done by explicitly calling failTiming in the script (C++, Java, FailTiming for C#). | <Timing_Name> | Empty | |
End timing: Stop a timing using endTiming (C++, Java, EndTiming for C#). | <Timing_Name> | Empty | |
VU status & Information |
Error: An Error event will be logged in the following circumstances: 1) When an error call is executed in the script (C++, Java, Error for C#). 2) When an error action type (i.e. ACT_ERROR) is specified on various verify methods in the WebBrowserUserScript class. Raising errors as described will not cause the VU to exit the run. 3) Raising an exception which is not handled by script code. The VU will exit the test run In Error. An error will appear in the Details column of the End event type. |
Error |
Error message. Example: beforeString: <div id="ctl00_LMenu1_, afterString: "> (extract fails) |
Warning: A warning will be logged when calling warn from the script (C++, Java, Warn for C#). Web VUs receiving "404 Not Found" status codes (shown in Info example here) or no server responses will also log warnings. Specifying a warning action type (i.e. ACT_WARNING) on verify methods being another example. | Warning |
Warning message. Example: /images/nav_logo.png HTTP_NOTFOUND http://www.example.com/images/nav_logo.png |
|
Message: Used for information messages. To write a message to the event log use writeMessage (C++, Java, WriteMessage for C#). Information messages can also be relayed by the Test Controller and engine as well by various API calls such as exitVU (C++, Java, ExitVU for C#, as shown in example). | Message |
Event Log message. Example: ExitVU called. |
|
Check/Progress point | Pass: Logged when the VU passes a check/progress point. Called in the script using setProgressPoint("message", true) for C++ and Java or SetProgressPoint("message", true) for C#. | Pass | Progress Point |
Fail: Logged when the VU fails a check/progress point. A false Boolean is passed to setProgressPoint (C++ and Java) or SetProgressPoint in C# to fail a checkpoint. | Fail | Progress Point |