Open source version of Intellisoft's PGNProfiler
Need an efficient tool to collect trace/profiling info from Intellisoft OLE DB Provider for PostgreSQL. The tool should be able to read very long traces from Windows applications and Services (32- and 64-bit), change logging levels, filter for errors, store traces to files, and display previously stored files. It has advanced features like injecting itself into another computer (where PGNProfiler is not installed or there is no local access) and collecting a remote trace. It supports light and dark themes. Etc.
Boost 1.70 with chrono, date_time, interprocess, regex installed into C:\Program Files (x86). Boost should be compiled for static linking.
The project compiles with Visual Studio 2022 Community Edition. Open/add file src/PGNProfiler.vcxproj.
I solely created the PGNProfiler in 2009. I got inspiration from another similar tool that I contributed a few years before. That other tool was written in Delphi 6/7 (Pascal). It provided me with good idea what is expected from a log viewer/tracer.
There are four main panels in the profiler window:
Filter panel allows user to enter text criteria for filtering out the SQL trace.
Applications/Logs panel contains tree-list of computer hosts, applications, and log files. The tree items have indicators such as trace collection in progress, closed process, and 32- or 64-bit.
Messages panel display columns with statement time, SQL text, profiler counters, etc. Columns contain following information:
AbsTime (or RelTime) is first column that displays either absolute or relative time. User can click "Time format" button on the toolbar to toggle between AbsTime and RelTime;
SQLType – displays SQL type, i.e.:
USER statements sent by the user application to PGNP provider
SYSTEM provider generated statements
NOTIFY schema change notifications sent to or received from Postgres
ERROR error condition in the provider
xxx_SCHEMA statement generated by the provider to support corresponding OLEDB schema
ClientSQL – displays either SQL from user application or generated by the provider;
Parse, Prepare, Execute, GetRows – time in milliseconds spent by provider to parse, prepare, execute statement and to read rows from database server;
Rows – number of rows read or affected during execution of the SQL;
Database, User – database and user name for the connection;
PID – process ID of the application that issued the message;
SessId – logical OLEDB session ID, it can be used to distinguish between connections made from the same application;
CmdId – logical OLEDB command ID, reserved for future, can be used to distinguish different commands in the same session;
CursorMode – displays Forward Only for ADO client cursor or Can scroll backwards – for ADO server cursor;
Application – application name and PID, i.e. origin of the message;
CmdType – statement type, e.g. SELECT, UPDATE, INSERT, DELETE, CREATE xxx, ALTER, SET, SHOW, DROP xxx, PROCEDURE, INTERNALPROC, START, COMMIT, ROLLBACK, NOTIFY, COPY, etc.
Details panel on the bottom displays detailed SQL text for the messages selected in Messages panel. For a selected message it can display one of or both Client SQL and Executed SQL. Client SQL displays the statement text sent by a user application. Executed SQL displays statement sent by PGNP provider to database. Client SQL and Executed SQL can be different. Latter displays parameter values, e.g.:
---------- Client SQL ------------
UPDATE tbl SET article=? WHERE id=?
---------- Executed SQL ---------
update tbl set article=[DBTYPE_WSTR,*Nexus12*] where id=[DBTYPE_I4,2000]
| Action | How-to |
|---|---|
| Start capture | Select localhost, host or an application in Application/Logs panel and click Capture button in the toolbar. |
| Stop/pause capture | Select localhost, host or an application in Application/Logs panel and click Pause button in the toolbar. |
| Remove application from the list | An application can be removed from the list only if it terminated, i.e. has "red" indicator icon. Click Clear button in the toolbar. |
| Start or stop filtering | Press "filter" button in the toolbar. |
| Toggle between absolute and relative time | Click "clock" button in the tolbar. |
The PGNProfiler supports receiving event traces from remote computers (not only from localhost). In order to connect to a remote system, right-click mouse in the Applications panel:
In the Connection Settings dialog enter a remote computer name or an IP address, and (optionally) user name and password. Then click Test Connection button. If connection test succeeds, the message will also display the number of applications available for profiling:
The Host name(s) combo-box keeps history of connections, and can be used to quickly choose one of the previous connections. Click OK button to open connection to the remote host. Then click Capture button in the toolbar on top in order to start collecting trace. The PGNP Profiler can look like the following:
The list of applications on remote hosts will refresh automatically every 10 seconds, similarly to the list on the local host. The closed applications will be marked with the “red bar” sign, and the new applications will be appended to the list. The list can be refreshed manually by right-clicking mouse on the remote host item, and selecting Refresh menu item, or by pressing F5.
Note: The PGNProfiler copies itself to and runs on remote host as Windows service in order to obtain list of applications available. When the Profiler closes, it performs cleanup. However, if physical connection broke, or some other irregular termination occurred, manual cleanup might be needed on the remote host computer. Use the following VB script for the cleanup:
' The script stops and deletes "PGNProfiler" services
Set objWMIService = GetObject("winmgmts:" & "{impersonationLevel=impersonate}!\\.\root\cimv2")
Set colListOfServices = objWMIService.ExecQuery ("Select * from Win32_Service ")
Set shell = CreateObject("WScript.Shell")
Set fso = WScript.CreateObject("Scripting.FileSystemObject")
For Each objService in colListOfServices
If Left(objService.name,11) = "PGNProfiler" then
If vbYes = Msgbox("Delete " & objService.name & "?", vbYesNo, "Delete Service") Then
shell.Run "sc stop " & objService.name, 0, True
shell.Exec "sc delete " & objService.name
filename = shell.ExpandEnvironmentStrings("%WinDir%") & "\" & objService.name & ".exe"
fso.DeleteFile(filename), DeleteReadOnly
End if
End if
Next
Set shell = Nothing
Set fso = Nothing
wscript.echo "Done!"
Filter pane accepts numeric, string and Boolean expressions on variables of a message. The variables names are the same as column names in “Messages panel”, i.e. clientsql, execute, etc. (see the columns list and descriptions above). There are several preconfigured filters available by right mouse click in the Filter panel:
“ClientSQL Like…” – display SQL messages according to the regular expression, e.g. clientsql ilike ‘select(.)+’
“Show Errors” – display error messages only, i.e. SQLType = ERROR
“Hide System” – hide any “system”, i.e. the provider generated messages, i.e. SQLType <> SYSTEM
“ExecuteTime > 1ms” – display statements with execution time over 1 millisecond, i.e. execute > 1.0
“Schema Alterations” – display only schema alteration messages such as DROP TABLE tbl, i.e. (ClientSQL ilike 'Alter(.)+' || ClientSQL ilike 'Create(.)+' || ClientSQL ilike 'Drop(.)+') && SQLType != ERROR
“Stored Procedures and Notifications” – display only stored procedures calls and notifications sent and received, i.e CMDType == PROCEDURE || CMDType == INTERNALPROC || CMDType == NOTIFY Following operators can be used in the expressions:
| Operator | Description |
|---|---|
| + | Add variables or numeric constants |
| - | Subtract variables or numeric constants, or negate a value |
| * | Multiply variables or numeric constants |
| / | Divide variables or numeric constants |
| > | Greater than |
| >= | Greater than or equal to |
| < | Less than |
| <= | Less than or equal to |
| != | Not equal |
| <> | Not equal |
| = | Equal |
| == | Equal |
| ! | Logical NOT |
| (…) | Sub-expressions grouping |
| && | Logical AND |
| || | Logical OR |
| like | Case sensitive regular expression LIKE |
| ilike | Case insensitive regular expression LIKE |
| not like | Case sensitive regular expression NOT LIKE |
| not ilike | Case insensitive regular expression NOT LIKE |
Like/ILike operators are based on boost regular expressions evaluation engine. For more details read article: http://www.boost.org/doc/libs/1_40_0/libs/regex/doc/html/boost_regex/syntax/perl_syntax.html (“Perl Regular Expression Syntax”). Following constants can be used in expressions when comparing a variable to a constant:
| Variable | Constant |
|---|---|
| SQLType | USER |
| CMDType | SELECT |
| CursorMode | Forward only |
| Size | Value | Description |
|---|---|---|
| 12 | PGNProfiler\1 | File header, same for all files. Single byte after ‘PGNProfiler’ is format version number. |
| 4 | Integer N | Total number of messages. |
| 4 | Integer E | Number of errors. This number is only for convenience of displaying PGL file in viewer. It is for avoiding calculation of errors count. |
| N*4 | Array of 4-byte integers representing messages and errors sizes. Messages and errors in format described in separate tables below. The messages and errors are always 4-byte aligned by zeroes appended to the end. The array of sizes contains sizes including the alignment. | |
| >4 | Logger ID to Name value pairs. Logger ID is 4-byte integer used in messages and error to resolve into Logger Name (usually Process name). The list can have one or more pairs. Logger Name ends with \0. |
| Size | Value | Description |
|---|---|---|
| 4 | number | Logger ID |
| 1 | 0 (TRC_NONE) |
Trace type |
| 1 | 0 (QT_NONE) |
Command type |
| 1 | 0 (FORWARD_ONLY) |
Cursor type |
| 1 | 0 | License chip (deprecated after 1.2.8) |
| 8 | FILETIME | Timestamp when the message was received |
| 8 | FILETIME | Parse duration in microseconds |
| 8 | FILETIME | Prepare duration in microseconds |
| 8 | FILETIME | Execution duration in microseconds |
| 8 | FILETIME | Data get operation duration |
| 4 | number | Number of rows affected |
| 2 | number | Session ID |
| 2 | number | Command ID |
| 4+len | Client SQL length and text | |
| 4+len | Executed Statement length and text | |
| 4+len | Database name length and text | |
| 4+len | User name length and text |
| Size | Value | Description |
|---|---|---|
| 4 | Logger ID | |
| 1 | 4 (TRC_ERROR) | Trace type |
| 1 | – Same as in Message – | Command type |
| 1 | – Same as in Message – | Cursor type |
| 1 | License chip (deprecated after 1.2.8) | |
| 8 | FILETIME | Timestamp when the message was received |
| 2 | number | Session ID |
| 2 | number | Command ID |
| 4+len | Database name length and text | |
| 4+len | User name length and text | |
| 4+len | Error length and text |
The following Registry keys in HKCU\SOFTWARE\INTELLISOFT<id>\PGNPROFILER could be used to enable and configure various advanced features of the PGNProfiler. Where is PGNP for Postgres and Greenplum products, and RSNP – for Redshift.
| Key | Type | Description |
|---|---|---|
| ConnectToHostEnabled | DWORD | When key exists and set to 1, UI for connecting to remote hosts enabled. |
| MaxLogFileSize | String | Contains abbreviated string with maximum size of the .pgl file (current trace). When the maximum size is reached the current file is closed, and new file is created with the latest timestamp added to the name. Examples: "1K" -> 1000, "360M" -> 360'000'000, "2.6G" -> 2'000'000'000, "3T" -> 3'000'000'000'000, "0" -> 0 (infinite size). When missing key or empty value, then maximum size is 2^30. The size cannot be set smaller than 16777216. |
I have not included the following:
- security-related code (ScrableText);
- UI controls implementation (WTLPropGrid);
- automated tests;
I included sample.pgl file (in miscdata directory). It can be used only for viewing/demo-ing the PGNProfiler. Distribution, transfer and altering of the file is prohibited.
Note: more information can be found in the Intellisoft's Developers Manual and the Forum.
Note: I described the approach to the messages filtration here: https://www.codeproject.com/Articles/51386/Yet-Another-Concurrent-Expression-Evaluator.
Since the profiler application was intended to be used on Windows only and should have a small size and high performance, the following dev tools were chosen:
- Visual Studio Community;
- C++, boost;
- Windows Template Library (WTL);
I considered raw Win32, MFC, WTL, and Qt for UI. MFC was rejected because of the size overhead being too high. Qt was unfamiliar and unaffordable. Raw Win32 for UI was too tedious/verbose. So, the best option known at that time, around 2008, was WTL.
I think the use of named pipes is sufficient for the purpose. The sender side (PGNP Provider) uses overlapped write to the pipe if it is open. The receiver side (PGNProfiler) reads from pipe(s) and stores the messages in a work file asynchronously. The work file is mapped to memory and used for displaying the messages.
Initially, I used WaitForMultipleObjects for the overlapped read from the named pipes, assuming that no more than 64 applications would run the PGNP Provider simultaneously. Later, I added support for IO Completion Ports to the CTraceReader and, therefore, removed the limitation on the number of processes that could be sources of messages.
| Class | Resource | Protection | Notes |
|---|---|---|---|
| CExplorerView | m_logFiles | m_rootLogger.Lock()/Unlock() | AddLogFile, RemoveClearedLogFiles |
| m_remoteHosts | --/--/-- | AddHost | |
| CProcessLoggerItem | CriticalSectionLock lock(_lock) | m_dwMMFsize, m_logWritePos, m_logStart, m_hLogFile, m_hMapping | GrowLogFile |
This advanced feature was created out of curiosity of how to inject a process on a remote host, and comminicate with it. See implementation in CRemoteApi class.
There are two scenarios for discovering the processes that are senders of messages: manual and automatic.
The manual scenario is when the user clicks the Refresh menu item in the PGNP-Explorer. The PGNProfiler scans available pipes with the names pgnprof_nnn where nnn is ProcessID. Then, it resolves the ProcessID into the process name and displays the name in the PGNP-Explorer.
The "automatic" scenario is intended to determine which process is a sender of messages automatically. I initially tried to broadcast a registered Windows message from the PGNProfiler. Also, I created a thread that waits for FileChangeNotification in \.\pipe folder (CPipesMonitor). However, those approaches did not allow for capturing some initial messages from senders. Therefore, I rewrote the CPipesMonitor to receive notifications about PGNP.DLL load/unload via transacted named pipe.
See the doc\pgnprofiler.drawio diagrams for additional details.