Lots of file I/O related to a file named logging.config

Posted by dbeavon on 06-Feb-2020 01:30

I have an ABL session that is constantly accessing a (missing) file in the working directory called "logging.config". 

Here is partial "-y" output for the session.  

C:\Progress\OpenEdge\oeide\eclipse\plugins\com.openedge.pdt.debug.core_11.7.5.00\abl\_debuglauncher.p
jms/impl/errorhndlr.r
jms/impl/header-message.r
jms/impl/message.r
jms/impl/message-consumer.r
jms/impl/message-header.r
jms/impl/msgreceiver.r
jms/impl/session.r
jms/impl/text-message.r
jms/ptpsession.r
OpenEdge/Core/Assert.r
OpenEdge/Core/Assertion/AssertObject.r
OpenEdge/Core/ByteBucket.r
OpenEdge/Core/Collections/ICollection.r
OpenEdge/Core/Collections/IIterable.r
OpenEdge/Core/Collections/IIterator.r
OpenEdge/Core/Collections/IMap.r
OpenEdge/Core/Collections/ISet.r
OpenEdge/Core/Collections/IStringKeyedMap.r
OpenEdge/Core/Collections/IStringStringMap.r
OpenEdge/Core/Collections/Iterator.r
OpenEdge/Core/Collections/KeySet.r
OpenEdge/Core/Collections/Map.r
OpenEdge/Core/Collections/MapBackedCollection.r
OpenEdge/Core/Collections/StringKeyedMap.r
OpenEdge/Core/Collections/StringStringMap.r
OpenEdge/Core/IAdaptable.r
OpenEdge/Core/ISupportEncoding.r
OpenEdge/Core/ISupportInitialize.r
OpenEdge/Core/Memptr.r
OpenEdge/Core/ServerConnection/IConnectionParameters.r
OpenEdge/Core/ServerConnection/IServerConnection.r
OpenEdge/Core/String.r
OpenEdge/Core/StringConstant.r
OpenEdge/Core/Util/BuilderRegistry.r
OpenEdge/Core/Util/ConfigBuilder.r
OpenEdge/Core/Util/MathUtil.r
OpenEdge/Core/WidgetHandle.r
OpenEdge/Logging/ConfigFileLoggerBuilder.r <<<<<<<<<<
OpenEdge/Logging/Filter/ILoggerFilter.r
OpenEdge/Logging/Filter/LogFilterBuilder.r
OpenEdge/Logging/ILogWriter.r
OpenEdge/Logging/ISupportLogging.r
OpenEdge/Logging/LoggerBuilder.r
OpenEdge/Logging/LogLevelEnum.r
OpenEdge/Logging/VoidLogger.r
OpenEdge/Net/HTTP/AuthenticatedRequest.r
OpenEdge/Net/HTTP/AuthorizationHeaderBuilder.r
OpenEdge/Net/HTTP/BuilderRegistry.r
OpenEdge/Net/HTTP/ClientBuilder.r
OpenEdge/Net/HTTP/ClientOptions.r
OpenEdge/Net/HTTP/ConfigBuilder.r
OpenEdge/Net/HTTP/ContentDispositionHeaderBuilder.r
OpenEdge/Net/HTTP/ContentTypeHeader.r
OpenEdge/Net/HTTP/ContentTypeHeaderBuilder.r
OpenEdge/Net/HTTP/DefaultHeaderBuilder.r
OpenEdge/Net/HTTP/DefaultHttpClientBuilder.r
OpenEdge/Net/HTTP/DefaultRequestBuilder.r
OpenEdge/Net/HTTP/DefaultResponseBuilder.r
OpenEdge/Net/HTTP/Filter/Header/SetCookieSetHeaderFilter.r
OpenEdge/Net/HTTP/Filter/Header/TransferEncodingSetHeaderFilter.r
OpenEdge/Net/HTTP/Filter/Payload/BinaryEntityWriter.r
OpenEdge/Net/HTTP/Filter/Payload/ClientSocketResponseWriter.r
OpenEdge/Net/HTTP/Filter/Payload/ConnectRequestFilter.r
OpenEdge/Net/HTTP/Filter/Payload/DefaultRequestFilter.r
OpenEdge/Net/HTTP/Filter/Payload/JsonEntityWriter.r
OpenEdge/Net/HTTP/Filter/Payload/MessageWriter.r
OpenEdge/Net/HTTP/Filter/Payload/MultipartEntityWriter.r
OpenEdge/Net/HTTP/Filter/Payload/MultipartFormEntityWriter.r
OpenEdge/Net/HTTP/Filter/Payload/StringEntityWriter.r
OpenEdge/Net/HTTP/Filter/Payload/XmlEntityWriter.r
OpenEdge/Net/HTTP/Filter/Status/AuthorizationStatusFilter.r
OpenEdge/Net/HTTP/Filter/Status/RedirectStatusFilter.r
OpenEdge/Net/HTTP/Filter/Writer/DefaultMessageWriterBuilder.r
OpenEdge/Net/HTTP/Filter/Writer/EntityWriterBuilder.r
OpenEdge/Net/HTTP/Filter/Writer/EntityWriterRegistry.r
OpenEdge/Net/HTTP/Filter/Writer/MessageWriterBuilder.r
OpenEdge/Net/HTTP/Filter/Writer/RequestWriterBuilder.r
OpenEdge/Net/HTTP/Filter/Writer/SetHeaderMessageWriterBuilder.r
OpenEdge/Net/HTTP/Filter/Writer/StatusCodeWriterBuilder.r
OpenEdge/Net/HTTP/HttpClient.r
OpenEdge/Net/HTTP/HttpClientDecorator.r
OpenEdge/Net/HTTP/HttpHeader.r
OpenEdge/Net/HTTP/HttpHeaderBuilder.r
OpenEdge/Net/HTTP/HttpHeaderCollection.r
OpenEdge/Net/HTTP/HttpMessage.r
OpenEdge/Net/HTTP/HttpRequest.r
OpenEdge/Net/HTTP/HttpRequestDecorator.r
OpenEdge/Net/HTTP/HttpResponse.r
OpenEdge/Net/HTTP/IAuthenticatedRequest.r
OpenEdge/Net/HTTP/ICookieJar.r
OpenEdge/Net/HTTP/IHttpClient.r
OpenEdge/Net/HTTP/IHttpClientLibrary.r
OpenEdge/Net/HTTP/IHttpMessage.r
OpenEdge/Net/HTTP/IHttpMessageWriter.r
OpenEdge/Net/HTTP/IHttpRequest.r
OpenEdge/Net/HTTP/IHttpResponse.r
OpenEdge/Net/HTTP/ISupportCookies.r
OpenEdge/Net/HTTP/ISupportProxy.r
OpenEdge/Net/HTTP/Lib/ABLSockets/ABLSocketLibrary.r
OpenEdge/Net/HTTP/Lib/ABLSockets/ABLSocketLibraryBuilder.r
OpenEdge/Net/HTTP/Lib/ClientLibraryBuilder.r
OpenEdge/Net/HTTP/MethodEnum.r
OpenEdge/Net/HTTP/ProxyHttpClient.r
OpenEdge/Net/HTTP/ProxyHttpRequest.r
OpenEdge/Net/HTTP/RequestBuilder.r
OpenEdge/Net/HTTP/ResponseBuilder.r
OpenEdge/Net/HTTP/SemicolonParamHeaderBuilder.r
OpenEdge/Net/HTTP/StatefulHttpClient.r
OpenEdge/Net/HTTP/StatusCodeEnum.r
OpenEdge/Net/HTTP/TransferEncodingEnum.r
OpenEdge/Net/ISupportEncoding.r
OpenEdge/Net/ISupportMultipartEntity.r
OpenEdge/Net/ISupportTransferEncoding.r
OpenEdge/Net/ServerConnection/ClientSocket.r
OpenEdge/Net/ServerConnection/ClientSocketConnectionParameters.r
OpenEdge/Net/ServerConnection/sockethelper.r
OpenEdge/Net/ServerConnection/SocketReadEventArgs.r
OpenEdge/Net/URI.r
OpenEdge/Net/UriSchemeEnum.r

I suspect the culprit is the item identified above by "<<<<<".  Can someone confirm? 

Is that supposed to be doing I/O on disk?  I think it is happening indirectly based on a dependency on OpenEdge.Net.HTTP.  Ideally we would turn off the file system I/O.  We don't currently need the logging functionality (and I'm not even sure what functionality is available).

We are running 11.7.5.

Posted by Peter Judge on 06-Feb-2020 16:10

>As far as implementation goes, I noticed lots of static members in that "ConfigFileLoggerBuilder".  Would it be possible to have a static method or
> property that adjusts the behavior of config and determines if config files should be read once per-session, or upon every REST call?

The LoggerBuilder:GetLogger() calls basically are once per REST call (typically once per OOABL object instantiation).
 
I'm sure we can add something to tweak the behaviour (like a "don't check the config file more than once an hour" or something).  I’m loath to check only once per session since the goal is to be able to tweak the logging dynamically in an AppServer. I'd suggest logging a bug for the behaviour you're seeing and we'll come up with something. Maybe an idea for a file-watcher wouldn't go amiss either, so that we don't have to poll  :) .
 

> As a side, is this "Consultingwerk" github repro the official one for OpenEdge API's?  I've wondered that before.  It is certainly the repo that comes
> up first in google searches.

Consultingwerk takes the Zip files from https://knowledgebase.progress.com/articles/Article/P9621  and puts them into github for better readability.  There's not an official Progress one at this time.

 
 

All Replies

Posted by Peter Judge on 06-Feb-2020 14:10

That file contains configuration info for the application logging  https://docs.progress.com/bundle/service-developer-guide/page/ABL-application-logging.html  . The HTTP client  and webhandlers all ask for a logger.
 
The logger builder touches the logging.config file on each request, to see if it's changed. github.com/.../ConfigFileLoggerBuilder.cls is where that happens.
 
The reason why it touches on each request (for a logger) is that the design allows for an admin to change the config while the system is running (no need to change code to change what's logged or where).
 
 

Posted by dbeavon on 06-Feb-2020 15:56

Thanks for digging into that for me.

Here is performance profiling for the session that I'm working with.

The dependency on application logging seems to come from the OpenEdge.Net namespace for HTTP/REST.  Our rest method calls are pretty quick, and we are starting to rely on it.  The only performance issue is when we make lots of REST requests in loops.  The file I/O that is associated with this logging can be a fairly significant portion of the total.

There are multiple factors involved.  One is that we often host our session working directories on file servers (NAS).  So repeatedly accessing the same file in the file system can create a network-related performance impact. 

As far as implementation goes, I noticed lots of static members in that "ConfigFileLoggerBuilder".  Would it be possible to have a static method or property that adjusts the behavior of config and determines if config files should be read once per-session, or upon every REST call?

I suppose I could manage my own static members as a workaround (eg. I might hold onto a long-lived copy of the same OpenEdge.Net.HTTP.IHttpClient and OpenEdge.Net.HTTP.IHttpRequest).  But these things seem like they should be transient (unlike config, which is not edited often, and typically requires that an application be restarted.)

As a side, is this "Consultingwerk" github repro the official one for OpenEdge API's?  I've wondered that before.  It is certainly the repo that comes up first in google searches.

Posted by Peter Judge on 06-Feb-2020 16:10

>As far as implementation goes, I noticed lots of static members in that "ConfigFileLoggerBuilder".  Would it be possible to have a static method or
> property that adjusts the behavior of config and determines if config files should be read once per-session, or upon every REST call?

The LoggerBuilder:GetLogger() calls basically are once per REST call (typically once per OOABL object instantiation).
 
I'm sure we can add something to tweak the behaviour (like a "don't check the config file more than once an hour" or something).  I’m loath to check only once per session since the goal is to be able to tweak the logging dynamically in an AppServer. I'd suggest logging a bug for the behaviour you're seeing and we'll come up with something. Maybe an idea for a file-watcher wouldn't go amiss either, so that we don't have to poll  :) .
 

> As a side, is this "Consultingwerk" github repro the official one for OpenEdge API's?  I've wondered that before.  It is certainly the repo that comes
> up first in google searches.

Consultingwerk takes the Zip files from https://knowledgebase.progress.com/articles/Article/P9621  and puts them into github for better readability.  There's not an official Progress one at this time.

 
 

Posted by dbeavon on 06-Feb-2020 16:17

Thanks again for the pointers.

This thread is closed