Kubernetes tail Spring Boot json logs in plain text Log4j (Logback) format using Stern
A few days ago we were debugging a Java Spring Boot web application (called engine-export-service) in Kubernetes and we wanted to tail the Pod logs. Since we have a lot of replicas for the engine-export-service Deployment of this application, we decided to use Stern, The Multi pod and container log tailing for Kubernetes!
Therefore we set up stern, opened up a shell and run:
stern --context ctx-jetengine-factory --namespace=jetengine-factory-prod engine-export*
The output we got was looking like the following:
+ engine-export-service-7f6c797f5b-q7cm8 › engine-export
engine-export-service-7f6c797f5b-q7cm8 engine-export {"@timestamp":"2023-06-15T02:09:23.240Z","@version":"1","message":"Started sending of 1000 messages","logger_name":"org.manios.airplanefactory.engineexport.rabbit.RabbitService","thread_name":"ForkJoinPool.commonPool-worker-3","level":"INFO","level_value":20000}
engine-export-service-7f6c797f5b-q7cm8 engine-export {"@timestamp":"2023-06-15T02:09:25.710Z","@version":"1","message":"Finished sending of 1000 messages","logger_name":"org.manios.airplanefactory.engineexport.rabbit.RabbitService","thread_name":"ForkJoinPool.commonPool-worker-3","level":"INFO","level_value":20000}
engine-export-service-7f6c797f5b-q7cm8 engine-export {"@timestamp":"2023-06-15T02:09:26.990Z","@version":"1","message":"Finished retrieving engine information chunk 51/51 for 2023-06-18 after 9 minute/s and 26 seconds","logger_name":"org.manios.airplanefactory.engineexport.EngineExportService","thread_name":"ForkJoinPool.commonPool-worker-3","level":"INFO","level_value":20000}
engine-export-service-7f6c797f5b-q7cm8 engine-export {"@timestamp":"2023-06-15T02:09:27.088Z","@version":"1","message":"Loaded 1000 normal prices in 0 seconds","logger_name":"org.manios.airplanefactory.engineexport.engine.dao.EngineRepositoryImpl","thread_name":"ForkJoinPool.commonPool-worker-3","level":"INFO","level_value":20000}
engine-export-service-7f6c797f5b-q7cm8 engine-export {"@timestamp":"2023-06-15T02:09:27.139Z","@version":"1","message":"Loaded 0 special prices in 0 seconds","logger_name":"org.manios.airplanefactory.engineexport.engine.dao.EngineRepositoryImpl","thread_name":"ForkJoinPool.commonPool-worker-3","level":"INFO","level_value":20000}
engine-export-service-7f6c797f5b-q7cm8 engine-export {"@timestamp":"2023-06-15T02:09:27.225Z","@version":"1","message":"Started sending of 1000 messages","logger_name":"org.manios.airplanefactory.engineexport.rabbit.RabbitService","thread_name":"ForkJoinPool.commonPool-worker-3","level":"INFO","level_value":20000}
engine-export-service-7f6c797f5b-q7cm8 engine-export {"@timestamp":"2023-06-15T02:09:29.645Z","@version":"1","message":"Finished sending of 1000 messages","logger_name":"org.manios.airplanefactory.engineexport.rabbit.RabbitService","thread_name":"ForkJoinPool.commonPool-worker-3","level":"INFO","level_value":20000}
engine-export-service-7f6c797f5b-q7cm8 engine-export {"@timestamp":"2023-06-15T02:09:29.645Z","@version":"1","message":"Finished export for 2023-06-18 after 9 minute/s and 29 seconds","logger_name":"org.manios.airplanefactory.engineexport.EngineExportService","thread_name":"scheduling-1","level":"INFO","level_value":20000}
engine-export-service-7f6c797f5b-q7cm8 engine-export {"@timestamp":"2023-06-15T02:09:29.645Z","@version":"1","message":"Engine export successfully finished for date period: [2023-06-15,2023-06-18] after: 9.494 min","logger_name":"org.manios.airplanefactory.engineexport.EngineExportService","thread_name":"scheduling-1","level":"INFO","level_value":20000}
engine-export-service-7f6c797f5b-q7cm8 engine-export {"@timestamp":"2023-06-15T02:09:29.664Z","@version":"1","message":"Open links after closing: 0","logger_name":"org.manios.airplanefactory.engineexport.database.OracleLinkService","thread_name":"scheduling-1","level":"INFO","level_value":20000}
This is quite normal, since we have configured Logback in Spring to print the logs in JSON format which is easily parsed by FluentD in order to push the logs to Elasticsearch and view them in Kibana. However, although JSON is nice and machine readable, the parsing and propagation of logs to Elasticsearch can take some time. Therefire we wanted to view the logs quickly and in a human friendly way!
Fortunately, Stern allows to format the logs using a Golang text template! We opened up an editor and created one! This is it (stern-spring-template.tpl):
We saved the template into a file, called stern-spring-template.tpl and we run again the command with the addition of the --template-file parameter!
stern --context ctx-jetengine-factory --namespace=jetengine-factory-prod --template-file="~/stern-spring-template.tpl" engine-export*
Now the output looks like (almost) the same as the normal we get when we develop the Spring Boot application in our IDE!
+ engine-export-service-7f6c797f5b-q7cm8 › engine-export
engine-export-service-7f6c797f5b-q7cm8 2023-06-15T02:09:23.240Z 20000 INFO --- [ForkJoinPool.co] org.manios.airplanefactory.engineexport.rabbit.RabbitService : Started sending of 1000 messages
engine-export-service-7f6c797f5b-q7cm8 2023-06-15T02:09:25.710Z 20000 INFO --- [ForkJoinPool.co] org.manios.airplanefactory.engineexport.rabbit.RabbitService : Finished sending of 1000 messages
engine-export-service-7f6c797f5b-q7cm8 2023-06-15T02:09:26.990Z 20000 INFO --- [ForkJoinPool.co] org.manios.airplanefactory.engineexport.EngineExportService : Finished retrieving engine information chunk 51/51 for 2023-06-18 after 9 minute/s and 26 seconds
engine-export-service-7f6c797f5b-q7cm8 2023-06-15T02:09:27.088Z 20000 INFO --- [ForkJoinPool.co] org.manios.airplanefactory.engineexport.engine.dao.EngineRepository : Loaded 1000 normal prices in 0 seconds
engine-export-service-7f6c797f5b-q7cm8 2023-06-15T02:09:27.139Z 20000 INFO --- [ForkJoinPool.co] org.manios.airplanefactory.engineexport.engine.dao.EngineRepository : Loaded 0 special prices in 0 seconds
engine-export-service-7f6c797f5b-q7cm8 2023-06-15T02:09:27.225Z 20000 INFO --- [ForkJoinPool.co] org.manios.airplanefactory.engineexport.rabbit.RabbitService : Started sending of 1000 messages
engine-export-service-7f6c797f5b-q7cm8 2023-06-15T02:09:29.645Z 20000 INFO --- [ForkJoinPool.co] org.manios.airplanefactory.engineexport.rabbit.RabbitService : Finished sending of 1000 messages
engine-export-service-7f6c797f5b-q7cm8 2023-06-15T02:09:29.645Z 20000 INFO --- [ scheduling-1] org.manios.airplanefactory.engineexport.EngineExportService : Finished export for 2023-06-18 after 9 minute/s and 29 seconds
engine-export-service-7f6c797f5b-q7cm8 2023-06-15T02:09:29.645Z 20000 INFO --- [ scheduling-1] org.manios.airplanefactory.engineexport.EngineExportService : Engine export successfully finished for date period: [2023-06-15,2023-06-18] after: 9.494 min
engine-export-service-7f6c797f5b-q7cm8 2023-06-15T02:09:29.664Z 20000 INFO --- [ scheduling-1] org.manios.airplanefactory.engineexport.database.OracleLinkService : Open links after closing: 0
I hope this helped you a little bit with your next Kubernetes endeavour!
Comments