Export psp CPU and Wall time to access log

Summary:
Getting this timing inside php is difficult and not accurate.
Provide this timing inside of HPHP via %Z and %z.

Test Plan:
added %Z %z in the access log and compared to timings
calculated in php and they were slighly higher, which is expected.

Reviewers: qigao

Reviewed By: qigao

CC: jasont, ps, mwilliams, qigao

Differential Revision: 346858

Task ID: 755067

src/runtime/base/server/access_log.cpp

@@ -19,6 +19,7 @@
 #include <time.h>
 #include <runtime/base/runtime_option.h>
 #include <runtime/base/server/server_note.h>
+#include <runtime/base/server/server_stats.h>
 #include <runtime/base/server/request_uri.h>
 #include <util/process.h>
 #include <util/atomic.h>
@@ -385,6 +386,12 @@ bool AccessLog::genField(ostringstream &out, const char* &format,
       }
     }
     break;
+  case 'Z':
+     out << ServerStats::Get("page.wall.psp");
+     break;
+  case 'z':
+     out << ServerStats::Get("page.cpu.psp");
+     break;
   default:
     return false;
   }

src/runtime/base/server/http_request_handler.cpp

@@ -263,6 +263,11 @@ void HttpRequestHandler::handleRequest(Transport *transport) {
     Logger::Error("Unhandled exception in HPHP server engine.");
   }
   GetAccessLog().log(transport, vhost);
+  /*
+   * HPHP logs may need to access data in ServerStats, so we have to
+   * clear the hashtable after writing the log entry.
+   */
+  ServerStats::Reset();
   hphp_session_exit();
 
   HttpProtocol::ClearRecord(ret, tmpfile);

src/runtime/base/server/server_stats.cpp

@@ -645,6 +645,10 @@ int64 ServerStats::Get(const string &name) {
   return ServerStats::s_logger->get(name);
 }
 
+void ServerStats::Reset() {
+  ServerStats::s_logger->reset();
+}
+
 void ServerStats::Clear() {
   Lock lock(s_lock, false);
   for (unsigned int i = 0; i < s_loggers.size(); i++) {
@@ -1027,7 +1031,6 @@ void ServerStats::logPage(const string &url, int code) {
     Merge(ps.m_values, m_values);
   }
 
-  m_values.clear();
   m_last = now;
   if (m_min == 0) {
     m_min = now;
@@ -1040,6 +1043,10 @@ void ServerStats::logPage(const string &url, int code) {
   m_threadStatus.m_done = time(0);
 }
 
+void ServerStats::reset() {
+  m_values.clear();
+}
+
 void ServerStats::clear() {
   Lock lock(m_lock, false);
   for (unsigned int i = 0; i < m_slots.size(); i++) {

src/runtime/base/server/server_stats.h

@@ -47,6 +47,7 @@ class ServerStats {
   static void Log(const std::string &name, int64 value);
   static int64 Get(const std::string &name);
   static void LogPage(const std::string &url, int code);
+  static void Reset();
   static void Clear();
   static void GetKeys(std::string &out, int64 from, int64 to);
   static void Report(std::string &out, Format format, int64 from, int64 to,
@@ -132,6 +133,7 @@ class ServerStats {
   void log(const std::string &name, int64 value);
   int64 get(const std::string &name);
   void logPage(const std::string &url, int code);
+  void reset();
   void clear();
   void collect(std::list<TimeSlot*> &slots, int64 from, int64 to);