[Progress Communities] [Progress OpenEdge ABL] Forum Post: Make the PASOE logs less noisy in the event of (fully-handled) STOP conditions

[dbeavon]

We are migrating to PASOE and the logs are quite noisy since STOP conditions happen more frequently than the did on classic appserver. We haven't quite upgraded to the new S.E.H. model of handling lock conflicts (-catchStop 1). The ABL code still has "ON STOP" qualifiers around blocks of code that are likely to fail because of lock conflicts. eg. /* Possible problem */ DEFINE VARIABLE m_PossibleProblem AS CHARACTER NO-UNDO. m_PossibleProblem = "Possible lock conflict on table.". /* Error is unexpected */ DEFINE VARIABLE m_ErrorUnex AS CHARACTER NO-UNDO. m_ErrorUnex = "Unexpected error in " + PROGRAM-NAME(1) + " at line {&LINE-NUMBER}. " + m_PossibleProblem. /* BlockForTransaction */ BlockForTransaction: DO TRANSACTION ON STOP UNDO BlockForTransaction, RETURN ERROR m_ErrorUnex ON ERROR UNDO BlockForTransaction, RETURN ERROR m_ErrorUnex ON ENDKEY UNDO BlockForTransaction, RETURN ERROR m_ErrorUnex: ... whatever code results in lock conflicts... END. When we encounter lock conflicts, they raise the STOP condition that causes the unexpected error to be returned (RETURN ERROR m_ErrorUnex). The end result is that the client/calling program receives the necessary details. In some cases this is a remote openclient. Notice that the exceptions are fully handled (not "swallowed"). They are properly captured and sent back to the client/caller. Given that this is the case, it doesn't seem helpful that the PASOE prints this event as a critical message in the agent logs. It is printed without having any log entry types selected. Here is the message, formatted as shown based on the options -errorstack and -debugalert. Note the scary messages (8812) and (1750) [19/03/28@10:41:21.287-0400] P-002404 T-006936 1 AS-492 -- Lock wait timeout of 10 seconds expired (8812) [19/03/28@10:41:21.287-0400] P-002404 T-006936 1 AS-492 -- ** ABL Debug-Alert Stack Trace ** [19/03/28@10:41:21.287-0400] P-002404 T-006936 1 AS-492 -- --> FetchAsyncDataTransaction app/p/app0479.p at line 594 (\\grnetappm03\oe_prod\OpenEdge\USW\LumberTrack\app\p\app0479.r) [19/03/28@10:41:21.287-0400] P-002404 T-006936 1 AS-492 -- FetchAsyncData app/p/app0479.p at line 501 (\\grnetappm03\oe_prod\OpenEdge\USW\LumberTrack\app\p\app0479.r) [19/03/28@10:41:21.287-0400] P-002404 T-006936 1 AS-492 -- Could not read table 685 for undoing DBKEY 131307145 partitionId 0. [19/03/28@10:41:21.287-0400] P-002404 T-006936 1 AS-492 -- ** ABL Debug-Alert Stack Trace ** [19/03/28@10:41:21.287-0400] P-002404 T-006936 1 AS-492 -- --> FetchAsyncDataTransaction app/p/app0479.p at line 843 (\\grnetappm03\oe_prod\OpenEdge\USW\LumberTrack\app\p\app0479.r) [19/03/28@10:41:21.287-0400] P-002404 T-006936 1 AS-492 -- FetchAsyncData app/p/app0479.p at line 501 (\\grnetappm03\oe_prod\OpenEdge\USW\LumberTrack\app\p\app0479.r) Is there a common mechanism by which we can avoid printing this (STOP stuff) to the agent logs when the problems are already being handled in code? In case it helps, our logging level and log entry types are as follows. Logging level: 1 Log entry types: (blank) In the general case we DO want critical messages in the logs. (***see PS) But for modern programs that handle errors more consistently (using BLOCK-LEVEL ON ERROR UNDO, THROW) we don't need the extra noise in the logs. It is redundant since we know that any problems will be sent back to client/callers via the callstack. The only option I can think of is to change LOG-MANAGER:LOGGING-LEVEL to zero and then try to ensure that it gets changed back to 1 again at the end (which is an approach that is made more challenging based on the common occurrences of lock conflicts and other types of errors). Any ideas would be appreciated. It is unfortunate that the logs are noisy, considering that the errors are being fully handled. It just means that the people responsible for reading them every day have a lot of unnecessary noise in the logs (and on top of that, it is very scary-looking noise ). Thanks, David *** In general we DO want messages in the logs because some of our legacy ABL code is good at ignoring errors and proceeding without any error handling whatsoever (based on the default ON ERROR behavior in ABL). We have legacy programmers who are responsible for reviewing the logs after the fact (the next day) to see how scary the errors were, and how likely it is that the legacy ABL has corrupted data in the OE database.

Continue reading...