# HG changeset patch
# User Gregory Szorc <gregory.szorc@gmail.com>
# Date 1471225044 25200
# Node ID 80df04266a16837e7659b92450f8a564e3da6531
# Parent  fc2442492606d94382fb6eef7dda9f8a80badaad
hgweb: profile HTTP requests

Currently, running `hg serve --profile` doesn't yield anything useful:
when the process is terminated the profiling output displays results
from the main thread, which typically spends most of its time in
select.select(). Furthermore, it has no meaningful results from
mercurial.* modules because the threads serving HTTP requests don't
actually get profiled.

This patch teaches the hgweb wsgi applications to profile individual
requests. If profiling is enabled, the profiler kicks in after
HTTP/WSGI environment processing but before Mercurial's main request
processing.

The profile results are printed to the configured profiling output.
If running `hg serve` from a shell, they will be printed to stderr,
just before the HTTP request line is logged. If profiling to a file,
we only write a single profile to the file because the file is not
opened in append mode. We could add support for appending to files
in a future patch if someone wants it.

Per request profiling doesn't work with the statprof profiler because
internally that profiler collects samples from the thread that
*initially* requested profiling be enabled. I have plans to address
this by vendoring Facebook's customized statprof and then improving
it.

diff -r fc2442492606 -r 80df04266a16 mercurial/hgweb/hgweb_mod.py
--- a/mercurial/hgweb/hgweb_mod.py	Sun Aug 14 16:03:30 2016 -0700
+++ b/mercurial/hgweb/hgweb_mod.py	Sun Aug 14 18:37:24 2016 -0700
@@ -28,6 +28,7 @@
     error,
     hg,
     hook,
+    profiling,
     repoview,
     templatefilters,
     templater,
@@ -305,8 +306,9 @@
         should be using instances of this class as the WSGI application.
         """
         with self._obtainrepo() as repo:
-            for r in self._runwsgi(req, repo):
-                yield r
+            with profiling.maybeprofile(repo.ui):
+                for r in self._runwsgi(req, repo):
+                    yield r
 
     def _runwsgi(self, req, repo):
         rctx = requestcontext(self, repo)
diff -r fc2442492606 -r 80df04266a16 mercurial/hgweb/hgwebdir_mod.py
--- a/mercurial/hgweb/hgwebdir_mod.py	Sun Aug 14 16:03:30 2016 -0700
+++ b/mercurial/hgweb/hgwebdir_mod.py	Sun Aug 14 18:37:24 2016 -0700
@@ -31,6 +31,7 @@
     encoding,
     error,
     hg,
+    profiling,
     scmutil,
     templater,
     ui as uimod,
@@ -217,7 +218,9 @@
         return False
 
     def run_wsgi(self, req):
-        return self._runwsgi(req)
+        with profiling.maybeprofile(self.ui):
+            for r in self._runwsgi(req):
+                yield r
 
     def _runwsgi(self, req):
         try:
diff -r fc2442492606 -r 80df04266a16 tests/test-profile.t
--- a/tests/test-profile.t	Sun Aug 14 16:03:30 2016 -0700
+++ b/tests/test-profile.t	Sun Aug 14 18:37:24 2016 -0700
@@ -31,4 +31,18 @@
 
 #endif
 
+#if lsprof serve
+
+Profiling of HTTP requests works
+
+  $ hg --profile --config profiling.format=text --config profiling.output=../profile.log serve -d -p $HGPORT --pid-file ../hg.pid -A ../access.log
+  $ cat ../hg.pid >> $DAEMON_PIDS
+  $ hg -q clone -U http://localhost:$HGPORT ../clone
+
+A single profile is logged because file logging doesn't append
+  $ grep CallCount ../profile.log | wc -l
+  \s*1 (re)
+
+#endif
+
   $ cd ..