Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with HTTPS or Subversion.

Download ZIP

Loading…

Feature which optionally times the performance of snippet evaluation #1377

Closed
wants to merge 3 commits into from

5 participants

@NoelKennedy

This feature optionally times the evaluation of snippets as discussed in this thread.

https://groups.google.com/forum/?fromgroups=#!topic/liftweb/yy8gxcjH_bs

I think this is worth writing up a quick wiki as its discoverability is zero and it is quite a useful feature (I used it to track down a performance problem in my app). Where should I be submitting documentation to?

Cheers,

Noel

@Shadowfiend

Why wrap this here instead of around S.doSnippet?

Ok, so if it is done in S.doSnippet there will be two timings for each snippet. Once for the evaluation of the outer element which contains the snippet tag (this is what I wanted to profile). And then another timing which reports when the closing element is encountered. This second timing will accumulate all the timings for any inner child snippets as well as the initial timing for the opening element. It will also be printed even if there are no inner children snippets which is usually done so quickly that the timings are identical and can appear to be duplicate recordings in the output.

You could go either way with this one but I felt it was easier to understand the output if the time reported for evaluating a snippet was just for that snippet. It doesn't seem right that timings for child snippets are 'double counted' into parent snippets' timings.

Hm. Ok, I'm all right with doing it this way for now. Last thing: let's make this a LiftRules thing. Something like LiftRules.snippetTimer { ... } or somesuch. I would definitely drop the apply and substitute it for braces, as that makes it clearer that you're passing a function in.

In LiftRules, I'd make snippetTimer a FactoryMaker as well (see noCometSessionCmd at https://github.com/lift/framework/blob/master/web/webkit/src/main/scala/net/liftweb/http/LiftRules.scala#L622 ). So then you'd use LiftRules.snippetTimer.vend { ... }. The purpose here is that you could then turn snippet timer logging off altogether except for a certain session (say you're debugging slowness with a particular user), or a certain request (if you want to debug slowness in a certain path), etc. Also it's in LiftRules so that people can exchange the logging for, say, a metrics instrumentation.

Sure! That sounds like a much more configurable way of doing it. I will hopefully have some time this week/next so will amend and resubmit. Could you advise on where I need to add the documentation? Is the best place on Assembla?

The wiki on Assembla is a good place, the Lift cookbook is another solid place. Documenting the property in LiftRules is the most basic docs you should add though.

@NoelKennedy

That's where I put it first actually but there was some reason why that wasn't so helpful. Let me put it back there and see if I can remember what the issue was.

contributors.md
@@ -65,3 +65,9 @@ Francis Rhys-Jones
### Email: ###
francis.rhys-jones at guardian dot co dot uk
+
+### Name: ###
+Noel Kennedy
+
+### Email: ###
+nkennedy@rvc.ac.uk
@fmpwizard Owner

very small detail but, the email should be as

nkennedy at rvc.ac.uk

:)

hehe, I believe in my bayesian filters, bring it on spam lords!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
@fmpwizard
Owner

@NoelKennedy : once you implement this as a LiftRule, please add a comment so I can then rebase this to master, thanks for the work so far!

@NoelKennedy

I should be able to work on it tonight. Cheers!

@lkuczera
Collaborator

Useful stuff I did it before but couldn't expand it to more reusable state.

@Shadowfiend
Owner

Have you had a chance to look at this @NoelKennedy ?

@NoelKennedy
@Shadowfiend
Owner

No worries at all! Just wanted to check in in case you weren't planning on making the change after all :) Good luck with the remainder of the move!

@NoelKennedy
@farmdawgnation
Collaborator

I moved this to the Lift 2.6 milestone, since it was attached to the 2.5-M5 milestone which has long since shipped. What's the status on this guy? Should we leave him open or close him until he's ready to ship?

@NoelKennedy
@fmpwizard
Owner

is there a way to detach the pull request nature of this and have it be an "issue"? What I mean is, if we close it, it would not be on the "pending bugs to be fixed list", if we leave it open, it shows as a pull request. I'd like to have the "issue ticket" of this, so that other committers or anyone who would like to contribute the feature, can pick it up.

@lkuczera
Collaborator
@Shadowfiend
Owner

Yeah, I think we'd have to create a new issue if we wanted to do that. I'm kind of fine simply labeling it somehow as needing help.

@farmdawgnation
Collaborator

The rub with just labeling this as "needing help" is that it doesn't exist in the main lift repo. Other comitters/users wouldn't have access to push updates, no?

@fmpwizard
Owner

I created a ticket that we can keep and label as we wish, and if anyone wants to take it over, they can send a new pull request and reference that ticket. The ticket is #1460

@fmpwizard fmpwizard closed this
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Commits on Dec 7, 2012
Commits on Dec 8, 2012
  1. Ammended my line in contributers to follow convention

    Noel Kennedy authored
  2. Snippet timer's message was incorrect. This version doesn't include t…

    Noel Kennedy authored
    …imings for a snippet's children.
This page is out of date. Refresh to see the latest.
View
6 contributors.md
@@ -65,3 +65,9 @@ Francis Rhys-Jones
### Email: ###
francis.rhys-jones at guardian dot co dot uk
+
+### Name: ###
+Noel Kennedy
+
+### Email: ###
+nkennedy at rvc dot ac dot uk
View
5 web/webkit/src/main/scala/net/liftweb/http/LiftSession.scala
@@ -1686,10 +1686,11 @@ class LiftSession(private[http] val _contextPath: String, val uniqueId: String,
val ret: NodeSeq =
try {
-
snippetName.map{snippet =>
val (cls, method) = splitColonPair(snippet)
- S.doSnippet(snippet)(
+ val snippetTimer = SnippetTimer.evaluate(snippet)
+
+ snippetTimer apply S.doSnippet(snippet)(
runWhitelist(snippet, cls, method, kids){(S.locateMappedSnippet(snippet).map(_(kids)) or
locSnippet(snippet)).openOr(
S.locateSnippet(snippet).map(_(kids)) openOr {
View
39 web/webkit/src/main/scala/net/liftweb/http/SnippetTimer.scala
@@ -0,0 +1,39 @@
+package net.liftweb.http
+
+import xml.NodeSeq
+import net.liftweb.util.TimeHelpers._
+import net.liftweb.util.Props
+
+/**
+ * Times the performance of evaluating of individual snippets
+ */
+object SnippetTimer {
+
+ /**
+ * The configured snippet timing function. Defaults to not timing snippets.
+ */
+ lazy val evaluate: String => (=> NodeSeq) => NodeSeq = {
+ if(Props.getBool("run.timesnippets",defVal = false))
+ timeSnippet _
+ else
+ noTiming _
+ }
+
+ /**
+ * Times the evaluation of a snippet
+ * @param snippetName String The name of the snippet
+ * @param f The snippet function
+ * @return NodeSeq The result of evaluating f
+ */
+ def timeSnippet(snippetName:String)(f: => NodeSeq) = {
+ logTime("Snippet %s evaluation" format snippetName, f)
+ }
+
+ /**
+ * A function which doesn't time a snippet but just evaluates it
+ * @param snippetName String Name of the snippet which is ignored
+ * @param f The snippet function
+ * @return NodeSeq The result of evaluating f
+ */
+ def noTiming(snippetName:String)(f: => NodeSeq) = f
+}
Something went wrong with that request. Please try again.