Please confirm the following
Bug Summary
Assisted-by: Claude Opus 5.5. Drafted with AI assistance; the loss measurements come from a running Ascender 25.4.0 deployment, the rsyslog behavior is cited from rsyslog's source, and every Ascender line cited was read at main 640cf5f2.
External logging discards job events silently, and the policy can't be changed. construct_rsyslog_conf_template() emits queue.discardSeverity="5" as a literal. Job events and activity stream entries are logged at INFO (analytics_logger.info('Event data saved.', ...) in ascender/main/models/events.py), so once LOG_AGGREGATOR_LEVEL lets them through, every one of them is eligible, and once the action queue passes queue.discardMark they're dropped with no error, no warning and nothing an operator can query.
#965 documents this as "what is discarded is the least important": severity 5 and above goes before a warning. That's true of the severities, butthe severity of almost everything being shipped is INFO, so in practice the graded discard isn't graded: it drops job events wholesale.
The same literal exists upstream; the AWX report is ansible/awx#16713.
Ascender version
25.4.0. The code involved is unchanged on main 640cf5f2.
Select the relevant components
Installation method
kubernetes
Modifications
no
Ansible version
No response
Operating system
No response
Web browser
No response
Steps to reproduce
- Configure external logging to a TCP destination:
LOG_AGGREGATOR_ENABLED=true, LOG_AGGREGATOR_PROTOCOL=tcp, LOG_AGGREGATOR_HOST/_PORT pointing at a collector, LOG_AGGREGATOR_LOGGERS including job_events, and LOG_AGGREGATOR_LEVEL=INFO (the registered default, WARNING, filters job events out entirely).
- Set
LOG_AGGREGATOR_ACTION_QUEUE_SIZE low (100, say) so the derived queue.discardMark (90% of it) is reached quickly.
- Make the destination accept the connection but stop reading, so the queue backs up rather than draining.
- Launch a job that emits a few hundred events, for example
Demo Job Template with verbosity raised.
- Compare the events Ascender recorded (
GET /api/v2/jobs/<id>/job_events/) against what the collector received.
- Look for a way to change what happens at that threshold. There is none:
queue.discardSeverity is a literal in ascender/main/utils/external_logging.py.
Expected results
Whether job events are dropped when the queue fills is an operator's decision, and a durable record of what automation did is a reasonable thing to prefer over bounded memory use. queue.discardSeverity should be settable.
Actual results
Messages are discarded and nothing says so. The job succeeds, the API shows every event, the collector never receives some of them, and no field or log line records the gap.
Seen twice on one deployment. The sharper case: two consecutive hourly runs of one playbook succeeded and none of their events arrived, while the same playbook, in the same runs, against a second host delivered every event throughout.
| target |
hour 1 |
hour 2 |
hour 3 |
hour 4 |
| host A |
18 |
18 |
18 |
18 |
| host B |
18 |
0 |
0 |
18 |
Across the deployment in those hours the loss was inversely related to how much each playbook emits:
| playbook's share of traffic |
share of its events lost |
| 95% |
1% |
| 3.5% |
14% |
| 1% |
40% |
| 0.3% |
72% |
| 0.01% (18 events per run) |
100% |
Delivered volume in those hours was 145k against a 148k baseline: nothing was down, no connection error was logged, no retry was reported. A large emitter loses a rounding error while a small one loses everything, and the small emitters are exactly the jobs operators watch with a heartbeat (a nightly backup, a periodic sync). So the resulting alert says a job failed when it succeeded, and the reverse, a real failure whose alert never fires because its events were dropped, can't be detected at all.
Additional information
ascender/main/utils/external_logging.py, construct_rsyslog_conf_template():
f'queue.size="{action_queue_size}"', # max number of messages in queue
f'queue.highwaterMark="{int(action_queue_size * 0.75)}"', # 75% of queue.size
f'queue.discardMark="{int(action_queue_size * 0.9)}"', # 90% of queue.size
'queue.discardSeverity="5"', # Only discard notice, info, debug if we must discard anythingWhat rsyslog does with these values, from runtime/queue.c on rsyslog main:
| Behavior |
Where |
A message is discarded only if discardMark > 0 && size >= discardMark and msg_severity >= discardSeverity |
qqueueChkDiscardMsg() |
rsyslog's own default for discardSeverity is 8, commented /* turn off */: no real severity reaches it, so stock rsyslog discards nothing here |
qqueueSetDefaultsActionQueue() |
discardMark can't be used to opt out: any value below 1 is rewritten to 98% of the queue size |
qqueueConstructFinalize() |
With nothing discardable, a full queue blocks the sender for queue.timeoutEnqueue (default 2000 ms) and drops the message only if it still hasn't drained |
doEnqSingleObject() |
So 5 is a departure from rsyslog's default, in the direction of dropping data, and discardSeverity is the only parameter that can express the other choice. At 8 the nearly-full discard is off and the sender blocks briefly under sustained pressure, which for a durable record is usually the better trade.
The one lever available today is bounded both ways. LOG_AGGREGATOR_ACTION_QUEUE_SIZE moves discardMark, but it also scales queue.highwaterMark, so more accumulates in memory before the disk assist engages; the disk side is capped by LOG_AGGREGATOR_ACTION_MAX_DISK_USAGE_GB. Raising either buys a longer burst before the same silent discard.
The attached PR registers LOG_AGGREGATOR_ACTION_QUEUE_DISCARD_SEVERITY (0–8, default 5) and emits it in place of the literal. The default keeps today's behavior exactly, so #965's durability tests still pass unchanged; the PR adds the setting to that file's "settings users can set reach the queue" list. Whether the default should move to 8 to match rsyslog is a separate decision.
That the discard is unobservable is a different problem with a different answer, requested separately (queue observability, #1097 ).
Please confirm the following
Bug Summary
Assisted-by: Claude Opus 5.5. Drafted with AI assistance; the loss measurements come from a running Ascender 25.4.0 deployment, the rsyslog behavior is cited from rsyslog's source, and every Ascender line cited was read at
main640cf5f2.External logging discards job events silently, and the policy can't be changed.
construct_rsyslog_conf_template()emitsqueue.discardSeverity="5"as a literal. Job events and activity stream entries are logged at INFO (analytics_logger.info('Event data saved.', ...)inascender/main/models/events.py), so onceLOG_AGGREGATOR_LEVELlets them through, every one of them is eligible, and once the action queue passesqueue.discardMarkthey're dropped with no error, no warning and nothing an operator can query.#965 documents this as "what is discarded is the least important": severity 5 and above goes before a warning. That's true of the severities, butthe severity of almost everything being shipped is INFO, so in practice the graded discard isn't graded: it drops job events wholesale.
The same literal exists upstream; the AWX report is ansible/awx#16713.
Ascender version
25.4.0. The code involved is unchanged on
main640cf5f2.Select the relevant components
Installation method
kubernetes
Modifications
no
Ansible version
No response
Operating system
No response
Web browser
No response
Steps to reproduce
LOG_AGGREGATOR_ENABLED=true,LOG_AGGREGATOR_PROTOCOL=tcp,LOG_AGGREGATOR_HOST/_PORTpointing at a collector,LOG_AGGREGATOR_LOGGERSincludingjob_events, andLOG_AGGREGATOR_LEVEL=INFO(the registered default, WARNING, filters job events out entirely).LOG_AGGREGATOR_ACTION_QUEUE_SIZElow (100, say) so the derivedqueue.discardMark(90% of it) is reached quickly.Demo Job Templatewith verbosity raised.GET /api/v2/jobs/<id>/job_events/) against what the collector received.queue.discardSeverityis a literal inascender/main/utils/external_logging.py.Expected results
Whether job events are dropped when the queue fills is an operator's decision, and a durable record of what automation did is a reasonable thing to prefer over bounded memory use.
queue.discardSeverityshould be settable.Actual results
Messages are discarded and nothing says so. The job succeeds, the API shows every event, the collector never receives some of them, and no field or log line records the gap.
Seen twice on one deployment. The sharper case: two consecutive hourly runs of one playbook succeeded and none of their events arrived, while the same playbook, in the same runs, against a second host delivered every event throughout.
Across the deployment in those hours the loss was inversely related to how much each playbook emits:
Delivered volume in those hours was 145k against a 148k baseline: nothing was down, no connection error was logged, no retry was reported. A large emitter loses a rounding error while a small one loses everything, and the small emitters are exactly the jobs operators watch with a heartbeat (a nightly backup, a periodic sync). So the resulting alert says a job failed when it succeeded, and the reverse, a real failure whose alert never fires because its events were dropped, can't be detected at all.
Additional information
ascender/main/utils/external_logging.py,construct_rsyslog_conf_template():What rsyslog does with these values, from
runtime/queue.con rsyslogmain:discardMark > 0 && size >= discardMarkandmsg_severity >= discardSeverityqqueueChkDiscardMsg()discardSeverityis 8, commented/* turn off */: no real severity reaches it, so stock rsyslog discards nothing hereqqueueSetDefaultsActionQueue()discardMarkcan't be used to opt out: any value below 1 is rewritten to 98% of the queue sizeqqueueConstructFinalize()queue.timeoutEnqueue(default 2000 ms) and drops the message only if it still hasn't draineddoEnqSingleObject()So
5is a departure from rsyslog's default, in the direction of dropping data, anddiscardSeverityis the only parameter that can express the other choice. At 8 the nearly-full discard is off and the sender blocks briefly under sustained pressure, which for a durable record is usually the better trade.The one lever available today is bounded both ways.
LOG_AGGREGATOR_ACTION_QUEUE_SIZEmovesdiscardMark, but it also scalesqueue.highwaterMark, so more accumulates in memory before the disk assist engages; the disk side is capped byLOG_AGGREGATOR_ACTION_MAX_DISK_USAGE_GB. Raising either buys a longer burst before the same silent discard.The attached PR registers
LOG_AGGREGATOR_ACTION_QUEUE_DISCARD_SEVERITY(0–8, default 5) and emits it in place of the literal. The default keeps today's behavior exactly, so #965's durability tests still pass unchanged; the PR adds the setting to that file's "settings users can set reach the queue" list. Whether the default should move to 8 to match rsyslog is a separate decision.That the discard is unobservable is a different problem with a different answer, requested separately (queue observability, #1097 ).