In OpenEdge 10.0B the DynObjects log entry type was introduced. This logging feature allows all Dynamic objects created and deleted in a OpenEdge session to be logged
This feature is used by specifying one or more of the following after the -logentrytypes parameter or by setting the LOG-ENTRY-TYPES attribute of the LOG-MANAGER handle.
- DynObjects.Class
- DynObjects.DB
- DynObjects.Other
- DynObjects.XML
- DynObjects.UI
- DynObjects.* <all of the above>
DynObjects.* can be used to include all of the above.
Examples for an ABL client process (WebClient, GUI client, ChUI client):
-clientlog <logfilename> -logentrytypes "DynObjects.Class,DynObjects.UI" -logginglevel 3
-clientlog <logfilename> -logentrytypes "DynObjects.*:3"
Note: ':3' at the end of the log entry type above. This demonstrates setting the logging level for that specific log entry type. This overrides -logginglevel for just that log entry type.
For WebSpeed/AppServer Agents and PASOE, the same log entry types and logging levels can be specified in the server/agent's properties file. All Dynamic objects created and deleted will then be written to the *.[server|agent].log logfile.
Examples for AppServer, WebSpeed & PASOE
- AppServer/WebSpeed ($DLC/properties/ubroker.properties file)
srvrLogEntryTypes=ASPlumbing,DB.Connects,DynObjects.*:3
- PASOE (<instance-dir>/conf/openedge.properties file)
[AppServer.SessMgr.<instance>]
agentLogEntryTypes=ASPlumbing,DB.Connects,DynObjects.*:3
Note: The instance will have to be restarted unless allowRuntimeUpdates was previously set to 1.
DynObjects Output
Once output is generated, it can be analyzed using ABL code, or by simply opening the file and matching up all the creates with all the deletes. Like any forensic memory leak analysis tool this process can sometimes generate false leaks. Refer to the detail log in order to find the exact line number of instances of leaks that were reported in the summary, so that you can observe the logging and verify it wasn't simply missed due to some problem in the generated logging.
Logs will show the following patterns:
- For a given MEMPTR or LONGCHAR variable Allocated and Deallocated entries are shown. If no corresponding Deallocated entry is visible for a given Allocate, this represents a leak. These do not have access to a handle value from the perspective of the logging code (within the AVM), so the handle is generally 0, so generally you can match up the Deallocate based on size.
- For any Handle based object or Progress.Lang.Object Created and corresponding Deleted entries can be matched using the Handle. It's important to note that handles are not unique per session, so it's best to isolate the logging for a specific PID or for PASOE the specific process (e.g. AS-4) before analyzing.
Researching Logs for Leaks
quickLeakCheck
An ABL example procedure called quickLeakCheck.p is provided (attached) which can be used to quickly determine whether it's worth performing deeper research into a given log file containing DYNOBJECTS output. This is particularly useful for very large (multi-GB) log files. Performing a full leakCheck on a log or series of logs can take a significant amount of time. Running quickLeakCheck is very fast and stores nothing except 4 INT64 variables.
- quickLeakCheck.p quickly reads all lines from the log and checks within lines that contain the DYNOBJECTS string, for the Create, Delete, Allocate and Deallocate strings and provides a count of each. If there are large disparities in the counts for a given category, that would indicate the need to continue researching the log.
findLeaks
The attached findLeaks.p provides an example procedure to parse the log entries generated; it will report any "Created" entry that does not have a matching "Deleted" entry, along with where in the code the create happened.
- findLeaks.p - Parses the log files generated on the clients, WebSpeed agents, Classic Appserver and PASOE agents.
For .NET objects, client logging can only track the ABL side. This will not show anything for .NET objects that are not referred to on the ABL side. A .NET control may use several sub-objects. If there is never a reference to one of these subobjects on the ABL side, it will never show up in the client log.
Note: In a development environment the tools can clean up objects in a way that gets logged. This can potentially mask memory leaks.
Filtering out logging lines matching "*adecomm/_runcode.p*" can help to avoid this.
At runtime, if findLeaks detects that the log seems to be in a series of logs it will compile a list of these files and prompt the user whether they wish to include these files in the analysis (below).
findLeaks Output
Summary Report
Naming convention:
Single log - When analyzing a single log volume: <AppServer log file name without the extension>_summary_report.txt
Series log - If the log is detected to be in a series and the user clicks Yes, to process the whole series, the log series number is omitted from the summary report name, e.g. myAppServer.server_summary_report.txt
The Summary Report provides a summary of all the leaks found by the process. It gives the location of the leak (where the create/allocate executed) and a summary of how many times that particular leak occurred.
Generating Final Summary Report (1 OF 1)
Object Type Where Created Total Leaks
----------------------------------------------------------------------------------------------------
MEMPTR (Originally: MEMPTR) allocMem C:\findLeaks\test\createLeaks.p @ 41 --- 2000 objects leaked, Total Memory: 1,001,000 bytes
TEMP-TABLE C:\findLeaks\test\createLeaks.p @ 14 --- 30 objects leaked
*********** The following items were created by the agent process ***********
PROCEDURE(adm2/data.p) as_startup.p @ 1000 --- 10 objects leaked
Known False Leaks:
-----------------------------------------------------------------------------------
Progress.Lang.Object(OpenEdge.Net.HTTP.BuilderRegistry) propGet_Registry OpenEdge.Net.HTTP.ClientBuilder @ 43 --- 4 objects leaked
REPORT INFO
Logs read: 1
If while viewing the summary, you have doubts about whether a reported leak is indeed correct, you can copy the string from the "Location" in the summary line and search for it in the Detail Log (below) to find the original line in the log file.
*********** The following items were created by the agent process ***********
When you see the above in the summary, this means that you are analyzing PASOE log output with RequestId enabled, and the object actually got allocated/created by the agent process (RequestId=?:?:?) itself, meaning it was done in one of the hooks (agentStartupProc, agentShutdownProc).
While it's certainly possible to leak objects in those routines, typically you'll see adm2 or dynamics peristent procedures here, or any persistent procedures started by your application. These are typically meant to stay until the session is terminated.
Series Summaries - While processing a series of logs, findLeaks.p overwrites the summary report after each individual log in the series is processed. This gives you a sneak peak at what leaks have been found thus far in the process.
Known False Leaks:
Known false leaks are objects that are created from a location containing 'OpenEdge." and contain the word "Registry" in it. This describes objects whose static properties and methods were accessed
These are always of Type Progress.Lang.Object. A static class is never removed from a session's memory once it has been referenced, however only one copy of that class' r-code is ever kept in memory.
These are presented at the end of the report in case there is a clash in naming conventions that causes any application leaks not to be shown in the main summary.
Note - Some leaks that were reported early in the analysis of a log series can disappear by the time the log is finished processing. This is because one temp-table of leak information is kept for the whole series, so when finally objects are cleaned up (for long running processes) the leaks are eliminated from the temp-table and finally not reported.
Detail Report
The detail log is used when you doubt an item that appears in the summary report. This provides the line number and original log name for all the lines used to construct the Summary. If the summary is in question, search for the exact string (from the Location field in the summary) in the Detail log.
For example, if you have questions about the TEMP-TABLE leaks in the summary example above, search for the location string "C:\findLeaks\test\createLeaks.p @ 14" in the corresponding detail report and can see the original log that contains the DynObjects output and the line it was logged at.
Application Log
While it is running findLeaks.p generates a session log named like "findLeaks_<DDMMYYYY>_<HH:MM:SS>-<999>.out".
This log provides insight into where the utility is in the process of reading/processing the log(s) it's reading. There is a variable in the program called giLoggingLevel that can be set to increase the amount of logging done by findLeaks.p on its own operations. Increasing the giLoggingLevel will increase the size of this log considerably. Setting giLoggingLevel to 3 or higher will cause the utility to generate a .csv file with the log contents in order to cross reference what the tool read with what was in the original log.
This log also (by default) provides information about any lines that did not match the expected format. When such lines are encountered, it is possible that leaks may be missed, or mis-reported.
OE Manager DynObjects REST API
OpenEdge 11.7.3 introduced a *NEW* REST API to track memory leaks in ABL application code used by a PAS ABL Session. In 11.7.4 further updates were provided in the API. This functionality some of the best methods to identify memory leaks within a PASOE application.
For more details see article: ABL Objects Tracking REST API under PASOE
OpenEdge.Core.Util.LeakCheck class:
In OE 12.6 the OpenEdge.Core.Util.LeakCheck class was added to support internal testing.
For more details see article: How to use the OpenEdge.Core.Util.LeakCheck class ?
Full documentation of LOG-MANAGER's available log entry types and their output is here: Log Entry Types Detail (progress.com)
