Commit 563b668a authored by Steven Murray's avatar Steven Murray
Browse files

First complete set of new logging code. Please note this code cannot compile

until some work is pulled/rebased from the remote master.  Please also note
that more work still needs to be done before this can be used by somebody else.
parent 822a6be2
......@@ -25,3 +25,16 @@
// Include Files
#include "castor/log/IPAddress.hpp"
//------------------------------------------------------------------------------
// constructor
//------------------------------------------------------------------------------
castor::log::IPAddress::IPAddress(const int ip) throw() : m_ip(ip) {
}
//------------------------------------------------------------------------------
// ip
//------------------------------------------------------------------------------
int castor::log::IPAddress::ip() const throw() {
return m_ip;
}
......@@ -27,35 +27,33 @@
#define CASTOR_LOG_IPADDRESS_HPP 1
namespace castor {
namespace log {
namespace log {
/**
* A simple object around an IP address
*/
class IPAddress {
public:
/**
* A simple object around an IP address
*/
class IPAddress {
/**
* Constructor
*/
IPAddress(int ip) : m_ip(ip) {};
public:
/**
* Accessor
*/
int ip() { return m_ip; }
/**
* Constructor
*/
IPAddress(const int ip) throw();
private:
/**
* Accessor
*/
int ip() const throw();
/// the IP address, as an int
int m_ip;
private:
};
/// the IP address, as an int
int m_ip;
} // end of namespace log
};
} // end of namespace castor
} // namespace log
} // namespace castor
#endif // CASTOR_LOG_IPADDRESS_HPP
......@@ -24,6 +24,7 @@
// Include Files
#include "castor/log/Log.hpp"
#include "h/Castor_limits.h"
#include "h/getconfent.h"
#include <errno.h>
......@@ -32,6 +33,7 @@
#include <sys/un.h>
#include <sys/types.h>
#include <sys/socket.h>
#include <sys/syscall.h>
#include <unistd.h>
#include <fcntl.h>
#include <stdio.h>
......@@ -57,17 +59,17 @@ static const size_t LOG_MAX_PARAMNAMELEN = 20;
/**
* Maximum length of a string value.
*/
//static size_t LOG_MAX_PARAMSTRLEN = 1024;
static size_t LOG_MAX_PARAMSTRLEN = 1024;
/**
* Maximum length of an ident/facility.
*/
static const size_t CASTOR_MAX_IDENTLEN = 20;
static const size_t LOG_MAX_IDENTLEN = 20;
/**
* Maximum length of a log message.
*/
static size_t CASTOR_MAX_LINELEN = 8192;
static size_t LOG_MAX_LINELEN = 8192;
/**
* True if the interface of the CASTOR logging system has been initialized.
......@@ -104,6 +106,22 @@ static const char* s_progname = 0;
*/
static int s_maxmsglen = DEFAULT_SYSLOG_MSGLEN;
static struct {
char *name; // Name of the priority
int value; // The priority's numeric representation in syslog
char *text; // Textual representation of the priority
} s_prioritylist[] = {
{ "LOG_EMERG", LOG_EMERG, "Emerg" },
{ "LOG_ALERT", LOG_ALERT, "Alert" },
{ "LOG_CRIT", LOG_CRIT, "Crit" },
{ "LOG_ERR", LOG_ERR, "Error" },
{ "LOG_WARNING", LOG_WARNING, "Warn" },
{ "LOG_NOTICE", LOG_NOTICE, "Notice" },
{ "LOG_INFO", LOG_INFO, "Info" },
{ "LOG_DEBUG", LOG_DEBUG, "Debug" },
{ NULL, 0, NULL }
};
//-----------------------------------------------------------------------------
// castor_openlog
//-----------------------------------------------------------------------------
......@@ -157,7 +175,7 @@ int initLog(const char *ident) {
}
/* Check if the ident is too big */
if (strlen(ident) > CASTOR_MAX_IDENTLEN) {
if (strlen(ident) > LOG_MAX_IDENTLEN) {
errno = EINVAL;
return (-1);
}
......@@ -198,8 +216,7 @@ int initLog(const char *ident) {
}
/* Check that the size of messages falls within acceptable limits */
if ((size >= DEFAULT_SYSLOG_MSGLEN) &&
(size <= CASTOR_MAX_LINELEN)) {
if ((size >= DEFAULT_SYSLOG_MSGLEN) && (size <= LOG_MAX_LINELEN)) {
s_maxmsglen = size;
}
......@@ -229,7 +246,7 @@ static void castor_closelog() {
//-----------------------------------------------------------------------------
// castor_syslog
//-----------------------------------------------------------------------------
static void castor_syslog(const std::string &msg) throw() {
static void castor_syslog(const char *const msg, const int msgLen) throw() {
int send_flags = 0;
#ifndef __APPLE__
// MAC has has no MSG_NOSIGNAL
......@@ -245,14 +262,14 @@ static void castor_syslog(const std::string &msg) throw() {
}
if (!s_connected ||
send(s_logFile, msg.c_str(), msg.length(), send_flags) < 0) {
send(s_logFile, msg, msgLen, send_flags) < 0) {
if (s_connected) {
// Try to reopen the syslog connection. Maybe it went down.
castor_closelog();
castor_openlog();
}
if (!s_connected ||
send(s_logFile, msg.c_str(), msg.length(), send_flags) < 0) {
send(s_logFile, msg, msgLen, send_flags) < 0) {
castor_closelog(); // attempt re-open next time
}
}
......@@ -261,6 +278,79 @@ static void castor_syslog(const std::string &msg) throw() {
pthread_mutex_unlock(&s_syslogMutex);
}
//-----------------------------------------------------------------------------
// build_syslog_header
//-----------------------------------------------------------------------------
static int build_syslog_header(char *const buffer,
const int buflen,
const int priority,
const struct timeval &timeStamp,
const int pid) {
struct tm tmp;
int len = snprintf(buffer, buflen, "<%d>", priority);
localtime_r(&(timeStamp.tv_sec), &tmp);
len += strftime(buffer + len, buflen - len, "%Y-%m-%dT%T", &tmp);
len += snprintf(buffer + len, buflen - len, ".%06ld",
(unsigned long)timeStamp.tv_usec);
len += strftime(buffer + len, buflen - len, "%z: ", &tmp);
// dirty trick to have the proper timezone format (':' between hh and mm)
buffer[len-2] = buffer[len-3];
buffer[len-3] = buffer[len-4];
buffer[len-4] = ':';
// if no source given, you by default the name of the process in which we run
// print source and pid
len += snprintf(buffer + len, buflen - len, "%s[%d]: ", s_progname, pid);
return len;
}
//-----------------------------------------------------------------------------
// _clean_string
//-----------------------------------------------------------------------------
static std::string _clean_string(const std::string &s, const bool underscore) {
char *str = strdup(s.c_str());
// Return an empty string if the strdup() failed
if(NULL == str) {
return "";
}
// Variables
char *end = NULL;
char *ptr = NULL;
// Replace newline and tab with a space
while (((ptr = strchr(str, '\n')) != NULL) ||
((ptr = strchr(str, '\t')) != NULL)) {
*ptr = ' ';
}
// Remove leading whitespace
while (isspace(*str)) str++;
// Remove trailing whitespace
end = str + strlen(str) - 1;
while (end > str && isspace(*end)) end--;
// Write new null terminator
*(end + 1) = '\0';
// Replace double quotes with single quotes
while ((ptr = strchr(str, '"')) != NULL) {
*ptr = '\'';
}
// Check for replacement of spaces with underscores
if (underscore) {
while ((ptr = strchr(str, ' ')) != NULL) {
*ptr = '_';
}
}
std::string result(str);
free(str);
return result;
}
} // namespace log
} // namespace castor
......@@ -268,7 +358,7 @@ static void castor_syslog(const std::string &msg) throw() {
// writeMsg
//-----------------------------------------------------------------------------
void castor::log::writeMsg(
const int severity,
const int priority,
const std::string &msg,
const int numParams,
const castor::log::Param params[],
......@@ -276,13 +366,127 @@ void castor::log::writeMsg(
//---------------------------------------------------------------------------
// Note that we do here part of the work of the real syslog call, by building
// the message ourselves. We then only call a reduced version of syslog
// (namely dlf_syslog). The reason behind it is to be able to set the
// (namely castor_syslog). The reason behind it is to be able to set the
// message timestamp ourselves, in case we log messages asynchronously, as
// we do when retrieving logs from the DB
//----------------------------------------------------------------------------
const std::string toBeDoneMsg = "TO BE DONE";
castor_syslog(toBeDoneMsg);
char buffer[LOG_MAX_LINELEN * 2];
size_t len = 0;
// Do nothing if the logging interface has not been initialized
if (!s_initialized) {
return;
}
// Do nothing if the log priority is not valid
if (priority > LOG_DEBUG) {
return;
}
// Initialize buffers
memset(buffer, '\0', sizeof(buffer));
// Start message with priority, time, program and PID (syslog standard
// format)
len += build_syslog_header(buffer, s_maxmsglen - len, priority | LOG_LOCAL3,
timeStamp, getpid());
// Append the log level, the thread id and the message text
#ifdef __APPLE__
len += snprintf(buffer + len, s_maxmsglen - len, "LVL=%s TID=%d MSG=\"%s\" ",
s_prioritylist[priority].text,(int)mach_thread_self(), msg.c_str());
#else
len += snprintf(buffer + len, s_maxmsglen - len, "LVL=%s TID=%d MSG=\"%s\" ",
s_prioritylist[priority].text,(int)syscall(__NR_gettid), msg.c_str());
#endif
// Process parameters
for (int i = 0; i < numParams; i++) {
const Param &param = params[i];
// Check the parameter name, if it's an empty string set the value to
// "Undefined".
const std::string name = param.getName() == "" ? "Undefined" :
_clean_string(param.getName(), true);
// Process the data type associated with the parameter
switch (params[i].getType()) {
// Strings
case LOG_MSG_PARAM_TPVID:
case LOG_MSG_PARAM_STR:
{
const std::string value = _clean_string(param.getStrValue(), false);
if (LOG_MSG_PARAM_TPVID == param.getType()) {
len += snprintf(buffer + len, s_maxmsglen - len, "TPVID=%.*s ",
CA_MAXVIDLEN, value.c_str());
} else {
len += snprintf(buffer + len, s_maxmsglen - len, "%.*s=\"%.*s\" ",
(int)LOG_MAX_PARAMNAMELEN, name.c_str(),
(int)LOG_MAX_PARAMSTRLEN, value.c_str());
}
}
break;
// Numerical values
case LOG_MSG_PARAM_INT:
len += snprintf(buffer + len, s_maxmsglen - len, "%.*s=%d ",
(int)LOG_MAX_PARAMNAMELEN, name.c_str(),
param.getIntValue());
break;
case LOG_MSG_PARAM_INT64:
len += snprintf(buffer + len, s_maxmsglen - len, "%.*s=%lld ",
(int)LOG_MAX_PARAMNAMELEN, name.c_str(),
param.getUint64Value());
break;
case LOG_MSG_PARAM_DOUBLE:
len += snprintf(buffer + len, s_maxmsglen - len, "%.*s=%f ",
(int)LOG_MAX_PARAMNAMELEN, name.c_str(),
param.getDoubleValue());
break;
// Subrequest uuid
case LOG_MSG_PARAM_UUID:
{
char uuidstr[CUUID_STRING_LEN + 1];
if (Cuuid2string(uuidstr, CUUID_STRING_LEN + 1,
&param.getUuidValue())) {
return;
}
len += snprintf(buffer + len, s_maxmsglen - len, "SUBREQID=%.*s ",
CUUID_STRING_LEN, uuidstr);
}
break;
case LOG_MSG_PARAM_RAW:
len += snprintf(buffer + len, s_maxmsglen - len, "%s ",
param.getStrValue().c_str());
break;
default:
// Please note that this case is used for normal program execution
// for the following parameter types:
//
// LOG_MSG_PARAM_UID
// LOG_MSG_PARAM_GID
// LOG_MSG_PARAM_STYPE
// LOG_MSG_PARAM_SNAME
break; // Nothing
}
// Check if there is enough space in the buffer
if ((int)len >= s_maxmsglen) {
buffer[s_maxmsglen - 1] = '\n';
break;
}
}
// Terminate the string
if ((int)len < s_maxmsglen) {
len += snprintf(buffer + (len - 1), s_maxmsglen - len, "\n");
}
castor_syslog(buffer, len);
}
//-----------------------------------------------------------------------------
......
......@@ -73,13 +73,13 @@ int initLog (const char *ident);
* Note that this version of writeMsg() allows the caller to specify the
* time stamp of the log message.
*
* @param severity the severity of the message.
* @param priority the priority of the message.
* @param msg the message.
* @param numParams the number of parameters in the message.
* @param params the parameters of the message, given as an array.
* @param timeStamp the time stamp of the log message.
*/
void writeMsg(const int severity,
void writeMsg(const int priority,
const std::string &msg,
const int numParams,
const Param params[],
......@@ -97,11 +97,11 @@ void writeMsg(const int severity,
* @param timeStamp the time stamp of the log message.
*/
template<int numParams>
void writeMsg(const int severity,
void writeMsg(const int priority,
const std::string &msg,
castor::log::Param(&params)[numParams],
const struct timeval &timeStamp) throw() {
writeMsg(severity, msg, numParams, params, timeStamp);
writeMsg(priority, msg, numParams, params, timeStamp);
}
/**
......@@ -112,12 +112,12 @@ void writeMsg(const int severity,
* Note that this version of writeMsg() implicitly uses the current time as
* the time stamp of the message.
*
* @param severity the severity of the message.
* @param priority the priority of the message.
* @param msg the message.
* @param numParams the number of parameters in the message.
* @param params the parameters of the message, given as an array.
*/
void writeMsg(const int severity,
void writeMsg(const int priority,
const std::string &msg,
const int numParams,
const castor::log::Param params[]) throw();
......@@ -130,15 +130,15 @@ void writeMsg(const int severity,
* Note that this version of writeMsg() implicitly uses the current time as
* the time stamp of the message.
*
* @param severity the severity of the message.
* @param priority the priority of the message.
* @param msg the message.
* @param params the parameters of the message, given as an array.
*/
template<int numParams>
void writeMsg(const int severity,
void writeMsg(const int priority,
const std::string &msg,
castor::log::Param(&params)[numParams]) throw() {
writeMsg(severity, msg, numParams, params);
writeMsg(priority, msg, numParams, params);
}
} // namespace log
......
......@@ -34,51 +34,48 @@
//-----------------------------------------------------------------------------
// Constructor
//-----------------------------------------------------------------------------
castor::log::Param::Param(const char* name,
castor::IObject* value) :
m_deallocate(true) {
m_cParam.name = (char*) name;
m_cParam.type = LOG_MSG_PARAM_STR;
std::ostringstream s;
castor::log::Param::Param(const std::string &name,
const castor::IObject *const value) :
m_name(name), m_type(LOG_MSG_PARAM_STR),
m_intValue(0), m_uint64Value(0), m_doubleValue(0.0), m_uuidValue(nullCuuid) {
std::ostringstream oss;
castor::ObjectSet set;
value->print(s, "", set);
m_cParam.value.par_string = strdup(s.str().c_str());
value->print(oss, "", set);
m_strValue = oss.str();
}
//-----------------------------------------------------------------------------
// Constructor
//-----------------------------------------------------------------------------
castor::log::Param::Param(const char* name,
castor::log::IPAddress value) :
m_deallocate(true) {
m_cParam.name = (char*) name;
m_cParam.type = LOG_MSG_PARAM_STR;
std::ostringstream s;
s << ((value.ip() & 0xFF000000) >> 24) << "."
<< ((value.ip() & 0x00FF0000) >> 16) << "."
<< ((value.ip() & 0x0000FF00) >> 8) << "."
<< ((value.ip() & 0x000000FF));
m_cParam.value.par_string = strdup(s.str().c_str());
castor::log::Param::Param(const std::string &name,
const castor::log::IPAddress &value) :
m_name(name), m_type(LOG_MSG_PARAM_STR),
m_intValue(0), m_uint64Value(0), m_doubleValue(0.0), m_uuidValue(nullCuuid) {
std::ostringstream oss;
oss << ((value.ip() & 0xFF000000) >> 24) << "."
<< ((value.ip() & 0x00FF0000) >> 16) << "."
<< ((value.ip() & 0x0000FF00) >> 8) << "."
<< ((value.ip() & 0x000000FF));
m_strValue = oss.str();
}
//-----------------------------------------------------------------------------
// Constructor
//-----------------------------------------------------------------------------
castor::log::Param::Param(const char* name,
castor::log::TimeStamp value) :
m_deallocate(true) {
m_cParam.name = (char*) name;
m_cParam.type = LOG_MSG_PARAM_STR;
castor::log::Param::Param(const std::string &name,
const castor::log::TimeStamp &value) :
m_name(name), m_type(LOG_MSG_PARAM_STR),
m_intValue(0), m_uint64Value(0), m_doubleValue(0.0), m_uuidValue(nullCuuid) {
time_t time = value.time();
// There is NO localtime_r() on Windows,
// so we will use non-reentrant version localtime().
struct tm tmstruc;
localtime_r (&time, &tmstruc);
std::ostringstream s;
s << std::setw(2) << tmstruc.tm_mon+1
<< "/" << tmstruc.tm_mday
<< " " << tmstruc.tm_hour
<< ":" << tmstruc.tm_min
<< ":" << tmstruc.tm_sec;
m_cParam.value.par_string = strdup(s.str().c_str());
std::ostringstream oss;
oss << std::setw(2) << tmstruc.tm_mon+1
<< "/" << tmstruc.tm_mday
<< " " << tmstruc.tm_hour
<< ":" << tmstruc.tm_min
<< ":" << tmstruc.tm_sec;
m_strValue = oss.str();
}
......@@ -53,21 +53,6 @@
namespace castor {
namespace log {
/**
* Provided for C++ users. Refer to: castor/log/Param.hpp
*/
struct castor_write_param_t {
char *name; /* Name of the parameter */
int type; /* Parameter type, one of LOG_MSG_PARAM_* */
union {
char *par_string; /* Value for type LOG_PARAM_STRING */
int par_int; /* Value for type LOG_PARAM_INT */
u_signed64 par_u64; /* Value for type LOG_PARAM_INT64 */
double par_double; /* Value for type LOG_PARAM_DOUBLE */
Cuuid_t par_uuid; /* Value for type LOG_PARAM_UUID */
} value;
};
/**
* A parameter for the CASTOR logging system.
*/
......@@ -78,193 +63,256 @@ public:
/**
* Constructor for strings
*/
Param(const char* name, std::string value) :
m_deallocate(true) {
m_cParam.name = (char*) name;
m_cParam.type = LOG_MSG_PARAM_STR;
if (!strcmp(name, "TPVID")) {
m_cParam.type = LOG_MSG_PARAM_TPVID;
}
m_cParam.value.par_string = strdup(value.c_str());
};
/**
* Constructor for C strings
*/
Param(const char* name, const char* value) :
m_deallocate(true) {
m_cParam.name = (char*) name;
m_cParam.type = LOG_MSG_PARAM_STR;
if (!strcmp(name, "TPVID")) {
m_cParam.type = LOG_MSG_PARAM_TPVID;
}
if (0 != value) {
m_cParam.value.par_string = strdup(value);
} else {
m_cParam.value.par_string = 0;
}
};
Param(const std::string &name, const std::string &value) :
m_name(name),
m_type(name == "TPVID" ? LOG_MSG_PARAM_TPVID : LOG_MSG_PARAM_STR),
m_strValue(value), m_intValue(0), m_uint64Value(0), m_doubleValue(0.0),
m_uuidValue(nullCuuid) {
}
/**
* Constructor for uuids
*/
Param(const char* name, Cuuid_t value) :
m_deallocate(false) {
m_cParam.name = (char*) name;
m_cParam.type = LOG_MSG_PARAM_UUID;
m_cParam.value.par_uuid = value;
};
Param(const std::string &name, const Cuuid_t value) :
m_name(name), m_type(LOG_MSG_PARAM_UUID),
m_strValue(), m_intValue(0), m_uint64Value(0), m_doubleValue(0.0),
m_uuidValue(value) {
}
/**
* Constructor for SubRequest uuids
*/
Param(Cuuid_t value) :
m_deallocate(false) {
m_cParam.name = NULL;
m_cParam.type = LOG_MSG_PARAM_UUID;
m_cParam.value.par_uuid = value;