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.

Sign up for GitHub

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

Jump to bottom

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

Merged
merged 13 commits into from
Mar 11, 2024
Merged

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

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
13 commits
Select commit Hold shift + click to select a range
0ae652c
BAAS-28597: Add counter for limiter wait calls
Calvinnix Feb 13, 2024
ea92633
add doc for LimiterWaitCount
Calvinnix Feb 13, 2024
9824c33
formatting
Calvinnix Feb 13, 2024
5edfab1
Improve wait tracking logic
Calvinnix Feb 16, 2024
c0dc87a
adjust how we wait to be more efficient
Calvinnix Feb 20, 2024
9796a86
change limiterWaitTotalTime type to time.Duration
Calvinnix Feb 21, 2024
d861907
clean up if condition
Calvinnix Feb 21, 2024
e07d007
another area to clean up if condition
Calvinnix Feb 21, 2024
c4ada0f
need to check if context is Done, this check doesn't happen if delay …
Calvinnix Feb 22, 2024
8b8c99f
remove ctx cancel check, may re-add and include default case since th…
Calvinnix Feb 28, 2024
5f81ce0
implement the ctx deadline check correctly
Calvinnix Feb 28, 2024
760c1e6
update panic error message
Calvinnix Feb 28, 2024
43a5dab
move select statement for consistency
Calvinnix Feb 28, 2024
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
5 changes: 5 additions & 0 deletions runtime.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -203,6 +203,7 @@

limiter *rate.Limiter
limiterTicksLeft int
limiterWaitCount uint64
ticks uint64

tickMetricTrackingEnabled bool
Expand All @@ -213,6 +214,10 @@
return self.ticks
}

func (self *Runtime) LimiterWaitCount() uint64 {
Calvinnix marked this conversation as resolved.
Show resolved Hide resolved
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)

Copy link

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.

}

// 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 +503,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 506 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
1 change: 1 addition & 0 deletions vm.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -617,6 +617,7 @@ func (vm *vm) run() {
ctx = context.Background()
}

vm.r.limiterWaitCount++
Copy link

Choose a reason for hiding this comment

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

we aren't actually waiting every time we call WaitN. To be able to determine if we are actually waiting take a look at this as an example. We'll only wait if the delay is > 0.

[opt] in addition to the number of times we waited, I think it would also be valuable to track the total delay for the entire execution.

Copy link
Author

Choose a reason for hiding this comment

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

Oh I see the distinction, does that come down to timing?

We have a rate limit of 10_000_000 and a burst value of 250_000 which I think is effectively 50_000 when you account for the burst divisor,

Aside from a lot of process yielding, I'm not sure I fully understand what scenario we actually wait and for how long.

If we use 10_000_000 ticks in half a second would we wait another half a second because that is the amount left until we can execute 50_000 ticks (provided by fillBucket)?

If we use 10_000_000 ticks with only 1ms left in the "second" window, would we only wait that 1ms before we can execute 50_000 ticks?

Copy link
Author

Choose a reason for hiding this comment

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

If the above is true I assume we could do something like:

reservation := vm.r.limiter.Reserve(time.Now(), vm.r.limiterTicksLeft)
// count reservation.Delay()
// increment wait counter if Delay > 0

Copy link
Author

Choose a reason for hiding this comment

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

			if r := vm.r.limiter.ReserveN(time.Now(), vm.r.limiterTicksLeft); r.OK() {
				waitDelayMS := r.Delay().Milliseconds()
				if waitDelayMS > 0 {
					vm.r.limiterWaitTotalMS += waitDelayMS
					vm.r.limiterWaitCount++
				}
			}
			if waitErr := vm.r.limiter.WaitN(ctx, vm.r.limiterTicksLeft); waitErr != nil {

Copy link

Choose a reason for hiding this comment

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

From the comment above WaitN:

WaitN blocks until lim permits n events to happen.

In other words, we aren't going to wait if the limit allows those n events to be processed. To be able to determine if we're actually waiting or not, you want to do something along these lines:

	now = time.Now()
	r := vm.r.limiter.ReserveN(now, vm.r.limiterTicksLeft)
	if !r.OK() {
		panic("")
	}

	// Wait if necessary
	delay = r.DelayFrom(now)
	if delay > 0 {
		vm.r.limiterWaitCount++
		
		err := util.Sleep(ctx, delay)
		if err != nil {
			r.Cancel()
			panic(err)
		}
	}

If we use 10_000_000 ticks in half a second would we wait another half a second because that is the amount left until we can execute 50_000 ticks (provided by fillBucket)?

Not exactly. We would approximately wait until enough time has passed to process the next 50k ticks. i.e. (50_000 / 10_000_000) => 0.005s => 5ms. You can find more about that here.

If we use 10_000_000 ticks with only 1ms left in the "second" window, would we only wait that 1ms before we can execute 50_000 ticks?

This can't happen. The rate limiter won't process more than 10_000_000 ticks / s. So it would just take 1s to process the first 10MM ticks. In other words, since we process 50k ticks at a time, a function can process at most 50k ticks every 5ms.

These docs do a decent job at explaining how this works. Let me know if you have more questions about it. I'm happy to also hop on a quick call.

if waitErr := vm.r.limiter.WaitN(ctx, vm.r.limiterTicksLeft); waitErr != nil {
if vm.r.vm.ctx == nil {
panic(waitErr)
Expand Down
Loading