Skip to content

Duplicate log lines: every OTS log message appears twice (named logger + propagated root) #304

@TX-RX

Description

@TX-RX

Symptom

Every log line produced by the `OpenTAKServer` logger appears twice in the log output — once well-formatted by the configured handlers, and once in the bare default format by the root logger:

```
[2026-05-11 02:11:08,054] - OpenTAKServer[586492] - mumble_ice_app - attach_callbacks - 164 - DEBUG - Attaching meta callback
DEBUG:OpenTAKServer:Attaching meta callback
```

Visible in `/home//ots/logs/opentakserver.log` and on stderr, on a fresh install (Ubuntu 22.04, Python 3.10, OTS 1.7.10).

Root cause

`opentakserver/extensions.py:12` creates the named logger:

```python
logger = colorlog.getLogger("OpenTAKServer")
```

`opentakserver/app.py:203-231` (`setup_logging`) attaches a colorlog `StreamHandler` and a `TimedRotatingFileHandler` to that named logger. Both produce the well-formatted line.

The named logger's `propagate` attribute is `True` (Python default). Every `logger.info(...)` call therefore also bubbles up to the root logger, which has a handler installed somewhere in the dependency chain (Flask / gevent / one of the extensions) that emits the bare `LEVEL:NAME:msg` format — producing the duplicate line.

This isn't a regression; it's been the behavior at least back to 1.7.10. It's also harmless functionally — the named logger's output is fully correct — but it doubles log volume and makes `tail -f` significantly noisier.

Suggested fix

One line after the named logger is created in `extensions.py`:

```python
logger = colorlog.getLogger("OpenTAKServer")
logger.propagate = False
```

This stops the upward propagation to the root logger. The configured colorlog + file handlers continue to receive every message; the bare-format root-logger output disappears.

Verification

Before:

```
[2026-05-11 02:11:08,054] - OpenTAKServer[586492] - mumble_ice_app - attach_callbacks - 164 - DEBUG - Attaching meta callback
DEBUG:OpenTAKServer:Attaching meta callback
```

After:

```
[2026-05-11 02:11:08,054] - OpenTAKServer[586492] - mumble_ice_app - attach_callbacks - 164 - DEBUG - Attaching meta callback
```

Found while doing VX voice work on a fork — happy to send a PR if you'd like, but it's small enough you may want to just apply it directly.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions