Skip to content

Commit e8487d7

Browse files
orestisflmergify[bot]
authored andcommitted
kerneltracingprovider: Fix backoff data races (#51745)
The add_session_metadata processor's kernel_tracing provider read and wrote its backoff accounting fields with no synchronization. The provider's only lock, qqMtx, guards the quark queue lookups, not these fields. The fix guards the backoff fields with a dedicated mutex, kept separate from qqMtx so backoff accounting does not serialize with quark queue lookups. (cherry picked from commit 49a887e)
1 parent f51c00c commit e8487d7

2 files changed

Lines changed: 42 additions & 28 deletions

File tree

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,3 @@
1+
kind: bug-fix
2+
summary: Fix data races in the add_session_metadata kernel_tracing provider backoff accounting
3+
component: auditbeat

x-pack/auditbeat/processors/sessionmd/provider/kerneltracingprovider/kerneltracingprovider_linux.go

Lines changed: 39 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -29,10 +29,13 @@ import (
2929
)
3030

3131
type prvdr struct {
32-
ctx context.Context
33-
logger *logp.Logger
34-
qq *quark.Queue
35-
qqMtx *sync.Mutex
32+
ctx context.Context
33+
logger *logp.Logger
34+
35+
qqMtx sync.Mutex
36+
qq *quark.Queue
37+
38+
backoffMtx sync.Mutex
3639
combinedWait time.Duration
3740
inBackoff bool
3841
backoffStart time.Time
@@ -94,15 +97,11 @@ func NewProvider(ctx context.Context, logger *logp.Logger, reg *monitoring.Regis
9497
procMetrics := NewStats(reg)
9598

9699
p := &prvdr{
97-
ctx: ctx,
98-
logger: logger,
99-
qq: qq,
100-
qqMtx: new(sync.Mutex),
101-
combinedWait: 0 * time.Millisecond,
102-
inBackoff: false,
103-
backoffStart: time.Now(),
104-
since: time.Now(),
105-
backoffSkipped: 0,
100+
ctx: ctx,
101+
logger: logger,
102+
qq: qq,
103+
backoffStart: time.Now(),
104+
since: time.Now(),
106105
}
107106

108107
go func(ctx context.Context, qq *quark.Queue, logger *logp.Logger, p *prvdr, stats *Stats) {
@@ -176,8 +175,7 @@ func (p *prvdr) Sync(_ *beat.Event, pid uint32) error {
176175

177176
start := time.Now()
178177

179-
p.handleBackoff(start)
180-
if p.inBackoff {
178+
if p.handleBackoff(start) {
181179
return nil
182180
}
183181

@@ -187,11 +185,11 @@ func (p *prvdr) Sync(_ *beat.Event, pid uint32) error {
187185
waited := time.Since(start)
188186
if _, found := p.lookupLocked(pid); found {
189187
p.logger.Debugw("got process that was missing ", "waited", waited)
190-
p.combinedWait = p.combinedWait + waited
188+
p.addCombinedWait(waited)
191189
return nil
192190
}
193191
if waited >= maxWaitLimit {
194-
p.combinedWait = p.combinedWait + waited
192+
p.addCombinedWait(waited)
195193
return fmt.Errorf("process %v was not seen after %v", pid, waited)
196194
}
197195
time.Sleep(nextWait)
@@ -203,34 +201,47 @@ func (p *prvdr) Sync(_ *beat.Event, pid uint32) error {
203201
}
204202
}
205203

206-
// handleBackoff handles backoff logic of `Sync`
204+
// handleBackoff handles backoff logic of `Sync` and reports whether the
205+
// provider is currently in backoff (in which case the caller must skip waiting
206+
// for the process to appear in the cache).
207+
//
207208
// If the combinedWait time exceeds the combinedWaitLimit duration, the provider will go into backoff state until the backoffDuration is exceeded.
208209
// If in a backoff period, it will track the number of skipped processes, and then log the number when exiting backoff.
209210
//
210211
// If there have been no backoffs within the resetDuration, the combinedWait duration is reset to zero, to keep a moving window in which delays are tracked.
211-
func (p *prvdr) handleBackoff(now time.Time) {
212+
func (p *prvdr) handleBackoff(now time.Time) bool {
213+
p.backoffMtx.Lock()
214+
defer p.backoffMtx.Unlock()
215+
212216
if p.inBackoff {
213217
if now.Sub(p.backoffStart) > backoffDuration {
214218
p.logger.Infow("ended backoff, skipped processes", "backoffSkipped", p.backoffSkipped)
215219
p.inBackoff = false
216-
p.combinedWait = 0 * time.Millisecond
220+
p.combinedWait = 0
217221
} else {
218222
p.backoffSkipped += 1
219-
return
220223
}
221224
} else {
222225
if p.combinedWait > combinedWaitLimit {
223226
p.logger.Info("starting backoff")
224227
p.inBackoff = true
225228
p.backoffStart = now
226229
p.backoffSkipped = 0
227-
return
228230
}
229231
if now.Sub(p.since) > resetDuration {
230232
p.since = now
231-
p.combinedWait = 0 * time.Millisecond
233+
p.combinedWait = 0
232234
}
233235
}
236+
return p.inBackoff
237+
}
238+
239+
// addCombinedWait adds waited to the shared wait budget under backoffMtx.
240+
func (p *prvdr) addCombinedWait(waited time.Duration) {
241+
p.backoffMtx.Lock()
242+
defer p.backoffMtx.Unlock()
243+
244+
p.combinedWait += waited
234245
}
235246

236247
// GetProcess returns a reference to Process struct that contains all known information for the
@@ -288,15 +299,15 @@ func (p *prvdr) GetProcess(pid uint32) (*types.Process, error) {
288299
return &ret, nil
289300
}
290301

291-
func (p prvdr) lookupLocked(pid uint32) (quark.Process, bool) {
302+
func (p *prvdr) lookupLocked(pid uint32) (quark.Process, bool) {
292303
p.qqMtx.Lock()
293304
defer p.qqMtx.Unlock()
294305

295306
return p.qq.Lookup(int(pid))
296307
}
297308

298309
// fillParent populates the parent process fields with the attributes of the process with PID `ppid`
299-
func (p prvdr) fillParent(process *types.Process, ppid uint32) {
310+
func (p *prvdr) fillParent(process *types.Process, ppid uint32) {
300311
proc, found := p.lookupLocked(ppid)
301312
if !found {
302313
return
@@ -330,7 +341,7 @@ func (p prvdr) fillParent(process *types.Process, ppid uint32) {
330341
}
331342

332343
// fillGroupLeader populates the process group leader fields with the attributes of the process with PID `pgid`
333-
func (p prvdr) fillGroupLeader(process *types.Process, pgid uint32) {
344+
func (p *prvdr) fillGroupLeader(process *types.Process, pgid uint32) {
334345
proc, found := p.lookupLocked(pgid)
335346
if !found {
336347
return
@@ -365,7 +376,7 @@ func (p prvdr) fillGroupLeader(process *types.Process, pgid uint32) {
365376
}
366377

367378
// fillSessionLeader populates the session leader fields with the attributes of the process with PID `sid`
368-
func (p prvdr) fillSessionLeader(process *types.Process, sid uint32) {
379+
func (p *prvdr) fillSessionLeader(process *types.Process, sid uint32) {
369380
proc, found := p.lookupLocked(sid)
370381
if !found {
371382
return
@@ -400,7 +411,7 @@ func (p prvdr) fillSessionLeader(process *types.Process, sid uint32) {
400411
}
401412

402413
// fillEntryLeader populates the entry leader fields with the attributes of the process with PID `elid`
403-
func (p prvdr) fillEntryLeader(process *types.Process, elid uint32) {
414+
func (p *prvdr) fillEntryLeader(process *types.Process, elid uint32) {
404415
proc, found := p.lookupLocked(elid)
405416
if !found {
406417
return

0 commit comments

Comments
 (0)