Add logging of server-side operation handling time

Logs are added only in debug mode for each service
method that implements API exposed by the daemon.

Change-Id: I90412b9d6c32edd0d7559f5eb713117ba0a1fecd

diff --git a/src/common/CMakeLists.txt b/src/common/CMakeLists.txt
index cfd9047b99810c63b643a09c9a4cd6329867f605..6222ba61ec411cd22831c31ef49da296dd81c925 100644 (file)
--- a/src/common/CMakeLists.txt
+++ b/src/common/CMakeLists.txt
@@ -66,6 +66,7 @@ SET(COMMON_SOURCES
     ${COMMON_PATH}/smack-check.cpp
     ${COMMON_PATH}/service_impl.cpp
     ${COMMON_PATH}/tzplatform-config.cpp
+    ${COMMON_PATH}/utils.cpp
     ${COMMON_PATH}/worker.cpp
     ${COMMON_PATH}/privilege-info.cpp
     ${COMMON_PATH}/privilege-gids.cpp

diff --git a/src/common/include/protocols.h b/src/common/include/protocols.h
index 0275c0e8a5921191e2b91be7e72e06c05a1b099f..006c8a7b9fc32887fe34e0990809dad228d58738 100644 (file)
--- a/src/common/include/protocols.h
+++ b/src/common/include/protocols.h
@@ -1,5 +1,5 @@
 /*
- *  Copyright (c) 2000 - 2016 Samsung Electronics Co., Ltd All Rights Reserved
+ *  Copyright (c) 2000 - 2019 Samsung Electronics Co., Ltd All Rights Reserved
  *
  *  Contact: Rafal Krypa <r.krypa@samsung.com>
  *
@@ -132,6 +132,9 @@ enum class SecurityModuleCall
     NOOP = 0x90,
 };
 
+// returns stringified name of return call type
+const char * SecurityModuleCallToString(SecurityModuleCall call_num);
+
 } // namespace SecurityManager
 
 struct policy_entry : ISerializable {

diff --git a/src/common/include/utils.h b/src/common/include/utils.h
index b2d3a80b6a0caccc32eb83689cee029b641b6418..a1d0514d8db657c44bd0709e461ddfcec3a19a69 100644 (file)
--- a/src/common/include/utils.h
+++ b/src/common/include/utils.h
@@ -1,5 +1,5 @@
 /*
- *  Copyright (c) 2016 Samsung Electronics Co., Ltd All Rights Reserved
+ *  Copyright (c) 2016 - 2019 Samsung Electronics Co., Ltd All Rights Reserved
  *
  *  Contact: Rafal Krypa <r.krypa@samsung.com>
  *
@@ -19,7 +19,7 @@
  * @file        utils.h
  * @author      Rafal Krypa <r.krypa@samsung.com>
  * @version     1.0
- * @brief       Utility macros and templates
+ * @brief       Utility functions, macros and templates
  */
 
 #pragma once
@@ -28,12 +28,35 @@
 #include <functional>
 #include <memory>
 #include <sys/wait.h>
+#include <time.h>
 #include <type_traits>
 #include <unistd.h>
 #include <vector>
+#include <string>
+
+#include <credentials.h>
 
 namespace SecurityManager {
 
+time_t monotonicNow();
+
+// Used for measuring function/method/scope execution time
+class ScopedTimeStamper {
+public:
+    ScopedTimeStamper(const std::string & location, const Credentials & creds);
+    virtual ~ScopedTimeStamper();
+
+private:
+    struct timespec m_start;
+    std::string m_locationStr;
+};
+
+#ifdef BUILD_TYPE_DEBUG
+#define LOG_EXECUTION_TIME(location, creds)    ScopedTimeStamper __stamper(location, creds)
+#else
+#define LOG_EXECUTION_TIME(location, creds)    do {} while (0)
+#endif
+
 // Pointer
 template<typename T>
 std::unique_ptr<T> makeUnique(T *ptr)

diff --git a/src/common/protocols.cpp b/src/common/protocols.cpp
index 798b9d69c9eb03ef8964ca32aedde2c540e051d7..465b844b6e8c455c4e6cc741b0461f98056afb04 100644 (file)
--- a/src/common/protocols.cpp
+++ b/src/common/protocols.cpp
@@ -1,5 +1,5 @@
 /*
- *  Copyright (c) 2000 - 2014 Samsung Electronics Co., Ltd All Rights Reserved
+ *  Copyright (c) 2000 - 2019 Samsung Electronics Co., Ltd All Rights Reserved
  *
  *  Contact: Rafal Krypa <r.krypa@samsung.com>
  *
@@ -33,5 +33,39 @@ namespace SecurityManager {
 char const * const SERVICE_SOCKET =
         SOCKET_PATH_PREFIX "security-manager.socket";
 
+#define SM_CODE_DESCRIBE(name) case name: return #name
+const char * SecurityModuleCallToString(SecurityModuleCall call_num) {
+    switch (call_num) {
+        SM_CODE_DESCRIBE(SecurityModuleCall::APP_INSTALL);
+        SM_CODE_DESCRIBE(SecurityModuleCall::APP_UPDATE);
+        SM_CODE_DESCRIBE(SecurityModuleCall::APP_UNINSTALL);
+        SM_CODE_DESCRIBE(SecurityModuleCall::APP_GET_PKG_NAME);
+        SM_CODE_DESCRIBE(SecurityModuleCall::APP_APPLY_PRIVATE_SHARING);
+        SM_CODE_DESCRIBE(SecurityModuleCall::APP_DROP_PRIVATE_SHARING);
+        SM_CODE_DESCRIBE(SecurityModuleCall::USER_ADD);
+        SM_CODE_DESCRIBE(SecurityModuleCall::USER_DELETE);
+        SM_CODE_DESCRIBE(SecurityModuleCall::POLICY_UPDATE);
+        SM_CODE_DESCRIBE(SecurityModuleCall::GET_POLICY);
+        SM_CODE_DESCRIBE(SecurityModuleCall::GET_CONF_POLICY_ADMIN);
+        SM_CODE_DESCRIBE(SecurityModuleCall::GET_CONF_POLICY_SELF);
+        SM_CODE_DESCRIBE(SecurityModuleCall::POLICY_GET_DESCRIPTIONS);
+        SM_CODE_DESCRIBE(SecurityModuleCall::GROUPS_GET);
+        SM_CODE_DESCRIBE(SecurityModuleCall::APP_HAS_PRIVILEGE);
+        SM_CODE_DESCRIBE(SecurityModuleCall::PATHS_REGISTER);
+        SM_CODE_DESCRIBE(SecurityModuleCall::GROUPS_FOR_UID);
+        SM_CODE_DESCRIBE(SecurityModuleCall::LABEL_FOR_PROCESS);
+        SM_CODE_DESCRIBE(SecurityModuleCall::SHM_APP_NAME);
+        SM_CODE_DESCRIBE(SecurityModuleCall::GET_APP_DEFINED_PRIVILEGE_PROVIDER);
+        SM_CODE_DESCRIBE(SecurityModuleCall::GET_APP_DEFINED_PRIVILEGE_LICENSE);
+        SM_CODE_DESCRIBE(SecurityModuleCall::GET_CLIENT_PRIVILEGE_LICENSE);
+        SM_CODE_DESCRIBE(SecurityModuleCall::APP_SETUP_NAMESPACE);
+        SM_CODE_DESCRIBE(SecurityModuleCall::APP_CLEAN_NAMESPACE);
+        SM_CODE_DESCRIBE(SecurityModuleCall::GET_APP_MANIFEST_POLICY);
+        SM_CODE_DESCRIBE(SecurityModuleCall::NOOP);
+        default: return "Code not defined";
+    }
+}
+#undef SM_CODE_DESCRIBE
+
 } // namespace SecurityManager
 

diff --git a/src/common/utils.cpp b/src/common/utils.cpp
new file mode 100644 (file)
index 0000000..fb215ed
--- /dev/null
+++ b/src/common/utils.cpp
@@ -0,0 +1,68 @@
+/*
+ *  Copyright (c) 2019 Samsung Electronics Co., Ltd All Rights Reserved
+ *
+ *  Contact: Tomasz Swierczek <t.swierczek@samsung.com>
+ *
+ *  Licensed under the Apache License, Version 2.0 (the "License");
+ *  you may not use this file except in compliance with the License.
+ *  You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ *  Unless required by applicable law or agreed to in writing, software
+ *  distributed under the License is distributed on an "AS IS" BASIS,
+ *  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ *  See the License for the specific language governing permissions and
+ *  limitations under the License
+ */
+/*
+ * @file        utils.cpp
+ * @author      Tomasz Swierczek <t.swierczek@samsung.com>
+ * @version     1.0
+ * @brief       Implementation of utility functions
+ */
+
+#include <utils.h>
+
+#include <dpl/log/log.h>
+#include <dpl/errno_string.h>
+
+namespace SecurityManager {
+
+time_t monotonicNow() {
+    struct timespec now;
+    if (clock_gettime(CLOCK_MONOTONIC_RAW, &now) == -1) {
+        int err = errno;
+        LogError("Can't access monotonic clock, error: " <<  GetErrnoString(err));
+        return 0;
+    }
+    return now.tv_sec;
+}
+
+ScopedTimeStamper::ScopedTimeStamper(const std::string & location, const Credentials & creds)
+{
+    m_locationStr = location +
+                    ", caller uid = " + std::to_string(creds.uid) +
+                    ", caller pid = " + std::to_string(creds.pid) +
+                    ", caller label = " + creds.label;
+
+    if (clock_gettime(CLOCK_MONOTONIC_RAW, &m_start) == -1) {
+        int err = errno;
+        LogError("Can't access monotonic clock, error: " <<  GetErrnoString(err));
+    }
+}
+
+ScopedTimeStamper::~ScopedTimeStamper()
+{
+    struct timespec end;
+    if (clock_gettime(CLOCK_MONOTONIC_RAW, &end) == -1) {
+        int err = errno;
+        LogError("Can't access monothonic clock, error: " <<  GetErrnoString(err));
+    }
+    long ndiff = (end.tv_nsec - m_start.tv_nsec ) + (end.tv_sec - m_start.tv_sec ) * 1E9;
+    float sec(ndiff);
+    sec *= 0.000000001;
+    LogDebug("Execution of " << m_locationStr << " took " << sec << " seconds");
+}
+
+} /* namespace SecurityManager */

diff --git a/src/server/main/include/socket-manager.h b/src/server/main/include/socket-manager.h
index 1395f4ff028e45ef5aab2722c74ab8071dba5cf3..ae94f60defb3054c3dfcb1ee2fc3536fe01c0054 100644 (file)
--- a/src/server/main/include/socket-manager.h
+++ b/src/server/main/include/socket-manager.h
@@ -71,8 +71,6 @@ protected:
     void NotifyMe(void);
     void CloseSocket(int sock);
 
-    time_t monotonicNow();
-
     struct SocketDescription {
         bool isListen;
         bool isOpen;

diff --git a/src/server/main/socket-manager.cpp b/src/server/main/socket-manager.cpp
index 900647f385dd8b900a503a9ccaedfe22e6c05275..27daf7d18f0092fab4877d84762923587c80d7e7 100644 (file)
--- a/src/server/main/socket-manager.cpp
+++ b/src/server/main/socket-manager.cpp
@@ -49,6 +49,7 @@
 #include <credentials.h>
 #include <smack-check.h>
 #include <socket-manager.h>
+#include <utils.h>
 
 namespace {
 
@@ -762,14 +763,4 @@ void SocketManager::CloseSocket(int sock) {
     LogDebug("Closing socket: " << sock << "  finished..");
 }
 
-time_t SocketManager::monotonicNow() {
-    struct timespec now;
-    if (clock_gettime(CLOCK_MONOTONIC_RAW, &now) == -1) {
-        int err = errno;
-        LogError("Can't access monothonic clock, error: " <<  GetErrnoString(err));
-        return 0;
-    }
-    return now.tv_sec;
-}
-
 } // namespace SecurityManager

diff --git a/src/server/service/service.cpp b/src/server/service/service.cpp
index 043f4a8560e7b79488202d6b8fea3efedb15d063..f233f201e811bf80576c8c0c119f67de1450613d 100644 (file)
--- a/src/server/service/service.cpp
+++ b/src/server/service/service.cpp
@@ -1,5 +1,5 @@
 /*
- *  Copyright (c) 2000 - 2016 Samsung Electronics Co., Ltd All Rights Reserved
+ *  Copyright (c) 2000 - 2019 Samsung Electronics Co., Ltd All Rights Reserved
  *
  *  Contact: Rafal Krypa <r.krypa@samsung.com>
  *
@@ -33,6 +33,7 @@
 #include "protocols.h"
 #include "service.h"
 #include "service_impl.h"
+#include "utils.h"
 
 namespace SecurityManager {
 
@@ -71,7 +72,7 @@ bool Service::processOne(const ConnectionID &conn, MessageBuffer &buffer,
             int call_type_int;
             Deserialization::Deserialize(buffer, call_type_int);
             SecurityModuleCall call_type = static_cast<SecurityModuleCall>(call_type_int);
-
+            LOG_EXECUTION_TIME(SecurityModuleCallToString(call_type), creds);
             switch (call_type) {
                 case SecurityModuleCall::NOOP:
                     LogDebug("call_type: SecurityModuleCall::NOOP");

diff --git a/test/CMakeLists.txt b/test/CMakeLists.txt
index a7046df60006207a2cad7b059b31fc51fd716185..4efb856852253a47982acb8dc0207be67b50f16b 100644 (file)
--- a/test/CMakeLists.txt
+++ b/test/CMakeLists.txt
@@ -81,6 +81,7 @@ SET(SM_TESTS_SOURCES
     ${PROJECT_SOURCE_DIR}/src/common/smack-rules.cpp
     ${PROJECT_SOURCE_DIR}/src/common/filesystem.cpp
     ${PROJECT_SOURCE_DIR}/src/common/tzplatform-config.cpp
+    ${PROJECT_SOURCE_DIR}/src/common/utils.cpp
     ${GEN_PATH}/db.h
 )