Skip to content

Commit

Permalink
Fix log message duplication (#6766)
Browse files Browse the repository at this point in the history
There are two independent problems that cause some log messages to be
printed twice:

* In the CVAT logging configuration, we attach a console handler to the
  `cvat` and `django` loggers. However, when any library[1] used by CVAT
  uses one of the top-level `logging` functions (e.g. `logging.info`),
  then it will cause the root logger to get autoconfigured with another
  console handler. Since `cvat` and `django` are configured to propagate
  events to the ancestor logger's handlers, those events are passed to
  _two_ console handlers, so they are printed twice.

  Fix it by moving our handlers to the root logger. If the root logger has
  handlers, it will no longer get autoconfigured when top-level `logging`
  functions are invoked; so there will only be one console handler in the
  logger chain.

  An alternative would be to configure the root logger with a
  `NullHandler` (which will also disable autoconfiguration), but this will
  suppress all logs that are coming from places other than Django and
  CVAT, which seems undesirable.

* The supervisord config file for the server redirects the server's
  stdout to supervisord's stdout. However, supervisord already displays
  the stdout of all child processes due to the `loglevel=debug` setting.
  So all stdout messages of the server are displayed twice.

  Fix it by removing the redirection.

[1] Specifically, Datumaro does this. It could probably be fixed, but
that wouldn't fix the root problem, which is the duplicate console
handler.
  • Loading branch information
SpecLad authored Sep 6, 2023
1 parent 182a645 commit 92f1372
Show file tree
Hide file tree
Showing 3 changed files with 6 additions and 5 deletions.
2 changes: 2 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
- Memory leak in the logging system (<https://github.com/opencv/cvat/pull/6804>)
- A race condition during initial `secret_key.py` creation
(<https://github.com/opencv/cvat/pull/6775>)
- Duplicate log entries from the CVAT server
(<https://github.com/opencv/cvat/pull/6766>)

### Security
- TDB
Expand Down
7 changes: 4 additions & 3 deletions cvat/settings/base.py
Original file line number Diff line number Diff line change
Expand Up @@ -548,17 +548,18 @@ class CVAT_QUEUES(Enum):
'database_path': EVENTS_LOCAL_DB_FILE,
}
},
'root': {
'handlers': ['console', 'server_file'],
},
'loggers': {
'cvat': {
'handlers': ['console', 'server_file'],
'level': os.getenv('DJANGO_LOG_LEVEL', 'DEBUG'),
},

'django': {
'handlers': ['console', 'server_file'],
'level': 'INFO',
'propagate': True
},

'vector': {
'handlers': [],
'level': 'INFO',
Expand Down
2 changes: 0 additions & 2 deletions supervisord/server.conf
Original file line number Diff line number Diff line change
Expand Up @@ -42,8 +42,6 @@ autorestart=true
environment=SSH_AUTH_SOCK="/tmp/ssh-agent.sock",CVAT_EVENTS_LOCAL_DB_FILENAME="events_%(process_num)03d.db"
numprocs=%(ENV_NUMPROCS)s
process_name=%(program_name)s-%(process_num)s
stdout_logfile=/dev/stdout
stdout_logfile_maxbytes=0

[program:smokescreen]
command=smokescreen --listen-ip=127.0.0.1 %(ENV_SMOKESCREEN_OPTS)s

0 comments on commit 92f1372

Please sign in to comment.