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 https_batch deadlock due to golang timer changes #648

Open
wants to merge 2 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
41 changes: 23 additions & 18 deletions src/pkg/egress/syslog/https_batch.go
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,8 @@ import (

const BATCHSIZE = 256 * 1024

var DefaultSendInterval = 1 * time.Second
Copy link
Contributor

Choose a reason for hiding this comment

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

I wonder if we need to expose config parameters which can be set with envvars on Syslog Agent start.

I don't have anything against, that we merge this as is and we open up the config parameters later.

Any thoughts on this @ctlong?


type HTTPSBatchWriter struct {
HTTPSWriter
msgs chan []byte
Expand Down Expand Up @@ -40,7 +42,7 @@ func NewHTTPSBatchWriter(
syslogConverter: c,
},
batchSize: BATCHSIZE,
sendInterval: 1 * time.Second,
sendInterval: DefaultSendInterval,
egrMsgCount: 0,
msgs: make(chan []byte),
}
Expand All @@ -65,34 +67,37 @@ func (w *HTTPSBatchWriter) Write(env *loggregator_v2.Envelope) error {
}

func (w *HTTPSBatchWriter) startSender() {
t := time.NewTimer(w.sendInterval)

var msgBatch bytes.Buffer
var msgCount float64
reset := func() {
msgBatch.Reset()
msgCount = 0
t.Reset(w.sendInterval)
ticker := time.NewTicker(w.sendInterval)
defer ticker.Stop()

msgCount = 0

sendBatch := func() {
if msgBatch.Len() > 0 {
w.sendHttpRequest(msgBatch.Bytes(), msgCount) //nolint:errcheck
msgBatch.Reset()
msgCount = 0
}
}

for {
select {
case msg := <-w.msgs:
length, buffer_err := msgBatch.Write(msg)
_, buffer_err := msgBatch.Write(msg)
if buffer_err != nil {
log.Printf("Failed to write to buffer, dropping buffer of size %d , err: %s", length, buffer_err)
reset()
log.Printf("Failed to write to buffer, dropping buffer of size %d , err: %s", msgBatch.Len(), buffer_err)
msgBatch.Reset()
msgCount = 0
} else {
msgCount++
if length >= w.batchSize {
w.sendHttpRequest(msgBatch.Bytes(), msgCount) //nolint:errcheck
reset()
if msgBatch.Len() >= w.batchSize {
sendBatch()
}
}
case <-t.C:
if msgBatch.Len() > 0 {
w.sendHttpRequest(msgBatch.Bytes(), msgCount) //nolint:errcheck
reset()
}
case <-ticker.C:
sendBatch()
}
}
}
28 changes: 22 additions & 6 deletions src/pkg/egress/syslog/https_batch_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,10 @@ import (

var string_to_1024_chars = "saljdflajsdssdfsdfljkfkajafjajlköflkjöjaklgljksdjlakljkflkjweljklkwjejlkfekljwlkjefjklwjklsdajkljklwerlkaskldgjksakjekjwrjkljasdjkgfkljwejklrkjlklasdkjlsadjlfjlkadfljkajklsdfjklslkdfjkllkjasdjkflsdlakfjklasldfkjlasdjfkjlsadlfjklaljsafjlslkjawjklerkjljklasjkdfjklwerjljalsdjkflwerjlkwejlkarjklalkklfsdjlfhkjsdfkhsewhkjjasdjfkhwkejrkjahjefkhkasdjhfkashfkjwehfkksadfjaskfkhjdshjfhewkjhasdfjdajskfjwehkfajkankaskjdfasdjhfkkjhjjkasdfjhkjahksdf"

func init() {
syslog.DefaultSendInterval = 100 * time.Millisecond // Modify behavior for tests
}

var _ = Describe("HTTPS_batch", func() {
var (
netConf syslog.NetworkTimeoutConfig
Expand Down Expand Up @@ -86,21 +90,33 @@ var _ = Describe("HTTPS_batch", func() {
env1 := buildLogEnvelope("APP", "1", "string to get log to 1024 characters:"+string_to_1024_chars, loggregator_v2.Log_OUT)
for i := 0; i < 10; i++ {
Expect(writer.Write(env1)).To(Succeed())
time.Sleep(99 * time.Millisecond)
time.Sleep(5 * time.Millisecond)
}
Expect(drain.getMessagesSize()).Should(Equal(0))
time.Sleep(100 * time.Millisecond)
Expect(drain.getMessagesSize()).Should(Equal(10))
})

It("probabilistic test for race condition", func() {
It("test dispatching for batches before timewindow is finished", func() {
env1 := buildLogEnvelope("APP", "1", "string to get log to 1024 characters:"+string_to_1024_chars, loggregator_v2.Log_OUT)
for i := 0; i < 10; i++ {
for i := 0; i < 300; i++ {
Expect(writer.Write(env1)).To(Succeed())
time.Sleep(99 * time.Millisecond)
}
time.Sleep(100 * time.Millisecond)
Expect(drain.getMessagesSize()).Should(Equal(10))
Expect(drain.getMessagesSize()).Should(Equal(256))
time.Sleep(101 * time.Millisecond)
Expect(drain.getMessagesSize()).Should(Equal(300))
})

It("test for hanging after some ticks", func() {
// This test will not succeed on the timer based implementation,
// it works fine with a ticker based implementation.
env1 := buildLogEnvelope("APP", "1", "only a short test message", loggregator_v2.Log_OUT)
for i := 0; i < 5; i++ {
Expect(writer.Write(env1)).To(Succeed())
time.Sleep(300 * time.Millisecond)
}
time.Sleep(101 * time.Millisecond)
Expect(drain.getMessagesSize()).Should(Equal(5))
})
})

Expand Down
Loading