Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

server: Add root-cause-exception-first logging to logback.xml #58

Merged
merged 3 commits into from
Oct 10, 2018
Merged

server: Add root-cause-exception-first logging to logback.xml #58

merged 3 commits into from
Oct 10, 2018

Conversation

rishacha
Copy link
Contributor

@rishacha rishacha commented Oct 6, 2018

Ref: Github issue #57

Problem

Explain the context and why you're making that change. What is the
problem you're trying to solve? In some cases there is not a problem
and this can be thought of being the motivation for your change.

There's always trouble in finding the root cause of an exception because java prints the stack trace in last-exception-first order. Hence, root-cause-exception-first logging would help identify the root cause faster.

Solution

Describe the modifications you've done.

Added %rEx conversion word to the encodern Pattern Layout.

Reference :
Logback docs (Chap 6 : Layouts)
Blog/Recipe referenced in the documentation

Result

What will change as a result of your pull request? Note that sometimes
this section is unnecessary because it is self-explanatory based on
the solution.

Outputs the stack trace of the exception associated with the logging event, if any. The root cause will be output first instead of the standard "root cause last"

If you changed the UI, please include screenshots.

No

This change helps identify the root cause in the stack trace of
exceptions.

Ref: Github issue #57
@rishacha
Copy link
Contributor Author

rishacha commented Oct 6, 2018

I need some help with testing this. I couldn't setup the environment on my PC (xsn rpc wasn't installing). I'm working on it.

@AlexITC
Copy link
Collaborator

AlexITC commented Oct 6, 2018

Then, an exception should be thrown (which is what we want to see).

Thanks.

@rishacha
Copy link
Contributor Author

rishacha commented Oct 9, 2018

I finally got rpc server to run. Sorry for the time taken.

Error caused by : No database details in application.conf

The difference is evident with Wrapped by vs Caused by. Attaching evidence as well as snippets.

With %rEx

org.postgresql.util.PSQLException: FATAL: database "xsn_blockchain" does not exist
	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2455)
	at org.postgresql.core.v3.QueryExecutorImpl.readStartupMessages(QueryExecutorImpl.java:2586)
	at org.postgresql.core.v3.QueryExecutorImpl.<init>(QueryExecutorImpl.java:113)
	at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:222)
	at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:52)
	at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:216)
	at org.postgresql.Driver.makeConnection(Driver.java:404)
	at org.postgresql.Driver.connect(Driver.java:272)
	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:117)
	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:123)
	at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:365)
	at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:194)
	at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:460)
	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:534)
	... 74 common frames omitted
Wrapped by: com.zaxxer.hikari.pool.HikariPool$PoolInitializationException: Failed to initialize pool: FATAL: database "xsn_blockchain" does not exist
	at com.zaxxer.hikari.pool.HikariPool.throwPoolInitializationException(HikariPool.java:569)
	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:555)
	at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115)
	at com.zaxxer.hikari.HikariDataSource.<init>(HikariDataSource.java:81)
	at play.api.db.HikariCPConnectionPool.$anonfun$create$1(HikariCPModule.scala:51)
	at scala.util.Try$.apply(Try.scala:209)
	at play.api.db.HikariCPConnectionPool.create(HikariCPModule.scala:47)
	... 69 common frames omitted
Wrapped by: play.api.Configuration$$anon$1: Configuration error[Failed to initialize pool: FATAL: database "xsn_blockchain" does not exist]
	at play.api.Configuration$.configError(Configuration.scala:156)
	at play.api.Configuration.reportError(Configuration.scala:990)
	at play.api.db.HikariCPConnectionPool.create(HikariCPModule.scala:63)
	at play.api.db.PooledDatabase.createDataSource(Databases.scala:205)
	at play.api.db.DefaultDatabase.dataSource$lzycompute(Databases.scala:123)
	at play.api.db.DefaultDatabase.dataSource(Databases.scala:121)
	at play.api.db.DefaultDatabase.getConnection(Databases.scala:142)
	at play.api.db.DefaultDatabase.getConnection(Databases.scala:138)
	at play.api.db.DefaultDBApi.$anonfun$connect$1(DefaultDBApi.scala:44)

Without %rEx

play.api.Configuration$$anon$1: Configuration error[Cannot connect to database [default]]
	at play.api.Configuration$.configError(Configuration.scala:156)
	at play.api.Configuration.reportError(Configuration.scala:990)
	at play.api.db.DefaultDBApi.$anonfun$connect$1(DefaultDBApi.scala:48)
	at play.api.db.DefaultDBApi.$anonfun$connect$1$adapted(DefaultDBApi.scala:42)
	at scala.collection.immutable.List.foreach(List.scala:389)
	at play.api.db.DefaultDBApi.connect(DefaultDBApi.scala:42)
	at play.api.db.DBApiProvider.get$lzycompute(DBModule.scala:86)
	at play.api.db.DBApiProvider.get(DBModule.scala:75)
	at play.api.db.DBApiProvider.get(DBModule.scala:56)
	at com.google.inject.internal.ProviderInternalFactory.provision(ProviderInternalFactory.java:81)
	at com.google.inject.internal.BoundProviderFactory.provision(BoundProviderFactory.java:72)
	at com.google.inject.internal.ProviderInternalFactory.circularGet(ProviderInternalFactory.java:61)
	at com.google.inject.internal.BoundProviderFactory.get(BoundProviderFactory.java:62)
	at com.google.inject.internal.SingleFieldInjector.inject(SingleFieldInjector.java:54)
	at com.google.inject.internal.MembersInjectorImpl.injectMembers(MembersInjectorImpl.java:132)
	at com.google.inject.internal.MembersInjectorImpl$1.call(MembersInjectorImpl.java:93)
	at com.google.inject.internal.MembersInjectorImpl$1.call(MembersInjectorImpl.java:80)
	at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1092)
	at com.google.inject.internal.MembersInjectorImpl.injectAndNotify(MembersInjectorImpl.java:80)
	at com.google.inject.internal.MembersInjectorImpl.injectMembers(MembersInjectorImpl.java:62)
	at com.google.inject.internal.InjectorImpl.injectMembers(InjectorImpl.java:987)
	at com.google.inject.util.Providers$GuicifiedProviderWithDependencies.initialize(Providers.java:149)
	at com.google.inject.util.Providers$GuicifiedProviderWithDependencies$$FastClassByGuice$$2a7177aa.invoke(<generated>)
	at com.google.inject.internal.SingleMethodInjector$1.invoke(SingleMethodInjector.java:54)
	at com.google.inject.internal.SingleMethodInjector.inject(SingleMethodInjector.java:89)
	at com.google.inject.internal.MembersInjectorImpl.injectMembers(MembersInjectorImpl.java:132)
	at com.google.inject.internal.MembersInjectorImpl$1.call(MembersInjectorImpl.java:93)
	at com.google.inject.internal.MembersInjectorImpl$1.call(MembersInjectorImpl.java:80)
	at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1085)
	at com.google.inject.internal.MembersInjectorImpl.injectAndNotify(MembersInjectorImpl.java:80)
	at com.google.inject.internal.Initializer$InjectableReference.get(Initializer.java:223)
	at com.google.inject.internal.Initializer.injectAll(Initializer.java:132)
	at com.google.inject.internal.InternalInjectorCreator.injectDynamically(InternalInjectorCreator.java:174)
	at com.google.inject.internal.InternalInjectorCreator.build(InternalInjectorCreator.java:110)
	at com.google.inject.Guice.createInjector(Guice.java:99)
	at com.google.inject.Guice.createInjector(Guice.java:84)
	at play.api.inject.guice.GuiceBuilder.injector(GuiceInjectorBuilder.scala:185)
	at play.api.inject.guice.GuiceApplicationBuilder.build(GuiceApplicationBuilder.scala:137)
	at play.api.inject.guice.GuiceApplicationLoader.load(GuiceApplicationLoader.scala:21)
	at play.core.server.DevServerStart$$anon$1.$anonfun$reload$3(DevServerStart.scala:174)
	at play.utils.Threads$.withContextClassLoader(Threads.scala:21)
	at play.core.server.DevServerStart$$anon$1.reload(DevServerStart.scala:171)
	at play.core.server.DevServerStart$$anon$1.get(DevServerStart.scala:124)
	at play.core.server.AkkaHttpServer.handleRequest(AkkaHttpServer.scala:202)
	at play.core.server.AkkaHttpServer.$anonfun$createServerBinding$1(AkkaHttpServer.scala:117)
	at akka.stream.impl.fusing.MapAsync$$anon$25.onPush(Ops.scala:1194)
	at akka.stream.impl.fusing.GraphInterpreter.processPush(GraphInterpreter.scala:519)
	at akka.stream.impl.fusing.GraphInterpreter.processEvent(GraphInterpreter.scala:482)
	at akka.stream.impl.fusing.GraphInterpreter.execute(GraphInterpreter.scala:378)
	at akka.stream.impl.fusing.GraphInterpreterShell.runBatch(ActorGraphInterpreter.scala:585)
	at akka.stream.impl.fusing.GraphInterpreterShell$AsyncInput.execute(ActorGraphInterpreter.scala:469)
	at akka.stream.impl.fusing.GraphInterpreterShell.processEvent(ActorGraphInterpreter.scala:560)
	at akka.stream.impl.fusing.ActorGraphInterpreter.akka$stream$impl$fusing$ActorGraphInterpreter$$processEvent(ActorGraphInterpreter.scala:742)
	at akka.stream.impl.fusing.ActorGraphInterpreter$$anonfun$receive$1.applyOrElse(ActorGraphInterpreter.scala:757)
	at akka.actor.Actor.aroundReceive(Actor.scala:517)
	at akka.actor.Actor.aroundReceive$(Actor.scala:515)
	at akka.stream.impl.fusing.ActorGraphInterpreter.aroundReceive(ActorGraphInterpreter.scala:667)
	at akka.actor.ActorCell.receiveMessage(ActorCell.scala:590)
	at akka.actor.ActorCell.invoke(ActorCell.scala:559)
	at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:257)
	at akka.dispatch.Mailbox.run(Mailbox.scala:224)
	at akka.dispatch.Mailbox.exec(Mailbox.scala:234)
	at akka.dispatch.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
	at akka.dispatch.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
	at akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
	at akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
Caused by: play.api.Configuration$$anon$1: Configuration error[Failed to initialize pool: FATAL: database "xsn_blockchain" does not exist]
	at play.api.Configuration$.configError(Configuration.scala:156)
	at play.api.Configuration.reportError(Configuration.scala:990)
	at play.api.db.HikariCPConnectionPool.create(HikariCPModule.scala:63)
	at play.api.db.PooledDatabase.createDataSource(Databases.scala:205)
	at play.api.db.DefaultDatabase.dataSource$lzycompute(Databases.scala:123)
	at play.api.db.DefaultDatabase.dataSource(Databases.scala:121)
	at play.api.db.DefaultDatabase.getConnection(Databases.scala:142)
	at play.api.db.DefaultDatabase.getConnection(Databases.scala:138)
	at play.api.db.DefaultDBApi.$anonfun$connect$1(DefaultDBApi.scala:44)
	... 63 common frames omitted
Caused by: com.zaxxer.hikari.pool.HikariPool$PoolInitializationException: Failed to initialize pool: FATAL: database "xsn_blockchain" does not exist
	at com.zaxxer.hikari.pool.HikariPool.throwPoolInitializationException(HikariPool.java:569)
	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:555)
	at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115)
	at com.zaxxer.hikari.HikariDataSource.<init>(HikariDataSource.java:81)
	at play.api.db.HikariCPConnectionPool.$anonfun$create$1(HikariCPModule.scala:51)
	at scala.util.Try$.apply(Try.scala:209)
	at play.api.db.HikariCPConnectionPool.create(HikariCPModule.scala:47)
	... 69 common frames omitted
Caused by: org.postgresql.util.PSQLException: FATAL: database "xsn_blockchain" does not exist
	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2455)
	at org.postgresql.core.v3.QueryExecutorImpl.readStartupMessages(QueryExecutorImpl.java:2586)
	at org.postgresql.core.v3.QueryExecutorImpl.<init>(QueryExecutorImpl.java:113)
	at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:222)
	at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:52)
	at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:216)
	at org.postgresql.Driver.makeConnection(Driver.java:404)
	at org.postgresql.Driver.connect(Driver.java:272)
	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:117)
	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:123)
	at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:365)
	at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:194)
	at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:460)
	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:534)
	... 74 common frames omitted

Files :

application.log
rEx.log

server/conf/logback.xml Outdated Show resolved Hide resolved
@AlexITC AlexITC merged commit 35deff6 into wiringbits:develop Oct 10, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants