You are viewing a plain text version of this content. The canonical link for it is here.
Posted to server-dev@james.apache.org by "David Leangen (Jira)" <se...@james.apache.org> on 2020/06/25 04:35:00 UTC

[jira] [Commented] (JAMES-3251) Reduce INFO chatter for Basic Server

    [ https://issues.apache.org/jira/browse/JAMES-3251?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17144640#comment-17144640 ] 

David Leangen commented on JAMES-3251:
--------------------------------------

Current output as of 2020-06-25:

{noformat}
james_1  | 14:02:36,033 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [/opt/apache-james/james-basic-server/conf/logback.xml]
james_1  | 14:02:36,034 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
james_1  | 14:02:36,035 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
james_1  | 14:02:36,038 |-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  | 14:02:36,065 |-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  | 14:02:36,320 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
james_1  | 14:02:36,322 |-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  | 14:02:36,379 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@2a5c8d3f - Propagating DEBUG level on Logger[ROOT] onto the JUL framework
james_1  | 14:02:36,380 |-INFO in ch.qos.logback.classic.joran.action.LoggerContextListenerAction - Starting LoggerContextListener
james_1  | 14:02:36,380 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
james_1  | 14:02:36,386 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [CONSOLE]
james_1  | 14:02:36,389 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
james_1  | 14:02:36,396 |-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  | 14:02:36,396 |-WARN in ch.qos.logback.classic.encoder.PatternLayoutEncoder@752325ad - Please move "immediateFlush" property into the enclosing appender.
james_1  | 14:02:36,512 |-WARN in ch.qos.logback.classic.encoder.PatternLayoutEncoder@752325ad - Setting the "immediateFlush" property of the enclosing appender to false
james_1  | 14:02:36,513 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to WARN
james_1  | 14:02:36,513 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@2a5c8d3f - Propagating WARN level on Logger[ROOT] onto the JUL framework
james_1  | 14:02:36,513 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[ROOT]
james_1  | 14:02:36,514 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.apache.james] to INFO
james_1  | 14:02:36,514 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@2a5c8d3f - Propagating INFO level on Logger[org.apache.james] onto the JUL framework
james_1  | 14:02:36,515 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
james_1  | 14:02:36,520 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@279fedbd - Registering current configuration as safe fallback point
james_1  | 
james_1  | 14:02:36.576 [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/}}
james_1  | WARNING: An illegal reflective access operation has occurred
james_1  | WARNING: Illegal reflective access by com.google.inject.internal.cglib.core.$ReflectUtils$1 (file:/opt/apache-james/james-basic-server/lib/guice-4.2.2.jar) to method java.lang.ClassLoader.defineClass(java.lang.String,byte[],int,int,java.security.ProtectionDomain)
james_1  | WARNING: Please consider reporting this to the maintainers of com.google.inject.internal.cglib.core.$ReflectUtils$1
james_1  | WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
james_1  | WARNING: All illegal access operations will be denied in a future release
james_1  | 14:02:39.035 [INFO ] o.a.j.StartUpChecksPerformer - StartUpChecks all succeeded
james_1  | 14:02:39.270 [INFO ] o.a.j.CONFIGURATION - Load configuration file /opt/apache-james/james-basic-server/conf/healthcheck.properties
james_1  | 14:02:39.273 [WARN ] o.a.j.m.PeriodicalHealthChecksModule - Could not find healthcheck configuration file, using default configuration
james_1  | 14:02:39.287 [INFO ] o.a.j.CONFIGURATION - Load configuration file /opt/apache-james/james-basic-server/conf/james-database.properties
james_1  | 48  Global  WARN   [main] openjpa.Runtime - Could not create the optional validation provider. Reason returned: "A default ValidatorFactory could not be created."
james_1  | 14:02:39.984 [INFO ] o.a.j.CONFIGURATION - Load configuration file /opt/apache-james/james-basic-server/conf/extensions.properties
james_1  | 14:02:40.045 [INFO ] o.a.j.u.ExtensionModule - No extensions.properties configuration found. No additional Guice module will be used for instantiating extensions.
james_1  | 14:02:40.077 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file mailrepositorystore.xml, assuming empty configuration
james_1  | 14:02:40.087 [WARN ] o.a.j.m.s.MailStoreRepositoryModule - Empty MailRepository store configuration supplied. Defaulting to default configuration for this product
james_1  | 14:02:40.544 [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  | 14:02:40.892 [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 55732 mb of usable space. - resetting to maximum available disk space: 55732 mb
james_1  | 14:02:40.923 [INFO ] o.a.j.q.a.EmbeddedActiveMQ - Started embedded activeMq
james_1  | 14:02:41.069 [INFO ] o.a.j.CONFIGURATION - Load configuration file /opt/apache-james/james-basic-server/conf/elasticsearch.properties
james_1  | 14:02:41.070 [INFO ] o.a.j.m.s.ElasticSearchMetricReporterModule - Can not locate elasticsearch configuration
james_1  | 14:02:41.074 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file domainlist.xml, assuming empty configuration
james_1  | 1200  Global  INFO   [main] openjpa.Runtime - Starting OpenJPA 3.1.0
james_1  | 1285  Global  INFO   [main] openjpa.jdbc.JDBC - Using dictionary class "org.apache.openjpa.jdbc.sql.DerbyDictionary".
james_1  | 2660  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  | 14:02:44.239 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file listeners.xml, assuming empty configuration
james_1  | 14:02:44.423 [INFO ] o.a.j.CONFIGURATION - Load configuration file /opt/apache-james/james-basic-server/conf/webadmin.properties
james_1  | 14:02:44.424 [INFO ] o.a.j.m.s.WebAdminServerModule - No webadmin.properties file. Disabling WebAdmin interface.
james_1  | 14:02:45.660 [INFO ] o.a.j.CONFIGURATION - Load configuration file /opt/apache-james/james-basic-server/conf/webadmin.properties
james_1  | 14:02:45.673 [INFO ] o.a.j.CONFIGURATION - Load configuration file /opt/apache-james/james-basic-server/conf/jmx.properties
james_1  | 14:02:45.674 [WARN ] o.a.j.m.s.JMXServerModule - Could not locate configuration file for JMX. Defaults to rmi://127.0.0.1:9999
james_1  | 14:02:45.702 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file dnsservice.xml, assuming empty configuration
james_1  | 14:02:45.702 [INFO ] o.a.j.d.d.DNSJavaService - Autodiscovery is enabled - trying to discover your system's DNS Servers
james_1  | 14:02:45.712 [INFO ] o.a.j.d.d.DNSJavaService - Adding autodiscovered server 127.0.0.11
james_1  | 14:02:45.716 [INFO ] o.a.j.d.d.DNSJavaService - DNS Server is: 127.0.0.11
james_1  | 14:02:45.733 [INFO ] o.a.j.d.d.DNSJavaService - Registered cache, resolver and search paths as DNSJava defaults
james_1  | 14:02:45.798 [INFO ] o.a.j.m.m.MemoryMailRepositoryStore - JamesMailStore init... org.apache.james.mailrepository.memory.MemoryMailRepositoryStore@1b26fac2
james_1  | 14:02:45.800 [INFO ] o.a.j.d.l.AbstractDomainList - Set autodetect to: false
james_1  | 14:02:45.801 [INFO ] o.a.j.d.l.AbstractDomainList - Set autodetectIP to: false
james_1  | 14:02:46.212 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file usersrepository.xml, assuming empty configuration
james_1  | 14:02:46.215 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file recipientrewritetable.xml, assuming empty configuration
james_1  | 14:02:46.216 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file mailetcontainer.xml, assuming empty configuration
james_1  | 14:02:46.218 [WARN ] o.a.j.m.s.CamelMailetContainerModule - Could not locate configuration for Mailet context. Assuming empty configuration for this component.
james_1  | 14:02:46.398 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file mailetcontainer.xml, assuming empty configuration
james_1  | 14:02:46.398 [WARN ] o.a.j.m.s.CamelMailetContainerModule - Could not load configuration for Processors. Fallback to default.
james_1  | 14:02:46.675 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:46.684 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet PostmasterAlias instantiated.
james_1  | 14:02:46.687 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher RelayLimit=30 instantiated.
james_1  | 14:02:46.691 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet Null instantiated.
james_1  | 14:02:46.692 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:46.696 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet ToProcessor instantiated.
james_1  | 14:02:46.948 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:46.965 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet Bounce instantiated.
james_1  | 14:02:46.966 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:46.968 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet Null instantiated.
james_1  | 14:02:46.985 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher SMTPAuthSuccessful instantiated.
james_1  | 14:02:46.994 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet SetMimeHeader instantiated.
james_1  | 14:02:46.995 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:47.002 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet RemoveMimeHeader instantiated.
james_1  | 14:02:47.003 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:47.019 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet RecipientRewriteTable instantiated.
james_1  | 14:02:47.023 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher RecipientIsLocal instantiated.
james_1  | 14:02:47.039 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet LocalDelivery instantiated.
james_1  | 14:02:47.045 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher HostIsLocal instantiated.
james_1  | 14:02:47.050 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet ToProcessor instantiated.
james_1  | 14:02:47.051 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher SMTPAuthSuccessful instantiated.
james_1  | 14:02:47.085 [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  | 14:02:47.087 [WARN ] o.a.j.t.m.r.d.DelaysAndMaxRetry - Delay of 8 minutes 20 seconds is now attempted: 1 times
james_1  | 14:02:47.168 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet RemoteDelivery instantiated.
james_1  | 14:02:47.169 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:47.182 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet ToProcessor instantiated.
james_1  | 14:02:47.216 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:47.217 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet Null instantiated.
james_1  | 14:02:47.226 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:47.230 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet Bounce instantiated.
james_1  | 14:02:47.231 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:47.232 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet Null instantiated.
james_1  | 14:02:47.254 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:47.256 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet Bounce instantiated.
james_1  | 14:02:47.257 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:47.260 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet Null instantiated.
james_1  | 14:02:47.271 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Matcher All instantiated.
james_1  | 14:02:47.285 [INFO ] o.a.j.m.l.AbstractStateMailetProcessor - Mailet DSNBounce instantiated.
james_1  | 14:02:47.300 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file mailetcontainer.xml, assuming empty configuration
james_1  | 14:02:47.307 [WARN ] o.a.j.m.s.CamelMailetContainerModule - Could not locate configuration for James Spooler. Assuming empty configuration for this component.
james_1  | 14:02:47.316 [INFO ] o.a.j.m.i.JamesMailSpooler - init...
james_1  | 14:02:47.316 [INFO ] o.a.j.m.i.JamesMailSpooler - Concurrency level is 100
james_1  | 14:02:47.320 [INFO ] o.a.j.m.i.JamesMailSpooler - Spooler started
james_1  | 14:02:47.359 [INFO ] o.a.j.r.f.AbstractFileRepository - Init org.apache.james.repository.file.FilePersistentObjectRepository Store
james_1  | 14:02:47.373 [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  | 14:02:47.375 [INFO ] o.a.j.r.f.AbstractFileRepository - Init org.apache.james.repository.file.FilePersistentStreamRepository Store
james_1  | 14:02:47.376 [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  | 14:02:47.447 [INFO ] o.a.j.m.m.MailboxListenersLoaderImpl - Loading user registered mailbox listeners
james_1  | 14:02:47.453 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file imapserver.xml, assuming empty configuration
james_1  | 14:02:47.456 [INFO ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file lmtpserver.xml, assuming empty configuration
james_1  | 14:02:47.457 [INFO ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file managesieveserver.xml, assuming empty configuration
james_1  | 14:02:47.496 [INFO ] o.a.j.p.l.n.AbstractConfigurableAsyncServer - POP3 Service disabled by configuration
james_1  | 14:02:47.497 [WARN ] o.a.j.s.c.c.FileConfigurationProvider - Unable to locate configuration file smtpserver.xml, assuming empty configuration
{noformat}

I will attempt to break this down into actionable chunks in the following comment.

> Reduce INFO chatter for Basic Server
> ------------------------------------
>
>                 Key: JAMES-3251
>                 URL: https://issues.apache.org/jira/browse/JAMES-3251
>             Project: James Server
>          Issue Type: Sub-task
>            Reporter: David Leangen
>            Priority: Major
>
> In the context of the *Basic Server*, based on the principle that the Operator does not know (and does not need to know) the internals of the system:
>  # Reduce the Operator's log output to the absolute minimum (in one way or another)
>  # Ensure that any output is useful and actionable in the Basic context
>  # Consider what to do with regard to diagnostic information that, in the case of a problem, would allow experienced James Developers to assist when necessary
> This issue focuses only on point #1 in the above list. Once that is completed, we should consider the other two points.



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

---------------------------------------------------------------------
To unsubscribe, e-mail: server-dev-unsubscribe@james.apache.org
For additional commands, e-mail: server-dev-help@james.apache.org