Must-share information (formatted with Markdown):
- which versions are you using: SonarQube 10.3 Community Edition
- how is SonarQube deployed: Docker
- what are you trying to achieve: get error logs in JSON format
- what have you tried so far to achieve this: configure SonarQube to write logs in JSON format.
We are using Vector to scrappe logs to send them to Grafana Loki. We first started sending the error logs in the standard format but soon realised we were missing most of the information about the error. To avoid having to write something complicated for Vector to send multiline logs with the whole stacktrace of the error, we first tried the JSON output format. But then we saw that the JSON format is missing quite some information as well.
For testing purposes, I just launched the 10.3 Community Edition locally with Docker, configured to connect to a non-existant database. Then I got this as output in the logs:
2024.10.01 09:43:10 INFO web[][o.s.d.DefaultDatabase] Create JDBC data source for jdbc:postgresql://localhost/toto
2024.10.01 09:43:10 INFO web[][c.z.h.HikariDataSource] HikariPool-1 - Starting...
**2024.10.01 09:43:11 ERROR web[][c.z.h.p.HikariPool] HikariPool-1 - Exception during pool initialization.**
**org.postgresql.util.PSQLException: Connection to localhost:5432 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.**
at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:342)
at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:54)
at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:263)
at org.postgresql.Driver.makeConnection(Driver.java:443)
at org.postgresql.Driver.connect(Driver.java:297)
at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:121)
at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:359)
at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:201)
at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:470)
at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:561)
at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:100)
at com.zaxxer.hikari.HikariDataSource.<init>(HikariDataSource.java:81)
at org.sonar.db.DefaultDatabase.createHikariDataSource(DefaultDatabase.java:159)
at org.sonar.db.DefaultDatabase.initDataSource(DefaultDatabase.java:148)
at org.sonar.db.DefaultDatabase.start(DefaultDatabase.java:126)
at org.sonar.core.platform.StartableBeanPostProcessor.postProcessBeforeInitialization(StartableBeanPostProcessor.java:33)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:440)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1796)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:620)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542)
at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:955)
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:920)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:583)
at org.sonar.core.platform.SpringComponentContainer.startComponents(SpringComponentContainer.java:200)
at org.sonar.server.platform.platformlevel.PlatformLevel.start(PlatformLevel.java:80)
at org.sonar.server.platform.platformlevel.PlatformLevel1.start(PlatformLevel1.java:164)
at org.sonar.server.platform.PlatformImpl.start(PlatformImpl.java:214)
at org.sonar.server.platform.PlatformImpl.startLevel1Container(PlatformImpl.java:179)
at org.sonar.server.platform.PlatformImpl.init(PlatformImpl.java:79)
at org.sonar.server.platform.web.PlatformServletContextListener.contextInitialized(PlatformServletContextListener.java:45)
at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4462)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:4914)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:171)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1332)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1322)
at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
at java.base/java.util.concurrent.AbstractExecutorService.submit(Unknown Source)
at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:866)
at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:794)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:171)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1332)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1322)
at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
at java.base/java.util.concurrent.AbstractExecutorService.submit(Unknown Source)
at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:866)
at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:248)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:171)
at org.apache.catalina.core.StandardService.startInternal(StandardService.java:433)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:171)
at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:921)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:171)
at org.sonar.server.app.EmbeddedTomcat.start(EmbeddedTomcat.java:72)
at org.sonar.server.app.WebServer.start(WebServer.java:55)
at org.sonar.process.ProcessEntryPoint.launch(ProcessEntryPoint.java:97)
at org.sonar.process.ProcessEntryPoint.launch(ProcessEntryPoint.java:81)
at org.sonar.server.app.WebServer.main(WebServer.java:104)
Caused by: java.net.ConnectException: Connection refused
at java.base/sun.nio.ch.Net.pollConnect(Native Method)
at java.base/sun.nio.ch.Net.pollConnectNow(Unknown Source)
at java.base/sun.nio.ch.NioSocketImpl.timedFinishConnect(Unknown Source)
at java.base/sun.nio.ch.NioSocketImpl.connect(Unknown Source)
at java.base/java.net.SocksSocketImpl.connect(Unknown Source)
at java.base/java.net.Socket.connect(Unknown Source)
at org.postgresql.core.PGStream.createSocket(PGStream.java:243)
at org.postgresql.core.PGStream.<init>(PGStream.java:98)
at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:132)
at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:258)
... 62 common frames omitted
**2024.10.01 09:43:11 WARN web[][o.s.c.a.AnnotationConfigApplicationContext] Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'jdk.internal.loader.ClassLoaders$AppClassLoader@4b3ed2f0-org.sonar.db.DefaultDatabase': Initialization of bean failed; nested exception is java.lang.IllegalStateException: Fail to connect to database**
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'jdk.internal.loader.ClassLoaders$AppClassLoader@4b3ed2f0-org.sonar.db.DefaultDatabase': Initialization of bean failed; nested exception is java.lang.IllegalStateException: Fail to connect to database
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:628)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542)
at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:955)
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:920)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:583)
at org.sonar.core.platform.SpringComponentContainer.startComponents(SpringComponentContainer.java:200)
at org.sonar.server.platform.platformlevel.PlatformLevel.start(PlatformLevel.java:80)
at org.sonar.server.platform.platformlevel.PlatformLevel1.start(PlatformLevel1.java:164)
at org.sonar.server.platform.PlatformImpl.start(PlatformImpl.java:214)
at org.sonar.server.platform.PlatformImpl.startLevel1Container(PlatformImpl.java:179)
at org.sonar.server.platform.PlatformImpl.init(PlatformImpl.java:79)
at org.sonar.server.platform.web.PlatformServletContextListener.contextInitialized(PlatformServletContextListener.java:45)
at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4462)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:4914)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:171)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1332)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1322)
at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
at java.base/java.util.concurrent.AbstractExecutorService.submit(Unknown Source)
at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:866)
at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:794)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:171)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1332)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1322)
at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
at java.base/java.util.concurrent.AbstractExecutorService.submit(Unknown Source)
at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:866)
at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:248)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:171)
at org.apache.catalina.core.StandardService.startInternal(StandardService.java:433)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:171)
at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:921)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:171)
at org.sonar.server.app.EmbeddedTomcat.start(EmbeddedTomcat.java:72)
at org.sonar.server.app.WebServer.start(WebServer.java:55)
at org.sonar.process.ProcessEntryPoint.launch(ProcessEntryPoint.java:97)
at org.sonar.process.ProcessEntryPoint.launch(ProcessEntryPoint.java:81)
at org.sonar.server.app.WebServer.main(WebServer.java:104)
Caused by: java.lang.IllegalStateException: Fail to connect to database
at org.sonar.db.DefaultDatabase.start(DefaultDatabase.java:130)
at org.sonar.core.platform.StartableBeanPostProcessor.postProcessBeforeInitialization(StartableBeanPostProcessor.java:33)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:440)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1796)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:620)
... 44 common frames omitted
Caused by: com.zaxxer.hikari.pool.HikariPool$PoolInitializationException: Failed to initialize pool: Connection to localhost:5432 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
at com.zaxxer.hikari.pool.HikariPool.throwPoolInitializationException(HikariPool.java:596)
at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:582)
at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:100)
at com.zaxxer.hikari.HikariDataSource.<init>(HikariDataSource.java:81)
at org.sonar.db.DefaultDatabase.createHikariDataSource(DefaultDatabase.java:159)
at org.sonar.db.DefaultDatabase.initDataSource(DefaultDatabase.java:148)
at org.sonar.db.DefaultDatabase.start(DefaultDatabase.java:126)
... 48 common frames omitted
Caused by: org.postgresql.util.PSQLException: Connection to localhost:5432 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:342)
at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:54)
at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:263)
at org.postgresql.Driver.makeConnection(Driver.java:443)
at org.postgresql.Driver.connect(Driver.java:297)
at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:121)
at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:359)
at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:201)
at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:470)
at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:561)
... 53 common frames omitted
Caused by: java.net.ConnectException: Connection refused
at java.base/sun.nio.ch.Net.pollConnect(Native Method)
at java.base/sun.nio.ch.Net.pollConnectNow(Unknown Source)
at java.base/sun.nio.ch.NioSocketImpl.timedFinishConnect(Unknown Source)
at java.base/sun.nio.ch.NioSocketImpl.connect(Unknown Source)
at java.base/java.net.SocksSocketImpl.connect(Unknown Source)
at java.base/java.net.Socket.connect(Unknown Source)
at org.postgresql.core.PGStream.createSocket(PGStream.java:243)
at org.postgresql.core.PGStream.<init>(PGStream.java:98)
at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:132)
at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:258)
... 62 common frames omitted
2024.10.01 09:43:11 INFO web[][o.s.p.ProcessEntryPoint] Hard stopping process
2024.10.01 09:43:11 INFO app[][o.s.a.SchedulerImpl] Process[Web Server] is stopped
2024.10.01 09:43:11 INFO app[][o.s.a.SchedulerImpl] Process[ElasticSearch] is stopped
2024.10.01 09:43:11 WARN app[][o.s.a.p.AbstractManagedProcess] Process exited with exit value [ElasticSearch]: 143
2024.10.01 09:43:11 INFO app[][o.s.a.SchedulerImpl] SonarQube is stopped
Then I tried using the JSON logging format and I got this:
{"process":"web","timestamp":"2024-10-01T09:45:13.877Z","severity":"INFO","logger":"org.sonar.db.DefaultDatabase","message":"Create JDBC data source for jdbc:postgresql://localhost/toto"}
{"process":"web","timestamp":"2024-10-01T09:45:13.881Z","severity":"INFO","logger":"com.zaxxer.hikari.HikariDataSource","message":"HikariPool-1 - Starting..."}
{"process":"web","timestamp":"2024-10-01T09:45:14.908Z","severity":"WARN","logger":"org.springframework.context.annotation.AnnotationConfigApplicationContext","message":"Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'jdk.internal.loader.ClassLoaders$AppClassLoader@4b6e2263-org.sonar.db.DefaultDatabase': Initialization of bean failed; nested exception is java.lang.IllegalStateException: Fail to connect to database"}
{"process":"web","timestamp":"2024-10-01T09:45:14.945Z","severity":"INFO","logger":"org.sonar.process.ProcessEntryPoint","message":"Hard stopping process"}
{"process":"app","timestamp":"2024-10-01T09:45:14.959Z","severity":"INFO","logger":"org.sonar.application.SchedulerImpl","message":"Process[Web Server] is stopped"}
{"process":"app","timestamp":"2024-10-01T09:45:15Z","severity":"INFO","logger":"org.sonar.application.SchedulerImpl","message":"Process[ElasticSearch] is stopped"}
**{"process":"app","timestamp":"2024-10-01T09:45:15Z","severity":"WARN","logger":"org.sonar.application.process.AbstractManagedProcess","message":"Process exited with exit value [ElasticSearch]: 143"}**
{"process":"app","timestamp":"2024-10-01T09:45:15Z","severity":"INFO","logger":"org.sonar.application.SchedulerImpl","message":"SonarQube is stopped"}
I highlighted the relevant logs. In the standard format, I get a log in the ERROR level and another one in the WARN level. In JSON format I only got the WARN level log. I tried using different log levels with the same results. Given we want to be able to be alerted in case there are errors in the logs and that we want to have information about what happened exactly, this kind of behaviour prevents us from using the JSON format, which would be much easier to parse.
This is just an example as it’s the simplest exception I can make the service throw during startup. I don’t know if the same behaviour is expected for other types of errors.
Is there anything I need to add to the configuration in order for the output to include the errors? According to this documentation, this is all that’s configurable in terms of logging.
Thanks.
