Commit
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.
finagle-core: Stop recording transit latency and deadline budget for …
…clients Problem Finagle records transit latency for clients, but only servers care about it. Solution Move the transit latency stat out of StatsFilter and into ServerStatsFilter. Handletime is also a server-specific stat, so moved that into ServerStatsFilter too, and deleted HandletimeFilter. This has the added advantage of recording transit latency at the same time we do handletime, which is one of the earliest points. This review also handles some other miscellaneous cleanup, making no-allocation, testable, elapsed duration easier to use, adding tests for handletime, transit latency and deadline budget. Result Finagle services no longer export transit_latency_ms or deadline_budget_ms for clients. It's not useful for clients, so it's safe to remove it. RB_ID=751268
- Loading branch information
Showing
16 changed files
with
212 additions
and
109 deletions.
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
49 changes: 0 additions & 49 deletions
49
finagle-core/src/main/scala/com/twitter/finagle/filter/HandletimeFilter.scala
This file was deleted.
Oops, something went wrong.
67 changes: 67 additions & 0 deletions
67
finagle-core/src/main/scala/com/twitter/finagle/filter/ServerStatsFilter.scala
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,67 @@ | ||
| package com.twitter.finagle.filter | ||
|
|
||
| import com.twitter.finagle.Deadline | ||
| import com.twitter.finagle.context.Contexts | ||
| import com.twitter.finagle.stats.StatsReceiver | ||
| import com.twitter.finagle.{param, Service, ServiceFactory, SimpleFilter, Stack, Stackable} | ||
| import com.twitter.util.{Future, Stopwatch, Time, Duration} | ||
| import java.util.concurrent.TimeUnit | ||
|
|
||
| private[finagle] object ServerStatsFilter { | ||
| val role = Stack.Role("ServerStats") | ||
|
|
||
| /** | ||
| * Creates a [[com.twitter.finagle.Stackable]] [[com.twitter.finagle.filter.ServerStatsFilter]]. | ||
| */ | ||
| def module[Req, Rep]: Stackable[ServiceFactory[Req, Rep]] = | ||
| new Stack.Module1[param.Stats, ServiceFactory[Req, Rep]] { | ||
| val role = ServerStatsFilter.role | ||
| val description = "Record elapsed execution time, transit latency, deadline budget, of underlying service" | ||
| def make(_stats: param.Stats, next: ServiceFactory[Req, Rep]) = { | ||
| val param.Stats(statsReceiver) = _stats | ||
| new ServerStatsFilter(statsReceiver).andThen(next) | ||
| } | ||
| } | ||
|
|
||
| /** Used as a sentinel with reference equality to indicate the absence of a deadline */ | ||
| private val NoDeadline = Deadline(Time.Undefined, Time.Undefined) | ||
| private val NoDeadlineFn = () => NoDeadline | ||
| } | ||
|
|
||
| /** | ||
| * A [[com.twitter.finagle.Filter]] that records the elapsed execution | ||
| * times of the underlying [[com.twitter.finagle.Service]], transit | ||
| * time, and budget time. | ||
| * | ||
| * @note the stat does not include the time that it takes to satisfy | ||
| * the returned `Future`, only how long it takes for the `Service` | ||
| * to return the `Future`. | ||
| */ | ||
| private[finagle] class ServerStatsFilter[Req, Rep](statsReceiver: StatsReceiver, nowNanos: () => Long) | ||
| extends SimpleFilter[Req, Rep] | ||
| { | ||
| import ServerStatsFilter._ | ||
|
|
||
| def this(statsReceiver: StatsReceiver) = this(statsReceiver, Stopwatch.systemNanos) | ||
|
|
||
| private[this] val handletime = statsReceiver.stat("handletime_us") | ||
| private[this] val transitTimeStat = statsReceiver.stat("transit_latency_ms") | ||
| private[this] val budgetTimeStat = statsReceiver.stat("deadline_budget_ms") | ||
|
|
||
| def apply(request: Req, service: Service[Req, Rep]): Future[Rep] = { | ||
| val startAt = nowNanos() | ||
|
|
||
| val dl = Contexts.broadcast.getOrElse(Deadline, NoDeadlineFn) | ||
| if (dl ne NoDeadline) { | ||
| val now = Time.now | ||
| transitTimeStat.add(((now-dl.timestamp) max Duration.Zero).inUnit(TimeUnit.MILLISECONDS)) | ||
| budgetTimeStat.add(((dl.deadline-now) max Duration.Zero).inUnit(TimeUnit.MILLISECONDS)) | ||
| } | ||
|
|
||
| try service(request) | ||
| finally { | ||
| val elapsedNs = nowNanos() - startAt | ||
| handletime.add(TimeUnit.MICROSECONDS.convert(elapsedNs, TimeUnit.NANOSECONDS)) | ||
| } | ||
| } | ||
| } |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
58 changes: 58 additions & 0 deletions
58
finagle-core/src/test/scala/com/twitter/finagle/filter/ServerStatsFilterTest.scala
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,58 @@ | ||
| package com.twitter.finagle.filter | ||
|
|
||
| import com.twitter.finagle.{Deadline, Service} | ||
| import com.twitter.finagle.context.Contexts | ||
| import com.twitter.finagle.stats.InMemoryStatsReceiver | ||
| import com.twitter.util.{Stopwatch, Time, Future} | ||
| import com.twitter.conversions.time._ | ||
| import org.junit.runner.RunWith | ||
| import org.scalatest.FunSuite | ||
| import org.scalatest.junit.JUnitRunner | ||
|
|
||
| @RunWith(classOf[JUnitRunner]) | ||
| class ServerStatsFilterTest extends FunSuite { | ||
| test("Records handletime for a service") { | ||
| Time.withCurrentTimeFrozen { ctl => | ||
| val inMemory = new InMemoryStatsReceiver | ||
| val svc = Service.mk[Unit, Unit] { unit => | ||
| ctl.advance(5.microseconds) | ||
| Future.never | ||
| } | ||
| val filter = new ServerStatsFilter[Unit, Unit](inMemory, Stopwatch.timeNanos) | ||
| filter.andThen(svc)(()) | ||
| val expected = 5 | ||
| val actual = inMemory.stats(Seq("handletime_us"))(0) | ||
| assert(actual == expected) | ||
| } | ||
| } | ||
|
|
||
| test("Records budget remaining for a service") { | ||
| Time.withCurrentTimeFrozen { ctl => | ||
| val inMemory = new InMemoryStatsReceiver | ||
| Contexts.broadcast.let(Deadline, Deadline(Time.now, Time.now + 15.milliseconds)) { | ||
| ctl.advance(5.milliseconds) | ||
| val svc = Service.mk[Unit, Unit] { unit => Future.never } | ||
| val filter = new ServerStatsFilter[Unit, Unit](inMemory, Stopwatch.timeNanos) | ||
| filter.andThen(svc)(()) | ||
| val expected = 10f | ||
| val actual = inMemory.stats(Seq("deadline_budget_ms"))(0) | ||
| assert(actual == expected) | ||
| } | ||
| } | ||
| } | ||
|
|
||
| test("Records transit time for a service") { | ||
| Time.withCurrentTimeFrozen { ctl => | ||
| val inMemory = new InMemoryStatsReceiver | ||
| Contexts.broadcast.let(Deadline, Deadline(Time.now, Time.now + 15.milliseconds)) { | ||
| ctl.advance(5.milliseconds) | ||
| val svc = Service.mk[Unit, Unit] { unit => Future.never } | ||
| val filter = new ServerStatsFilter[Unit, Unit](inMemory, Stopwatch.timeNanos) | ||
| filter.andThen(svc)(()) | ||
| val expected = 5f | ||
| val actual = inMemory.stats(Seq("transit_latency_ms"))(0) | ||
| assert(actual == expected) | ||
| } | ||
| } | ||
| } | ||
| } |
39 changes: 39 additions & 0 deletions
39
finagle-core/src/test/scala/com/twitter/finagle/server/StackServerTest.scala
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,39 @@ | ||
| package com.twitter.finagle.server | ||
|
|
||
| import com.twitter.conversions.time._ | ||
| import com.twitter.finagle.{Service, ServiceFactory, Deadline, Stack} | ||
| import com.twitter.finagle.context.Contexts | ||
| import com.twitter.finagle.param.Stats | ||
| import com.twitter.finagle.server.StackServer | ||
| import com.twitter.finagle.service.TimeoutFilter | ||
| import com.twitter.finagle.stack.Endpoint | ||
| import com.twitter.finagle.stats.InMemoryStatsReceiver | ||
| import com.twitter.util.{Await, Future, Time} | ||
| import org.junit.runner.RunWith | ||
| import org.scalatest.FunSuite | ||
| import org.scalatest.junit.JUnitRunner | ||
|
|
||
| @RunWith(classOf[JUnitRunner]) | ||
| class StackServerTest extends FunSuite { | ||
| test("Deadline isn't changed until after it's recorded") { | ||
| val echo = ServiceFactory.const(Service.mk[Unit, Deadline] { unit => | ||
| Future.value(Contexts.broadcast(Deadline)) | ||
| }) | ||
| val stack = StackServer.newStack[Unit, Deadline] ++ Stack.Leaf(Endpoint, echo) | ||
| val statsReceiver = new InMemoryStatsReceiver | ||
| val factory = stack.make(StackServer.defaultParams + TimeoutFilter.Param(1.second) + Stats(statsReceiver)) | ||
| val svc = Await.result(factory(), 5.seconds) | ||
| Time.withCurrentTimeFrozen { ctl => | ||
| Contexts.broadcast.let(Deadline, Deadline.ofTimeout(5.seconds)) { | ||
| ctl.advance(1.second) | ||
| val result = svc(()) | ||
|
|
||
| // we should be one second ahead | ||
| assert(statsReceiver.stats(Seq("transit_latency_ms"))(0) == 1.second.inMilliseconds.toFloat) | ||
|
|
||
| // but the deadline inside the service's closure should be updated | ||
| assert(Await.result(result) == Deadline.ofTimeout(1.second)) | ||
| } | ||
| } | ||
| } | ||
| } |
Oops, something went wrong.