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

Named handler log files get logs duplicated when hot reload is performed #10578

Closed
bmontuelle opened this issue Jul 8, 2020 · 0 comments · Fixed by #15798
Closed

Named handler log files get logs duplicated when hot reload is performed #10578

bmontuelle opened this issue Jul 8, 2020 · 0 comments · Fixed by #15798
Labels
area/logging kind/bug Something isn't working
Milestone

Comments

@bmontuelle
Copy link

bmontuelle commented Jul 8, 2020

Describe the bug
In properties file I have configured 2 different named handlers, for very specific logging categories.
In dev mode the log in these categories are working fine and directed toward the right file handler.
When an hot-reload is performed I see the log lines duplicated, and each time a new hot-reload is performed there is one more copy of the log lines pushed to the files.
This might be related to the named log handler being registered multiple times on hot reload, I'm guessing, because console log and the general quarkus.log.file.path do not get duplicates traces after several hot reloads.

Expected behavior
Hot reload should reset logging configuration, and not duplicate log lines in named handler files

Actual behavior
After hot reload duplicate log lines are added to named handler log files, and the duplication factor is the number of live reloads performed.

To Reproduce
Steps to reproduce the behavior:

  1. Configure named log handler
  2. Append to the matching log topic/categories
  3. See log lines appears one at a time
  4. Perform hot reload, changing a blank line in source or something meaningless
  5. See log lines appears duplicate
  6. Perform another hot reload
  7. See log lines appear 3 times each

Configuration

# Add your application.properties here, if applicable.

#Logging
quarkus.log.level=INFO
quarkus.log.category."com.darva.urlshortener".level=DEBUG

# Configure a named handler that logs to Activite file
quarkus.log.handler.file."ACTIVITE".enable=true
quarkus.log.handler.file."ACTIVITE".path=../logs/activite.log
quarkus.log.handler.file."ACTIVITE".format=%d{yyyy-MM-dd'T'HH:mm:ss.SSSXXX};%X{raisonsociale};%X{userroles};%X{sessionId};%X{posteId};%X{userId};%X{versionApp};%X{service};SERVICE-NAME;%X{numclient};%X{transactionId};%X{versionConfApp};%X{versionConfTech};%X{codePro};%X{codeAbo};%m%n
quarkus.log.category."com.company.log.ActivityTracer".level=INFO
quarkus.log.category."com.company.log.ActivityTracer".handlers=ACTIVITE

# Configure a named handler that logs to Exploitation file
quarkus.log.handler.file."EXPLOITATION".enable=true
quarkus.log.handler.file."EXPLOITATION".path=../logs/exploitation.log
quarkus.log.handler.file."EXPLOITATION".format=%d{yyyy-MM-dd'T'HH:mm:ss.SSSXXX};%X{raisonsociale};%X{userroles};%X{sessionId};%X{posteId};%X{userId};%X{versionApp};%X{service};SERVICE-NAME;%X{numclient};%X{transactionId};%X{versionConfApp};%X{versionConfTech};%X{codePro};%X{codeAbo};%p;%C;%m;%M%n
quarkus.log.category."com.company.log.ExploitationTracer".level=ERROR
quarkus.log.category."com.company.log.ExploitationTracer".handlers=EXPLOITATION

# General log goes to Application file
quarkus.log.file.enable=true
quarkus.log.file.path=../logs/application.log
quarkus.log.file.format=%d{yyyy-MM-dd'T'HH:mm:ss.SSSXXX};%X{raisonsociale};%X{userroles};%X{sessionId};%X{posteId};%X{userId};%X{versionApp};%X{service};SERVICE-NAME;%X{numclient};%X{transactionId};%X{versionConfApp};%X{versionConfTech};%X{codePro};%X{codeAbo};%p;%C;%m;%M%n
quarkus.log.file.level=DEBUG
quarkus.log.min-level=DEBUG

Environment (please complete the following information):

  • Output of uname -a or ver: Darwin ***********.local 19.5.0 Darwin Kernel Version 19.5.0: Tue May 26 20:41:44 PDT 2020; root:xnu-6153.121.2~2/RELEASE_X86_64 x86_64
  • Output of java -version: java version "11.0.7" 2020-04-14 LTS
    Java(TM) SE Runtime Environment 18.9 (build 11.0.7+8-LTS)
    Java HotSpot(TM) 64-Bit Server VM 18.9 (build 11.0.7+8-LTS, mixed mode)
  • GraalVM version (if different from Java):
  • Quarkus version or git rev: 1.5.2.Final
  • Build tool (ie. output of mvnw --version or gradlew --version): Apache Maven 3.6.3 (cecedd343002696d0abb50b32b541b8a6ba2883f)

Additional context
This all happened in dev mode, running the application using either mvn quarkus:dev or ./mvnw quarkus:dev. Not very critical to me either, as hot reload is only useful for dev environment.

@bmontuelle bmontuelle added the kind/bug Something isn't working label Jul 8, 2020
stuartwdouglas added a commit to stuartwdouglas/quarkus that referenced this issue Mar 17, 2021
@quarkus-bot quarkus-bot bot added this to the 1.13 - main milestone Mar 17, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/logging kind/bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants