I use the client logging to correlate the logic (4GLTrace) with the elapsed time that is consumed in various parts of my code. I believe there are other tools like profilers that I should start using as well. The following problem may be better solved by a profiler (please let me know if that is the case, since I don't have much experience with ABL profiling).
When I'm doing development work I may forget to compile a program, or I may deliberately leave programs uncompiled. However there is a runtime penalty associated with that (especially when -q is omitted). There can be surprising performance implications related to the on-the-fly compilation of ABL. The performance of doing runtime compile operations over client/server is not great, considering that schema has to be retrieved remotely.
The problem I have is related to the client logging (using 4GLTrace). I can see where one program starts to call another, and I can see gaps of time (100's of milliseconds) where the program is paused, but it doesn't tell me whether that is because of the logic in my own code, or because of a runtime compile operation. It would be really nice if there was some way for the client logging to alert me about long-running compiler operations, due to the fact that r-code wasn't present. Is there a log entry type for that? Or are there any OE profiling tools that would quickly alert me to long-running compile operations?
There isn't any logging available specifically for what you asked for. There is a log entry type called FileID that will log an entry when we open and close a file, so you would be able to see if we opened the .r or .p, which you may find useful for this case.
There isn't any logging available specifically for what you asked for. There is a log entry type called FileID that will log an entry when we open and close a file, so you would be able to see if we opened the .r or .p, which you may find useful for this case.
Yes that is useful. I will look for that and, if I see a source file being opened, and a subsequent 300 ms delay then I will know who to blame. ;)
This is very helpful. I've also used procmon (sysinternals) in the past to see whether source or r-code was being opened, but it is much easier when everything is in the same client log instead of cross-referencing across two logs.
Still, it would be better if there was a log entry type for compiler operations. I'm surprised that it is missing, considering that there are other log entry types for lots of other minor activities that are happening in an ABL session.
FYI, your name came up in a conversation today with my tech support engineer. It was in regards to this post from two years ago: community.progress.com/.../33923
We supposedly have a fix now for "stale schema" issues in remote (client/server) connections, but it still doesn't behave exactly like the self-service connections. In the remote connection we still see a system error message ... the only difference in the oe 11.7.5 sp is that the remote ABL client doesn't crash after showing the error. Personally it worries me if a client application does NOT crash after it generates a scary system error about "stale schema". What is the alternative to crashing? Just winging it?
I really like the log entry type of FileID for seeing exactly when things are being compiled, within the control flow of the ABL programs.
Additionally I wanted to point out that I found another way to see what was compiled between "check-points". IE. you can run a program, and after it comes back you can check to see if anything important was compiled along the way.
This is possible by enabling the "-y" startup parameter for "procedure usage statistics": https://documentation.progress.com/output/ua/OpenEdge_latest/index.html#page/dpspr%2Fstatistics-(-y).html%23
Then you can use the SHOW-STATS or SHOW-STATS CLEAR commands whenever you wish to know about the possible compilation of programs on the fly. The output looks like the following. If you see zero compilations and zero saves, then you know that there were no delays that were compiler-related.
Saves of compilation .r's: 0 0 Compilations of .p's: 0 0 Checks of files with stat: 64 0
Unfortunately this information isn't going to appear in the client logging file, but in another file (named in the format "client.XXX.AS-YYY.mon") which will be located in your working directory. We then have to correlate the information from one log file with the information from the other log file. This correlation is easier if the SHOW-STATS statement is used on a frequent basis.
Some tips
That is helpful. I did find the profiler in PDSOE, and used it for the first time a couple months ago. This is definitely the most thorough way to find performance issues, and it easily isolates the slowest parts of the code. I was pretty happy with the profiler; it was easy to use and it worked on the first attempt.
>>You should profile compiled application...
My question was related to my development environment. IE. when I'm doing development work on my local machine and I leave certain programs uncompiled, and something in the code is unexpectedly slower than it should be, then how can I quickly determine whether I'm being impacted by a compiler issue or by the logic of the code itself. One way is what you mentioned - to recompile the entire project and test again. But PDSOE compile operations on a large project are slow and hardly practical. Besides, much of the r-code should continue to remain uncompiled, if I'm actively making changes.
As I point out above, the problem of performance (in the context of uncompiled code) is primarily only an issue in development. By the time code is promoted to production, the majority of it is already precompiled ahead of time, and there aren't many unexpected issues related to compiling ABL on the fly. (In production if there is still an impact related to dynamic compilation then it is usually enough to find it by monitoring for FileID in the client logs or use "-y" w/SHOW-STATS-CLEAR. These will tell us where the OE runtime is doing compilation operations that we might not expect).