Prometheus - log per-document details for getMetrics.

This should perform and still be reasonably compact even
for large numbers of documents.

Change-Id: I3820af6c23806d569c23a893bd8db040dfb351e8
Signed-off-by: Michael Meeks <michael.meeks@collabora.com>

wsd/AdminModel.cpp

@@ -1159,6 +1159,32 @@ void AdminModel::getMetrics(std::ostringstream &oss)
     oss << "error_unauthorized_request " << UnauthorizedRequestException::count << "\n";
     oss << "error_service_unavailable " << ServiceUnavailableException::count << "\n";
     oss << "error_parse_error " << ParseError::count << "\n";
+    oss << std::endl;
+
+    int tick_per_sec = sysconf(_SC_CLK_TCK);
+    // dump document data
+    for (const auto& it : _documents)
+    {
+        const Document &doc = *it.second;
+        std::string suffix = "{pid=" + std::to_string(doc.getPid()) + "} ";
+        oss << "doc_host" << suffix << "= \"" << doc.getHostName() << "\"\n";
+        oss << "doc_key" << suffix << "= \"" << doc.getDocKey() << "\"\n"; // often WOPISrc
+
+        std::string encodedFilename;
+        Poco::URI::encode(doc.getFilename(), " ", encodedFilename);
+        oss << "doc_filename" << suffix << "= \"" << encodedFilename << "\"\n";
+
+        oss << "doc_views" << suffix << doc.getViews().size() << "\n";
+        oss << "doc_views_active" << suffix << doc.getActiveViews() << "\n";
+        oss << "doc_is_modified" << suffix << doc.getModifiedStatus() << "\n";
+        oss << "doc_memory_used_bytes" << suffix << doc.getMemoryDirty() << "\n";
+        oss << "doc_cpu_used_seconds" << suffix << ((double)doc.getLastJiffies()/tick_per_sec) << "\n";
+        oss << "doc_open_time_seconds" << suffix << doc.getOpenTime() << "\n";
+        oss << "doc_idle_time_seconds" << suffix << doc.getIdleTime() << "\n";
+        oss << "doc_download_time_seconds" << suffix << ((double)doc.getWopiDownloadDuration().count() / 1000) << "\n";
+        oss << "doc_upload_time_seconds" << suffix << ((double)doc.getWopiUploadDuration().count() / 1000) << "\n";
+        oss << std::endl;
+    }
 }
 
 std::set<pid_t> AdminModel::getDocumentPids() const

wsd/AdminModel.hpp

@@ -185,7 +185,7 @@ public:
 
     unsigned getActiveViews() const { return _activeViews; }
 
-    unsigned getLastJiffies() const { return _lastJiffy; }
+    size_t getLastJiffies() const { return _lastJiffy; }
     void setLastJiffies(size_t newJ);
     unsigned getLastCpuPercentage(){ return _lastCpuPercentage; }
 
@@ -240,7 +240,7 @@ private:
     /// The dirty (ie. un-shared) memory of the document's Kit process.
     size_t _memoryDirty;
     /// Last noted Jiffy count
-    unsigned _lastJiffy;
+    size_t _lastJiffy;
     std::chrono::steady_clock::time_point _lastJiffyTime;
     unsigned _lastCpuPercentage;
 

wsd/metrics.txt

@@ -171,3 +171,15 @@ SELECTED ERRORS - all integer counts
     error_unauthorized_request - an authorization exception usually on CheckFileInfo
     error_service_unavailable - internal error, service is unavailable
     error_parse_error - badly formed data provided for us to parse.
+
+PER DOCUMENT DETAILS - suffixed by {pid=<pid>} for each document:
+
+    doc_host - host this document was fetched from
+    doc_key - key often WOPISrc used to fetch the document
+    doc_active_views - number of views/users currently
+    doc_is_modified - is the document modified, or not ie. saved/readonly
+    doc_memory_used_bytes - bytes of memory dirtied by this process
+    doc_cpu_used_seconds - number of seconds of CPU time used
+    doc_open_time_seconds - time since the document was first opened
+    doc_download_time_seconds - how long it took to download the doc
+    doc_upload_time_seconds - how long it last took to up-load the doc or 0 if unsaved.