[
https://issues.apache.org/jira/browse/JAMES-3248?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17143600#comment-17143600
]
David Leangen commented on JAMES-3248:
--------------------------------------
A lot of improvement!! (y)
There is still a bit of unnecessary chatter about the logging system itself at
startup:
{noformat}
james_1 | 06:28:52,306 |-INFO in ch.qos.logback.classic.LoggerContext[default]
- Could NOT find resource
[/opt/apache-james/james-basic-server/conf/logback.xml]
james_1 | 06:28:52,307 |-INFO in ch.qos.logback.classic.LoggerContext[default]
- Could NOT find resource [logback-test.xml]
james_1 | 06:28:52,308 |-INFO in ch.qos.logback.classic.LoggerContext[default]
- Could NOT find resource [logback.groovy]
james_1 | 06:28:52,309 |-INFO in ch.qos.logback.classic.LoggerContext[default]
- Found resource [logback.xml] at
[jar:file:/opt/apache-james/james-basic-server/lib/james-server-jpa-guice-3.6.0-SNAPSHOT.jar!/logback.xml]
james_1 | 06:28:52,337 |-INFO in
ch.qos.logback.core.joran.spi.ConfigurationWatchList@3a52dba3 - URL
[jar:file:/opt/apache-james/james-basic-server/lib/james-server-jpa-guice-3.6.0-SNAPSHOT.jar!/logback.xml]
is not of type file
james_1 | 06:28:52,556 |-INFO in
ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not
set
james_1 | 06:28:52,558 |-INFO in
ch.qos.logback.classic.joran.action.LoggerContextListenerAction - Adding
LoggerContextListener of type
[ch.qos.logback.classic.jul.LevelChangePropagator] to the object stack
james_1 | 06:28:52,612 |-INFO in
ch.qos.logback.classic.jul.LevelChangePropagator@2a5c8d3f - Propagating DEBUG
level on Logger[ROOT] onto the JUL framework
james_1 | 06:28:52,613 |-INFO in
ch.qos.logback.classic.joran.action.LoggerContextListenerAction - Starting
LoggerContextListener
james_1 | 06:28:52,613 |-INFO in
ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender
of type [ch.qos.logback.core.ConsoleAppender]
james_1 | 06:28:52,619 |-INFO in
ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [CONSOLE]
james_1 | 06:28:52,623 |-INFO in
ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default
type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder]
property
james_1 | 06:28:52,628 |-WARN in
ch.qos.logback.classic.encoder.PatternLayoutEncoder@752325ad - As of version
1.2.0 "immediateFlush" property should be set within the enclosing Appender.
james_1 | 06:28:52,628 |-WARN in
ch.qos.logback.classic.encoder.PatternLayoutEncoder@752325ad - Please move
"immediateFlush" property into the enclosing appender.
james_1 | 06:28:52,728 |-WARN in
ch.qos.logback.classic.encoder.PatternLayoutEncoder@752325ad - Setting the
"immediateFlush" property of the enclosing appender to false
james_1 | 06:28:52,730 |-INFO in
ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT
logger to WARN
james_1 | 06:28:52,730 |-INFO in
ch.qos.logback.classic.jul.LevelChangePropagator@2a5c8d3f - Propagating WARN
level on Logger[ROOT] onto the JUL framework
james_1 | 06:28:52,730 |-INFO in
ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named
[CONSOLE] to Logger[ROOT]
james_1 | 06:28:52,732 |-INFO in
ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger
[org.apache.james] to INFO
james_1 | 06:28:52,732 |-INFO in
ch.qos.logback.classic.jul.LevelChangePropagator@2a5c8d3f - Propagating INFO
level on Logger[org.apache.james] onto the JUL framework
james_1 | 06:28:52,733 |-INFO in
ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
james_1 | 06:28:52,736 |-INFO in
ch.qos.logback.classic.joran.JoranConfigurator@279fedbd - Registering current
configuration as safe fallback point
{noformat}
Not sure if this is useful or not:
{noformat}
james_1 | 06:28:52.793 [INFO ] o.a.j.CONFIGURATION - Loading configuration
Basic{configurationPath=ConfigurationPath{value=file://conf/},
directories=JamesServerResourceLoader{rootDirectory=/opt/apache-james/james-basic-server,
varDirectory=/opt/apache-james/james-basic-server/var/,
confDirectory=/opt/apache-james/james-basic-server/conf/}}
{noformat}
General comment for this and other log entries given the context of the Basic
Server: are they necessary for "INFO"? (Make them "DEBUG"??) Or should the log
output be set to WARN?
*In any case*, log entires at INFO and above should never be too "technical".
If intended for developers, it should be DEBUG or lower. If for operators, it
should actually help them find and fix the problem, for instance by providing a
link to useful instructions. Confusing and over-verbose logs are just a PITA. :)
Same question about the following entry:
{noformat}
james_1 | 06:28:55.218 [INFO ] o.a.j.StartUpChecksPerformer - StartUpChecks
all succeeded
{noformat}
There is a series of configuration logs, which is probably not necessary. A
WARN should only be used if there is a potential problem. If the expected
behaviour is to use a default configuration, then is a WARN necessary? And in
the context of Basic, it is actually expected.
Is there any diagnostic view on the system OTHER than the logs? I.e., it is
possible to view config info for example via the CLI?
{noformat}
james_1 | 06:28:55.429 [INFO ] o.a.j.CONFIGURATION - Load configuration file
/opt/apache-james/james-basic-server/conf/healthcheck.properties
james_1 | 06:28:55.433 [WARN ] o.a.j.m.PeriodicalHealthChecksModule - Could
not find healthcheck configuration file, using default configuration
james_1 | 06:28:55.449 [INFO ] o.a.j.CONFIGURATION - Load configuration file
/opt/apache-james/james-basic-server/conf/james-database.properties
james_1 | 46 Global WARN [main] openjpa.Runtime - Could not create the
optional validation provider. Reason returned: "A default ValidatorFactory
could not be created."
james_1 | 06:28:56.081 [INFO ] o.a.j.CONFIGURATION - Load configuration file
/opt/apache-james/james-basic-server/conf/extensions.properties
james_1 | 06:28:56.082 [INFO ] o.a.j.u.ExtensionModule - No
extensions.properties configuration found. No additional Guice module will be
used for instantiating extensions.
james_1 | 06:28:56.114 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file mailrepositorystore.xml, assuming empty
configuration
james_1 | 06:28:56.124 [WARN ] o.a.j.m.s.MailStoreRepositoryModule - Empty
MailRepository store configuration supplied. Defaulting to default
configuration for this product
james_1 | 06:28:56.557 [WARN ] o.a.a.b.BrokerService - Memory Usage for the
Broker (1024mb) is more than the maximum available for the JVM: 986 mb -
resetting to 70% of maximum available: 690 mb
james_1 | 06:28:56.885 [WARN ] o.a.a.b.BrokerService - Store limit is 102400
mb (current store usage is 0 mb). The data directory:
/opt/apache-james/james-basic-server/var/store/activemq/brokers/KahaDB only has
58163 mb of usable space. - resetting to maximum available disk space: 58163 mb
james_1 | 06:28:56.913 [INFO ] o.a.j.q.a.EmbeddedActiveMQ - Started embedded
activeMq
james_1 | 06:28:57.058 [INFO ] o.a.j.CONFIGURATION - Load configuration file
/opt/apache-james/james-basic-server/conf/elasticsearch.properties
james_1 | 06:28:57.060 [INFO ] o.a.j.m.s.ElasticSearchMetricReporterModule -
Can not locate elasticsearch configuration
james_1 | 06:28:57.065 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file domainlist.xml, assuming empty configuration
james_1 | 1110 Global INFO [main] openjpa.Runtime - Starting OpenJPA 3.1.0
james_1 | 1202 Global INFO [main] openjpa.jdbc.JDBC - Using dictionary
class "org.apache.openjpa.jdbc.sql.DerbyDictionary".
james_1 | 2500 Global INFO [main] openjpa.jdbc.JDBC - Connected to Apache
Derby version 10.10 using JDBC driver Apache Derby Embedded JDBC Driver version
10.14.2.0 - (1828579).
james_1 | 06:29:00.003 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file listeners.xml, assuming empty configuration
james_1 | 06:29:00.191 [INFO ] o.a.j.CONFIGURATION - Load configuration file
/opt/apache-james/james-basic-server/conf/webadmin.properties
james_1 | 06:29:00.192 [INFO ] o.a.j.m.s.WebAdminServerModule - No
webadmin.properties file. Disabling WebAdmin interface.
james_1 | 06:29:01.423 [INFO ] o.a.j.CONFIGURATION - Load configuration file
/opt/apache-james/james-basic-server/conf/webadmin.properties
james_1 | 06:29:01.436 [INFO ] o.a.j.CONFIGURATION - Load configuration file
/opt/apache-james/james-basic-server/conf/jmx.properties
james_1 | 06:29:01.437 [WARN ] o.a.j.m.s.JMXServerModule - Could not locate
configuration file for JMX. Defaults to rmi://127.0.0.1:9999
james_1 | 06:29:01.468 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file dnsservice.xml, assuming empty configuration
james_1 | 06:29:01.468 [INFO ] o.a.j.d.d.DNSJavaService - Autodiscovery is
enabled - trying to discover your system's DNS Servers
james_1 | 06:29:01.477 [INFO ] o.a.j.d.d.DNSJavaService - Adding
autodiscovered server 127.0.0.11
james_1 | 06:29:01.479 [INFO ] o.a.j.d.d.DNSJavaService - DNS Server is:
127.0.0.11
james_1 | 06:29:01.492 [INFO ] o.a.j.d.d.DNSJavaService - Registered cache,
resolver and search paths as DNSJava defaults
james_1 | 06:29:01.539 [INFO ] o.a.j.m.m.MemoryMailRepositoryStore -
JamesMailStore init...
org.apache.james.mailrepository.memory.MemoryMailRepositoryStore@1b26fac2
james_1 | 06:29:01.541 [INFO ] o.a.j.d.l.AbstractDomainList - Set autodetect
to: false
james_1 | 06:29:01.541 [INFO ] o.a.j.d.l.AbstractDomainList - Set autodetectIP
to: false
james_1 | 06:29:01.974 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file usersrepository.xml, assuming empty configuration
james_1 | 06:29:01.976 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file recipientrewritetable.xml, assuming empty
configuration
james_1 | 06:29:01.978 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file mailetcontainer.xml, assuming empty configuration
james_1 | 06:29:01.978 [WARN ] o.a.j.m.s.CamelMailetContainerModule - Could
not locate configuration for Mailet context. Assuming empty configuration for
this component.
james_1 | 06:29:02.163 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file mailetcontainer.xml, assuming empty configuration
james_1 | 06:29:02.164 [WARN ] o.a.j.m.s.CamelMailetContainerModule - Could
not load configuration for Processors. Fallback to default.
james_1 | 06:29:02.434 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:02.445 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
PostmasterAlias instantiated.
james_1 | 06:29:02.450 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher RelayLimit=30 instantiated.
james_1 | 06:29:02.455 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
Null instantiated.
james_1 | 06:29:02.456 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:02.461 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
ToProcessor instantiated.
james_1 | 06:29:02.697 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:02.713 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
Bounce instantiated.
james_1 | 06:29:02.714 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:02.716 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
Null instantiated.
james_1 | 06:29:02.729 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher SMTPAuthSuccessful instantiated.
james_1 | 06:29:02.735 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
SetMimeHeader instantiated.
james_1 | 06:29:02.737 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:02.743 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
RemoveMimeHeader instantiated.
james_1 | 06:29:02.744 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:02.758 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
RecipientRewriteTable instantiated.
james_1 | 06:29:02.762 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher RecipientIsLocal instantiated.
james_1 | 06:29:02.775 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
LocalDelivery instantiated.
james_1 | 06:29:02.778 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher HostIsLocal instantiated.
james_1 | 06:29:02.780 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
ToProcessor instantiated.
james_1 | 06:29:02.781 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher SMTPAuthSuccessful instantiated.
james_1 | 06:29:02.805 [WARN ] o.a.j.t.m.r.d.DelaysAndMaxRetry - maxRetries is
larger than total number of attempts specified. Increasing last delayTime with
22 attempts
james_1 | 06:29:02.809 [WARN ] o.a.j.t.m.r.d.DelaysAndMaxRetry - Delay of 8
minutes 20 seconds is now attempted: 1 times
james_1 | 06:29:02.887 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
RemoteDelivery instantiated.
james_1 | 06:29:02.888 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:02.890 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
ToProcessor instantiated.
james_1 | 06:29:02.924 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:02.925 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
Null instantiated.
james_1 | 06:29:02.931 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:02.933 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
Bounce instantiated.
james_1 | 06:29:02.935 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:02.936 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
Null instantiated.
james_1 | 06:29:02.952 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:02.954 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
Bounce instantiated.
james_1 | 06:29:02.955 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:02.956 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
Null instantiated.
james_1 | 06:29:03.007 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor -
Matcher All instantiated.
james_1 | 06:29:03.022 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet
DSNBounce instantiated.
james_1 | 06:29:03.040 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file mailetcontainer.xml, assuming empty configuration
james_1 | 06:29:03.041 [WARN ] o.a.j.m.s.CamelMailetContainerModule - Could
not locate configuration for James Spooler. Assuming empty configuration for
this component.
james
{noformat}
Then some other questionable stuff:
{noformat}
james_1 | 06:29:03.044 [INFO ] o.a.j.m.i.JamesMailSpooler - init...
james_1 | 06:29:03.044 [INFO ] o.a.j.m.i.JamesMailSpooler - Concurrency level
is 100
james_1 | 06:29:03.047 [INFO ] o.a.j.m.i.JamesMailSpooler - Spooler started
james_1 | 06:29:03.089 [INFO ] o.a.j.r.f.AbstractFileRepository - Init
org.apache.james.repository.file.FilePersistentObjectRepository Store
james_1 | 06:29:03.101 [INFO ] o.a.j.r.f.AbstractFileRepository -
org.apache.james.repository.file.FilePersistentObjectRepository opened in
/opt/apache-james/james-basic-server/var/mail/error
james_1 | 06:29:03.103 [INFO ] o.a.j.r.f.AbstractFileRepository - Init
org.apache.james.repository.file.FilePersistentStreamRepository Store
james_1 | 06:29:03.103 [INFO ] o.a.j.r.f.AbstractFileRepository -
org.apache.james.repository.file.FilePersistentStreamRepository opened in
/opt/apache-james/james-basic-server/var/mail/error
james_1 | 06:29:03.164 [INFO ] o.a.j.m.m.MailboxListenersLoaderImpl - Loading
user registered mailbox listeners
james_1 | 06:29:03.169 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file imapserver.xml, assuming empty configuration
james_1 | 06:29:03.172 [INFO ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file lmtpserver.xml, assuming empty configuration
james_1 | 06:29:03.174 [INFO ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file managesieveserver.xml, assuming empty configuration
james_1 | 06:29:03.185 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file pop3server.xml, assuming empty configuration
james_1 | 06:29:03.187 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable
to locate configuration file smtpserver.xml, assuming empty configuration
{noformat}
And finally an entry that is actually truly useful and comprehensible to a
Basic Operator :) :
{noformat}
james_1 | 06:28:55.218 [INFO ] o.a.j.StartUpChecksPerformer - StartUpChecks
all succeeded
{noformat}
> Eliminate log warnings
> ----------------------
>
> Key: JAMES-3248
> URL: https://issues.apache.org/jira/browse/JAMES-3248
> Project: James Server
> Issue Type: Sub-task
> Reporter: David Leangen
> Priority: Major
>
> Warnings generated in the logs should be ideally completely eliminated, as it
> creates anxiety for the Basic Operator and is bad for mental health. ;)
> I will post the warnings here one by one so we can figure out how to deal
> with each of them (simple resolution, or something that requires a separate
> issue).
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
