[C5] Java Util Logging vs Pax Logging for C5

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

[C5] Java Util Logging vs Pax Logging for C5

Kasun Gajasinghe
Hi,

We have done an initial POC on the affect of logging framework for the C5 server startup between SLF4J (via pax logging) and JUL. Below are the initial findings. 

TL;DR The c5 kernel starts in 0.7 seconds with JUL, a 350ms decrease compared to pax-logging. But the time taken to log under a load test is quiet high for JUL.

Product tested - wso2carbon-kernel-5.1.0-SNAPSHOT
JDK - 1.8.0_60
OS  - OS X El Capitan

Pax-Logging (SLF4J)Java Util Logging
startup1.059s0.705s
100k logs4.5s7.9s
1m logs23.482s57.723s


Current C5 kernel uses SLF4J API provided Pax-Logging. Pax-Logging uses Log4J 2 as the back-end. With that, the server startup is around 1.059s. The server startup decreased by around 350 ms after removing pax-logging and replacing the slf4j logs with java util logging. 

It seems that log4j2 loads ~750 classes to find classes with @Plugin annotation which causes this delay in the startup. This seems to be essential for its function.

Inline image 2

As the number of logs increases, the time taken to log all the log entries increased considerably with java util logging. 

Inline image 3

With these numbers, not sure whether we want to go with JUL.



-- 
Kasun Gajasinghe
Senior Software Engineer, WSO2 Inc.
email: kasung AT spamfree wso2.com
linked-in: http://lk.linkedin.com/in/gajasinghe
blog: http://kasunbg.org
 
 

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture
Kasun Gajasinghe
Software Engineer; WSO2 Inc.
http://kasunbg.org
Reply | Threaded
Open this post in threaded view
|

Re: [C5] Java Util Logging vs Pax Logging for C5

Samisa Abeysinghe-4
This model is about how to log. 

Can we also be clear on what to log? 

Basically, we see lots of log patches being shipped for C4 products. 
Ideally, they should all have been already there with debug level and rather than log patching we could have enabled debug only for that component/call and figured out what is going on. Please note that patching for just logging is always very costly. 

Do we have a solution/suggestion? 

(If this is not the right thread, then lets start a new one on this matter) 


Thanks,
Samisa...


Samisa Abeysinghe

Vice President Delivery 

WSO2 Inc. 
http://wso2.com


On Tue, May 24, 2016 at 3:36 PM, KasunG Gajasinghe <[hidden email]> wrote:
Hi,

We have done an initial POC on the affect of logging framework for the C5 server startup between SLF4J (via pax logging) and JUL. Below are the initial findings. 

TL;DR The c5 kernel starts in 0.7 seconds with JUL, a 350ms decrease compared to pax-logging. But the time taken to log under a load test is quiet high for JUL.

Product tested - wso2carbon-kernel-5.1.0-SNAPSHOT
JDK - 1.8.0_60
OS  - OS X El Capitan

Pax-Logging (SLF4J)Java Util Logging
startup1.059s0.705s
100k logs4.5s7.9s
1m logs23.482s57.723s


Current C5 kernel uses SLF4J API provided Pax-Logging. Pax-Logging uses Log4J 2 as the back-end. With that, the server startup is around 1.059s. The server startup decreased by around 350 ms after removing pax-logging and replacing the slf4j logs with java util logging. 

It seems that log4j2 loads ~750 classes to find classes with @Plugin annotation which causes this delay in the startup. This seems to be essential for its function.

Inline image 2

As the number of logs increases, the time taken to log all the log entries increased considerably with java util logging. 

Inline image 3

With these numbers, not sure whether we want to go with JUL.



-- 
Kasun Gajasinghe
Senior Software Engineer, WSO2 Inc.
email: kasung AT spamfree wso2.com
linked-in: http://lk.linkedin.com/in/gajasinghe
blog: http://kasunbg.org
 
 

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture



_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture
Reply | Threaded
Open this post in threaded view
|

Re: [C5] Java Util Logging vs Pax Logging for C5

Sameera Jayasoma
Hi Samisa,

I was also planning to start a thread on Logging strategy for C5 and also the exception handling strategy. I will try to comp up with a document. We can review it later. 

This thread is about performance of different logging APIs and backends.

Thanks,
Sameera.

On Fri, May 27, 2016 at 7:12 AM, Samisa Abeysinghe <[hidden email]> wrote:
This model is about how to log. 

Can we also be clear on what to log? 

Basically, we see lots of log patches being shipped for C4 products. 
Ideally, they should all have been already there with debug level and rather than log patching we could have enabled debug only for that component/call and figured out what is going on. Please note that patching for just logging is always very costly. 

Do we have a solution/suggestion? 

(If this is not the right thread, then lets start a new one on this matter) 


Thanks,
Samisa...


Samisa Abeysinghe

Vice President Delivery 

WSO2 Inc. 
http://wso2.com


On Tue, May 24, 2016 at 3:36 PM, KasunG Gajasinghe <[hidden email]> wrote:
Hi,

We have done an initial POC on the affect of logging framework for the C5 server startup between SLF4J (via pax logging) and JUL. Below are the initial findings. 

TL;DR The c5 kernel starts in 0.7 seconds with JUL, a 350ms decrease compared to pax-logging. But the time taken to log under a load test is quiet high for JUL.

Product tested - wso2carbon-kernel-5.1.0-SNAPSHOT
JDK - 1.8.0_60
OS  - OS X El Capitan

Pax-Logging (SLF4J)Java Util Logging
startup1.059s0.705s
100k logs4.5s7.9s
1m logs23.482s57.723s


Current C5 kernel uses SLF4J API provided Pax-Logging. Pax-Logging uses Log4J 2 as the back-end. With that, the server startup is around 1.059s. The server startup decreased by around 350 ms after removing pax-logging and replacing the slf4j logs with java util logging. 

It seems that log4j2 loads ~750 classes to find classes with @Plugin annotation which causes this delay in the startup. This seems to be essential for its function.

Inline image 2

As the number of logs increases, the time taken to log all the log entries increased considerably with java util logging. 

Inline image 3

With these numbers, not sure whether we want to go with JUL.



-- 
Kasun Gajasinghe
Senior Software Engineer, WSO2 Inc.
email: kasung AT spamfree wso2.com
linked-in: http://lk.linkedin.com/in/gajasinghe
blog: http://kasunbg.org
 
 

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture





--
Sameera Jayasoma,
Software Architect,

WSO2, Inc. (http://wso2.com)
email: [hidden email]
blog: 
http://blog.sameera.org
Mobile: 0094776364456

Lean . Enterprise . Middleware


_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture
Reply | Threaded
Open this post in threaded view
|

Re: [C5] Java Util Logging vs Pax Logging for C5

Samisa Abeysinghe-4


On Fri, May 27, 2016 at 7:27 AM, Sameera Jayasoma <[hidden email]> wrote:
Hi Samisa,

I was also planning to start a thread on Logging strategy for C5 and also the exception handling strategy. I will try to comp up with a document. We can review it later. 

​Great. May be we can start a new thread and discuss the issues we should handle for the time being, until we have time to attend a doc. 

This thread is about performance of different logging APIs and backends.

Thanks,
Sameera.

On Fri, May 27, 2016 at 7:12 AM, Samisa Abeysinghe <[hidden email]> wrote:
This model is about how to log. 

Can we also be clear on what to log? 

Basically, we see lots of log patches being shipped for C4 products. 
Ideally, they should all have been already there with debug level and rather than log patching we could have enabled debug only for that component/call and figured out what is going on. Please note that patching for just logging is always very costly. 

Do we have a solution/suggestion? 

(If this is not the right thread, then lets start a new one on this matter) 


Thanks,
Samisa...


Samisa Abeysinghe

Vice President Delivery 

WSO2 Inc. 
http://wso2.com


On Tue, May 24, 2016 at 3:36 PM, KasunG Gajasinghe <[hidden email]> wrote:
Hi,

We have done an initial POC on the affect of logging framework for the C5 server startup between SLF4J (via pax logging) and JUL. Below are the initial findings. 

TL;DR The c5 kernel starts in 0.7 seconds with JUL, a 350ms decrease compared to pax-logging. But the time taken to log under a load test is quiet high for JUL.

Product tested - wso2carbon-kernel-5.1.0-SNAPSHOT
JDK - 1.8.0_60
OS  - OS X El Capitan

Pax-Logging (SLF4J)Java Util Logging
startup1.059s0.705s
100k logs4.5s7.9s
1m logs23.482s57.723s


Current C5 kernel uses SLF4J API provided Pax-Logging. Pax-Logging uses Log4J 2 as the back-end. With that, the server startup is around 1.059s. The server startup decreased by around 350 ms after removing pax-logging and replacing the slf4j logs with java util logging. 

It seems that log4j2 loads ~750 classes to find classes with @Plugin annotation which causes this delay in the startup. This seems to be essential for its function.

Inline image 2

As the number of logs increases, the time taken to log all the log entries increased considerably with java util logging. 

Inline image 3

With these numbers, not sure whether we want to go with JUL.



-- 
Kasun Gajasinghe
Senior Software Engineer, WSO2 Inc.
email: kasung AT spamfree wso2.com
linked-in: http://lk.linkedin.com/in/gajasinghe
blog: http://kasunbg.org
 
 

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture





--
Sameera Jayasoma,
Software Architect,

WSO2, Inc. (http://wso2.com)
email: [hidden email]
blog: 
http://blog.sameera.org
Mobile: <a href="tel:0094776364456" value="+94776364456" target="_blank">0094776364456

Lean . Enterprise . Middleware



_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture
Reply | Threaded
Open this post in threaded view
|

Re: [C5] Java Util Logging vs Pax Logging for C5

Sameera Jayasoma


On Fri, May 27, 2016 at 7:30 AM, Samisa Abeysinghe <[hidden email]> wrote:


On Fri, May 27, 2016 at 7:27 AM, Sameera Jayasoma <[hidden email]> wrote:
Hi Samisa,

I was also planning to start a thread on Logging strategy for C5 and also the exception handling strategy. I will try to comp up with a document. We can review it later. 

​Great. May be we can start a new thread and discuss the issues we should handle for the time being, until we have time to attend a doc. 

+1.  

This thread is about performance of different logging APIs and backends.

Thanks,
Sameera.

On Fri, May 27, 2016 at 7:12 AM, Samisa Abeysinghe <[hidden email]> wrote:
This model is about how to log. 

Can we also be clear on what to log? 

Basically, we see lots of log patches being shipped for C4 products. 
Ideally, they should all have been already there with debug level and rather than log patching we could have enabled debug only for that component/call and figured out what is going on. Please note that patching for just logging is always very costly. 

Do we have a solution/suggestion? 

(If this is not the right thread, then lets start a new one on this matter) 


Thanks,
Samisa...


Samisa Abeysinghe

Vice President Delivery 

WSO2 Inc. 
http://wso2.com


On Tue, May 24, 2016 at 3:36 PM, KasunG Gajasinghe <[hidden email]> wrote:
Hi,

We have done an initial POC on the affect of logging framework for the C5 server startup between SLF4J (via pax logging) and JUL. Below are the initial findings. 

TL;DR The c5 kernel starts in 0.7 seconds with JUL, a 350ms decrease compared to pax-logging. But the time taken to log under a load test is quiet high for JUL.

Product tested - wso2carbon-kernel-5.1.0-SNAPSHOT
JDK - 1.8.0_60
OS  - OS X El Capitan

Pax-Logging (SLF4J)Java Util Logging
startup1.059s0.705s
100k logs4.5s7.9s
1m logs23.482s57.723s


Current C5 kernel uses SLF4J API provided Pax-Logging. Pax-Logging uses Log4J 2 as the back-end. With that, the server startup is around 1.059s. The server startup decreased by around 350 ms after removing pax-logging and replacing the slf4j logs with java util logging. 

It seems that log4j2 loads ~750 classes to find classes with @Plugin annotation which causes this delay in the startup. This seems to be essential for its function.

Inline image 2

As the number of logs increases, the time taken to log all the log entries increased considerably with java util logging. 

Inline image 3

With these numbers, not sure whether we want to go with JUL.



-- 
Kasun Gajasinghe
Senior Software Engineer, WSO2 Inc.
email: kasung AT spamfree wso2.com
linked-in: http://lk.linkedin.com/in/gajasinghe
blog: http://kasunbg.org
 
 

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture





--
Sameera Jayasoma,
Software Architect,

WSO2, Inc. (http://wso2.com)
email: [hidden email]
blog: 
http://blog.sameera.org
Mobile: <a href="tel:0094776364456" value="+94776364456" target="_blank">0094776364456

Lean . Enterprise . Middleware





--
Sameera Jayasoma,
Software Architect,

WSO2, Inc. (http://wso2.com)
email: [hidden email]
blog: 
http://blog.sameera.org
Mobile: 0094776364456

Lean . Enterprise . Middleware


_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture
Reply | Threaded
Open this post in threaded view
|

Re: [C5] Java Util Logging vs Pax Logging for C5

Afkham Azeez-2
In reply to this post by Kasun Gajasinghe
Your stress test is a purely theoretical one. There will be no instance where a server writes 100k logs or 1m logs simultaneously. If that happens, we will have other problems like quickly running out of disk space, for example. Hence I think for all practical purposes, JUL is good.

On Tue, May 24, 2016 at 3:36 PM, KasunG Gajasinghe <[hidden email]> wrote:
Hi,

We have done an initial POC on the affect of logging framework for the C5 server startup between SLF4J (via pax logging) and JUL. Below are the initial findings. 

TL;DR The c5 kernel starts in 0.7 seconds with JUL, a 350ms decrease compared to pax-logging. But the time taken to log under a load test is quiet high for JUL.

Product tested - wso2carbon-kernel-5.1.0-SNAPSHOT
JDK - 1.8.0_60
OS  - OS X El Capitan

Pax-Logging (SLF4J)Java Util Logging
startup1.059s0.705s
100k logs4.5s7.9s
1m logs23.482s57.723s


Current C5 kernel uses SLF4J API provided Pax-Logging. Pax-Logging uses Log4J 2 as the back-end. With that, the server startup is around 1.059s. The server startup decreased by around 350 ms after removing pax-logging and replacing the slf4j logs with java util logging. 

It seems that log4j2 loads ~750 classes to find classes with @Plugin annotation which causes this delay in the startup. This seems to be essential for its function.

Inline image 2

As the number of logs increases, the time taken to log all the log entries increased considerably with java util logging. 

Inline image 3

With these numbers, not sure whether we want to go with JUL.



-- 
Kasun Gajasinghe
Senior Software Engineer, WSO2 Inc.
email: kasung AT spamfree wso2.com
linked-in: http://lk.linkedin.com/in/gajasinghe
blog: http://kasunbg.org
 
 



--
Afkham Azeez
Director of ArchitectureWSO2, Inc.; http://wso2.com
Member; Apache Software Foundation; http://www.apache.org/

email:
[hidden email] cell: +94 77 3320919
blog:
http://blog.afkham.org
twitter:
http://twitter.com/afkham_azeez
linked-in:
http://lk.linkedin.com/in/afkhamazeez

Lean . Enterprise . Middleware

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture
Reply | Threaded
Open this post in threaded view
|

Re: [C5] Java Util Logging vs Pax Logging for C5

Kishanthan Thangarajah-2
From the platform point of view, we should provide a logging framework which should support most of the commonly used logging API's (JUL, Log4j, Commons, SLF4J, etc), which pax-logging is providing.

But as mentioned above, the concern with pax-logging-framework is that it is tightly coupled to log4j as the backend, which cause the delay with startup with log4j initialization. If thats the case, shall we check whether we could use JUL as backend here? 

Also the above test on log4j2.0 (pax-logging-framework) were using synchronous logging, but the performance will also improve when we use asynchronous logging support with log4j2.0 - https://logging.apache.org/log4j/2.x/manual/async.html

On Fri, May 27, 2016 at 11:50 AM, Afkham Azeez <[hidden email]> wrote:
Your stress test is a purely theoretical one. There will be no instance where a server writes 100k logs or 1m logs simultaneously. If that happens, we will have other problems like quickly running out of disk space, for example. Hence I think for all practical purposes, JUL is good.

On Tue, May 24, 2016 at 3:36 PM, KasunG Gajasinghe <[hidden email]> wrote:
Hi,

We have done an initial POC on the affect of logging framework for the C5 server startup between SLF4J (via pax logging) and JUL. Below are the initial findings. 

TL;DR The c5 kernel starts in 0.7 seconds with JUL, a 350ms decrease compared to pax-logging. But the time taken to log under a load test is quiet high for JUL.

Product tested - wso2carbon-kernel-5.1.0-SNAPSHOT
JDK - 1.8.0_60
OS  - OS X El Capitan

Pax-Logging (SLF4J)Java Util Logging
startup1.059s0.705s
100k logs4.5s7.9s
1m logs23.482s57.723s


Current C5 kernel uses SLF4J API provided Pax-Logging. Pax-Logging uses Log4J 2 as the back-end. With that, the server startup is around 1.059s. The server startup decreased by around 350 ms after removing pax-logging and replacing the slf4j logs with java util logging. 

It seems that log4j2 loads ~750 classes to find classes with @Plugin annotation which causes this delay in the startup. This seems to be essential for its function.

Inline image 2

As the number of logs increases, the time taken to log all the log entries increased considerably with java util logging. 

Inline image 3

With these numbers, not sure whether we want to go with JUL.



-- 
Kasun Gajasinghe
Senior Software Engineer, WSO2 Inc.
email: kasung AT spamfree wso2.com
linked-in: http://lk.linkedin.com/in/gajasinghe
blog: http://kasunbg.org
 
 



--
Afkham Azeez
Director of ArchitectureWSO2, Inc.; http://wso2.com
Member; Apache Software Foundation; http://www.apache.org/

email:
[hidden email] cell: <a href="tel:%2B94%2077%203320919" value="+94773320919" target="_blank">+94 77 3320919
blog:
http://blog.afkham.org
twitter:
http://twitter.com/afkham_azeez
linked-in:
http://lk.linkedin.com/in/afkhamazeez


Lean . Enterprise . Middleware



--
Kishanthan Thangarajah
Associate Technical Lead, 
Platform Technologies Team,
WSO2, Inc.
lean.enterprise.middleware

Mobile - +94773426635

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture
Reply | Threaded
Open this post in threaded view
|

Re: [C5] Java Util Logging vs Pax Logging for C5

Afkham Azeez-2
In production setups, if you keep printing 100k logs per minute for example, it is going to be very cumbersome to find stuff. We should be logging only the important things in production. So for all practical purposes, I believe JUL may be sufficient. 

Let us take an example;

Take a following code blocks:

Logging with JUL
long start = System.currentTimeMillis();
doSomething();
julLog.info("Log item 1");
System.out.println("Execution took " + (System.currentTimeMillis() - start) + "ms");

Logging with Log4J
long start = System.currentTimeMillis();
doSomething();
log4jLog.info("Log item 1");
System.out.println("Execution took " + (System.currentTimeMillis() - start) + "ms");


If the first code block takes significantly longer than the 2nd one, then there is an issue. Have we seen such a behavior?



On Fri, May 27, 2016 at 12:01 PM, Kishanthan Thangarajah <[hidden email]> wrote:
From the platform point of view, we should provide a logging framework which should support most of the commonly used logging API's (JUL, Log4j, Commons, SLF4J, etc), which pax-logging is providing.

But as mentioned above, the concern with pax-logging-framework is that it is tightly coupled to log4j as the backend, which cause the delay with startup with log4j initialization. If thats the case, shall we check whether we could use JUL as backend here? 

Also the above test on log4j2.0 (pax-logging-framework) were using synchronous logging, but the performance will also improve when we use asynchronous logging support with log4j2.0 - https://logging.apache.org/log4j/2.x/manual/async.html

On Fri, May 27, 2016 at 11:50 AM, Afkham Azeez <[hidden email]> wrote:
Your stress test is a purely theoretical one. There will be no instance where a server writes 100k logs or 1m logs simultaneously. If that happens, we will have other problems like quickly running out of disk space, for example. Hence I think for all practical purposes, JUL is good.

On Tue, May 24, 2016 at 3:36 PM, KasunG Gajasinghe <[hidden email]> wrote:
Hi,

We have done an initial POC on the affect of logging framework for the C5 server startup between SLF4J (via pax logging) and JUL. Below are the initial findings. 

TL;DR The c5 kernel starts in 0.7 seconds with JUL, a 350ms decrease compared to pax-logging. But the time taken to log under a load test is quiet high for JUL.

Product tested - wso2carbon-kernel-5.1.0-SNAPSHOT
JDK - 1.8.0_60
OS  - OS X El Capitan

Pax-Logging (SLF4J)Java Util Logging
startup1.059s0.705s
100k logs4.5s7.9s
1m logs23.482s57.723s


Current C5 kernel uses SLF4J API provided Pax-Logging. Pax-Logging uses Log4J 2 as the back-end. With that, the server startup is around 1.059s. The server startup decreased by around 350 ms after removing pax-logging and replacing the slf4j logs with java util logging. 

It seems that log4j2 loads ~750 classes to find classes with @Plugin annotation which causes this delay in the startup. This seems to be essential for its function.

Inline image 2

As the number of logs increases, the time taken to log all the log entries increased considerably with java util logging. 

Inline image 3

With these numbers, not sure whether we want to go with JUL.



-- 
Kasun Gajasinghe
Senior Software Engineer, WSO2 Inc.
email: kasung AT spamfree wso2.com
linked-in: http://lk.linkedin.com/in/gajasinghe
blog: http://kasunbg.org
 
 



--
Afkham Azeez
Director of ArchitectureWSO2, Inc.; http://wso2.com
Member; Apache Software Foundation; http://www.apache.org/

email:
[hidden email] cell: <a href="tel:%2B94%2077%203320919" value="+94773320919" target="_blank">+94 77 3320919
blog:
http://blog.afkham.org
twitter:
http://twitter.com/afkham_azeez
linked-in:
http://lk.linkedin.com/in/afkhamazeez


Lean . Enterprise . Middleware



--
Kishanthan Thangarajah
Associate Technical Lead, 
Platform Technologies Team,
WSO2, Inc.
lean.enterprise.middleware

Mobile - <a href="tel:%2B94773426635" value="+94773426635" target="_blank">+94773426635



--
Afkham Azeez
Director of ArchitectureWSO2, Inc.; http://wso2.com
Member; Apache Software Foundation; http://www.apache.org/

email:
[hidden email] cell: +94 77 3320919
blog:
http://blog.afkham.org
twitter:
http://twitter.com/afkham_azeez
linked-in:
http://lk.linkedin.com/in/afkhamazeez

Lean . Enterprise . Middleware

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture
Reply | Threaded
Open this post in threaded view
|

Re: [C5] Java Util Logging vs Pax Logging for C5

Ramith Jayasinghe
how about taking a couple of production logs (for existing products) and replay that compute the cost ?

On Fri, May 27, 2016 at 12:19 PM, Afkham Azeez <[hidden email]> wrote:
In production setups, if you keep printing 100k logs per minute for example, it is going to be very cumbersome to find stuff. We should be logging only the important things in production. So for all practical purposes, I believe JUL may be sufficient. 

Let us take an example;

Take a following code blocks:

Logging with JUL
long start = System.currentTimeMillis();
doSomething();
julLog.info("Log item 1");
System.out.println("Execution took " + (System.currentTimeMillis() - start) + "ms");

Logging with Log4J
long start = System.currentTimeMillis();
doSomething();
log4jLog.info("Log item 1");
System.out.println("Execution took " + (System.currentTimeMillis() - start) + "ms");


If the first code block takes significantly longer than the 2nd one, then there is an issue. Have we seen such a behavior?



On Fri, May 27, 2016 at 12:01 PM, Kishanthan Thangarajah <[hidden email]> wrote:
From the platform point of view, we should provide a logging framework which should support most of the commonly used logging API's (JUL, Log4j, Commons, SLF4J, etc), which pax-logging is providing.

But as mentioned above, the concern with pax-logging-framework is that it is tightly coupled to log4j as the backend, which cause the delay with startup with log4j initialization. If thats the case, shall we check whether we could use JUL as backend here? 

Also the above test on log4j2.0 (pax-logging-framework) were using synchronous logging, but the performance will also improve when we use asynchronous logging support with log4j2.0 - https://logging.apache.org/log4j/2.x/manual/async.html

On Fri, May 27, 2016 at 11:50 AM, Afkham Azeez <[hidden email]> wrote:
Your stress test is a purely theoretical one. There will be no instance where a server writes 100k logs or 1m logs simultaneously. If that happens, we will have other problems like quickly running out of disk space, for example. Hence I think for all practical purposes, JUL is good.

On Tue, May 24, 2016 at 3:36 PM, KasunG Gajasinghe <[hidden email]> wrote:
Hi,

We have done an initial POC on the affect of logging framework for the C5 server startup between SLF4J (via pax logging) and JUL. Below are the initial findings. 

TL;DR The c5 kernel starts in 0.7 seconds with JUL, a 350ms decrease compared to pax-logging. But the time taken to log under a load test is quiet high for JUL.

Product tested - wso2carbon-kernel-5.1.0-SNAPSHOT
JDK - 1.8.0_60
OS  - OS X El Capitan

Pax-Logging (SLF4J)Java Util Logging
startup1.059s0.705s
100k logs4.5s7.9s
1m logs23.482s57.723s


Current C5 kernel uses SLF4J API provided Pax-Logging. Pax-Logging uses Log4J 2 as the back-end. With that, the server startup is around 1.059s. The server startup decreased by around 350 ms after removing pax-logging and replacing the slf4j logs with java util logging. 

It seems that log4j2 loads ~750 classes to find classes with @Plugin annotation which causes this delay in the startup. This seems to be essential for its function.

Inline image 2

As the number of logs increases, the time taken to log all the log entries increased considerably with java util logging. 

Inline image 3

With these numbers, not sure whether we want to go with JUL.



-- 
Kasun Gajasinghe
Senior Software Engineer, WSO2 Inc.
email: kasung AT spamfree wso2.com
linked-in: http://lk.linkedin.com/in/gajasinghe
blog: http://kasunbg.org
 
 



--
Afkham Azeez
Director of ArchitectureWSO2, Inc.; http://wso2.com
Member; Apache Software Foundation; http://www.apache.org/

email:
[hidden email] cell: <a href="tel:%2B94%2077%203320919" value="+94773320919" target="_blank">+94 77 3320919
blog:
http://blog.afkham.org
twitter:
http://twitter.com/afkham_azeez
linked-in:
http://lk.linkedin.com/in/afkhamazeez


Lean . Enterprise . Middleware



--
Kishanthan Thangarajah
Associate Technical Lead, 
Platform Technologies Team,
WSO2, Inc.
lean.enterprise.middleware

Mobile - <a href="tel:%2B94773426635" value="+94773426635" target="_blank">+94773426635



--
Afkham Azeez
Director of ArchitectureWSO2, Inc.; http://wso2.com
Member; Apache Software Foundation; http://www.apache.org/

email:
[hidden email] cell: <a href="tel:%2B94%2077%203320919" value="+94773320919" target="_blank">+94 77 3320919
blog:
http://blog.afkham.org
twitter:
http://twitter.com/afkham_azeez
linked-in:
http://lk.linkedin.com/in/afkhamazeez

Lean . Enterprise . Middleware

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture




--
Ramith Jayasinghe
Technical Lead
WSO2 Inc., http://wso2.com
lean.enterprise.middleware

E: [hidden email]
P: +94 772534930

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture
Reply | Threaded
Open this post in threaded view
|

Re: [C5] Java Util Logging vs Pax Logging for C5

Isuru Perera
Did anyone look at Java Microbenchmarks (JMH) for Log4j 2? Those are available in [1] and results are mentioned in [2]

If we are also trying to benchmark, I recommend to use JMH [3]

On Fri, May 27, 2016 at 12:25 PM, Ramith Jayasinghe <[hidden email]> wrote:
how about taking a couple of production logs (for existing products) and replay that compute the cost ?

On Fri, May 27, 2016 at 12:19 PM, Afkham Azeez <[hidden email]> wrote:
In production setups, if you keep printing 100k logs per minute for example, it is going to be very cumbersome to find stuff. We should be logging only the important things in production. So for all practical purposes, I believe JUL may be sufficient. 

Let us take an example;

Take a following code blocks:

Logging with JUL
long start = System.currentTimeMillis();
doSomething();
julLog.info("Log item 1");
System.out.println("Execution took " + (System.currentTimeMillis() - start) + "ms");

Logging with Log4J
long start = System.currentTimeMillis();
doSomething();
log4jLog.info("Log item 1");
System.out.println("Execution took " + (System.currentTimeMillis() - start) + "ms");


If the first code block takes significantly longer than the 2nd one, then there is an issue. Have we seen such a behavior?



On Fri, May 27, 2016 at 12:01 PM, Kishanthan Thangarajah <[hidden email]> wrote:
From the platform point of view, we should provide a logging framework which should support most of the commonly used logging API's (JUL, Log4j, Commons, SLF4J, etc), which pax-logging is providing.

But as mentioned above, the concern with pax-logging-framework is that it is tightly coupled to log4j as the backend, which cause the delay with startup with log4j initialization. If thats the case, shall we check whether we could use JUL as backend here? 

Also the above test on log4j2.0 (pax-logging-framework) were using synchronous logging, but the performance will also improve when we use asynchronous logging support with log4j2.0 - https://logging.apache.org/log4j/2.x/manual/async.html

On Fri, May 27, 2016 at 11:50 AM, Afkham Azeez <[hidden email]> wrote:
Your stress test is a purely theoretical one. There will be no instance where a server writes 100k logs or 1m logs simultaneously. If that happens, we will have other problems like quickly running out of disk space, for example. Hence I think for all practical purposes, JUL is good.

On Tue, May 24, 2016 at 3:36 PM, KasunG Gajasinghe <[hidden email]> wrote:
Hi,

We have done an initial POC on the affect of logging framework for the C5 server startup between SLF4J (via pax logging) and JUL. Below are the initial findings. 

TL;DR The c5 kernel starts in 0.7 seconds with JUL, a 350ms decrease compared to pax-logging. But the time taken to log under a load test is quiet high for JUL.

Product tested - wso2carbon-kernel-5.1.0-SNAPSHOT
JDK - 1.8.0_60
OS  - OS X El Capitan

Pax-Logging (SLF4J)Java Util Logging
startup1.059s0.705s
100k logs4.5s7.9s
1m logs23.482s57.723s


Current C5 kernel uses SLF4J API provided Pax-Logging. Pax-Logging uses Log4J 2 as the back-end. With that, the server startup is around 1.059s. The server startup decreased by around 350 ms after removing pax-logging and replacing the slf4j logs with java util logging. 

It seems that log4j2 loads ~750 classes to find classes with @Plugin annotation which causes this delay in the startup. This seems to be essential for its function.

Inline image 2

As the number of logs increases, the time taken to log all the log entries increased considerably with java util logging. 

Inline image 3

With these numbers, not sure whether we want to go with JUL.



-- 
Kasun Gajasinghe
Senior Software Engineer, WSO2 Inc.
email: kasung AT spamfree wso2.com
linked-in: http://lk.linkedin.com/in/gajasinghe
blog: http://kasunbg.org
 
 



--
Afkham Azeez
Director of ArchitectureWSO2, Inc.; http://wso2.com
Member; Apache Software Foundation; http://www.apache.org/

email:
[hidden email] cell: <a href="tel:%2B94%2077%203320919" value="+94773320919" target="_blank">+94 77 3320919
blog:
http://blog.afkham.org
twitter:
http://twitter.com/afkham_azeez
linked-in:
http://lk.linkedin.com/in/afkhamazeez


Lean . Enterprise . Middleware



--
Kishanthan Thangarajah
Associate Technical Lead, 
Platform Technologies Team,
WSO2, Inc.
lean.enterprise.middleware

Mobile - <a href="tel:%2B94773426635" value="+94773426635" target="_blank">+94773426635



--
Afkham Azeez
Director of ArchitectureWSO2, Inc.; http://wso2.com
Member; Apache Software Foundation; http://www.apache.org/

email:
[hidden email] cell: <a href="tel:%2B94%2077%203320919" value="+94773320919" target="_blank">+94 77 3320919
blog:
http://blog.afkham.org
twitter:
http://twitter.com/afkham_azeez
linked-in:
http://lk.linkedin.com/in/afkhamazeez

Lean . Enterprise . Middleware

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture




--
Ramith Jayasinghe
Technical Lead
WSO2 Inc., http://wso2.com
lean.enterprise.middleware

E: [hidden email]
P: <a href="tel:%2B94%20772534930" value="+94772534930" target="_blank">+94 772534930

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture




--
Isuru Perera
Associate Technical Lead | WSO2, Inc. | http://wso2.com/
Lean . Enterprise . Middleware

about.me/chrishantha

_______________________________________________
Architecture mailing list
[hidden email]
https://mail.wso2.org/cgi-bin/mailman/listinfo/architecture