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

fix(docker-logs source): old messages that are dropped should be a component_error #14449

Merged
merged 4 commits into from
Sep 22, 2022

Conversation

StephenWakely
Copy link
Contributor

@StephenWakely StephenWakely commented Sep 16, 2022

Ref #14411

When receiving a message from docker that is older than the previous one, this message was being dropped and a trace message was emitted.

I would argue that this should be a component error, and this PR makes it so.

It's not 100% clear to me under what circumstances this error would occur, so I am open to arguments as to why this should remain a trace - in which case I will update to add a comment with that reason.

Signed-off-by: Stephen Wakely fungus.humungus@gmail.com

Signed-off-by: Stephen Wakely <fungus.humungus@gmail.com>
@netlify
Copy link

netlify bot commented Sep 16, 2022

Deploy Preview for vector-project canceled.

Name Link
🔨 Latest commit 802d5a1
🔍 Latest deploy log https://app.netlify.com/sites/vector-project/deploys/632c35537d4d6b000840595e

@github-actions github-actions bot added the domain: sources Anything related to the Vector's sources label Sep 16, 2022
Signed-off-by: Stephen Wakely <fungus.humungus@gmail.com>
Copy link
Contributor

@neuronull neuronull left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not sure I know enough about this source to intelligently debate whether it should be a trace! or an internal event.
I guess the question I have is - when that occurs it looks like we just don't insert a timestamp into the created log event. But it still looks like we process it the same otherwise. 🤔 I guess I'm not totally convinced it is an Error case 🤷

src/sources/docker_logs.rs Outdated Show resolved Hide resolved
src/internal_events/docker_logs.rs Outdated Show resolved Hide resolved
@StephenWakely
Copy link
Contributor Author

But it still looks like we process it the same otherwise. thinking I guess I'm not totally convinced it is an Error case shrug

No. If you note when we hit that point there is a return None;. This breaks out of creating the event completely. None values get filtered out.

Signed-off-by: Stephen Wakely <fungus.humungus@gmail.com>
@github-actions
Copy link

Soak Test Results

Baseline: 9cf1ea9
Comparison: 4f5960f
Total Vector CPUs: 4

Explanation

A soak test is an integrated performance test for vector in a repeatable rig, with varying configuration for vector. What follows is a statistical summary of a brief vector run for each configuration across SHAs given above. The goal of these tests are to determine, quickly, if vector performance is changed and to what degree by a pull request. Where appropriate units are scaled per-core.

The table below, if present, lists those experiments that have experienced a statistically significant change in their throughput performance between baseline and comparision SHAs, with 90.0% confidence OR have been detected as newly erratic. Negative values mean that baseline is faster, positive comparison. Results that do not exhibit more than a ±8.87% change in mean throughput are discarded. An experiment is erratic if its coefficient of variation is greater than 0.3. The abbreviated table will be omitted if no interesting changes are observed.

No interesting changes in throughput with confidence ≥ 90.00% and absolute Δ mean >= ±8.87%:

Fine details of change detection per experiment.
experiment Δ mean Δ mean % confidence baseline mean baseline stdev baseline stderr baseline outlier % baseline CoV comparison mean comparison stdev comparison stderr comparison outlier % comparison CoV erratic declared erratic
socket_to_socket_blackhole 253.92KiB 1.08 100.00% 22.89MiB 549.6KiB 11.22KiB 0 0.0234449 23.14MiB 217.32KiB 4.44KiB 0 0.00917114 False False
http_pipelines_blackhole_acks 9.95KiB 0.8 99.90% 1.21MiB 116.83KiB 2.38KiB 0 0.0944206 1.22MiB 92.02KiB 1.87KiB 0 0.0737749 False False
syslog_loki 108.75KiB 0.73 100.00% 14.49MiB 433.22KiB 8.87KiB 0 0.0291819 14.6MiB 748.57KiB 15.22KiB 0 0.0500575 False False
syslog_log2metric_humio_metrics 47.0KiB 0.36 99.99% 12.9MiB 268.71KiB 5.48KiB 0 0.0203378 12.95MiB 503.59KiB 10.25KiB 0 0.0379796 False False
splunk_hec_indexer_ack_blackhole 7.05KiB 0.03 21.86% 23.76MiB 896.77KiB 18.25KiB 0 0.0368563 23.76MiB 868.85KiB 17.68KiB 0 0.0356985 False False
splunk_hec_to_splunk_hec_logs_noack 4.5KiB 0.02 33.35% 23.83MiB 386.08KiB 7.88KiB 0 0.0158164 23.84MiB 335.29KiB 6.85KiB 0 0.0137334 False False
http_pipelines_blackhole 232.99B 0.01 6.72% 1.62MiB 58.43KiB 1.19KiB 0 0.0351275 1.62MiB 118.81KiB 2.42KiB 0 0.0714174 False False
enterprise_http_to_http 1.05KiB 0 11.56% 23.85MiB 249.73KiB 5.1KiB 0 0.0102256 23.85MiB 251.4KiB 5.14KiB 0 0.0102935 False False
splunk_hec_to_splunk_hec_logs_acks 873.07B 0 2.81% 23.76MiB 842.11KiB 17.13KiB 0 0.0346112 23.76MiB 841.32KiB 17.12KiB 0 0.0345777 False False
http_to_http_acks -5.97KiB -0.03 2.00% 17.61MiB 8.09MiB 169.1KiB 0 0.459282 17.6MiB 8.07MiB 168.33KiB 0 0.45821 True True
file_to_blackhole -55.48KiB -0.06 39.74% 95.34MiB 3.38MiB 70.13KiB 0 0.035476 95.28MiB 3.86MiB 80.21KiB 0 0.0404589 False False
http_to_http_json -42.2KiB -0.17 99.87% 23.85MiB 335.86KiB 6.86KiB 0 0.013749 23.81MiB 548.59KiB 11.2KiB 0 0.0224962 False False
fluent_elasticsearch -168.52KiB -0.21 100.00% 79.47MiB 55.55KiB 1.12KiB 0 0.000682474 79.31MiB 1.46MiB 30.03KiB 0 0.0184025 False False
datadog_agent_remap_blackhole_acks -143.56KiB -0.23 79.00% 61.08MiB 4.5MiB 93.65KiB 0 0.0736225 60.94MiB 3.15MiB 65.88KiB 0 0.05172 False False
http_to_http_noack -69.5KiB -0.28 99.85% 23.84MiB 408.11KiB 8.34KiB 0 0.0167158 23.77MiB 992.74KiB 20.23KiB 0 0.0407784 False False
datadog_agent_remap_datadog_logs_acks -244.26KiB -0.38 96.68% 62.3MiB 3.44MiB 71.88KiB 0 0.0552354 62.06MiB 4.29MiB 89.3KiB 0 0.0690997 False False
datadog_agent_remap_blackhole -287.79KiB -0.46 99.76% 61.68MiB 3.56MiB 74.3KiB 0 0.0577422 61.4MiB 2.83MiB 59.1KiB 0 0.0461213 False False
splunk_hec_route_s3 -151.07KiB -0.78 97.99% 19.01MiB 2.21MiB 45.94KiB 0 0.11599 18.87MiB 2.19MiB 45.93KiB 0 0.116311 False False
datadog_agent_remap_datadog_logs -540.66KiB -0.84 100.00% 62.83MiB 299.12KiB 6.12KiB 0 0.00464837 62.3MiB 4.18MiB 87.03KiB 0 0.0670678 False False
syslog_regex_logs2metric_ddmetrics -122.06KiB -0.95 100.00% 12.51MiB 575.08KiB 11.72KiB 0 0.0448857 12.39MiB 560.86KiB 11.43KiB 0 0.0441968 False False
http_pipelines_no_grok_blackhole -138.46KiB -1.25 100.00% 10.84MiB 93.72KiB 1.91KiB 0 0.00844227 10.7MiB 1.07MiB 22.36KiB 0 0.100317 False False
syslog_splunk_hec_logs -226.76KiB -1.33 100.00% 16.6MiB 714.94KiB 14.56KiB 0 0.0420574 16.38MiB 609.67KiB 12.43KiB 0 0.0363495 False False
syslog_humio_logs -252.72KiB -1.49 100.00% 16.58MiB 109.32KiB 2.23KiB 0 0.00643698 16.33MiB 129.63KiB 2.65KiB 0 0.00774826 False False
syslog_log2metric_splunk_hec_metrics -294.92KiB -1.62 100.00% 17.81MiB 699.63KiB 14.25KiB 0 0.0383597 17.52MiB 776.76KiB 15.81KiB 0 0.0432885 False False
http_text_to_http_json -2.25MiB -5.81 100.00% 38.68MiB 884.51KiB 18.05KiB 0 0.0223285 36.43MiB 842.69KiB 17.2KiB 0 0.0225847 False False

@neuronull
Copy link
Contributor

But it still looks like we process it the same otherwise. thinking I guess I'm not totally convinced it is an Error case shrug

No. If you note when we hit that point there is a return None;. This breaks out of creating the event completely. None values get filtered out.

Ah, I missed the return None; there. 👍

@@ -197,7 +197,7 @@ pub struct DockerLogsReceivedOldLogError<'a> {
impl InternalEvent for DockerLogsReceivedOldLogError<'_> {
fn emit(self) {
error!(
message = "Received older log.",
message = "Received out of order log message.",
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Small thing but, 💭 Should we update the name of the event to more closely match this? E.g. DockerLogsReceivedOutOfOrderError or just DockerLogsOutOfOrderError ?

Signed-off-by: Stephen Wakely <fungus.humungus@gmail.com>
@StephenWakely StephenWakely enabled auto-merge (squash) September 22, 2022 10:19
@StephenWakely StephenWakely merged commit d8ca608 into master Sep 22, 2022
@StephenWakely StephenWakely deleted the stephen/docker_source_old_error branch September 22, 2022 11:42
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
domain: sources Anything related to the Vector's sources
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants