From c1d33410ad77b30c9930b606ac5a6095c6cb7fcb Mon Sep 17 00:00:00 2001 From: chodges15 Date: Wed, 31 Aug 2022 10:31:31 -0500 Subject: [PATCH 1/8] [promtail] Fix dropping logs issue when a target's labels are updated --- .../targets/file/filetargetmanager.go | 36 ++++++------- .../targets/file/filetargetmanager_test.go | 50 +++++++++++++++++++ 2 files changed, 69 insertions(+), 17 deletions(-) diff --git a/clients/pkg/promtail/targets/file/filetargetmanager.go b/clients/pkg/promtail/targets/file/filetargetmanager.go index 2a7f9188555e..d17a6343012d 100644 --- a/clients/pkg/promtail/targets/file/filetargetmanager.go +++ b/clients/pkg/promtail/targets/file/filetargetmanager.go @@ -273,6 +273,25 @@ func (s *targetSyncer) sync(groups []*targetgroup.Group, targetEventHandler chan targets := map[string]struct{}{} dropped := []target.Target{} + // process target removal first to avoid cleaning up fileEventWatchers that are needed by a new target + for key, target := range s.targets { + if _, ok := targets[key]; !ok { + level.Info(s.log).Log("msg", "Removing target", "key", key) + target.Stop() + s.metrics.targetsActive.Add(-1.) + delete(s.targets, key) + + // close related file event watcher + k := target.path + if _, ok := s.fileEventWatchers[k]; ok { + close(s.fileEventWatchers[k]) + delete(s.fileEventWatchers, k) + } else { + level.Warn(s.log).Log("msg", "failed to remove file event watcher", "path", k) + } + } + } + for _, group := range groups { for _, t := range group.Targets { level.Debug(s.log).Log("msg", "new target", "labels", t) @@ -356,23 +375,6 @@ func (s *targetSyncer) sync(groups []*targetgroup.Group, targetEventHandler chan } } - for key, target := range s.targets { - if _, ok := targets[key]; !ok { - level.Info(s.log).Log("msg", "Removing target", "key", key) - target.Stop() - s.metrics.targetsActive.Add(-1.) - delete(s.targets, key) - - // close related file event watcher - k := target.path - if _, ok := s.fileEventWatchers[k]; ok { - close(s.fileEventWatchers[k]) - delete(s.fileEventWatchers, k) - } else { - level.Warn(s.log).Log("msg", "failed to remove file event watcher", "path", k) - } - } - } s.droppedTargets = dropped } diff --git a/clients/pkg/promtail/targets/file/filetargetmanager_test.go b/clients/pkg/promtail/targets/file/filetargetmanager_test.go index b23a5493176d..3c718b2a2659 100644 --- a/clients/pkg/promtail/targets/file/filetargetmanager_test.go +++ b/clients/pkg/promtail/targets/file/filetargetmanager_test.go @@ -527,3 +527,53 @@ func TestDeadlockStartWatchingDuringSync(t *testing.T) { ftm.Stop() ps.Stop() } + +func TestLabelSetUpdate(t *testing.T) { + client := fake.New(func() {}) + defer client.Stop() + + targetEventHandler := make(chan fileTargetEvent) + defer func() { + close(targetEventHandler) + }() + + syncer := &targetSyncer{ + metrics: NewMetrics(nil), + log: log.NewLogfmtLogger(log.NewSyncWriter(os.Stderr)), + positions: nil, + entryHandler: client, + hostname: "localhost", + fileEventWatchers: make(map[string]chan fsnotify.Event), + targets: make(map[string]*FileTarget), + targetConfig: &Config{ + SyncPeriod: time.Hour, + }, + } + + var target = model.LabelSet{ + hostLabel: "localhost", + pathLabel: "baz", + "job": "foo", + } + + syncer.sync([]*targetgroup.Group{ + { + Targets: []model.LabelSet{target}, + }, + }, targetEventHandler) + syncer.sendFileCreateEvent(fsnotify.Event{Name: "baz"}) + + require.Equal(t, 1, len(syncer.targets)) + require.Equal(t, 1, len(syncer.fileEventWatchers)) + + target["job"] = "bar" + syncer.sync([]*targetgroup.Group{ + { + Targets: []model.LabelSet{target}, + }, + }, targetEventHandler) + + require.Equal(t, 1, len(syncer.targets)) + require.Equal(t, 1, len(syncer.fileEventWatchers)) + +} From bc8ccfac0f837fe564eb7828cac94897fa8200fb Mon Sep 17 00:00:00 2001 From: chodges15 Date: Wed, 31 Aug 2022 10:45:14 -0500 Subject: [PATCH 2/8] update changelog --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 26938816d84e..8e19a316851d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -36,6 +36,7 @@ ##### Fixes * [6766](https://github.com/grafana/loki/pull/6766) **kavirajk**: fix(logql): Make `LabelSampleExtractor` ignore processing the line if it doesn't contain that specific label. Fixes unwrap behavior explained in the issue https://github.com/grafana/loki/issues/6713 +* [?](https://github.com/grafana/loki/pull/?) **chodges15**: Fix issue with dropping logs when a target's labels are updated ##### Changes From 48dffe0936ebf383627ed8cc4cf56e72b6e096c4 Mon Sep 17 00:00:00 2001 From: chodges15 Date: Wed, 31 Aug 2022 10:53:02 -0500 Subject: [PATCH 3/8] update comment, gofmt --- clients/pkg/promtail/targets/file/filetargetmanager.go | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/clients/pkg/promtail/targets/file/filetargetmanager.go b/clients/pkg/promtail/targets/file/filetargetmanager.go index d17a6343012d..697647404e76 100644 --- a/clients/pkg/promtail/targets/file/filetargetmanager.go +++ b/clients/pkg/promtail/targets/file/filetargetmanager.go @@ -8,8 +8,6 @@ import ( "sync" "github.com/bmatcuk/doublestar" - "gopkg.in/fsnotify.v1" - "github.com/go-kit/log" "github.com/go-kit/log/level" "github.com/prometheus/client_golang/prometheus" @@ -19,6 +17,7 @@ import ( "github.com/prometheus/prometheus/discovery/targetgroup" "github.com/prometheus/prometheus/model/labels" "github.com/prometheus/prometheus/model/relabel" + "gopkg.in/fsnotify.v1" "github.com/grafana/loki/clients/pkg/logentry/stages" "github.com/grafana/loki/clients/pkg/promtail/api" @@ -273,7 +272,7 @@ func (s *targetSyncer) sync(groups []*targetgroup.Group, targetEventHandler chan targets := map[string]struct{}{} dropped := []target.Target{} - // process target removal first to avoid cleaning up fileEventWatchers that are needed by a new target + // process target removal first to avoid cleaning up fileEventWatchers that are needed by a new or modified target for key, target := range s.targets { if _, ok := targets[key]; !ok { level.Info(s.log).Log("msg", "Removing target", "key", key) From b26fea3497fa9d5c00ed8c6bdbd583c615662036 Mon Sep 17 00:00:00 2001 From: chodges15 Date: Wed, 31 Aug 2022 10:55:36 -0500 Subject: [PATCH 4/8] add github pull request # --- CHANGELOG.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 8e19a316851d..e1d2caee7158 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -36,7 +36,7 @@ ##### Fixes * [6766](https://github.com/grafana/loki/pull/6766) **kavirajk**: fix(logql): Make `LabelSampleExtractor` ignore processing the line if it doesn't contain that specific label. Fixes unwrap behavior explained in the issue https://github.com/grafana/loki/issues/6713 -* [?](https://github.com/grafana/loki/pull/?) **chodges15**: Fix issue with dropping logs when a target's labels are updated +* [7016](https://github.com/grafana/loki/pull/7016) **chodges15**: Fix issue with dropping logs when a target's labels are updated ##### Changes From e3e33b730706a29208361866d95ae9bcd25971cd Mon Sep 17 00:00:00 2001 From: chodges15 Date: Thu, 1 Sep 2022 09:41:45 -0500 Subject: [PATCH 5/8] fix issue where file watchers were deleted/recreated every sync --- .../targets/file/filetargetmanager.go | 63 ++++++++++++------- 1 file changed, 42 insertions(+), 21 deletions(-) diff --git a/clients/pkg/promtail/targets/file/filetargetmanager.go b/clients/pkg/promtail/targets/file/filetargetmanager.go index 697647404e76..ccb39e4c5666 100644 --- a/clients/pkg/promtail/targets/file/filetargetmanager.go +++ b/clients/pkg/promtail/targets/file/filetargetmanager.go @@ -269,28 +269,9 @@ func (s *targetSyncer) sync(groups []*targetgroup.Group, targetEventHandler chan s.mtx.Lock() defer s.mtx.Unlock() - targets := map[string]struct{}{} + targetsSeen := map[string]struct{}{} dropped := []target.Target{} - // process target removal first to avoid cleaning up fileEventWatchers that are needed by a new or modified target - for key, target := range s.targets { - if _, ok := targets[key]; !ok { - level.Info(s.log).Log("msg", "Removing target", "key", key) - target.Stop() - s.metrics.targetsActive.Add(-1.) - delete(s.targets, key) - - // close related file event watcher - k := target.path - if _, ok := s.fileEventWatchers[k]; ok { - close(s.fileEventWatchers[k]) - delete(s.fileEventWatchers, k) - } else { - level.Warn(s.log).Log("msg", "failed to remove file event watcher", "path", k) - } - } - } - for _, group := range groups { for _, t := range group.Targets { level.Debug(s.log).Log("msg", "new target", "labels", t) @@ -345,7 +326,7 @@ func (s *targetSyncer) sync(groups []*targetgroup.Group, targetEventHandler chan key = fmt.Sprintf("%s:%s", key, pathExclude) } - targets[key] = struct{}{} + targetsSeen[key] = struct{}{} if _, ok := s.targets[key]; ok { dropped = append(dropped, target.NewDroppedTarget("ignoring target, already exists", discoveredLabels)) level.Debug(s.log).Log("msg", "ignoring target, already exists", "labels", labels.String()) @@ -375,6 +356,46 @@ func (s *targetSyncer) sync(groups []*targetgroup.Group, targetEventHandler chan } s.droppedTargets = dropped + + // keep track of how many targets are using a fileEventWatcher + watcherUseCount := make(map[string]int, len(s.fileEventWatchers)) + for _, target := range s.targets { + if _, ok := watcherUseCount[target.path]; !ok { + watcherUseCount[target.path] = 1 + } else { + watcherUseCount[target.path] += 1 + } + } + + // remove existing targets not seen in groups arg; cleanup unused fileEventWatchers + for key, target := range s.targets { + if _, ok := targetsSeen[key]; !ok { + level.Info(s.log).Log("msg", "Removing target", "key", key) + target.Stop() + s.metrics.targetsActive.Add(-1.) + delete(s.targets, key) + + // close related file event watcher if no other targets are using + k := target.path + count, ok := watcherUseCount[k] + if !ok { + level.Warn(s.log).Log("msg", "failed to find file event watcher", "path", k) + continue + } else { + watcherUseCount[k] -= 1 + if count != 1 { + // Multiple targets are using this file watcher, leave it alone + continue + } + } + if _, ok := s.fileEventWatchers[k]; ok { + close(s.fileEventWatchers[k]) + delete(s.fileEventWatchers, k) + } else { + level.Warn(s.log).Log("msg", "failed to remove file event watcher", "path", k) + } + } + } } // sendFileCreateEvent sends file creation events to only the targets with matched path. From abc7c2d950f2c1083c21fdc3647822f13ba007d4 Mon Sep 17 00:00:00 2001 From: chodges15 Date: Thu, 1 Sep 2022 14:04:14 -0500 Subject: [PATCH 6/8] fix lint error --- clients/pkg/promtail/targets/file/filetargetmanager.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/clients/pkg/promtail/targets/file/filetargetmanager.go b/clients/pkg/promtail/targets/file/filetargetmanager.go index ccb39e4c5666..1d07fcfdff72 100644 --- a/clients/pkg/promtail/targets/file/filetargetmanager.go +++ b/clients/pkg/promtail/targets/file/filetargetmanager.go @@ -363,7 +363,7 @@ func (s *targetSyncer) sync(groups []*targetgroup.Group, targetEventHandler chan if _, ok := watcherUseCount[target.path]; !ok { watcherUseCount[target.path] = 1 } else { - watcherUseCount[target.path] += 1 + watcherUseCount[target.path]++ } } @@ -382,7 +382,7 @@ func (s *targetSyncer) sync(groups []*targetgroup.Group, targetEventHandler chan level.Warn(s.log).Log("msg", "failed to find file event watcher", "path", k) continue } else { - watcherUseCount[k] -= 1 + watcherUseCount[k]-- if count != 1 { // Multiple targets are using this file watcher, leave it alone continue From 3b341eaefa895c4ecfd2bf7693cd2c3c8decf2a4 Mon Sep 17 00:00:00 2001 From: Chris Hodges Date: Tue, 6 Sep 2022 14:31:45 -0500 Subject: [PATCH 7/8] make changelog entry clearer --- CHANGELOG.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index e1d2caee7158..9e6cc26316c7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -36,7 +36,7 @@ ##### Fixes * [6766](https://github.com/grafana/loki/pull/6766) **kavirajk**: fix(logql): Make `LabelSampleExtractor` ignore processing the line if it doesn't contain that specific label. Fixes unwrap behavior explained in the issue https://github.com/grafana/loki/issues/6713 -* [7016](https://github.com/grafana/loki/pull/7016) **chodges15**: Fix issue with dropping logs when a target's labels are updated +* [7016](https://github.com/grafana/loki/pull/7016) **chodges15**: Fix issue with dropping logs when a file based SD target's labels are updated ##### Changes From 9ad137deed56b32dce4a31e2d0dc27ca49026872 Mon Sep 17 00:00:00 2001 From: chodges15 Date: Wed, 7 Sep 2022 09:37:28 -0500 Subject: [PATCH 8/8] improve readability of file watcher use count check, add more robust testing --- .../targets/file/filetargetmanager.go | 5 ++--- .../targets/file/filetargetmanager_test.go | 21 +++++++++++++++++-- 2 files changed, 21 insertions(+), 5 deletions(-) diff --git a/clients/pkg/promtail/targets/file/filetargetmanager.go b/clients/pkg/promtail/targets/file/filetargetmanager.go index 1d07fcfdff72..f886a9ba6b37 100644 --- a/clients/pkg/promtail/targets/file/filetargetmanager.go +++ b/clients/pkg/promtail/targets/file/filetargetmanager.go @@ -377,13 +377,12 @@ func (s *targetSyncer) sync(groups []*targetgroup.Group, targetEventHandler chan // close related file event watcher if no other targets are using k := target.path - count, ok := watcherUseCount[k] + _, ok := watcherUseCount[k] if !ok { level.Warn(s.log).Log("msg", "failed to find file event watcher", "path", k) continue } else { - watcherUseCount[k]-- - if count != 1 { + if watcherUseCount[k]--; watcherUseCount[k] > 0 { // Multiple targets are using this file watcher, leave it alone continue } diff --git a/clients/pkg/promtail/targets/file/filetargetmanager_test.go b/clients/pkg/promtail/targets/file/filetargetmanager_test.go index 3c718b2a2659..83c7adb1195f 100644 --- a/clients/pkg/promtail/targets/file/filetargetmanager_test.go +++ b/clients/pkg/promtail/targets/file/filetargetmanager_test.go @@ -556,16 +556,24 @@ func TestLabelSetUpdate(t *testing.T) { "job": "foo", } + var target2 = model.LabelSet{ + hostLabel: "localhost", + pathLabel: "baz", + "job": "foo2", + } + + // two separate targets with same path syncer.sync([]*targetgroup.Group{ { - Targets: []model.LabelSet{target}, + Targets: []model.LabelSet{target, target2}, }, }, targetEventHandler) syncer.sendFileCreateEvent(fsnotify.Event{Name: "baz"}) - require.Equal(t, 1, len(syncer.targets)) + require.Equal(t, 2, len(syncer.targets)) require.Equal(t, 1, len(syncer.fileEventWatchers)) + // remove second target and modify the first target["job"] = "bar" syncer.sync([]*targetgroup.Group{ { @@ -576,4 +584,13 @@ func TestLabelSetUpdate(t *testing.T) { require.Equal(t, 1, len(syncer.targets)) require.Equal(t, 1, len(syncer.fileEventWatchers)) + // cleanup all targets + syncer.sync([]*targetgroup.Group{ + { + Targets: []model.LabelSet{}, + }, + }, targetEventHandler) + require.Equal(t, 0, len(syncer.targets)) + require.Equal(t, 0, len(syncer.fileEventWatchers)) + }