Changing PASOE agent logging dynamically - Forum - OpenEdge Development - Progress Community

Changing PASOE agent logging dynamically

 Forum

Changing PASOE agent logging dynamically

This question is answered

We use the .Net open client, and any time an S.E.H. error is thrown in ABL, we still need to trap it and convert it to the legacy error format (ie.  RETURN ERROR ch-error).    This was true in classic appserver and it still remains true in PASOE.

Unfortunately there are times when an SEH error is not caught, and bypasses our conversion efforts .  The user gets a generic failure message (Runtime4GLErrorException) in the .net open client, and a message is shown in the logs like so:

[18/11/28] P-000768 T-004092 1 AS-33 -- Cannot throw or return error/stop object to remote client because object is not serializable or client does not support it. (14438)

There is nothing more in the logs to say what the error is, or where it came from.  Therefore, unless the end-user decides to report the failure, this mystery message will never be resolved and will continue to appear in the logs forever.

I'm aware that increasing the logging level and adding 4GLTrace to the log entry types will get to the bottom of the problem.  The issues with this is that, (1) logging needs to be turned on for a very long time to diagnose an infrequent error, and will generate tons of logging in the meantime.  This could be worse than living with the mystery message. And (2) I haven't found a way yet to cause PASOE to dynamically adjust its logging, based on changes in openedge.properties config values.  Even if the agent process for an application is stopped individually and a new one is restarted, it doesn't seem to adjust the logs as requested.  The only solution is to restart the entire instance.  This is disruptive to openclient sessions (end users) with long-lived sessions because it will generate error(s) when the PASOE instance is restarted.

Does anyone have any ideas how, in PASOE, to turn on agent logging dynamically until an error message can be captured, then turn it off again?  These are the logging config values I'd like to be able to manipulate: agentLoggingLevel , agentLogEntryTypes.  I'm quite sure that agents won't pick up my changes to openedge.properties (even new ones that are added on the fly) until the entire PASOE/tomcat instance is restarted.  I believe there may be a way to accomplish this type of thing with system-wide custom-code by adjusting LOG-MANAGER properties myself but I'm hoping this won't be necessary if there is something already built into PASOE that I've overlooked.

Also, is there any log entry type that I may have overlooked that is specifically for S.E.H. error handling.  Ideally I'd be able to turn on logging for all errors thrown ("first-chance" errors) and that would reduce the amount of information sent to the agent logs (as compared to 4GLTrace).

Any help would be appreciated.  I found some links to some very helpful information about logging and PASOE troubleshooting.  But they don't give me a way to adjust logging for an ABL application on the fly without restarting the entire instance.

http://pugchallenge.org/downloads2017/2017NAPUGLogFilesA.pptx 
https://knowledgebase.progress.com/servlet/fileField?id=0BEa0000000TisZ

Thanks in advance, David

Verified Answer
  • Oh.  So you are not talking about what goes into the AppServer log.  You are talking about what gets sent back to the Open Client code.  In that I totally agree with you.  Or I should say WE totally agree with you.  In version 12, we have already fixed this, but so far only for Java Open clients.  i.e,. Error objects can now be serialized back to the client and you will get the error message and error number on the client side. So you would leave in your BLOCK-LEVEL ON ERROR UNDO, THROW directive and would not need your special CATCH block logic anymore.  

    Unfortunately, we have not done it yet for .NET Open clients, but it is on the roadmap.  You can press product management to make this a higher priority.

    And until that happens, at least you should avoid getting error 14438 by removing the BLOCK-LEVEL directive from your top-level server procedures.  Then you will at least see the error message in the AppServer log file even if it doesn't make it back to the client.

  • An update on this.... Irfan claims that in production on 11.7.4 I should be able to change the logging level on the fly.  

    This should allow me to turn up logging to 4 (extended) for long enough to capture the source of a problem and then turn it off again.

    The key is a property, "allowRuntimeUpdates", in PASOE.  As important as this sounds, I am not getting a lot of hits for that property in my google searches.  I'm really hoping it works as described!  I may have to stop pre-existing agent processes for the change to take effect, but even that would be a fairly reasonable compromise.

  • An update on this ... Irfan thinks that logging levels might be able to change on the fly via a PASOE property, allowRuntimeUpdates, which is in OE 11.7.4

All Replies
  • I think the biggest problem with this...

    Cannot throw or return error/stop object to remote client because object is not serializable or client does not support it. (14438)

    ... is that it is essentially the equivalent of an "unhandled exception" which is escaping ABL/PASOE . But there is no more information than that.

    The logs don't have any additional detail, and the .Net openclient receives no additional information than a generic message saying that an error occurred. That is not what software developers generally expect from unhandled exceptions. There is a lot more information that is available within our S.E.H Progress errors, including their data type, member fields, and stack information, and ToString() output. Why can't this stuff be written somewhere? I probably wouldn't even mind if the MS-agent-session crashed as long as it gave me the relevant information about the unhandled exception that was escaping the ABL runtime environment.

    We have configured our sessions using the -errorstack.  Is there any other parameter I can use to force the session to spill all the related error information that is available?

  • I'm a little confused.  The only way an object is thrown out of a procedure is if you explicitly do RETURN ERROR <obj> or if your top level .p has a ROUTINE-LEVEL ON ERROR UNDO, THROW statement at the top.  i.e., This cannot happen by accident - i.e., because you forgot a CATCH block somewhere or something.  It has to be done on purpose, explicitly.  Seems like you should be able to find this and fix it.

    But having said that, I agree that if you get that error (14438), we should also log the error message that caused that to happen.  You could log a bug for that if it is not happening.  

    I don't think there is anything other than using the LOG-MANAGER that you can use to turn logging on/off in the middle of a session.

  • If you have implemented your own error class (inherited from Progress.Lang.AppError) then this class needs to be defined as SERIALIZABLE!

    Otherwise it can not be thrown from AppServer or PASOE to client

  • @Laura the problem is absolutely by accident.  If ABL programs and classes are using the new SEH pattern, then they will have...

    BLOCK-LEVEL ON ERROR UNDO, THROW.

    ... and errors (exceptions) cause the callstack to unwind up to a matching handler (CATCH).  If there are no matching handlers, then the error is normally considered "unhandled" and typically causes a crash (at least that's what happens in the runtimes of other technologies).  When this occurs, developers would expect to have access to the fatal error details (error type, member fields, and stack information, and ToString output.)

    Exceptions frequently find themselves being unhandled for accidental reasons (as in our case).  For example, at the outer-most PersistentProcedure.p which is used for app server entry, there might be a catch block that handles *every* possible error of type Progress.Lang.AppError, but even that won't necessarily catch .Net errors (which are only catch-able using interface Progress.Lang.Error) or other types of unusual ProErrors (custom ones or otherwise).  Typically a developer will catch *ONLY* the errors that they feel they understand and know how to resolve on their own.  For any other errors they don't understand (or future ones that may not even exist yet) then they rely on the runtime to do something "reasonable" (even if that means causing the session to crash, and providing access to the error details for diagnostic purposes).

    (FYI for fatal system errors a regular ABL developer would probably be unable to do any meaningful error handling .  These errors would be things like network disconnections, disks filling up, out-of-memory issues and so on.  Even PASOE itself is likely to behave in unpredictable ways - IE. it's own error handlers would likely run into errors of their own, depending on how unreliable the system became.)

    To make a long story short, in the case of ABL/PASOE the runtime doesn't give us a "reasonable" mechanism for errors that are "unhandled" by custom ABL code.  I get the generic message in the agent log, and the user sees a generic message as well.  None of the underlying details about the error are provided - not even the outer-most procedure name or the -errorstack of the error.  These would otherwise allow a developer to troubleshoot and fix the problem so it doesn't keep coming up in the future.  I can't find any way that a developer to get to the bottom of this log message ("Cannot throw or return error/stop object to remote client because object is not serializable or client does not support it").  I shouldn't have to turn on 4GLTrace for the entire application just to find the related programs, then do additional custom programming in those ABL programs to catch the error and puke out the related details.

  • @Torben our PASOE clients are .Net openclients. So even if our error classes were SERIALIZABLE, I believe they are still unable to pass from server to client.

    The only supported way to send an error back to the client is for us to encode/serialize it as a character and return it in a statement like so: RETURN ERROR ch-error.

  • First of all, errors do not cause a "crash".  An error is an error.  If it is unhandled, it will kick you out of the current block context and the application/server continues on.  It may be that you have had some unhandled Stop conditions, not errors.  But even with that, these do not cause a crash.  The process remains intact. If you are at the top of the AppServer call stack, this should cause an error message to be logged and it will kick you out of the procedure, but the process is still there to service subsequent requests.  And BTW, starting in 11.7, using -catchStop (in 12 it will be the default), you can also catch unexpected Stop conditions with the same Progress.Lang.Error CATCH block.  That is because you will get a Stop object that implements the Progress.Lang.Error interface.

    If you have a CATCH block at the "outer-most  PersistentProcedure.p which is used for app server entry" but it does not handle some condition, all that means is that the error message will be issued and go to the log file rather than the error going to your CATCH block which then presumably issues a message which goes to the log file.   Though I appreciate that maybe you log extra information from your CATCH block (see below regarding -debugalert).

    Even though in general, you want to use BLOCK-LEVEL ON ERROR UNDO, THROW when doing structured error handling, you should NOT have this directive at the top-most .p that is the app server entry procedure if you never want errors to be thrown back to the client.  And in your case, you do not want that because then you then just get the error you are complaining about.

    If you get a fatal error, I don't think this discussion is relevant.  The process (or session for PASOE) will be terminated.

    I believe if you use -debugalert, any error that is written to the log will show a stack trace.  Though, I agree, that if this is an error that has bubbled up from somewhere else, this is not very useful.  You need the error stack information from the object itself.  If that is not output, that is a valid complaint.

    I don't know what you mean be a "generic message"?  You should definitely at least see the specific error message based on what error occurred.  But this whole discussion started with you getting the error "Cannot throw or return error/stop object to remote client because object is not serializable or client does not support it".  I will repeat - just don't use BLOCK-LEVEL ON ERROR UNDO, THROW in the top level procedure.  That is just wrong for this .Net Open Client scenario.  And that is what is masking what the real error is.  If you weren't trying to throw it out of the server, you will see the real error in the log.

  • Thanks for suggestions.  I realize that I may be dealing with an issue that doesn't affect everyone, given that we use .Net openclients.

    I think BLOCK-LEVEL ON ERROR UNDO, THROW  would work fine in the top level procedures too if all the errors were serializable *and* if my client wasn't the .Net openclient.  They would simply be passed along to the ABL client.  It would also be a lot less programming effort than putting TRY/CATCH blocks around all the logic in every method of the top-level procedures.  

    However in the case of errors which aren't SERIALIZABLE, or ones that are destined for a .Net, then we see the kind of troubles I've been complaining about.

    When I talked about how "unhandled" exceptions may "crash" a runtime, I was talking in general about my experience from other technologies (like .Net).  The "crash" in the context of PASOE might be analogous to what happens when using the QUIT statement from an ABL session.  Ultimately I don't really care if it "crashes" altogether or not, but I do want the escaping error details, because they are not made available to .Net and they are not made available to the PASOE logs.

    As far as the "generic message" that the .Net open client gets, I mean that it is something totally unhelpful (ie. it is basically an exception that says "an error occurred", and is derived from the type Runtime4GLErrorException).  This doesn't help identify the underlying cause, any more than the message written to the PASOE logs (ie. "Cannot throw or return error/stop object to remote client because object is not serializable").

    >> Just don't use BLOCK-LEVEL ON ERROR UNDO, THROW in the top level procedure.  That is just wrong for this .Net Open Client scenario.  And that is what is masking what the real error is.  If you weren't trying to throw it out of the server, you will see the real error in the log.

    I realize this is true. As a customer that uses the .Net openclient proxy, we are forced to wrap error handling around all the top-level methods in the top-level procedures.  They all use something like this:

       CATCH v_AppError 
          AS Progress.Lang.AppError :
          RETURN ERROR (IF v_AppError:ReturnValue <> ""
             THEN v_AppError:ReturnValue
             ELSE "Unknown application error in ~"TopLevel~" at line {&LINE-NUMBER}.").
       END CATCH.
       CATCH v_ProError 
          AS Progress.Lang.ProError :
          RETURN ERROR "Yet another unknown error: ". +
             v_ProError:GetMessage(1).
       END CATCH.
    

    But if that repetitive code is ever omitted , then we get the kind of troubles I've been complaining about.  Similarly if we remember to have a CATCH block for Progress.Lang.AppError but not for another type of error (Progress.Lang.ProError or Pro.Lang.Error) then we get the kind of troubles I'm complaining about.  This type of issue is rare and troublesome considering that the PASOE runtime doesn't point us to the root source, or give any of the error or the stack detail.  If there was a way to change the configuration of agent logging on the fly then I might consider turning on 4GLTrace for the day, but this doesn't seem possible either without restarting the whole PASOE instance.

  • Oh.  So you are not talking about what goes into the AppServer log.  You are talking about what gets sent back to the Open Client code.  In that I totally agree with you.  Or I should say WE totally agree with you.  In version 12, we have already fixed this, but so far only for Java Open clients.  i.e,. Error objects can now be serialized back to the client and you will get the error message and error number on the client side. So you would leave in your BLOCK-LEVEL ON ERROR UNDO, THROW directive and would not need your special CATCH block logic anymore.  

    Unfortunately, we have not done it yet for .NET Open clients, but it is on the roadmap.  You can press product management to make this a higher priority.

    And until that happens, at least you should avoid getting error 14438 by removing the BLOCK-LEVEL directive from your top-level server procedures.  Then you will at least see the error message in the AppServer log file even if it doesn't make it back to the client.

  • Thanks for the tips.  I was talking about both the client side and the appserver log.  One or both of them should have more error details.  

    EG whenever PASOE is going out if its way to print this in the logs ("Cannot throw or return error/stop object to remote client because object is not serializable or client does not support it"). Then at that same time it could at least say which top-level procedure was involved, and the error type, and the -errorstack (if available).

    Unfortunately we now have BLOCK-LEVEL directives in all our *.p and *.cls.  Otherwise Progress ABL error handling behaves in unusual ways (especially for loops that use the default ON ERROR behavior).

    Without knowing which top-level procedure is failing, it is hard to remove that procedure's BLOCK-LEVEL directive.  I suppose we will probably have to shut down the PASOE instance this weekend and enable 4GLTrace logging for the following week.  That appears to be the most certain way to find the source of the error (unless the affected user will eventually call us about their error messages that they are probably getting in their application U/I).

    Thanks for the news about the improved marshalling of errors from PASOE to Java.  That is definitely something we'd be interested in for the .Net openclient too.  You'd be amazed how hard we have to work to cram the relevant error information into the legacy statement, "RETURN ERROR CH-Error".  It can sometimes be a huge chunk of xml or some such thing.  Another option can involve storing the error and returning only an identifier... so that the related details can be fetched as a ProDataSet in a subsequent round-trip.

  • As you note, currently, the only way to intercept any error from AppServers calls is to add the BLOCK-LEVEL directive and a CATCH block to any and all .P that’s called from a client. This is, um , clunky.
     
    We have talked informally internally about adding some form of handler to be able to generally catch unhandled errors/exceptions in PASOE. It may be worth raising the issue of how to generally handle errors raised on an AppServer request (without having to change every entrypoint) in the CVP forum and also creating an Idea for it.
     
     
  • We do provide -undothrow n (n = 1: ROUTINE-LEVEL, 2 = BLOCK-LEVEL) if you really do want these everywhere.  This takes effect at compile time.  Then you wouldn't have to code it everywhere.  But then of course, you also could not make any exceptions, as I believe you want to do in this case.  I hate to be redundant, but it seems like you should avoid having sub-procedures that need the UNDO, THROW directive in your top-level procedures such that you could just remove the directive from ALL top-level procedures instead of having to figure out which one(s) you've been having a problem with. But I will shut up now and let you handle it however you see fit  :-)

  • @Peter thanks for letting me know that there have already been discussions around the "escaping" errors (they may be handled by the remote client but they are unhandled in the PASOE agent.)

    Ideally we could hook into first-chance errors as well as the escaping errors.  In .Net we have an appdomain with events for both:

    System.AppDomain.FirstChanceException

    System.AppDomain.UnhandledException

    Also, the individual U/I technologies may have some similar events as well, eg. Windows.UI.Xaml.Application.UnhandledException

    I would definitely hook into errors if there was a mechanism (and providing it performed reasonably well).

    @Laura, thanks for the pointer to -undothrow.  I had seen that option in the past but  it seemed that it was best suited to compiling at runtime, IE. for legacy programs that are compiled dynamically and don't otherwise have a default error handling declaration.  

    I don't think I would trust our code to run without the explicit BLOCK-LEVEL directives anymore.  As I recall, when omitting that directive we had to override the ON ERROR phrase of every loop that exists in our code, because otherwise the default error handling was so problematic.  Thankfully those days are behind us.

  • I opened a support call with Progress about the messages in the logs which alert us to mysterious and unexplainable problems (ie. "Cannot throw or return error/stop object to remote client because...").

    Tech support has agreed that the only good way to track down the source of an error is to turn on the 4GLTrace for a while.  The challenge in doing that is that there isn't a way to change the PASOE logging level on the fly. So it requires a brief outage (to stop and restart the instance) in order for the change to take effect.

    That isn't the end of the world.  But it involves a lot of steps, just to find some additional details about an unexpected error.  Here is the KB : knowledgebase.progress.com/.../Tracking-down-the-root-cause-of-error-14438

    I should point out that we are already pretty reliable in our exception handling.  We regularly remember to put CATCH blocks in our entry-level.p programs for PASOE, and we use those blocks to convert the ABL error types and send them back to the openclient. (We have to send errors back to the .Net openclient using the legacy statement, "RETURN ERROR CH-error." ).

    The only gotcha is that these CATCH statements normally limit themselves to the application error type, "Progress.Lang.AppError" (and to types that inherit from that).  So if there is an error of an unexpected internal type (eg. Progress.Lang.ProError or similar) then those will be the ones that will escape.  They are things that come up for reasons that may not have anything to do with our own business logic.  

  • Just an FYI;  it may not alter the essentials of what you said.  I really can’t think of an error that does not implement the Progress.Lang.Error interface.  ProErrors certainly do.  Anyway, I don’t believe you can ever actually get a ProError itself.  That is an artificial level in the class hierarchy to distinguish from a .NET Exception, and even .NET exceptions implement the Progress.Lang.Error interface.  

    I’d rather not wade through all the text above to see, and I can’t search right now (at home on my iPad), but I don’t remember you talking about Stop conditions.  If so, sorry for redundancy.  And if not SORRY I did not think of this till JUST now.  If your version is pre 11.7 (I don’t remember if you said that either) or are using some 11.7 version, but not using -catchStop 1, then Stop conditions will not be caught by a CATCH for Progress.Lang.Error.  So if you are as diligent about using structured error handling as you say, I would guess that you are getting a STOP condition.  If you are using 11.7.x I would suggest using -catchStop 1 to see if that helps.

    Also, what error message(s) are you getting?  We could probably determine if these are conditions that would generate Stop.

  • The only message is 14438.  I thought about the possibility that this might be a STOP too (and was therefore bypassing my apperror CATCH statements.) But there were no lock wait timeout messages in the agent logs, and I can't imagine STOP coming up this frequently for any other reason.

    I'm fairly convinced now that these are Progress.Lang.Error which represent a .Net problem.  We use .Net very little in abl, but it is possibly just enough to see a few of these 14438 messages every day.   I suppose that if we are going to use the clr bridge more frequently (now that we are getting out of HpUx) then we should probably start adding the extra CATCH statements in order to handle anything based on the Progress.Lang.Error interface.  

    Something came to my mind today about Progress errors. Don't you have a secret way to edit the PROMSGS file to incorporate special behaviors?  Ie. so that an occurrence of a rare error, like 14438, will trigger memory dumps, stack traces (prostack and native) and give us better clues about the source of the problem?

    I think that the sysinternals "process monitor" is also able to show the stack trace for every file operation (eg at the moment that the 14438 message is written to the log)  That would probably give an obscure native stack, But I doubt it would help identify the prostack.

    Ultimately I will probably just restart pasoe with 4gltrace level 2.