Log Monitor Operations
Log Monitor captures detailed chronological activity for executable files that the captured application starts. Log Monitor intercepts and logs names, addresses, parameters, and return values for each function call by target executable files or DLLs. Log Monitor captures the following activity:
The generated log files can be large and over 100MB depending on how long the application runs with Log Monitor and how busy an application is. The only reason to run Log Monitor for an application is to capture trace files. Trace files are critical for troubleshooting problems by analyzing and correlating multiple entries within the trace file.
Troubleshoot Activity with Log Monitor
You can use Log Monitor to perform basic troubleshooting.
Generate ThinApp logs
1
2
On the computer where you captured the application, select Start > All Programs > VMware > ThinApp Log Monitor.
To start Log Monitor on a deployment machine, copy the log_monitor.exe, logging.dll, logging64.dll, Capture.ini, LogFilter.ini and Setup Capture.exe files from C:\Program Files\VMware\VMware ThinApp to the deployment machine and double-click the log_monitor.exe file.
3
As the application starts, a new entry appears in the Log Monitor’s tace file list. Log Monitor shows one entry for each new trace file. Each file corresponds with a single process.
4
5
a
Select the .trace file in the list.
b
Click Generate text trace report.
Child processes that the parent process generates reside in the same log. Multiple independent processes do not reside in the same log.
ThinApp generates a .trace file. Log Monitor converts the binary .trace file into a .txt file.
6
(Optional) Open the .txt file with a text editor and scan the information. In some circumstances, the .txt file is too large to open with the text editor.
7
Zip the .txt files and send the files to VMware support.
Perform Advanced Log Monitor Operations
Advanced operations in Log Monitor include stopping applications or deleting trace files. If an application is busy or experiencing slow performance with a specific action, you can perform suspend and resume operations to capture logs for a specific duration. The resulting log file is smaller than the typical log file and easier to analyze. Please also keep in mind even when you use the suspend and resume operations, the cause of an error might occur outside of your duration window. Suspend and resume operations are global and affect all applications.
For more information about using these options, contact VMware support.
Perform advanced Log Monitor operations
1
2
On the computer where you captured the application, select Start > All Programs > VMware > ThinApp Log Monitor.
To start Log Monitor on a deployment machine, copy the log_monitor.exe, logging.dll, logging64.dll, Capture.ini, LogFilter.ini and Setup Capture.exe files from C:\Program Files\VMware\VMware ThinApp to the deployment machine and double-click the log_monitor.exe file.
3
a
Select the Suspend check box.
b
c
In Log Monitor, deselect the Suspend check box to resume the logging process.
You can check the application behavior to isolate the issue.
d
Select the Suspend check box again to stop the logging process.
4
5
(Optional) Click Kill App to stop a running process.
6
(Optional) Click the Compress check box to decrease the size of a trace file.
This operation slows the performance of the application.
7
a
b
c
(Optional) Clear the Full report check box to get a report containing only virtualized function calls.
d
Click Generate text trace report to create a report.
You can view the file with a text editor that supports UNIX-style line breaks.
Locating Errors
ThinApp logging provides a large amount of information. The following tips might help advanced users investigate errors:
Review the Potential Errors Detected section of the .txt trace file.
Entries might not indicate errors. ThinApp lists each Win32 API call where the Windows error code changed.
Exceptions can indicate errors. Exception types include C++ and .NET. The trace file records the exception type and DLL that generates the exception. If the application, such as a .NET or Java application, creates an exception from self-generating code, the trace file indicates an unknown module.
The following example is a .trace entry for an exception.
*** Exception CXX_EXCEPTION(e06d7363) flags=1 num_args=4 caller_addr=unknown_module:0x000007F8162389CC
If you find an exception, scan the earlier part of the trace file for the source of the exception. Ignore the floating point exceptions that Virtual Basic 6 applications generate during typical use.
Log Monitor produces one .trace file for each process. If an application starts several child processes, determine which process is causing the problem. Sometimes, such as in circumstances involving out-of-process COM, a parent application uses COM to start a child process, runs a function remotely, and continues to run functions. You can use the recorded timestamp to correlate log entries across multiple processes.
ThinApp addresses the slow performance of Symantec antivirus applications by restarting processes.
Some applications call the MessageBox Win32 API function to display unexpected errors at runtime. You can search a trace file for MessageBox or the contents of the string displayed in the error and determine what the application was running just before the dialog box appeared.
The log format specifies the DLL and thread that makes a call. You can often ignore the calls from system DLLs.
Log Format
A trace file includes the following sections:
This section includes information about the operating system, drives, installed software, environment variables, process list, services, and drivers.
The information starts with a Dump started on string and ends with a Dump ended on string.
This section shows contextual information for the instance of the process that Log Monitor tracks. Some of the displayed attributes show logging options, address ranges when the operating system runtime is loaded, and macro mapping to actual system paths.
ThinApp marks the beginning of the header section with sequence number 000001. In typical circumstances, ThinApp marks the end of this section with a message about the Application Sync utility.
This section includes trace activity as the application starts and performs operations. Each line represents function calls that target executable files or one of the DLLs make.
The section typically starts with a New Modules detected in memory entry, followed by the SYSTEM_LOADED modules list. The section ends with a Modules Loaded entry.
This section includes modules that the captured application loads, potential errors, and a profile of the 150 slowest calls, and a profile of Win32 APIs.
The section starts with the Modules Loaded message.
General API Log Message Format
The following message shows a format example for API calls.
044803 00250128735714 0d40 0ccc mydll.dll:74b0f2fc->kernel32.dll:766533d3 GetProcAddress+ (HMODULE hModule=75e80000h, struct {LPCSTR lpProcName=*74C27BC8h->"ImmGetContext")
044808 00250128916396 0d40 0ccc mydll.dll:74b0f2fc<-kernel32.dll:766533d3 GetProcAddress+ -
>*=*7FE521F2h (HMODULE hModule=75e80000h, struct {LPCSTR lpProcName=*74C27BC8h->"ImmGetContext")
This example includes the following entries:
0ccc indicates the current running thread ID. If the application has one thread, this number does not change. If two or more threads record data to the log file, you might use the thread ID to follow thread-specific sequential actions because ThinApp records log entries in the order in which they occur.
mydll.dll indicates the DLL that makes the API call.
74b0f2fc indicates the return address for the API call that mydll.dll makes. In typical circumstances, the return address is the address in the code where the call originates.
-> indicates the process of entering the call. For the call entry log element, ThinApp displays the input parameters. These parameters are in and in/out parameters.
<- indicates the process of the call returning to the original caller. For call exit log entries, ThinApp displays the output parameters. These parameters are out and in/out parameters.
kernel32.dll indicates the DLL where the API call lands.
766533d3 indicates the address of the API inside kernel32 where the call lands. If you disassemble kernel32.dll at the 766533d3 address, you find the code for the GetProcAddress function.
Application Startup Information
The following entries show basic information about the application, such as the module name and process ID (PID), and about Log Monitor, such as the version and options.
000012 00180923241442 0000 1334 Logging started for ThinApp C:\Notepad++(5.0)\bin\Notepad++.exe
Using archive = C:\Notepad++(5.0)\bin\Notepad++.exe
PID = 0xc78 [3192], 32-bit process
CommandLine = "Notepad++.exe"
000016 00180923650589 0000 1334 System Current Directory = C:\Notepad++(5.0)\bin
Virtual Current Directory =
 
000018 00180923671507 0000 1334 |start_env_var| =C:=C:\Notepad++(5.0)\bin
0000019 00180923672549 0000 1334 |start_env_var| =H:=H:\
000020 00180923673142 0000 1334 |start_env_var| ALLUSERSPROFILE=C:\ProgramData
...
...
...
List of DLLs Loaded into Memory During Runtime
The Modules loaded section is located near the end of the log file and describes the DLLs that are loaded into memory at runtime and the DLL addresses. The information shows whether Windows or ThinApp loads the DLLs.
SYSTEM_LOADED indicates that Windows loads the DLL. The file must exist on the disk.
--- Modules loaded ---
NTSECTION_MAP 00400000-005c0fff, C:\Program Files\Notepad++\notepad++.exe
NTSECTION_MAP 01ea0000-01fa2fff, C:\Program Files\Notepad++\SciLexer.dll
SYSTEM_LOADED 6f600000-6f62afff, C:\Program Files\Internet Explorer\ieproxy.dll
SYSTEM_LOADED 71ae0000-71b0dfff, C:\Windows\system32\SHDOCVW.dll
 
8255572220 total cycles (2955.56 ms): |sprof| thinapp_LoadLibrary2
 
765380728 cycles (274.01 ms) on log entry 21753
428701805 cycles (153.48 ms) on log entry 191955
410404281 cycles (146.93 ms) on log entry 193969
.
.
... 438 total calls
7847975891 total cycles (2809.64 ms): |sprof| ts_load_internal_module
764794646 cycles (273.80 ms) on log entry 21753
426837866 cycles (152.81 ms) on log entry 191955
408570540 cycles (146.27 ms) on log entry 193969
.
.
... 94 total calls
4451728477 total cycles (1593.76 ms): |sprof| ts_lookup_imports
544327945 cycles (194.87 ms) on log entry 21758
385149968 cycles (137.89 ms) on log entry 193970
187246661 cycles (67.04 ms) on log entry 190210
.
.
... 34 total calls
1099873523 total cycles (393.76 ms): |sprof| new_thread_start
561664565 cycles (201.08 ms) on log entry 151922
531551734 cycles (190.30 ms) on log entry 152733
1619002 cycles (0.58 ms) on log entry 72875
Potential Errors
The Potential Errors Detected section marks log entries that might post problems with three asterisks (***). For information about interpreting this section, see Locating Errors.
----Potential Errors Detected ---
 
006425 00249708402579 00000d40 00001334 LoadLibraryExW 'C:\Program Files\Adobe\Reader
8.0\Reader\Microsoft.Windows.Common-Controls.DLL' flags=2 -> 0 (failed ***)
006427 00250258056144 00000d40 00001334 LoadLibraryExW 'C:\Program Files\Adobe\Reader
8.0\Reader\Microsoft.Windows.Common-Controls\Microsoft.Windows.Common-Controls.DLL' flags=2
-> 0 (failed ***)
006428 00250258537959 00000d40 00001334 nview.dll :1005b94b<-kernel32.dll:7c80ae4b *** LoadLibraryW
->HMODULE=7c800000h () *** GetLastError() returns 2 [0]: The system cannot find the file specified.
019127 00250294059361 00000d40 00001334 MSVCR80.dll :781348cc<-msvcrt.dll :77c10396 *** GetEnvironmentVariableA
->DWORD=0h (OUT LPSTR lpBuffer=*0h <bad ptr>) *** GetLastError() returns 203 [0]: The system
could not find the environment option that was entered.
019133 00250307158486 00000d40 00001334 MSVCR80.dll :78133003<-nview.dll :1000058c *** GetProcAddress
->FARPROC=*0h () *** GetLastError() returns 127 [203]: The specified procedure could not be found.
Troubleshooting Example for cmd.exe Utility
In the troubleshooting example, ThinApp packages the cmd.exe utility with logging turned on. The example shows how you can simulate application failure by running an invalid command. If you request the cmd.exe utility to run the foobar command, the utility generates the foobar is not recognized as an internal or external command message. You can scan the trace file and check the Potential Errors Detected section to find the API functions that modified the GetLastError code.
The example shows the C:\test\cmd_test\bin\foobar.*, C:\WINDOWS\system32\foobar.*, and C:\WINDOWS\foobar paths as the locations where the cmd.exe utility looks for the foobar command.
The log entries show the %drive_C%\test\cmd_test\bin, %SystemSystem%\foobar, and %SystemRoot%\foobar paths as the locations in the virtual file system that ThinApp probes.
----Potential Errors Detected ---
0001550 00185994582578 00000c78 00001334 *** FindFirstFileW ’C:\test\cmd_test\bin\foobar.*’ -> INVALID_HANDLE_VALUE *** failed
[system probe C:\test\cmd_test\bin\foobar.* -> ffffffffh][no virtual or system matches]
*** FindFirstFileW ->HANDLE=ffffffffh .. *** GetLastError() returns 2 [203]: The system cannot
find the file specified.
*** FindFirstFileW ’C:\test\cmd_test\bin\foobar’ -> INVALID_HANDLE_VALUE *** failed
[FS missing in view 0][fs entry not found %drive_C%\test\cmd_test\bin\foobar]
[fs entry not found %drive_C%\test\cmd_test\bin]
*** FindFirstFileW ’C:\WINDOWS\system32\foobar.*’ -> INVALID_HANDLE_VALUE *** failed
[system probe C:\WINDOWS\system32\foobar.* -> ffffffffh][no virtual or system matches]
*** FindFirstFileW ’C:\WINDOWS\system32\foobar’ -> INVALID_HANDLE_VALUE *** failed
[FS missing in view 0][fs entry not found %SystemSystem%\foobar]
*** FindFirstFileW ’C:\WINDOWS\foobar.*’ -> INVALID_HANDLE_VALUE *** failed
[system probe C:\WINDOWS\foobar.* -> ffffffffh][no virtual or system matches]
*** FindFirstFileW ’C:\WINDOWS\foobar’ -> INVALID_HANDLE_VALUE *** failed
[FS missing in view 0][fs entry not found %SystemRoot%\foobar]
Perform Advanced Examination for cmd.exe Log Entries
A more thorough examination of an entry from the Potential Errors section of a trace file might involve searching the full body of the Log Monitor trace file for that specific entry and reviewing the system calls and conditions leading to the potential error.
For example, the following entry for the cmd.exe utility in the Potential Errors section might require a more thorough examination throughout the Log Monitor trace file.
001550 00185994582578 00000c78 00001334 *** FindFirstFileW ’C:\test\cmd_test\bin\foobar.*' -> INVALID_HANDLE_VALUE *** failed
Perform an advanced examination of the cmd.exe entry
1
To determine why the cmd.exe utility probes c:\test\cmd_test\bin, scan the log for this log entry number and determine what occurs before this call.
2
To determine the locations where the cmd.exe utility obtains the c:\test\cmd_test path, scan the log for GetCurrentDirectoryW and GetFullPathNameW entries.
000861 00184029262193 00000c78 00001334 cmd.exe :4ad01580->USERENV.dll :769c0396 GetCurrentDirectoryW (IN DWORD
nBufferLength=104h)
000862 00184037503381 00000c78 00001334 GetCurrentDirectoryW -> 0x14 (C:\test\cmd_test\bin)
000863 00184355766742 00000c78 00001334 cmd.exe :4ad01580<-USERENV.dll :769c0396 GetCurrentDirectoryW ->DWORD=14h
(OUT LPWSTR lpBuffer=*4AD34400h->L"C:\test\cmd_test\bin")
000864 00184362179933 00000c78 00001334 cmd.exe :4ad05b74->ole32.dll :774e03f0 Getfile type (IN HANDLE hFile=7h)
000865 00185208991133 00000c78 00001334 Getfile type 7 -> 0x2
000866 00185212957170 00000c78 00001334 cmd.exe :4ad05b74<-ole32.dll :774e03f0 Getfile type ->DWORD=2h ()
.
.
001533 00185221099590 00000c78 00001334 cmd.exe :4ad01b0d<-kernel32.dll:7c80ac0f SetErrorMode ->UINT=0h ()
0001534 00185221215368 00000c78 00001334 cmd.exe :4ad01b13->kernel32.dll:7c80ac0f SetErrorMode (IN UINT uMode=1h)
001535 00185221343489 00000c78 00001334 cmd.exe :4ad01b13<-kernel32.dll:7c80ac0f SetErrorMode ->UINT=0h ()
001536 00185727216844 00000c78 00001334 cmd.exe :4ad01b24->IMM32.DLL :7639039b GetFullPathNameW (IN LPCWSTR
lpFileName=*1638C0h->L."," IN DWORD nBufferLength=208h)
001537 00185731151471 00000c78 00001334 GetFullPathNameW . -> 20 (buf=C:\test\cmd_test\bin,
001538 00185734164499 00000c78 00001334 cmd.exe :4ad01b24<-IMM32.DLL :7639039b GetFullPathNameW ->DWORD=14h
(OUT LPWSTR lpBuffer=*163D60h->L"C:\test\cmd_test\bin," OUT *lpFilePart=*13D8D4h
->*163D82h->L"bin")
.
.
001549 00185993599811 00000c78 00001334 cmd.exe :4ad01b5f->USERENV.dll :769c03fa FindFirstFileW (IN LPCWSTR
lpFileName=*1638C0h->L"C:\test\cmd_test\bin\foobar.*")
001550 00185994582578 00000c78 00001334 FindFirstFileW ’C:\test\cmd_test\bin\foobar.*’ ->
INVALID_HANDLE_VALUE *** failed [system probe C:\test\cmd_test\bin\foobar.*
-> ffffffffh][no virtual or system matches]
The cmd.exe utility obtains the first location by calling GetCurrentDirectoryW and the second location by calling GetFullPathNameW with "." as the path specifies. These calls return the path for the current working directory. The log file shows that the cmd.exe utility creates the C:\test\cmd_test\bin> prompt. The utility queries the PROMPT environment variable that returns $P$G and uses the WriteConsoleW API function to print the prompt to the screen after internally expanding $P$G to C:\test\cmd_test\bin>.