Add extensive logging to Sock and channel classes

* add logging of unusual situations
* add handling of unlink() errors

Change-Id: Ibc41a6bc1df29531f6405433f15817abe0bcc250

diff --git a/src/ipc-lib/ask-user-channel.cpp b/src/ipc-lib/ask-user-channel.cpp
index 79c8a81..fe88252 100644 (file)
--- a/src/ipc-lib/ask-user-channel.cpp
+++ b/src/ipc-lib/ask-user-channel.cpp
@@ -38,7 +38,7 @@ int Channel::process(int fd, int mask) {
     try {
         auto it = m_sockets.find(fd);
         if (it == m_sockets.end()) {
-            ALOGE("Cannot find file descriptor " << fd);
+            ALOGE("process: Cannot find file descriptor " << fd);
             return -EBADF;
         }
 
@@ -110,7 +110,7 @@ int Channel::process(int fd, int mask) {
             int result = desc.sock.send(desc.output);
             if (result < 0) {
                 closeConnection(fd);
-                ALOGE("Cannot send a message on file descritptor: " << fd);
+                ALOGE("Cannot send a message on file descriptor: " << fd);
                 return -ENOTCONN;
             }
 
@@ -125,11 +125,11 @@ int Channel::process(int fd, int mask) {
         }
     } catch (const std::exception &e) {
         closeConnection(fd);
-        ALOGE("An exception occured while processing channel " << e.what());
+        ALOGE("An exception occurred while processing channel " << e.what());
         throw;
     } catch (...) {
         closeConnection(fd);
-        ALOGE("Unhandled exception while processing channel");
+        ALOGE("Unknown exception occurred while processing channel");
         throw;
     }
 
@@ -157,6 +157,7 @@ void Channel::closeConnection(int fd)
 {
     auto it = m_sockets.find(fd);
     if (it == m_sockets.end()) {
+        ALOGE("closeConnection: Cannot find file descriptor fd: " << fd);
         return;
     }
 

diff --git a/src/ipc-lib/ask-user-client-channel.cpp b/src/ipc-lib/ask-user-client-channel.cpp
index 035d503..d79b81c 100644 (file)
--- a/src/ipc-lib/ask-user-client-channel.cpp
+++ b/src/ipc-lib/ask-user-client-channel.cpp
@@ -25,6 +25,7 @@
 #include <attributes/attributes.h>
 #include <askuser-notification/ask-user-client-channel.h>
 #include <askuser-notification/connection-exception.h>
+#include <log/alog.h>
 
 #include <ask-user-config.h>
 #include <message-utils.h>
@@ -83,16 +84,20 @@ void ClientChannel::onClose(int fd) {
 }
 
 int ClientChannel::onReceive(UNUSED int fd, std::vector<std::string> &&message) {
-    if (!message.size())
+    if (!message.size()) {
+        ALOGE("Server received empty message");
         return -EINVAL;
+    }
 
     int command = std::stoi(message[0]);
 
     switch (command) {
     case MSGID_POPUP_RESPONSE:
         {
-            if (message.size() != 3)
+            if (message.size() != 3) {
+                ALOGE("Inappropriate message size for MSGID_POPUP_RESPONSE command, size: " << message.size());
                 return -EINVAL;
+            }
 
             RequestId id = std::stoi(message[1]);
             int response = std::stoi(message[2]);
@@ -101,6 +106,7 @@ int ClientChannel::onReceive(UNUSED int fd, std::vector<std::string> &&message)
             break;
         }
     default :
+        ALOGE("Client received unknown message, command: " << command);
         return -EINVAL;
     }
 

diff --git a/src/ipc-lib/ask-user-server-channel.cpp b/src/ipc-lib/ask-user-server-channel.cpp
index d6578f3..4a08a48 100644 (file)
--- a/src/ipc-lib/ask-user-server-channel.cpp
+++ b/src/ipc-lib/ask-user-server-channel.cpp
@@ -24,6 +24,7 @@
 
 #include <askuser-notification/ask-user-server-channel.h>
 #include <askuser-notification/connection-exception.h>
+#include <log/alog.h>
 
 #include <ask-user-config.h>
 #include <message-utils.h>
@@ -57,8 +58,10 @@ void ServerChannel::init() {
 void ServerChannel::popupResponse(ConnectionFd fd, RequestId id, int response) {
     try {
         auto it = m_sockets.find(fd);
-        if (it == m_sockets.end())
+        if (it == m_sockets.end()) {
+            ALOGE("popupResponse: Cannot find file descriptor " << fd);
             return;
+        }
 
         auto &desc = it->second;
 
@@ -68,7 +71,9 @@ void ServerChannel::popupResponse(ConnectionFd fd, RequestId id, int response) {
         std::copy(o.begin(), o.end(), std::back_inserter(desc.output));
 
         m_callbacks->updateConnection(fd, FdMask::READ | FdMask::WRITE);
-    } catch (const std::exception &){}
+    } catch (const std::exception &e){
+        ALOGE("Exception occurred during popupResponse: " << e.what());
+    }
 }
 
 void ServerChannel::onAccept(int fd) {
@@ -81,16 +86,20 @@ void ServerChannel::onClose(int fd) {
 }
 
 int ServerChannel::onReceive(int fd, std::vector<std::string> &&message) {
-    if (!message.size())
+    if (!message.size()) {
+        ALOGE("Server received empty message");
         return -EINVAL;
+    }
 
     int command = std::stoi(message[0]);
 
     switch (command) {
     case MSGID_POPUP:
         {
-            if (message.size() != 3)
+            if (message.size() != 3) {
+                ALOGE("Inappropriate message size for MSGID_POPUP command, size: " << message.size());
                 return -EINVAL;
+            }
 
             std::string privilege = base64Decode(message[1]);
             RequestId requestId = std::stoi(message[2]);
@@ -99,6 +108,7 @@ int ServerChannel::onReceive(int fd, std::vector<std::string> &&message) {
             break;
         }
     default :
+        ALOGE("Server received unknown message, command: " << command);
         return -EINVAL;
     }
 

diff --git a/src/ipc-lib/sock.cpp b/src/ipc-lib/sock.cpp
index fe8f22b..e0f2df1 100644 (file)
--- a/src/ipc-lib/sock.cpp
+++ b/src/ipc-lib/sock.cpp
@@ -16,8 +16,10 @@
 /**
  * @file        sock.cpp
  * @author      Bartlomiej Grzelewski <b.grzelewski@samsung.com>
+ * @author      Piotr Sawicki <p.sawicki2@partner.samsung.com>
  * @brief       The implementation of Sock.
  */
+#include <errno.h>
 #include <poll.h>
 #include <stdexcept>
 #include <sys/socket.h>
@@ -33,6 +35,7 @@
 
 #include <askuser-notification/ask-user-types.h>
 #include <askuser-notification/sock.h>
+#include <log/alog.h>
 
 namespace AskUser {
 namespace Protocol {
@@ -80,8 +83,10 @@ int Sock::getSocketFromSystemD() const {
 #ifdef BUILD_WITH_SYSTEMD_DAEMON
     int n = sd_listen_fds(0);
 
-    if (n < 0)
+    if (n < 0) {
+        ALOGE("sd_listen_fds failed");
         return -1;
+    }
 
     for (int fd = SD_LISTEN_FDS_START; fd < SD_LISTEN_FDS_START+n; ++fd)
         if (0 < sd_is_socket_unix(fd, getUnixSockType(), -1, m_path.c_str(), 0))
@@ -91,8 +96,10 @@ int Sock::getSocketFromSystemD() const {
 }
 
 int Sock::connect(const std::string &path) {
-    if (m_fd != -1)
+    if (m_fd != -1) {
+        ALOGE("Connect was called for already opened socket, file descriptor: " << m_fd);
         return -1;
+    }
 
     m_path = path;
 
@@ -135,14 +142,22 @@ int Sock::connect(const std::string &path) {
         }
     }
 
-    if (policyUnlink)
-        ::unlink(m_path.c_str());  // we ignore return value by design
+    if (policyUnlink) {
+        int ret = ::unlink(m_path.c_str());
+        if (ret < 0 && errno != ENOENT) {
+            close();
+            ALOGE("Unlink failed for path: " << m_path);
+            return -1;
+        }
+    }
 
     if (policySocket)
         m_fd = ::socket(AF_UNIX, getUnixSockType(), 0);
 
-    if (m_fd < 0)
+    if (m_fd < 0) {
+        ALOGE("Cannot create UNIX socket");
         return -1;
+    }
 
     // remote is used in bind and in connect
     sockaddr_un remote;
@@ -151,6 +166,7 @@ int Sock::connect(const std::string &path) {
         remote.sun_family = AF_UNIX;
         if (path.size() >= sizeof(remote.sun_path)) {
             close();
+            ALOGE("Too long address (path) for UNIX socket");
             return -1;
         }
         memcpy(remote.sun_path, path.c_str(), path.size()+1);
@@ -158,17 +174,20 @@ int Sock::connect(const std::string &path) {
 
     if (policyBind && (-1 == ::bind(m_fd, reinterpret_cast<sockaddr *>(&remote), sizeof(remote)))) {
         close();
+        ALOGE("Cannot bind socket, path: " << path);
         return -1;
     }
 
     if (policyListen && (-1 == ::listen(m_fd, 5))) {
         close();
+        ALOGE("Listen failed");
         return -1;
     }
 
     if (policyConnect && (-1 == TEMP_FAILURE_RETRY(::connect(m_fd, reinterpret_cast<sockaddr *>(&remote), static_cast<socklen_t>(length)))))
     {
         close();
+        ALOGE("Connection failed, path: " << path);
         return -1;
     }
     return 0;
@@ -184,11 +203,14 @@ Sock Sock::accept() {
 
 int Sock::send(const RawBuffer &buffer) {
     static const int flags = MSG_NOSIGNAL | MSG_DONTWAIT;
-    if (m_fd < 0)
+    if (m_fd < 0) {
+        ALOGE("Send was called on closed socket");
         return -1;
+    }
 
     switch(m_type) {
     default:
+        ALOGE("Send was called for inappropriate socket type");
         return -1;
     case CLI_STREAM:
         {
@@ -223,11 +245,14 @@ int Sock::wait(int mask) {
 }
 
 int Sock::recv(RawBuffer &output) {
-    if (m_fd < 0)
+    if (m_fd < 0) {
+        ALOGE("Receive was called on closed socket");
         return -1;
+    }
 
     switch(m_type) {
     default:
+        ALOGE("Receive was called for inappropriate socket type");
         return -1;
     case CLI_STREAM:
     case SRV_DGRAM: