From: Tomasz Swierczek <t.swierczek@samsung.com>
Date: Tue, 5 Mar 2019 06:26:04 +0000 (+0100)
Subject: Enhance logs in case of writing errors & socket problems
X-Git-Tag: accepted/tizen/unified/20190307.231033~2
X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=refs%2Fchanges%2F58%2F200858%2F3;p=platform%2Fcore%2Fsecurity%2Fsecurity-manager.git

Enhance logs in case of writing errors & socket problems

In rare case security-manager is closing connections to clients
and after that, it tries to write responses to already closed connections.

With these enhanced logs it would be possible to match if the closed connections
(already appearing in logs) are for same socket number like ignored packets.

Change-Id: Ia105c8731d64d83d8d83182e12ae8adee1b961f0
---

diff --git a/src/server/main/socket-manager.cpp b/src/server/main/socket-manager.cpp
index 6728af2..b4b12d9 100644
--- a/src/server/main/socket-manager.cpp
+++ b/src/server/main/socket-manager.cpp
@@ -246,6 +246,7 @@ void SocketManager::ReadyForRead(int sock) {
     ssize_t size = read(sock, &event.rawBuffer[0], 4096);
 
     if (size == 0) {
+        LogDebug("Reading returned 0 bytes, closing socket: " << sock);
         CloseSocket(sock);
     } else if (size >= 0) {
         event.rawBuffer.resize(size);
@@ -426,6 +427,7 @@ void SocketManager::MainLoop() {
             // and connection is open. Time to close it!
             // Putting new timeout in queue here is pointless.
             desc.isTimeout = false;
+            LogWarning("Closing socket because of timeout: " << pqTimeout.sock);
             CloseSocket(pqTimeout.sock);
 
             // All done. Now we should process next select ;-)
@@ -651,18 +653,21 @@ void SocketManager::ProcessQueue() {
             auto &desc = m_socketDescriptionVector[buffer.connectionID.sock];
 
             if (!desc.isOpen) {
-                LogError("Received packet for write but connection is closed. Packet ignored!");
+                LogError("Received packet for write but connection is closed. Packet ignored! Socket: "
+                         << buffer.connectionID.sock);
                 continue;
             }
 
             if (desc.counter != buffer.connectionID.counter)
             {
-                LogError("Received packet for write but counter is broken. Packet ignored!");
+                LogError("Received packet for write but counter is broken. Packet ignored! Socket: "
+                         << buffer.connectionID.sock);
                 continue;
             }
 
             if (desc.useSendMsg) {
-                LogError("Some service tried to push rawdata to socket that usees sendmsg!");
+                LogError("Some service tried to push rawdata to socket that usees sendmsg! Socket: "
+                         << buffer.connectionID.sock);
                 continue;
             }
 
@@ -681,18 +686,21 @@ void SocketManager::ProcessQueue() {
             auto &desc = m_socketDescriptionVector[data.connectionID.sock];
 
             if (!desc.isOpen) {
-                LogDebug("Received packet for sendmsg but connection is closed. Packet ignored!");
+                LogDebug("Received packet for sendmsg but connection is closed. Packet ignored! Socket: "
+                          << data.connectionID.sock);
                 continue;
             }
 
             if (desc.counter != data.connectionID.counter)
             {
-                LogDebug("Received packet for write but counter is broken. Packet ignored!");
+                LogDebug("Received packet for write but counter is broken. Packet ignored! Socket: "
+                          << data.connectionID.sock);
                 continue;
             }
 
             if (!desc.useSendMsg) {
-                LogError("Some service tries to push SendMsgData to socket that uses write!");
+                LogError("Some service tries to push SendMsgData to socket that uses write! Socket: "
+                          << data.connectionID.sock);
                 continue;
             }