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

BAAS-28597: Add counter for limiter wait calls #117

Merged
merged 13 commits into from
Mar 11, 2024
13 changes: 13 additions & 0 deletions runtime.go
Original file line number Diff line number Diff line change
Expand Up @@ -205,6 +205,9 @@
limiterTicksLeft int
ticks uint64

limiterWaitCount int64
limiterWaitTotalTime time.Duration

tickMetricTrackingEnabled bool
tickMetrics map[string]uint64
}
Expand All @@ -213,6 +216,16 @@
return self.ticks
}

// LimiterWaitCount tracks the amount of times the rate limiter throttles the execution.
func (self *Runtime) LimiterWaitCount() int64 {
return self.limiterWaitCount
Copy link
Author

Choose a reason for hiding this comment

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

@arahmanan the baas counterpart will be to log the LimiterWaitCount when the function execution finishes similar to how we log Ticks(). (This could also be a prometheus counter potentially, or perhaps I can piggyback on the Ticks log and include limiterWaitCount... we can discuss in the BAAS pr though)

Choose a reason for hiding this comment

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

oh I like the idea of adding it to the ticks log! If we do that, adding a new prom metric won't be necessary.

}

// LimiterWaitTotalTime tracks the total amount of time that the execution was throttled.
func (self *Runtime) LimiterWaitTotalTime() time.Duration {
return self.limiterWaitTotalTime
}

// SetStackTraceLimit sets an upper limit to the number of stack frames that
// goja will use when formatting an error's stack trace. By default, the limit
// is 10. This is consistent with V8 and SpiderMonkey.
Expand Down Expand Up @@ -498,7 +511,7 @@
// It is simpler, and not costly, to just have this map always initialized.
r.tickMetrics = make(map[string]uint64)

r.SetRateLimiter(rate.NewLimiter(rate.Inf, maxInt))

Check failure on line 514 in runtime.go

View workflow job for this annotation

GitHub Actions / test (1.16.x, ubuntu-latest, 386)

constant 9007199254740992 overflows int
}

func (r *Runtime) typeErrorResult(throw bool, args ...interface{}) {
Expand Down
41 changes: 31 additions & 10 deletions vm.go
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@ import (
"strings"
"sync"
"sync/atomic"
"time"

"github.com/dop251/goja/unistring"
)
Expand Down Expand Up @@ -617,17 +618,25 @@ func (vm *vm) run() {
ctx = context.Background()
}

if waitErr := vm.r.limiter.WaitN(ctx, vm.r.limiterTicksLeft); waitErr != nil {
if vm.r.vm.ctx == nil {
panic(waitErr)
}
if ctxErr := vm.r.vm.ctx.Err(); ctxErr != nil {
panic(ctxErr)
}
if strings.Contains(waitErr.Error(), "would exceed") {
panic(context.DeadlineExceeded)
now := time.Now()
r := vm.r.limiter.ReserveN(now, vm.r.limiterTicksLeft)
if !r.OK() {
panic("failed to make reservation")

Choose a reason for hiding this comment

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

Suggested change
panic("failed to make reservation")
panic(context.DeadlineExceeded)

This will keep the same behavior as the if strings.Contains(waitErr.Error(), "would exceed") { check. That being said, I don't believe this can ever happen at the moment.

}

if delay := r.DelayFrom(now); delay > 0 {
vm.r.limiterWaitCount++
vm.r.limiterWaitTotalTime += delay

if err := sleep(ctx, delay); err != nil {
r.Cancel()
panic(err)
}
panic(waitErr)
}
select {
case <-ctx.Done():
panic(ctx.Err())

Choose a reason for hiding this comment

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

[opt] I don't believe this extra check is necessary if delay == 0. We already interrupt the VM here, when the context times out / is canceled.

Copy link
Author

Choose a reason for hiding this comment

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

Hmm this was added in response to this test failing.. Though I still have test failures so I need to investigate what is happening.

Copy link
Author

Choose a reason for hiding this comment

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

Choose a reason for hiding this comment

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

Sorry, I'm not sure I follow. Did you figure out what caused the test to fail? I still think we can get rid of this extra select statement. Correct me if I'm wrong.

Copy link
Author

Choose a reason for hiding this comment

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

Ok tests are finally passing with these changes, test-api-other and test-vm-goja tasks do not finish without the extra context check (evergreen).

This check also exists in the WaitN function, so we're just pulling that over here.
image

Copy link
Author

Choose a reason for hiding this comment

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

Let me know if you'd like to chat about this.

Copy link
Author

@Calvinnix Calvinnix Feb 28, 2024

Choose a reason for hiding this comment

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

Specifically the TestFunctionExecTimeLimit test is what never finishes.

Choose a reason for hiding this comment

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

I see. [opt] The wait function has the select statement before it performs the reserve/wait operations. Should we do the same here? i.e. have this select statement right after we define ctx.

Copy link
Author

Choose a reason for hiding this comment

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

Yeah I think that's a good idea to stay consistent.

default:
}
}

Expand Down Expand Up @@ -5606,3 +5615,15 @@ func (s valueStack) MemUsage(ctx *MemUsageContext) (memUsage uint64, newMemUsage

return memUsage, newMemUsage, nil
}

// sleep is equivalent to time.Sleep, but is interruptible via context cancelation.
func sleep(ctx context.Context, duration time.Duration) error {
timer := time.NewTimer(duration)
defer timer.Stop()
select {
case <-ctx.Done():
return ctx.Err()
case <-timer.C:
return nil
}
}
Loading