Logging Changes

classic Classic list List threaded Threaded
16 messages Options
Reply | Threaded
Open this post in threaded view
|

Logging Changes

James Perkins
Hello All,
For WildFly 12 (maybe not until 13 at this stage) there are some thoughts on significantly changing the way logging is configured. Currently logging is initialized by reading a logging.properties file when JBoss Modules boots. While this works okay there are a few issues with this approach.

  1. For boot logging (before the logging subsystem is initialized) you can't use property expressions. This means when the logging subsystem rewrites the logging.properties file with all expressions expanded.
  2. Logging objects, such as handlers, cannot use resources from other subsystems. For example there is a need for a socket-handler. With the socket handler we need a way to get an SSL context from Elytron. There is no way for this to be done using a logging.properties file for the boot log configuration.
  3. If the user want to manually change the logging configuration by editing the XML they also have to edit the logging.properties. If not the old configuration will be used until the next boot.
It would be useful to introduce a way to queue log messages during boot [1]. Once the logging subsystem boot is complete the messages would be drained and sent to the new configuration. This of course isn't without it's own issues.

  1. Messages appeared delayed when WildFly is booting. Essentially all the boot messages are written at once so you see no messages, then all of them at once.
  2. A shutdown hook would have to be used in order to ensure errors that cause a boot failure are logged.
  3. This could get a little tricky with offline CLI as currently logging is configured based on the logging.properties file
  4. If users remove the logging subsystem there are more steps than just removing logging subsystem to get logging working.
  5. There will be a slight performance impact during boot. This can be greatly reduced if the caller calculation is disabled. This can be done in normal cases, but we likely can't make it the default. Note too this is only a boot impact. Once the logging subsystem takes over, the performance should be exactly the same as it was before.
There is some good however too. This does open the door allowing users to more easily replace the log manager implementation for standalone servers. Currently we still, and maybe always will, require the JBoss Log Manager to be used for domain servers, the host controller and process controller.

It also removes the need for a logging.properties for servers. I think this is a big bonus to the changes as logging for servers will only be configured in one place now. Domain will be a bit different, but we should likely introduce a logging subsystem on the host controller as well. I just don't think it makes much sense until we can sort out the issues above.

The current idea is that boot logging will be configurable via system properties. These properties would have to be set in the JAVA_OPTS.

I'm curious to hear any concerns others might have about this. This feels like a rather significant change so I'd rather get it right the first time.

I have started a design doc, but it's not finalized yet. If you're curious however you can have at look at it on my topic branch [2]. You can also see some of the small changes I've made to get it working on WildFly Core on that branch.



_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

David Lloyd-2
On Thu, Dec 7, 2017 at 2:02 PM, James Perkins <[hidden email]> wrote:
> There will be a slight performance impact during boot. This can be greatly
> reduced if the caller calculation is disabled. This can be done in normal
> cases, but we likely can't make it the default.

I suspect we can safely disable caller calculation by default on boot,
as long as users have an easy way to turn it on.

Also I think we should consider some kind of grimy hack to bootstrap
the logging subsystem first, if it's present, otherwise immediately
fall back to properties-based config if it's absent.

--
- DML
_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

Richard Opalka
In reply to this post by James Perkins
Hi James (all),

   What you outlined above is similar to effort [1] that was done for JDK 9.
Are there are any plans integrating this effort somehow with JDK9 or better
reuse what JDK9 already provides?
   I was doing some research few months back (but I didn't finish it yet) how
logging is done in JDK9. I was hoping for better JBoss-Logging integration
with JDK9 logging.
   Although I didn't finish it yet I'm posting here few analysis documents
I have created so far. I hope they will be helpful.

On Thu, Dec 7, 2017 at 9:02 PM, James Perkins <[hidden email]> wrote:
Hello All,
For WildFly 12 (maybe not until 13 at this stage) there are some thoughts on significantly changing the way logging is configured. Currently logging is initialized by reading a logging.properties file when JBoss Modules boots. While this works okay there are a few issues with this approach.

  1. For boot logging (before the logging subsystem is initialized) you can't use property expressions. This means when the logging subsystem rewrites the logging.properties file with all expressions expanded.
  2. Logging objects, such as handlers, cannot use resources from other subsystems. For example there is a need for a socket-handler. With the socket handler we need a way to get an SSL context from Elytron. There is no way for this to be done using a logging.properties file for the boot log configuration.
  3. If the user want to manually change the logging configuration by editing the XML they also have to edit the logging.properties. If not the old configuration will be used until the next boot.
It would be useful to introduce a way to queue log messages during boot [1]. Once the logging subsystem boot is complete the messages would be drained and sent to the new configuration. This of course isn't without it's own issues.

  1. Messages appeared delayed when WildFly is booting. Essentially all the boot messages are written at once so you see no messages, then all of them at once.
  2. A shutdown hook would have to be used in order to ensure errors that cause a boot failure are logged.
  3. This could get a little tricky with offline CLI as currently logging is configured based on the logging.properties file
  4. If users remove the logging subsystem there are more steps than just removing logging subsystem to get logging working.
  5. There will be a slight performance impact during boot. This can be greatly reduced if the caller calculation is disabled. This can be done in normal cases, but we likely can't make it the default. Note too this is only a boot impact. Once the logging subsystem takes over, the performance should be exactly the same as it was before.
There is some good however too. This does open the door allowing users to more easily replace the log manager implementation for standalone servers. Currently we still, and maybe always will, require the JBoss Log Manager to be used for domain servers, the host controller and process controller.

It also removes the need for a logging.properties for servers. I think this is a big bonus to the changes as logging for servers will only be configured in one place now. Domain will be a bit different, but we should likely introduce a logging subsystem on the host controller as well. I just don't think it makes much sense until we can sort out the issues above.

The current idea is that boot logging will be configurable via system properties. These properties would have to be set in the JAVA_OPTS.

I'm curious to hear any concerns others might have about this. This feels like a rather significant change so I'd rather get it right the first time.

I have started a design doc, but it's not finalized yet. If you're curious however you can have at look at it on my topic branch [2]. You can also see some of the small changes I've made to get it working on WildFly Core on that branch.



_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev



--
--
Richard Opalka
Principal Software Engineer
Red Hat JBoss Middleware
Mobile: +420 731 186 942
E-mail: [hidden email]


_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev

JdkLazyLogger_use_via_System.Logger_iface.pdf (38K) Download Attachment
JdkLazyLogger_use_via_PlatformLogger_iface.pdf (47K) Download Attachment
JDK9_System_Logger_Usage_Sequence_Diagram.pdf (35K) Download Attachment
JDK9_Platform_Logger_Usage_Sequence_Diagram.pdf (25K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

James Perkins
In reply to this post by David Lloyd-2
We could easily just allow the system property to be changed for the caller calculation. It would be fairly simple really.

Any hack would likely have to be done in the scripts would be my concern. I'm sure it's possible, but I'd rather not be messing with scripts if possible. Though maybe there is a way with a custom ConfigurationLocator. I'll have a look at that approach.

On Thu, Dec 7, 2017 at 3:46 PM, David Lloyd <[hidden email]> wrote:
On Thu, Dec 7, 2017 at 2:02 PM, James Perkins <[hidden email]> wrote:
> There will be a slight performance impact during boot. This can be greatly
> reduced if the caller calculation is disabled. This can be done in normal
> cases, but we likely can't make it the default.

I suspect we can safely disable caller calculation by default on boot,
as long as users have an easy way to turn it on.

Also I think we should consider some kind of grimy hack to bootstrap
the logging subsystem first, if it's present, otherwise immediately
fall back to properties-based config if it's absent.

--
- DML



--
James R. Perkins
JBoss by Red Hat

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

James Perkins
In reply to this post by Richard Opalka
That JEP unfortunately won't really help us here. The idea with that is the JDK itself, likely some tooling too, would just use a System.Logger which could be any logging implementation. It's not really meant to bootstrap anything it's just meant as a facade really. So if you wrote System.LoggerFinder implementation for log4j the JDK itself would log through log4j using the System.Logger.

I did experiment creating a JBoss Logging System.LoggerFinder, but I don't see much use in it as this point since we essentially use JUL which is the default finder. However if we do get to a point where we want the log manager in WildFly to be easily replaceable it may make since to have a System.LoggerFinder implementation.

On Fri, Dec 8, 2017 at 2:47 AM, Richard Opalka <[hidden email]> wrote:
Hi James (all),

   What you outlined above is similar to effort [1] that was done for JDK 9.
Are there are any plans integrating this effort somehow with JDK9 or better
reuse what JDK9 already provides?
   I was doing some research few months back (but I didn't finish it yet) how
logging is done in JDK9. I was hoping for better JBoss-Logging integration
with JDK9 logging.
   Although I didn't finish it yet I'm posting here few analysis documents
I have created so far. I hope they will be helpful.

On Thu, Dec 7, 2017 at 9:02 PM, James Perkins <[hidden email]> wrote:
Hello All,
For WildFly 12 (maybe not until 13 at this stage) there are some thoughts on significantly changing the way logging is configured. Currently logging is initialized by reading a logging.properties file when JBoss Modules boots. While this works okay there are a few issues with this approach.

  1. For boot logging (before the logging subsystem is initialized) you can't use property expressions. This means when the logging subsystem rewrites the logging.properties file with all expressions expanded.
  2. Logging objects, such as handlers, cannot use resources from other subsystems. For example there is a need for a socket-handler. With the socket handler we need a way to get an SSL context from Elytron. There is no way for this to be done using a logging.properties file for the boot log configuration.
  3. If the user want to manually change the logging configuration by editing the XML they also have to edit the logging.properties. If not the old configuration will be used until the next boot.
It would be useful to introduce a way to queue log messages during boot [1]. Once the logging subsystem boot is complete the messages would be drained and sent to the new configuration. This of course isn't without it's own issues.

  1. Messages appeared delayed when WildFly is booting. Essentially all the boot messages are written at once so you see no messages, then all of them at once.
  2. A shutdown hook would have to be used in order to ensure errors that cause a boot failure are logged.
  3. This could get a little tricky with offline CLI as currently logging is configured based on the logging.properties file
  4. If users remove the logging subsystem there are more steps than just removing logging subsystem to get logging working.
  5. There will be a slight performance impact during boot. This can be greatly reduced if the caller calculation is disabled. This can be done in normal cases, but we likely can't make it the default. Note too this is only a boot impact. Once the logging subsystem takes over, the performance should be exactly the same as it was before.
There is some good however too. This does open the door allowing users to more easily replace the log manager implementation for standalone servers. Currently we still, and maybe always will, require the JBoss Log Manager to be used for domain servers, the host controller and process controller.

It also removes the need for a logging.properties for servers. I think this is a big bonus to the changes as logging for servers will only be configured in one place now. Domain will be a bit different, but we should likely introduce a logging subsystem on the host controller as well. I just don't think it makes much sense until we can sort out the issues above.

The current idea is that boot logging will be configurable via system properties. These properties would have to be set in the JAVA_OPTS.

I'm curious to hear any concerns others might have about this. This feels like a rather significant change so I'd rather get it right the first time.

I have started a design doc, but it's not finalized yet. If you're curious however you can have at look at it on my topic branch [2]. You can also see some of the small changes I've made to get it working on WildFly Core on that branch.



_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev



--
--
Richard Opalka
Principal Software Engineer
Red Hat JBoss Middleware
Mobile: <a href="tel:+420%20731%20186%20942" value="+420731186942" target="_blank">+420 731 186 942
E-mail: [hidden email]




--
James R. Perkins
JBoss by Red Hat

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

Brian Stansberry
In reply to this post by David Lloyd-2


On Thu, Dec 7, 2017 at 5:46 PM, David Lloyd <[hidden email]> wrote:
On Thu, Dec 7, 2017 at 2:02 PM, James Perkins <[hidden email]> wrote:
> There will be a slight performance impact during boot. This can be greatly
> reduced if the caller calculation is disabled. This can be done in normal
> cases, but we likely can't make it the default.

I suspect we can safely disable caller calculation by default on boot,
as long as users have an easy way to turn it on.

Also I think we should consider some kind of grimy hack to bootstrap
the logging subsystem first, if it's present, otherwise immediately
fall back to properties-based config if it's absent.

I'm not sure what counts as first in this context, but fwiw if a logging subsystem is present during boot we always execute it's Stage.RUNTIME steps first before proceeding on to doing the parallel execution of the other subsystems. We could probably without too much trouble get a bit more grimy, e.g. to get the subsystem ops to run before a few others if they don't already. Beyond that I sense we wouldn't be talking grimy, we'd be talking horrible. :)

--
- DML
_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev



--
Brian Stansberry
Manager, Senior Principal Software Engineer
Red Hat

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

James Perkins


On Tue, Dec 12, 2017 at 9:37 AM, Brian Stansberry <[hidden email]> wrote:


On Thu, Dec 7, 2017 at 5:46 PM, David Lloyd <[hidden email]> wrote:
On Thu, Dec 7, 2017 at 2:02 PM, James Perkins <[hidden email]> wrote:
> There will be a slight performance impact during boot. This can be greatly
> reduced if the caller calculation is disabled. This can be done in normal
> cases, but we likely can't make it the default.

I suspect we can safely disable caller calculation by default on boot,
as long as users have an easy way to turn it on.

Also I think we should consider some kind of grimy hack to bootstrap
the logging subsystem first, if it's present, otherwise immediately
fall back to properties-based config if it's absent.

I'm not sure what counts as first in this context, but fwiw if a logging subsystem is present during boot we always execute it's Stage.RUNTIME steps first before proceeding on to doing the parallel execution of the other subsystems. We could probably without too much trouble get a bit more grimy, e.g. to get the subsystem ops to run before a few others if they don't already. Beyond that I sense we wouldn't be talking grimy, we'd be talking horrible. :)

Darran and I had a brief discussion about what we could do because at least parts of Elytron and logging are generally needed before other things are configured. Elytron would likely need to be first because logging will have to use capabilities from it.

I've wondered if there should be a new Stage.PRE_RUNTIME type of stage, but I can also see where that may get abused. 
 

--
- DML
_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev



--
Brian Stansberry
Manager, Senior Principal Software Engineer
Red Hat



--
James R. Perkins
JBoss by Red Hat

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

Brian Stansberry
On Tue, Dec 12, 2017 at 12:45 PM, James Perkins <[hidden email]> wrote:


On Tue, Dec 12, 2017 at 9:37 AM, Brian Stansberry <[hidden email]> wrote:


On Thu, Dec 7, 2017 at 5:46 PM, David Lloyd <[hidden email]> wrote:
On Thu, Dec 7, 2017 at 2:02 PM, James Perkins <[hidden email]> wrote:
> There will be a slight performance impact during boot. This can be greatly
> reduced if the caller calculation is disabled. This can be done in normal
> cases, but we likely can't make it the default.

I suspect we can safely disable caller calculation by default on boot,
as long as users have an easy way to turn it on.

Also I think we should consider some kind of grimy hack to bootstrap
the logging subsystem first, if it's present, otherwise immediately
fall back to properties-based config if it's absent.

I'm not sure what counts as first in this context, but fwiw if a logging subsystem is present during boot we always execute it's Stage.RUNTIME steps first before proceeding on to doing the parallel execution of the other subsystems. We could probably without too much trouble get a bit more grimy, e.g. to get the subsystem ops to run before a few others if they don't already. Beyond that I sense we wouldn't be talking grimy, we'd be talking horrible. :)

Darran and I had a brief discussion about what we could do because at least parts of Elytron and logging are generally needed before other things are configured. Elytron would likely need to be first because logging will have to use capabilities from it.

I've wondered if there should be a new Stage.PRE_RUNTIME type of stage, but I can also see where that may get abused. 

This is starting to smell bad.

Elytron needs DS it seems, and DS needs ? and, well, this is why we use MSC. :)  We hadn't had deps from logging to other subsystems before, which is what made the minor boot op ordering tricks we do useful, but since we now do, then we're really down to MSC. Boot op ordering tricks can help optimize common cases like a logging subsystem not having elytron dependencies, but I don't think we should try and create a duplicate MSC.
 
 

--
- DML
_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev



--
Brian Stansberry
Manager, Senior Principal Software Engineer
Red Hat



--
James R. Perkins
JBoss by Red Hat



--
Brian Stansberry
Manager, Senior Principal Software Engineer
Red Hat

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

David Lloyd-2
In reply to this post by Brian Stansberry
On Tue, Dec 12, 2017 at 11:37 AM, Brian Stansberry
<[hidden email]> wrote:

> On Thu, Dec 7, 2017 at 5:46 PM, David Lloyd <[hidden email]> wrote:
>> On Thu, Dec 7, 2017 at 2:02 PM, James Perkins <[hidden email]> wrote:
>> > There will be a slight performance impact during boot. This can be
>> > greatly
>> > reduced if the caller calculation is disabled. This can be done in
>> > normal
>> > cases, but we likely can't make it the default.
>>
>> I suspect we can safely disable caller calculation by default on boot,
>> as long as users have an easy way to turn it on.
>>
>> Also I think we should consider some kind of grimy hack to bootstrap
>> the logging subsystem first, if it's present, otherwise immediately
>> fall back to properties-based config if it's absent.
>>
> I'm not sure what counts as first in this context, but fwiw if a logging
> subsystem is present during boot we always execute it's Stage.RUNTIME steps
> first before proceeding on to doing the parallel execution of the other
> subsystems.

OK, that's exactly what I was alluding to, and we already do it, so
it's all fine then.

--
- DML
_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

James Perkins
In reply to this post by Brian Stansberry


On Tue, Dec 12, 2017 at 11:10 AM, Brian Stansberry <[hidden email]> wrote:

I'm not sure what counts as first in this context, but fwiw if a logging subsystem is present during boot we always execute it's Stage.RUNTIME steps first before proceeding on to doing the parallel execution of the other subsystems. We could probably without too much trouble get a bit more grimy, e.g. to get the subsystem ops to run before a few others if they don't already. Beyond that I sense we wouldn't be talking grimy, we'd be talking horrible. :)

Darran and I had a brief discussion about what we could do because at least parts of Elytron and logging are generally needed before other things are configured. Elytron would likely need to be first because logging will have to use capabilities from it.

I've wondered if there should be a new Stage.PRE_RUNTIME type of stage, but I can also see where that may get abused. 

This is starting to smell bad.

Elytron needs DS it seems, and DS needs ? and, well, this is why we use MSC. :)  We hadn't had deps from logging to other subsystems before, which is what made the minor boot op ordering tricks we do useful, but since we now do, then we're really down to MSC. Boot op ordering tricks can help optimize common cases like a logging subsystem not having elytron dependencies, but I don't think we should try and create a duplicate MSC.
 

Yes I definitely agree. I don't really think adding a new stage is a good idea.

The only real reason for logging to need a dependency on Elytron would be to get an SSLContext for sending log messages over a socket. We don't currently have a socket-handler and the syslog handler doesn't currently support SSL. However the syslog server for access logging does.

If we don't want to have logging rely on Elytron we'd just have to use the standard way of configuring an SSLContext.
 
--
Brian Stansberry
Manager, Senior Principal Software Engineer
Red Hat



--
James R. Perkins
JBoss by Red Hat

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

Brian Stansberry
On Tue, Dec 12, 2017 at 2:18 PM, James Perkins <[hidden email]> wrote:


On Tue, Dec 12, 2017 at 11:10 AM, Brian Stansberry <[hidden email]> wrote:

I'm not sure what counts as first in this context, but fwiw if a logging subsystem is present during boot we always execute it's Stage.RUNTIME steps first before proceeding on to doing the parallel execution of the other subsystems. We could probably without too much trouble get a bit more grimy, e.g. to get the subsystem ops to run before a few others if they don't already. Beyond that I sense we wouldn't be talking grimy, we'd be talking horrible. :)

Darran and I had a brief discussion about what we could do because at least parts of Elytron and logging are generally needed before other things are configured. Elytron would likely need to be first because logging will have to use capabilities from it.

I've wondered if there should be a new Stage.PRE_RUNTIME type of stage, but I can also see where that may get abused. 

This is starting to smell bad.

Elytron needs DS it seems, and DS needs ? and, well, this is why we use MSC. :)  We hadn't had deps from logging to other subsystems before, which is what made the minor boot op ordering tricks we do useful, but since we now do, then we're really down to MSC. Boot op ordering tricks can help optimize common cases like a logging subsystem not having elytron dependencies, but I don't think we should try and create a duplicate MSC.
 

Yes I definitely agree. I don't really think adding a new stage is a good idea.

The only real reason for logging to need a dependency on Elytron would be to get an SSLContext for sending log messages over a socket. We don't currently have a socket-handler and the syslog handler doesn't currently support SSL. However the syslog server for access logging does.

If we don't want to have logging rely on Elytron we'd just have to use the standard way of configuring an SSLContext.
 

I don't intend to advocate not relying on Elytron. But if a config does that I think it means some logging stuff isn't available until MSC says it is, and I guess that means queuing messages.

Is the queueing until the management op that installs the logging subsystem commits? Which basically means until the end of boot? If so that's an argument for splitting deployments out into a different chunk of boot ops from the deployments.

BTW, I'm not sure why a domain server would be different from a standalone one in terms of having to use JBoss Log Manager.

--
Brian Stansberry
Manager, Senior Principal Software Engineer
Red Hat

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

Brian Stansberry
In reply to this post by James Perkins
What would the system properties look like?

On Thu, Dec 7, 2017 at 2:02 PM, James Perkins <[hidden email]> wrote:
Hello All,
For WildFly 12 (maybe not until 13 at this stage) there are some thoughts on significantly changing the way logging is configured. Currently logging is initialized by reading a logging.properties file when JBoss Modules boots. While this works okay there are a few issues with this approach.

  1. For boot logging (before the logging subsystem is initialized) you can't use property expressions. This means when the logging subsystem rewrites the logging.properties file with all expressions expanded.
  2. Logging objects, such as handlers, cannot use resources from other subsystems. For example there is a need for a socket-handler. With the socket handler we need a way to get an SSL context from Elytron. There is no way for this to be done using a logging.properties file for the boot log configuration.
  3. If the user want to manually change the logging configuration by editing the XML they also have to edit the logging.properties. If not the old configuration will be used until the next boot.
It would be useful to introduce a way to queue log messages during boot [1]. Once the logging subsystem boot is complete the messages would be drained and sent to the new configuration. This of course isn't without it's own issues.

  1. Messages appeared delayed when WildFly is booting. Essentially all the boot messages are written at once so you see no messages, then all of them at once.
  2. A shutdown hook would have to be used in order to ensure errors that cause a boot failure are logged.
  3. This could get a little tricky with offline CLI as currently logging is configured based on the logging.properties file
  4. If users remove the logging subsystem there are more steps than just removing logging subsystem to get logging working.
  5. There will be a slight performance impact during boot. This can be greatly reduced if the caller calculation is disabled. This can be done in normal cases, but we likely can't make it the default. Note too this is only a boot impact. Once the logging subsystem takes over, the performance should be exactly the same as it was before.
There is some good however too. This does open the door allowing users to more easily replace the log manager implementation for standalone servers. Currently we still, and maybe always will, require the JBoss Log Manager to be used for domain servers, the host controller and process controller.

It also removes the need for a logging.properties for servers. I think this is a big bonus to the changes as logging for servers will only be configured in one place now. Domain will be a bit different, but we should likely introduce a logging subsystem on the host controller as well. I just don't think it makes much sense until we can sort out the issues above.

The current idea is that boot logging will be configurable via system properties. These properties would have to be set in the JAVA_OPTS.

I'm curious to hear any concerns others might have about this. This feels like a rather significant change so I'd rather get it right the first time.

I have started a design doc, but it's not finalized yet. If you're curious however you can have at look at it on my topic branch [2]. You can also see some of the small changes I've made to get it working on WildFly Core on that branch.



_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev



--
Brian Stansberry
Manager, Senior Principal Software Engineer
Red Hat

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

James Perkins
In reply to this post by Brian Stansberry


On Thu, Dec 14, 2017 at 1:23 PM, Brian Stansberry <[hidden email]> wrote:
On Tue, Dec 12, 2017 at 2:18 PM, James Perkins <[hidden email]> wrote:


On Tue, Dec 12, 2017 at 11:10 AM, Brian Stansberry <[hidden email]> wrote:

I'm not sure what counts as first in this context, but fwiw if a logging subsystem is present during boot we always execute it's Stage.RUNTIME steps first before proceeding on to doing the parallel execution of the other subsystems. We could probably without too much trouble get a bit more grimy, e.g. to get the subsystem ops to run before a few others if they don't already. Beyond that I sense we wouldn't be talking grimy, we'd be talking horrible. :)

Darran and I had a brief discussion about what we could do because at least parts of Elytron and logging are generally needed before other things are configured. Elytron would likely need to be first because logging will have to use capabilities from it.

I've wondered if there should be a new Stage.PRE_RUNTIME type of stage, but I can also see where that may get abused. 

This is starting to smell bad.

Elytron needs DS it seems, and DS needs ? and, well, this is why we use MSC. :)  We hadn't had deps from logging to other subsystems before, which is what made the minor boot op ordering tricks we do useful, but since we now do, then we're really down to MSC. Boot op ordering tricks can help optimize common cases like a logging subsystem not having elytron dependencies, but I don't think we should try and create a duplicate MSC.
 

Yes I definitely agree. I don't really think adding a new stage is a good idea.

The only real reason for logging to need a dependency on Elytron would be to get an SSLContext for sending log messages over a socket. We don't currently have a socket-handler and the syslog handler doesn't currently support SSL. However the syslog server for access logging does.

If we don't want to have logging rely on Elytron we'd just have to use the standard way of configuring an SSLContext.
 

I don't intend to advocate not relying on Elytron. But if a config does that I think it means some logging stuff isn't available until MSC says it is, and I guess that means queuing messages.

Is the queueing until the management op that installs the logging subsystem commits? Which basically means until the end of boot? If so that's an argument for splitting deployments out into a different chunk of boot ops from the deployments.

Yes. Log messages would be queued until the logging subsystem commits. There will also have to be some kind of way to discover there is no logging subsystem and fallback to a logging.properties file.

Splitting deployments out would probably have some benefit as it would cut down on the number of log messages. Currently if you set the level to something like DEBUG, which is what we'll have to default to in WildFly, it effectively sets the root logger to that level until the configuration has been completed. Likely not a huge deal, but something to consider for debugging/tracing with log messages.
 

BTW, I'm not sure why a domain server would be different from a standalone one in terms of having to use JBoss Log Manager.

Servers within a domain really shouldn't be too much of an issue. It's mainly the process controller and host controller I was speaking about that might be a bit different as they will still be controlled by a logging.properties file still. There is potential for the console messages to appear out of order I suppose too. Only if the console handler is used for all servers, the host controller and the process controller though.
 

--
Brian Stansberry
Manager, Senior Principal Software Engineer
Red Hat



--
James R. Perkins
JBoss by Red Hat

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

James Perkins
In reply to this post by Brian Stansberry


On Thu, Dec 14, 2017 at 1:28 PM, Brian Stansberry <[hidden email]> wrote:
What would the system properties look like?

I'm trying to use as few as possible, but right now they are:

* org.jboss.logmanager.bootstrap.enabled - A boolean property that determines whether or not the queuing should be done.
* org.jboss.logmanager.bootstrap.level - The log level, set on the root logger, that messages should be logged at. The default is DEBUG for WildFly.
* org.jboss.logmanager.bootstrap.queue-size - The default size of queue. The default is 10,000 and any messages after that will still be logged, however the first message is removed from the stack.
* org.jboss.logmanager.bootstrap.calculate.caller - A boolean property that indicates whether or not the caller should be calculated before the message is queued. In WildFly we'll have this disabled by default for performance.
* org.jboss.logmanager.bootstrap.fallback.config - This one may or may not stay. It will likely provide a path to the configuration file to use if a fallback is needed. A fallback will occur if the JVM exists before the logging subsystem is comitted or the logging subsystem is not available.
 

On Thu, Dec 7, 2017 at 2:02 PM, James Perkins <[hidden email]> wrote:
Hello All,
For WildFly 12 (maybe not until 13 at this stage) there are some thoughts on significantly changing the way logging is configured. Currently logging is initialized by reading a logging.properties file when JBoss Modules boots. While this works okay there are a few issues with this approach.

  1. For boot logging (before the logging subsystem is initialized) you can't use property expressions. This means when the logging subsystem rewrites the logging.properties file with all expressions expanded.
  2. Logging objects, such as handlers, cannot use resources from other subsystems. For example there is a need for a socket-handler. With the socket handler we need a way to get an SSL context from Elytron. There is no way for this to be done using a logging.properties file for the boot log configuration.
  3. If the user want to manually change the logging configuration by editing the XML they also have to edit the logging.properties. If not the old configuration will be used until the next boot.
It would be useful to introduce a way to queue log messages during boot [1]. Once the logging subsystem boot is complete the messages would be drained and sent to the new configuration. This of course isn't without it's own issues.

  1. Messages appeared delayed when WildFly is booting. Essentially all the boot messages are written at once so you see no messages, then all of them at once.
  2. A shutdown hook would have to be used in order to ensure errors that cause a boot failure are logged.
  3. This could get a little tricky with offline CLI as currently logging is configured based on the logging.properties file
  4. If users remove the logging subsystem there are more steps than just removing logging subsystem to get logging working.
  5. There will be a slight performance impact during boot. This can be greatly reduced if the caller calculation is disabled. This can be done in normal cases, but we likely can't make it the default. Note too this is only a boot impact. Once the logging subsystem takes over, the performance should be exactly the same as it was before.
There is some good however too. This does open the door allowing users to more easily replace the log manager implementation for standalone servers. Currently we still, and maybe always will, require the JBoss Log Manager to be used for domain servers, the host controller and process controller.

It also removes the need for a logging.properties for servers. I think this is a big bonus to the changes as logging for servers will only be configured in one place now. Domain will be a bit different, but we should likely introduce a logging subsystem on the host controller as well. I just don't think it makes much sense until we can sort out the issues above.

The current idea is that boot logging will be configurable via system properties. These properties would have to be set in the JAVA_OPTS.

I'm curious to hear any concerns others might have about this. This feels like a rather significant change so I'd rather get it right the first time.

I have started a design doc, but it's not finalized yet. If you're curious however you can have at look at it on my topic branch [2]. You can also see some of the small changes I've made to get it working on WildFly Core on that branch.



_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev



--
Brian Stansberry
Manager, Senior Principal Software Engineer
Red Hat



--
James R. Perkins
JBoss by Red Hat

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

Ken Wills-2
In reply to this post by James Perkins
I'm not so clear on a lot of the gritty details here, but I would caution against any sort of shutdown hook usage. For the embedded use case this is a bit of a problem, since they stack up until the user finally quits. There is a fairly clear need for an abstraction that executes on some sort of "executed unit of work," basis vs actually ends up calling exit().

Ken

On Thu, Dec 7, 2017 at 3:58 PM James Perkins <[hidden email]> wrote:
Hello All,
For WildFly 12 (maybe not until 13 at this stage) there are some thoughts on significantly changing the way logging is configured. Currently logging is initialized by reading a logging.properties file when JBoss Modules boots. While this works okay there are a few issues with this approach.

  1. For boot logging (before the logging subsystem is initialized) you can't use property expressions. This means when the logging subsystem rewrites the logging.properties file with all expressions expanded.
  2. Logging objects, such as handlers, cannot use resources from other subsystems. For example there is a need for a socket-handler. With the socket handler we need a way to get an SSL context from Elytron. There is no way for this to be done using a logging.properties file for the boot log configuration.
  3. If the user want to manually change the logging configuration by editing the XML they also have to edit the logging.properties. If not the old configuration will be used until the next boot.
It would be useful to introduce a way to queue log messages during boot [1]. Once the logging subsystem boot is complete the messages would be drained and sent to the new configuration. This of course isn't without it's own issues.

  1. Messages appeared delayed when WildFly is booting. Essentially all the boot messages are written at once so you see no messages, then all of them at once.
  2. A shutdown hook would have to be used in order to ensure errors that cause a boot failure are logged.
  3. This could get a little tricky with offline CLI as currently logging is configured based on the logging.properties file
  4. If users remove the logging subsystem there are more steps than just removing logging subsystem to get logging working.
  5. There will be a slight performance impact during boot. This can be greatly reduced if the caller calculation is disabled. This can be done in normal cases, but we likely can't make it the default. Note too this is only a boot impact. Once the logging subsystem takes over, the performance should be exactly the same as it was before.
There is some good however too. This does open the door allowing users to more easily replace the log manager implementation for standalone servers. Currently we still, and maybe always will, require the JBoss Log Manager to be used for domain servers, the host controller and process controller.

It also removes the need for a logging.properties for servers. I think this is a big bonus to the changes as logging for servers will only be configured in one place now. Domain will be a bit different, but we should likely introduce a logging subsystem on the host controller as well. I just don't think it makes much sense until we can sort out the issues above.

The current idea is that boot logging will be configurable via system properties. These properties would have to be set in the JAVA_OPTS.

I'm curious to hear any concerns others might have about this. This feels like a rather significant change so I'd rather get it right the first time.

I have started a design doc, but it's not finalized yet. If you're curious however you can have at look at it on my topic branch [2]. You can also see some of the small changes I've made to get it working on WildFly Core on that branch.


_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev
Reply | Threaded
Open this post in threaded view
|

Re: Logging Changes

James Perkins


On Thu, Dec 14, 2017 at 7:24 PM, Ken Wills <[hidden email]> wrote:
I'm not so clear on a lot of the gritty details here, but I would caution against any sort of shutdown hook usage. For the embedded use case this is a bit of a problem, since they stack up until the user finally quits. There is a fairly clear need for an abstraction that executes on some sort of "executed unit of work," basis vs actually ends up calling exit().

I think we're probably going to have to do some special handling for embedded. I made some minimal changes to get it working which seems work. However I did not test with errors that would stop logging from being fulling configured. Thanks for bringing this up as it will need to be tested for sure.
 

Ken

On Thu, Dec 7, 2017 at 3:58 PM James Perkins <[hidden email]> wrote:
Hello All,
For WildFly 12 (maybe not until 13 at this stage) there are some thoughts on significantly changing the way logging is configured. Currently logging is initialized by reading a logging.properties file when JBoss Modules boots. While this works okay there are a few issues with this approach.

  1. For boot logging (before the logging subsystem is initialized) you can't use property expressions. This means when the logging subsystem rewrites the logging.properties file with all expressions expanded.
  2. Logging objects, such as handlers, cannot use resources from other subsystems. For example there is a need for a socket-handler. With the socket handler we need a way to get an SSL context from Elytron. There is no way for this to be done using a logging.properties file for the boot log configuration.
  3. If the user want to manually change the logging configuration by editing the XML they also have to edit the logging.properties. If not the old configuration will be used until the next boot.
It would be useful to introduce a way to queue log messages during boot [1]. Once the logging subsystem boot is complete the messages would be drained and sent to the new configuration. This of course isn't without it's own issues.

  1. Messages appeared delayed when WildFly is booting. Essentially all the boot messages are written at once so you see no messages, then all of them at once.
  2. A shutdown hook would have to be used in order to ensure errors that cause a boot failure are logged.
  3. This could get a little tricky with offline CLI as currently logging is configured based on the logging.properties file
  4. If users remove the logging subsystem there are more steps than just removing logging subsystem to get logging working.
  5. There will be a slight performance impact during boot. This can be greatly reduced if the caller calculation is disabled. This can be done in normal cases, but we likely can't make it the default. Note too this is only a boot impact. Once the logging subsystem takes over, the performance should be exactly the same as it was before.
There is some good however too. This does open the door allowing users to more easily replace the log manager implementation for standalone servers. Currently we still, and maybe always will, require the JBoss Log Manager to be used for domain servers, the host controller and process controller.

It also removes the need for a logging.properties for servers. I think this is a big bonus to the changes as logging for servers will only be configured in one place now. Domain will be a bit different, but we should likely introduce a logging subsystem on the host controller as well. I just don't think it makes much sense until we can sort out the issues above.

The current idea is that boot logging will be configurable via system properties. These properties would have to be set in the JAVA_OPTS.

I'm curious to hear any concerns others might have about this. This feels like a rather significant change so I'd rather get it right the first time.

I have started a design doc, but it's not finalized yet. If you're curious however you can have at look at it on my topic branch [2]. You can also see some of the small changes I've made to get it working on WildFly Core on that branch.


_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev



--
James R. Perkins
JBoss by Red Hat

_______________________________________________
wildfly-dev mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/wildfly-dev