netipmid: replace std::cerr with phosphor::logging calls

This is part of a cleanup and standardization effort of code to get
existing code up to date.

Change-Id: I0c982ef8d7afa2f56a9cd204bb8ac3112769641c
Signed-off-by: Vernon Mauery <vernon.mauery@linux.intel.com>

17 files changed, 90 insertions, 72 deletions

diff --git a/auth_algo.cpp b/auth_algo.cpp
index 55df86d..4572831 100644
--- a/auth_algo.cpp
+++ b/auth_algo.cpp
@@ -4,7 +4,9 @@
 #include <openssl/hmac.h>
 #include <openssl/sha.h>
 
-#include <iostream>
+#include <phosphor-logging/log.hpp>
+
+using namespace phosphor::logging;
 
 namespace cipher
 {
@@ -23,7 +25,7 @@ std::vector<uint8_t>
     if (HMAC(EVP_sha1(), userKey.data(), userKey.size(), input.data(),
              input.size(), output.data(), &mdLen) == NULL)
     {
-        std::cerr << "Generate HMAC failed\n";
+        log<level::ERR>("Generate HMAC failed");
         output.resize(0);
     }
 
@@ -39,7 +41,7 @@ std::vector<uint8_t>
     if (HMAC(EVP_sha1(), sessionIntegrityKey.data(), SHA_DIGEST_LENGTH,
              input.data(), input.size(), output.data(), &mdLen) == NULL)
     {
-        std::cerr << "Generate Session Integrity Key failed\n";
+        log<level::ERR>("Generate Session Integrity Key failed");
         output.resize(0);
     }
     output.resize(integrityCheckValueLength);
@@ -56,7 +58,7 @@ std::vector<uint8_t>
     if (HMAC(EVP_sha256(), userKey.data(), userKey.size(), input.data(),
              input.size(), output.data(), &mdLen) == NULL)
     {
-        std::cerr << "Generate HMAC_SHA256 failed\n";
+        log<level::ERR>("Generate HMAC_SHA256 failed");
         output.resize(0);
     }
 
@@ -73,7 +75,8 @@ std::vector<uint8_t>
              sessionIntegrityKey.size(), input.data(), input.size(),
              output.data(), &mdLen) == NULL)
     {
-        std::cerr << "Generate HMAC_SHA256_128 Integrity Check Value failed\n";
+        log<level::ERR>(
+            "Generate HMAC_SHA256_128 Integrity Check Value failed");
         output.resize(0);
     }
     output.resize(integrityCheckValueLength);
diff --git a/comm_module.cpp b/comm_module.cpp
index a58ca5d..acc9089 100644
--- a/comm_module.cpp
+++ b/comm_module.cpp
@@ -12,7 +12,6 @@
 #include <algorithm>
 #include <cstring>
 #include <iomanip>
-#include <iostream>
 
 namespace command
 {
diff --git a/command/channel_auth.cpp b/command/channel_auth.cpp
index 1ad1472..1b5b604 100644
--- a/command/channel_auth.cpp
+++ b/command/channel_auth.cpp
@@ -2,8 +2,6 @@
 
 #include <host-ipmid/ipmid-api.h>
 
-#include <iostream>
-
 namespace command
 {
 
diff --git a/command/guid.cpp b/command/guid.cpp
index 8cd95a6..3751d64 100644
--- a/command/guid.cpp
+++ b/command/guid.cpp
@@ -3,10 +3,12 @@
 #include <host-ipmid/ipmid-api.h>
 #include <mapper.h>
 
-#include <iostream>
+#include <phosphor-logging/log.hpp>
 #include <sstream>
 #include <string>
 
+using namespace phosphor::logging;
+
 namespace cache
 {
 
@@ -42,8 +44,9 @@ Guid getSystemGUID()
         int rc = mapper_get_service(bus, guidObjPath, &busname);
         if (rc < 0)
         {
-            std::cerr << "Failed to get " << guidObjPath
-                      << " bus name: " << strerror(-rc) << "\n";
+            log<level::ERR>("Failed to get bus name",
+                            entry("PATH=%s", guidObjPath),
+                            entry("ERROR=%s", strerror(-rc)));
             break;
         }
 
@@ -51,14 +54,16 @@ Guid getSystemGUID()
                                 &error, &reply, "ss", chassisIntf, "uuid");
         if (rc < 0)
         {
-            std::cerr << "Failed to call Get Method:" << strerror(-rc) << "\n";
+            log<level::ERR>("Failed to call Get Method",
+                            entry("ERROR=%s", strerror(-rc)));
             break;
         }
 
         rc = sd_bus_message_read(reply, "v", "s", &uuid);
         if (rc < 0 || uuid == NULL)
         {
-            std::cerr << "Failed to get a response:" << strerror(-rc) << "\n";
+            log<level::ERR>("Failed to get a response",
+                            entry("ERROR=%s", strerror(-rc)));
             break;
         }
 
diff --git a/command/open_session.cpp b/command/open_session.cpp
index b48b7e9..51da9e1 100644
--- a/command/open_session.cpp
+++ b/command/open_session.cpp
@@ -4,7 +4,9 @@
 #include "endian.hpp"
 #include "main.hpp"
 
-#include <iostream>
+#include <phosphor-logging/log.hpp>
+
+using namespace phosphor::logging;
 
 namespace command
 {
@@ -62,10 +64,10 @@ std::vector<uint8_t> openSession(const std::vector<uint8_t>& inPayload,
     }
     catch (std::exception& e)
     {
-        std::cerr << e.what() << "\n";
         response->status_code =
             static_cast<uint8_t>(RAKP_ReturnCode::INSUFFICIENT_RESOURCE);
-        std::cerr << "openSession : Problem opening a session\n";
+        log<level::ERR>("openSession : Problem opening a session",
+                        entry("EXCEPTION=%s", e.what()));
         return outPayload;
     }
 
diff --git a/command/rakp12.cpp b/command/rakp12.cpp
index cd7dd68..594a8fe 100644
--- a/command/rakp12.cpp
+++ b/command/rakp12.cpp
@@ -10,10 +10,12 @@
 #include <algorithm>
 #include <cstring>
 #include <iomanip>
-#include <iostream>
+#include <phosphor-logging/log.hpp>
 #include <user_channel/channel_layer.hpp>
 #include <user_channel/user_layer.hpp>
 
+using namespace phosphor::logging;
+
 namespace command
 {
 
@@ -28,7 +30,7 @@ std::vector<uint8_t> RAKP12(const std::vector<uint8_t>& inPayload,
     if (endian::from_ipmi(request->managedSystemSessionID) ==
         session::SESSION_ZERO)
     {
-        std::cerr << "RAKP12: BMC invalid Session ID\n";
+        log<level::INFO>("RAKP12: BMC invalid Session ID");
         response->rmcpStatusCode =
             static_cast<uint8_t>(RAKP_ReturnCode::INVALID_SESSION_ID);
         return outPayload;
@@ -43,7 +45,8 @@ std::vector<uint8_t> RAKP12(const std::vector<uint8_t>& inPayload,
     }
     catch (std::exception& e)
     {
-        std::cerr << e.what() << "\n";
+        log<level::ERR>("RAKP12 : session not found",
+                        entry("EXCEPTION=%s", e.what()));
         response->rmcpStatusCode =
             static_cast<uint8_t>(RAKP_ReturnCode::INVALID_SESSION_ID);
         return outPayload;
@@ -197,8 +200,8 @@ std::vector<uint8_t> RAKP12(const std::vector<uint8_t>& inPayload,
         ((request->req_max_privilege_level & session::reqMaxPrivMask) >
          userAccess.privilege))
     {
-        std::cerr
-            << "Username/Privilege lookup failed for requested privilege\n";
+        log<level::INFO>(
+            "Username/Privilege lookup failed for requested privilege");
         response->rmcpStatusCode =
             static_cast<uint8_t>(RAKP_ReturnCode::UNAUTH_NAME);
         return outPayload;
diff --git a/command/rakp34.cpp b/command/rakp34.cpp
index a89e750..10c67fa 100644
--- a/command/rakp34.cpp
+++ b/command/rakp34.cpp
@@ -8,7 +8,9 @@
 
 #include <algorithm>
 #include <cstring>
-#include <iostream>
+#include <phosphor-logging/log.hpp>
+
+using namespace phosphor::logging;
 
 namespace command
 {
@@ -75,7 +77,7 @@ std::vector<uint8_t> RAKP34(const std::vector<uint8_t>& inPayload,
     // Check if the RAKP3 Payload Length is as expected
     if (inPayload.size() < sizeof(RAKP3request))
     {
-        std::cerr << "RAKP34: Invalid RAKP3 request\n";
+        log<level::INFO>("RAKP34: Invalid RAKP3 request");
         response->rmcpStatusCode =
             static_cast<uint8_t>(RAKP_ReturnCode::INVALID_INTEGRITY_VALUE);
         return outPayload;
@@ -85,7 +87,7 @@ std::vector<uint8_t> RAKP34(const std::vector<uint8_t>& inPayload,
     if (endian::from_ipmi(request->managedSystemSessionID) ==
         session::SESSION_ZERO)
     {
-        std::cerr << "RAKP34: BMC invalid Session ID\n";
+        log<level::INFO>("RAKP34: BMC invalid Session ID");
         response->rmcpStatusCode =
             static_cast<uint8_t>(RAKP_ReturnCode::INVALID_SESSION_ID);
         return outPayload;
@@ -100,7 +102,8 @@ std::vector<uint8_t> RAKP34(const std::vector<uint8_t>& inPayload,
     }
     catch (std::exception& e)
     {
-        std::cerr << e.what() << "\n";
+        log<level::ERR>("RAKP12 : session not found",
+                        entry("EXCEPTION=%s", e.what()));
         response->rmcpStatusCode =
             static_cast<uint8_t>(RAKP_ReturnCode::INVALID_SESSION_ID);
         return outPayload;
@@ -162,7 +165,7 @@ std::vector<uint8_t> RAKP34(const std::vector<uint8_t>& inPayload,
     if (inPayload.size() != (sizeof(RAKP3request) + output.size()) ||
         std::memcmp(output.data(), request + 1, output.size()))
     {
-        std::cerr << "Mismatch in HMAC sent by remote console\n";
+        log<level::INFO>("Mismatch in HMAC sent by remote console");
 
         response->messageTag = request->messageTag;
         response->rmcpStatusCode =
diff --git a/command/session_cmds.cpp b/command/session_cmds.cpp
index 5c74d28..3312c92 100644
--- a/command/session_cmds.cpp
+++ b/command/session_cmds.cpp
@@ -5,7 +5,6 @@
 
 #include <host-ipmid/ipmid-api.h>
 
-#include <iostream>
 #include <user_channel/channel_layer.hpp>
 #include <user_channel/user_layer.hpp>
 
diff --git a/command_table.cpp b/command_table.cpp
index 26859a5..d0ef173 100644
--- a/command_table.cpp
+++ b/command_table.cpp
@@ -6,7 +6,6 @@
 #include "sessions_manager.hpp"
 
 #include <iomanip>
-#include <iostream>
 #include <phosphor-logging/elog-errors.hpp>
 #include <phosphor-logging/log.hpp>
 #include <xyz/openbmc_project/Common/error.hpp>
@@ -62,9 +61,8 @@ std::vector<uint8_t> Table::executeCommand(uint32_t inCommand,
         // exceeded message
         if (elapsedSeconds > 2s)
         {
-            std::cerr << "E> IPMI command timed out:Elapsed time = "
-                      << elapsedSeconds.count() << "s"
-                      << "\n";
+            log<level::ERR>("IPMI command timed out",
+                            entry("DELAY=%d", elapsedSeconds.count()));
         }
     }
     return response;
@@ -81,8 +79,10 @@ std::vector<uint8_t>
     {
         errResponse.resize(1);
         errResponse[0] = IPMI_CC_INSUFFICIENT_PRIVILEGE;
-        std::cerr << "E> Table::Not enough privileges for command 0x"
-                  << std::hex << command.command << "\n";
+        log<level::INFO>("Table: Insufficient privilege for command",
+                         entry("LUN=%x", int(command.NetFnLun.lun)),
+                         entry("NETFN=%x", int(command.NetFnLun.netFn)),
+                         entry("CMD=%x", command.cmd));
         return errResponse;
     }
 
@@ -112,8 +112,11 @@ std::vector<uint8_t>
         // and return sane error code.
         catch (const std::exception& e)
         {
-            std::cerr << "E> Unspecified error for command 0x" << std::hex
-                      << command.command << " - " << e.what() << "\n";
+            log<level::ERR>("Table: Unspecified error for command",
+                            entry("EXCEPTION=%s", e.what()),
+                            entry("LUN=%x", int(command.NetFnLun.lun)),
+                            entry("NETFN=%x", int(command.NetFnLun.netFn)),
+                            entry("CMD=%x", command.cmd));
             respSize = 0;
             // fall through
         }
diff --git a/main.cpp b/main.cpp
index c3f3dfd..abb7958 100644
--- a/main.cpp
+++ b/main.cpp
@@ -17,11 +17,13 @@
 #include <systemd/sd-event.h>
 #include <unistd.h>
 
-#include <iostream>
+#include <phosphor-logging/log.hpp>
 #include <sdbusplus/asio/connection.hpp>
 #include <sdbusplus/timer.hpp>
 #include <tuple>
 
+using namespace phosphor::logging;
+
 // Tuple of Global Singletons
 static auto io = std::make_shared<boost::asio::io_context>();
 session::Manager manager;
@@ -117,8 +119,8 @@ int main()
     auto rc = sd_bus_default_system(&bus);
     if (rc < 0)
     {
-        std::cerr << "Failed to connect to system bus:" << strerror(-rc)
-                  << "\n";
+        log<level::ERR>("Failed to connect to system bus",
+                        entry("ERROR=%s", strerror(-rc)));
         return rc;
     }
 
@@ -126,7 +128,8 @@ int main()
     rc = sd_event_default(&events);
     if (rc < 0)
     {
-        std::cerr << "Failure to create sd_event" << strerror(-rc) << "\n";
+        log<level::ERR>("Failure to create sd_event",
+                        entry("ERROR=%s", strerror(-rc)));
         return EXIT_FAILURE;
     }
     sdbusp = std::make_shared<sdbusplus::asio::connection>(*io, bus);
diff --git a/message_handler.cpp b/message_handler.cpp
index 68c1b60..e98955b 100644
--- a/message_handler.cpp
+++ b/message_handler.cpp
@@ -8,11 +8,13 @@
 
 #include <sys/socket.h>
 
-#include <iostream>
 #include <memory>
+#include <phosphor-logging/log.hpp>
 #include <string>
 #include <vector>
 
+using namespace phosphor::logging;
+
 namespace message
 {
 
@@ -27,7 +29,7 @@ std::shared_ptr<Message> Handler::receive()
     // Read of the packet failed
     if (readStatus < 0)
     {
-        std::cerr << "E> Error in Read : " << std::hex << readStatus << "\n";
+        log<level::ERR>("Error in Read", entry("STATUS=%x", readStatus));
         return nullptr;
     }
 
diff --git a/message_handler.hpp b/message_handler.hpp
index 3c99660..c620a9d 100644
--- a/message_handler.hpp
+++ b/message_handler.hpp
@@ -5,7 +5,6 @@
 #include "session.hpp"
 #include "sol/console_buffer.hpp"
 
-#include <iostream>
 #include <memory>
 #include <numeric>
 
diff --git a/message_parsers.cpp b/message_parsers.cpp
index d7074fa..b820440 100644
--- a/message_parsers.cpp
+++ b/message_parsers.cpp
@@ -5,7 +5,6 @@
 #include "message.hpp"
 #include "sessions_manager.hpp"
 
-#include <iostream>
 #include <memory>
 
 namespace message
diff --git a/provider_registration.cpp b/provider_registration.cpp
index f0374f3..50f06c5 100644
--- a/provider_registration.cpp
+++ b/provider_registration.cpp
@@ -9,7 +9,9 @@
 #include <stdlib.h>
 #include <string.h>
 
-#include <iostream>
+#include <phosphor-logging/log.hpp>
+
+using namespace phosphor::logging;
 
 namespace provider
 {
@@ -31,8 +33,8 @@ void registerCallbackHandlers(const char* providerLibPath)
 {
     if (providerLibPath == NULL)
     {
-        std::cerr << "Path not provided for registering IPMI provider libraries"
-                  << "\n";
+        log<level::ERR>(
+            "Path not provided for registering IPMI provider libraries");
         return;
     }
 
@@ -56,7 +58,9 @@ void registerCallbackHandlers(const char* providerLibPath)
 
         if (lib_handler == NULL)
         {
-            std::cerr << "Error opening " << handlerPath << dlerror() << "\n";
+            log<level::ERR>("Error opening provider library",
+                            entry("PATH=%s", handlerPath.c_str()),
+                            entry("ERROR=%s", dlerror()));
         }
         free(handlerList[numLibs]);
     }
diff --git a/sessions_manager.cpp b/sessions_manager.cpp
index 1a70b49..95a8a15 100644
--- a/sessions_manager.cpp
+++ b/sessions_manager.cpp
@@ -5,8 +5,10 @@
 #include <algorithm>
 #include <cstdlib>
 #include <iomanip>
-#include <iostream>
 #include <memory>
+#include <phosphor-logging/log.hpp>
+
+using namespace phosphor::logging;
 
 namespace session
 {
@@ -89,15 +91,8 @@ std::shared_ptr<Session>
         return session;
     }
 
-    std::cerr << "E> No free sessions left: Active: " << activeSessions
-              << " Allowed: " << MAX_SESSION_COUNT << "\n";
+    log<level::INFO>("No free RMCP+ sessions left");
 
-    for (const auto& iterator : sessionsMap)
-    {
-        std::cerr << "E> Active Session: 0x" << std::hex << std::setfill('0')
-                  << std::setw(8) << (iterator.second)->getBMCSessionID()
-                  << "\n";
-    }
     throw std::runtime_error("No free sessions left");
 }
 
diff --git a/socket_channel.cpp b/socket_channel.cpp
index 2fa350a..a3e1301 100644
--- a/socket_channel.cpp
+++ b/socket_channel.cpp
@@ -6,9 +6,11 @@
 #include <sys/socket.h>
 #include <unistd.h>
 
-#include <iostream>
+#include <phosphor-logging/log.hpp>
 #include <string>
 
+using namespace phosphor::logging;
+
 namespace udpsocket
 {
 
@@ -28,7 +30,8 @@ std::tuple<int, std::vector<uint8_t>> Channel::read()
 
     if (ioctl(sockfd, FIONREAD, &readSize) < 0)
     {
-        std::cerr << "E> Channel::Read : ioctl failed with errno = " << errno;
+        log<level::ERR>("Channel::Read: ioctl failed",
+                        entry("ERRNO=%d", errno));
         rc = -errno;
         return std::make_tuple(rc, std::move(outBuffer));
     }
@@ -50,16 +53,15 @@ std::tuple<int, std::vector<uint8_t>> Channel::read()
 
         if (readDataLen == 0) // Peer has performed an orderly shutdown
         {
-            std::cerr << "E> Channel::Read : Connection Closed Fd[" << sockfd
-                      << "]\n";
+            log<level::ERR>("Channel::Read: Connection Closed");
             outBuffer.resize(0);
             rc = -1;
         }
         else if (readDataLen < 0) // Error
         {
             rc = -errno;
-            std::cerr << "E> Channel::Read : Receive Error Fd[" << sockfd << "]"
-                      << "errno = " << rc << "\n";
+            log<level::ERR>("Channel::Read: Receive Error",
+                            entry("ERRNO=%d", rc));
             outBuffer.resize(0);
         }
     } while ((readDataLen < 0) && (-(rc) == EINTR));
@@ -107,22 +109,22 @@ int Channel::write(const std::vector<uint8_t>& inBuffer)
                     if (writeDataLen < 0)
                     {
                         rc = -errno;
-                        std::cerr
-                            << "Channel::Write: Write failed with errno:" << rc
-                            << "\n";
+                        log<level::ERR>("Channel::Write: Write failed",
+                                        entry("ERRNO=%d", rc));
                     }
                     else if (static_cast<size_t>(writeDataLen) < bufferSize)
                     {
                         rc = -1;
-                        std::cerr << "Channel::Write: Complete data not written"
-                                     " to the socket\n";
+                        log<level::ERR>(
+                            "Channel::Write: Complete data not written"
+                            " to the socket");
                     }
                 } while ((writeDataLen < 0) && (-(rc) == EINTR));
             }
             else
             {
                 // Spurious wake up
-                std::cerr << "E> Spurious wake up on select (writeset)\n";
+                log<level::ERR>("Spurious wake up on select (writeset)");
                 spuriousWakeup = true;
             }
         }
@@ -132,14 +134,14 @@ int Channel::write(const std::vector<uint8_t>& inBuffer)
             {
                 // Timed out
                 rc = -1;
-                std::cerr << "E> We timed out on select call (writeset)\n";
+                log<level::ERR>("We timed out on select call (writeset)");
             }
             else
             {
                 // Error
                 rc = -errno;
-                std::cerr << "E> select call (writeset) had an error : " << rc
-                          << "\n";
+                log<level::ERR>("select call (writeset) error",
+                                entry("ERRNO=%d", rc));
             }
         }
     } while (spuriousWakeup);
diff --git a/test/cipher.cpp b/test/cipher.cpp
index 402a22f..09bd479 100644
--- a/test/cipher.cpp
+++ b/test/cipher.cpp
@@ -8,7 +8,6 @@
 #include <openssl/rand.h>
 #include <openssl/sha.h>
 
-#include <iostream>
 #include <vector>
 
 #include <gtest/gtest.h>