Add stack traces to error and fatal logs (#303)

.gitmodules

@@ -19,3 +19,6 @@
 [submodule "external/cotire"]
  path = external/cotire
  url = https://github.com/sakra/cotire.git
+[submodule "external/UniversalStacktrace"]
+ path = external/UniversalStacktrace
+ url = https://github.com/MisterTea/UniversalStacktrace.git

CMakeLists.txt

@@ -112,6 +112,7 @@ include_directories(
  external/Catch2/single_include
  external/cxxopts/include
  external/msgpack-c/include
+ external/UniversalStacktrace/ust
  src/base
  src/terminal
  src/terminal/forwarding

src/base/BackedReader.cpp

@@ -57,7 +57,7 @@ int BackedReader::read(Packet* packet) {
  // Read error
  return -1;
  } else {
- LOG(FATAL) << "Read returned value outside of [-1,inf): " << bytesRead;
+ STFATAL << "Read returned value outside of [-1,inf): " << bytesRead;
  }
  }
  if (partialMessage.length() < 4) {
@@ -84,7 +84,7 @@ int BackedReader::read(Packet* packet) {
  partialMessage.append(&s[0], bytesRead);
  messageRemainder -= bytesRead;
  } else {
- LOG(FATAL) << "Invalid value from read: " << bytesRead;
+ STFATAL << "Invalid value from read: " << bytesRead;
  }
  }
  if (!messageRemainder) {
@@ -106,7 +106,7 @@ void BackedReader::revive(int newSocketFd,
 
 int BackedReader::getPartialMessageLength() {
  if (partialMessage.length() < 4) {
- LOG(FATAL) << "Tried to construct a message header that wasn't complete";
+ STFATAL << "Tried to construct a message header that wasn't complete";
  }
  int messageSize;
  memcpy(&messageSize, &partialMessage[0], sizeof(int));
@@ -117,7 +117,7 @@ int BackedReader::getPartialMessageLength() {
 void BackedReader::constructPartialMessage(Packet* packet) {
  int messageSize = getPartialMessageLength();
  if (int(partialMessage.length()) - 4 != messageSize) {
- LOG(FATAL)
+ STFATAL
  << "Tried to construct a message that wasn't complete or over-filled: "
  << (int(partialMessage.length()) - 4) << " != " << messageSize;
  }

src/base/BackedWriter.cpp

@@ -40,8 +40,8 @@ BackedWriterWriteState BackedWriter::write(Packet packet) {
  messageSize = htonl(messageSize);
  string s = string("0000") + packet.serialize();
  if (int64_t(packet.length()) != int64_t(s.length()) - 4) {
- LOG(FATAL) << "Packet header size is invalid: " << packet.length()
-  << " != " << (s.length() - 4);
+ STFATAL << "Packet header size is invalid: " << packet.length()
+ << " != " << (s.length() - 4);
  }
  memcpy(&s[0], &messageSize, sizeof(int));
 
@@ -80,7 +80,7 @@ vector<std::string> BackedWriter::recover(int64_t lastValidSequenceNumber) {
 
  int64_t messagesToRecover = sequenceNumber - lastValidSequenceNumber;
  if (messagesToRecover < 0) {
- LOG(FATAL) << "Something went really wrong, client is ahead of server";
+ STFATAL << "Something went really wrong, client is ahead of server";
  }
  if (messagesToRecover == 0) {
  return vector<std::string>();

src/base/ClientConnection.cpp

@@ -37,8 +37,8 @@ bool ClientConnection::connect() {
  // Note: the response can be returning client if the client died while
  // performing the initial connection but the server thought the client
  // survived.
- LOG(ERROR) << "Error connecting to server: " << response.status() << ": "
-  << response.error();
+ STERROR << "Error connecting to server: " << response.status() << ": "
+ << response.error();
  cout << "Error connecting to server: " << response.status() << ": "
  << response.error() << endl;
  string s = string("Error connecting to server: ") +
@@ -112,8 +112,8 @@ void ClientConnection::pollReconnect() {
  return;
  }
  if (response.status() != RETURNING_CLIENT) {
- LOG(ERROR) << "Error reconnecting to server: " << response.status()
-  << ": " << response.error();
+ STERROR << "Error reconnecting to server: " << response.status()
+ << ": " << response.error();
  cout << "Error reconnecting to server: " << response.status()
  << ": " << response.error() << endl;
  socketHandler->close(newSocketFd);

src/base/Connection.cpp

@@ -3,11 +3,15 @@
 namespace et {
 Connection::Connection(shared_ptr<SocketHandler> _socketHandler,
  const string& _id, const string& _key)
- : socketHandler(_socketHandler), id(_id), key(_key), socketFd(-1), shuttingDown(false) {}
+ : socketHandler(_socketHandler),
+ id(_id),
+ key(_key),
+ socketFd(-1),
+ shuttingDown(false) {}
 
 Connection::~Connection() {
  if (!shuttingDown) {
- LOG(ERROR) << "Call shutdown before destructing a Connection.";
+ STERROR << "Call shutdown before destructing a Connection.";
  }
  if (socketFd != -1) {
  LOG(INFO) << "Connection destroyed";
@@ -70,7 +74,7 @@ void Connection::writePacket(const Packet& packet) {
 void Connection::closeSocket() {
  lock_guard<std::recursive_mutex> guard(connectionMutex);
  if (socketFd == -1) {
- LOG(ERROR) << "Tried to close a dead socket";
+ LOG(INFO) << "Tried to close a dead socket";
  return;
  }
  // TODO: There is a race condition where we invalidate and another
@@ -129,7 +133,7 @@ bool Connection::recover(int newSocketFd) {
  LOG(INFO) << "Finished recovering with socket fd: " << socketFd;
  return true;
  } catch (const runtime_error& err) {
- LOG(ERROR) << "Error recovering: " << err.what();
+ LOG(WARNING) << "Error recovering: " << err.what();
  socketHandler->close(newSocketFd);
  return false;
  }
@@ -155,8 +159,8 @@ bool Connection::read(Packet* packet) {
  return 0;
  } else {
  // Throw the error
- LOG(ERROR) << "Got a serious error trying to read: " << errno << " / "
-  << strerror(errno);
+ STERROR << "Got a serious error trying to read: " << errno << " / "
+ << strerror(errno);
  throw std::runtime_error("Failed a call to read");
  }
  } else {
@@ -188,8 +192,7 @@ bool Connection::write(const Packet& packet) {
  // The connection has been severed, handle and hide from the caller
  closeSocketAndMaybeReconnect();
  } else {
- LOG(FATAL) << "Unexpected socket error: " << errno << " "
- << strerror(errno);
+ STFATAL << "Unexpected socket error: " << errno << " " << strerror(errno);
  }
  }
 

src/base/CryptoHandler.cpp

@@ -1,19 +1,19 @@
 #include "CryptoHandler.hpp"
 
-#define SODIUM_FAIL(X)  \
- {  \
- int rc = (X);  \
- if ((rc) == -1) LOG(FATAL) << "Crypto Error: (" << rc << ")"; \
+#define SODIUM_FAIL(X) \
+ { \
+ int rc = (X); \
+ if ((rc) == -1) STFATAL << "Crypto Error: (" << rc << ")"; \
  }
 namespace et {
 
 CryptoHandler::CryptoHandler(const string& _key, unsigned char nonceMSB) {
  lock_guard<std::mutex> guard(cryptoMutex);
  if (-1 == sodium_init()) {
- LOG(FATAL) << "libsodium init failed";
+ STFATAL << "libsodium init failed";
  }
  if (_key.length() != crypto_secretbox_KEYBYTES) {
- LOG(FATAL) << "Invalid key length";
+ STFATAL << "Invalid key length";
  }
  memcpy(key, &_key[0], _key.length());
  memset(nonce, 0, crypto_secretbox_NONCEBYTES);
@@ -39,7 +39,7 @@ string CryptoHandler::decrypt(const string& buffer) {
  if (crypto_secretbox_open_easy((unsigned char*)&retval[0],
  (const unsigned char*)buffer.c_str(),
  buffer.length(), nonce, key) == -1) {
- LOG(FATAL) << "Decrypt failed. Possible key mismatch?";
+ STFATAL << "Decrypt failed. Possible key mismatch?";
  }
  return retval;
 }

src/base/DaemonCreator.cpp

@@ -39,7 +39,7 @@ int DaemonCreator::create(bool parentExit, string childPidFile) {
  if (childPidFile != "") {
  int pidFilehandle = open(childPidFile.c_str(), O_RDWR | O_CREAT, 0600);
  if (pidFilehandle == -1) {
- LOG(FATAL) << "Error opening pidfile for writing: " << childPidFile;
+ STFATAL << "Error opening pidfile for writing: " << childPidFile;
  }
 
  // Max pid length for x86_64 is 2^22 ~ 4000000

src/base/Headers.hpp

@@ -21,8 +21,10 @@
 #include <arpa/inet.h>
 #include <errno.h>
 #include <fcntl.h>
+#include <google/protobuf/message_lite.h>
 #include <pthread.h>
 #include <pwd.h>
+#include <sodium.h>
 #include <stdint.h>
 #include <stdio.h>
 #include <stdlib.h>
@@ -36,10 +38,12 @@
 #include <termios.h>
 #include <time.h>
 #include <unistd.h>
+
 #include <algorithm>
 #include <array>
 #include <atomic>
 #include <ctime>
+#include <cxxopts.hpp>
 #include <deque>
 #include <exception>
 #include <fstream>
@@ -55,38 +59,17 @@
 #include <unordered_set>
 #include <vector>
 
-#include <google/protobuf/message_lite.h>
 #include "ET.pb.h"
 #include "ETerminal.pb.h"
-inline std::ostream& operator<<(std::ostream& os,
- const et::SocketEndpoint& se) {
- if (se.has_name()) {
- os << se.name();
- }
- if (se.has_port()) {
- os << ":" << se.port();
- }
- return os;
-}
-
-#include "easylogging++.h"
-
-#include <cxxopts.hpp>
+#include "ThreadPool.h"
 #include "base64.hpp"
+#include "easylogging++.h"
 #include "json.hpp"
 #include "sole.hpp"
-
-#include "ThreadPool.h"
-
-#include <sodium.h>
+#include "ust.hpp"
 
 using namespace std;
 
-namespace google {}
-namespace gflags {}
-using namespace google;
-using namespace gflags;
-
 using json = nlohmann::json;
 
 // The ET protocol version supported by this binary
@@ -106,6 +89,10 @@ const int CLIENT_KEEP_ALIVE_DURATION = 5;
 // allow enough time.
 const int SERVER_KEEP_ALIVE_DURATION = 11;
 
+#define STFATAL LOG(FATAL) << "Stack Trace: " << endl << ust::generate()
+
+#define STERROR LOG(ERROR) << "Stack Trace: " << endl << ust::generate()
+
 #define FATAL_FAIL(X) \
  if (((X) == -1)) \
  LOG(FATAL) << "Error: (" << errno << "): " << strerror(errno);
@@ -121,6 +108,17 @@ const int SERVER_KEEP_ALIVE_DURATION = 11;
 #endif
 
 namespace et {
+inline std::ostream& operator<<(std::ostream& os,
+ const et::SocketEndpoint& se) {
+ if (se.has_name()) {
+ os << se.name();
+ }
+ if (se.has_port()) {
+ os << ":" << se.port();
+ }
+ return os;
+}
+
 template <typename Out>
 inline void split(const std::string& s, char delim, Out result) {
  std::stringstream ss;
@@ -175,7 +173,7 @@ template <typename T>
 inline T stringToProto(const string& s) {
  T t;
  if (!t.ParseFromString(s)) {
- LOG(FATAL) << "Error parsing string to proto: " << s.length() << " " << s;
+ STFATAL << "Error parsing string to proto: " << s.length() << " " << s;
  }
  return t;
 }
@@ -184,7 +182,7 @@ template <typename T>
 inline string protoToString(const T& t) {
  string s;
  if (!t.SerializeToString(&s)) {
- LOG(FATAL) << "Error serializing proto to string";
+ STFATAL << "Error serializing proto to string";
  }
  return s;
 }

src/base/Packet.hpp

@@ -23,13 +23,13 @@ class Packet {
  encrypted = false;
  payload = cryptoHandler->decrypt(payload);
  } else {
- LOG(FATAL) << "Tried to decrypt a packet that wasn't encrypted";
+ STFATAL << "Tried to decrypt a packet that wasn't encrypted";
  }
  }
 
  void encrypt(shared_ptr<CryptoHandler> cryptoHandler) {
  if (encrypted) {
- LOG(FATAL) << "Tried to encrypt a packet that was already encrypted";
+ STFATAL << "Tried to encrypt a packet that was already encrypted";
  } else {
  encrypted = true;
  payload = cryptoHandler->encrypt(payload);

src/base/PipeSocketHandler.cpp

@@ -108,9 +108,8 @@ set<int> PipeSocketHandler::getEndpointFds(const SocketEndpoint& endpoint) {
 
  string pipePath = endpoint.name();
  if (pipeServerSockets.find(pipePath) == pipeServerSockets.end()) {
- LOG(FATAL)
- << "Tried to getPipeFd on a pipe without calling listen() first: "
- << pipePath;
+ STFATAL << "Tried to getPipeFd on a pipe without calling listen() first: "
+ << pipePath;
  }
  return pipeServerSockets[pipePath];
 }
@@ -121,9 +120,8 @@ void PipeSocketHandler::stopListening(const SocketEndpoint& endpoint) {
  string pipePath = endpoint.name();
  auto it = pipeServerSockets.find(pipePath);
  if (it == pipeServerSockets.end()) {
- LOG(FATAL)
- << "Tried to stop listening to a pipe that we weren't listening on:"
- << pipePath;
+ STFATAL << "Tried to stop listening to a pipe that we weren't listening on:"
+ << pipePath;
  }
  int sockFd = *(it->second.begin());
  ::close(sockFd);

src/base/ServerConnection.cpp

@@ -44,9 +44,9 @@ void ServerConnection::clientHandler(int clientSocketFd) {
  {
  int version = request.version();
  if (version != PROTOCOL_VERSION) {
- LOG(ERROR) << "Got a client request but the client version does not "
-  "match. Client: "
-  << version << " != Server: " << PROTOCOL_VERSION;
+ STERROR << "Got a client request but the client version does not "
+ "match. Client: "
+ << version << " != Server: " << PROTOCOL_VERSION;
  et::ConnectResponse response;
 
  std::ostringstream errorStream;
@@ -74,7 +74,7 @@ void ServerConnection::clientHandler(int clientSocketFd) {
  }
  }
  if (!clientKeyExistsNow) {
- LOG(ERROR) << "Got a client that we have no key for";
+ LOG(INFO) << "Got a client that we have no key for";
 
  et::ConnectResponse response;
  std::ostringstream errorStream;
@@ -115,7 +115,7 @@ void ServerConnection::clientHandler(int clientSocketFd) {
  }
  } catch (const runtime_error& err) {
  // Comm failed, close the connection
- LOG(ERROR) << "Error handling new client: " << err.what();
+ LOG(WARNING) << "Error handling new client: " << err.what();
  socketHandler->close(clientSocketFd);
  }
 }

src/base/ServerConnection.hpp

@@ -2,7 +2,6 @@
 #define __ET_SERVER_CONNECTION__
 
 #include "Headers.hpp"
-
 #include "ServerClientConnection.hpp"
 #include "SocketHandler.hpp"
 
@@ -49,8 +48,7 @@ class ServerConnection {
  lock_guard<std::recursive_mutex> guard(mutex);
  auto it = clientConnections.find(clientId);
  if (it == clientConnections.end()) {
- LOG(FATAL)
- << "Error: Tried to get a client connection that doesn't exist";
+ STFATAL << "Error: Tried to get a client connection that doesn't exist";
  }
  return it->second;
  }