LoggerImplementation.cpp 14.8 KB
Newer Older
1
/******************************************************************************
2
 *                      castor/log/LoggerImplementation.cpp
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
 *
 * This file is part of the Castor project.
 * See http://castor.web.cern.ch/castor
 *
 * Copyright (C) 2003  CERN
 * This program is free software; you can redistribute it and/or
 * modify it under the terms of the GNU General Public License
 * as published by the Free Software Foundation; either version 2
 * of the License, or (at your option) any later version.
 * This program is distributed in the hope that it will be useful,
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 * GNU General Public License for more details.
 * You should have received a copy of the GNU General Public License
 * along with this program; if not, write to the Free Software
 * Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
 *
 * Interface to the CASTOR logging system
 *
 * @author Steven.Murray@cern.ch
 *****************************************************************************/

25
#include "castor/log/LoggerImplementation.hpp"
26
27
28
29
#include "h/Castor_limits.h"
#include "h/getconfent.h"

#include <errno.h>
30
#include <sstream>
31
#include <stdlib.h>
32
33
34
35
36
37
38
39
40
41
42
43
#include <string.h>
#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>

//------------------------------------------------------------------------------
// constructor
//------------------------------------------------------------------------------
44
castor::log::LoggerImplementation::LoggerImplementation(
45
46
  const std::string &programName)
  throw(castor::exception::Internal, castor::exception::InvalidArgument):
47
  Logger(programName),
48
49
50
51
52
53
54
55
56
57
  m_maxMsgLen(determineMaxMsgLen()),
  m_logFile(-1),
  m_connected(false),
  m_priorityToText(generatePriorityToTextMap()) {
  initMutex();
}

//------------------------------------------------------------------------------
// determineMaxMsgLen
//------------------------------------------------------------------------------
58
size_t castor::log::LoggerImplementation::determineMaxMsgLen() const throw() {
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
  const char *p = NULL;
  size_t msgSize = 0;

  if((p = getconfent("LOG", "MaxMessageSize", 0)) != NULL) {
    msgSize = atoi(p);
  } else {
    // Determine the size automatically, this is not guaranteed to work!
    FILE *const fp = fopen("/etc/rsyslog.conf", "r");
    if(fp) {
      char buffer[1024];

      // The /etc/rsyslog.conf file exists so we assume the default message
      // size of 2K.
      msgSize = DEFAULT_RSYSLOG_MSGLEN;

      // In rsyslog versions >= 3.21.4, the maximum size of a message became
      // configurable through the $MaxMessageSize global config directive.
      // Here we attempt to find out if the user has increased the size!
      while(fgets(buffer, sizeof(buffer), fp) != NULL) {
        if(strncasecmp(buffer, "$MaxMessageSize", 15)) {
          continue; // Option not of interest
        }
        msgSize = atol(&buffer[15]);
      }
      fclose(fp);
    }
    // If the /etc/rsyslog.conf file is missing which implies that we are
    // running on a stock syslogd system, therefore the message size is
    // governed by the syslog RFC: http://www.faqs.org/rfcs/rfc3164.html
  }

  // Check that the size of messages falls within acceptable limits
  if((msgSize >= DEFAULT_SYSLOG_MSGLEN) && (msgSize <= LOG_MAX_LINELEN)) {
    return msgSize;
  } else {
    return DEFAULT_SYSLOG_MSGLEN;
  }
}

//------------------------------------------------------------------------------
// generatePriorityToTextMap
//------------------------------------------------------------------------------
std::map<int, std::string>
102
  castor::log::LoggerImplementation::generatePriorityToTextMap() const 
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
  throw(castor::exception::Internal) {
  std::map<int, std::string> m;

  try {
    m[LOG_EMERG]   = "Emerg";
    m[LOG_ALERT]   = "Alert";
    m[LOG_CRIT]    = "Crit";
    m[LOG_ERR]     = "Error";
    m[LOG_WARNING] = "Warn";
    m[LOG_NOTICE]  = "Notice";
    m[LOG_INFO]    = "Info";
    m[LOG_DEBUG]   = "Debug";
  } catch(std::exception &se) {
    castor::exception::Internal ex;
    ex.getMessage() << "Failed to generate priority to text mapping: " <<
      se.what();
    throw ex;
  }

  return m;
}

//------------------------------------------------------------------------------
// initMutex
//------------------------------------------------------------------------------
128
void castor::log::LoggerImplementation::initMutex()
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
  throw(castor::exception::Internal) {
  pthread_mutexattr_t attr;
  int rc = pthread_mutexattr_init(&attr);
  if(0 != rc) {
    castor::exception::Internal ex;
    ex.getMessage() << "Failed to initialize mutex attribute for m_mutex: " <<
      sstrerror(rc);
    throw ex;
  }
  rc = pthread_mutexattr_settype(&attr, PTHREAD_MUTEX_ERRORCHECK);
  if(0 != rc) {
    castor::exception::Internal ex;
    ex.getMessage() << "Failed to set mutex type of m_mutex: " <<
      sstrerror(rc);
    throw ex;
  }
  rc = pthread_mutex_init(&m_mutex, NULL);
   if(0 != rc) {
     castor::exception::Internal ex;
     ex.getMessage() << "Failed to initialize m_mutex: " << sstrerror(rc);
     throw ex;
   }
  rc = pthread_mutexattr_destroy(&attr);
  if(0 != rc) {
    pthread_mutex_destroy(&m_mutex);
    castor::exception::Internal ex;
    ex.getMessage() << "Failed to destroy mutex attribute of m_mutex: " <<
      sstrerror(rc);
    throw ex;
  }
}

//------------------------------------------------------------------------------
// destructor
//------------------------------------------------------------------------------
164
castor::log::LoggerImplementation::~LoggerImplementation() throw() {
165
166
}

167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
//------------------------------------------------------------------------------
// prepareForFork
//------------------------------------------------------------------------------
void castor::log::LoggerImplementation::prepareForFork() 
  throw(castor::exception::Internal) {
  // Enter critical section
  {
    const int mutex_lock_rc = pthread_mutex_lock(&m_mutex);
    if(0 != mutex_lock_rc) {
      castor::exception::Internal ex;
      ex.getMessage() << "Failed to lock mutex of logger's critcial section: "
        << sstrerror(mutex_lock_rc);
      throw(ex);
    }
  }

  closeLog();

  // Leave critical section.
  {
    const int mutex_unlock_rc = pthread_mutex_unlock(&m_mutex);
    if(0 != mutex_unlock_rc) {
      castor::exception::Internal ex;
      ex.getMessage() << "Failed to unlock mutex of logger's critcial section: "
        << sstrerror(mutex_unlock_rc);
      throw(ex);
    }
  }
}

197
198
199
//------------------------------------------------------------------------------
// openLog
//------------------------------------------------------------------------------
200
void castor::log::LoggerImplementation::openLog() throw() {
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
  if(-1 == m_logFile) {
    struct sockaddr_un syslogAddr;
    syslogAddr.sun_family = AF_UNIX;
    strncpy(syslogAddr.sun_path, _PATH_LOG, sizeof(syslogAddr.sun_path));
    m_logFile = socket(AF_UNIX, SOCK_DGRAM, 0);
    if(-1 == m_logFile) {
      return;
    }

    if(-1 == fcntl(m_logFile, F_SETFD, FD_CLOEXEC)) {
      close(m_logFile);
      m_logFile = -1;
      return;
    }
  }
  if(!m_connected) {
    struct sockaddr_un syslogAddr;
    syslogAddr.sun_family = AF_UNIX;
    strncpy(syslogAddr.sun_path, _PATH_LOG, sizeof(syslogAddr.sun_path));
    if(-1 == connect(m_logFile, (struct sockaddr *)&syslogAddr,
      sizeof(syslogAddr))) {
      close(m_logFile);
      m_logFile = -1;
    } else {
#ifdef __APPLE__
      // MAC has has no MSG_NOSIGNAL
      // but >= 10.2 comes with SO_NOSIGPIPE
      int set = 1;
229
      if(0 != setsockopt(m_logFile, SOL_SOCKET, SO_NOSIGPIPE, &set,
230
231
232
233
234
235
236
237
238
239
240
241
242
243
        sizeof(int))) {
        close(m_logFile);
        m_logFile = -1;
        return;
      }
#endif
      m_connected = true;
    }
  }
}

//------------------------------------------------------------------------------
// closeLog
//------------------------------------------------------------------------------
244
void castor::log::LoggerImplementation::closeLog() throw() {
245
246
247
248
249
250
251
252
253
  if(!m_connected) {
    return;
  }
  close(m_logFile);
  m_logFile = -1;
  m_connected = false;
}

//-----------------------------------------------------------------------------
254
// operator() 
255
//-----------------------------------------------------------------------------
256
void castor::log::LoggerImplementation::operator() (
257
258
  const int priority,
  const std::string &msg,
259
  const std::vector<Param> &params,
260
  const struct timeval &timeStamp) throw() {
261
262
  operator() (priority, msg, params.begin(), params.end(), timeStamp);
}
263

264
265
266
267
268
269
270
271
272
273
//-----------------------------------------------------------------------------
// operator() 
//-----------------------------------------------------------------------------
void castor::log::LoggerImplementation::operator() (
  const int priority,
  const std::string &msg,
  const std::list<Param> &params,
  const struct timeval &timeStamp) throw() {
  operator() (priority, msg, params.begin(), params.end(), timeStamp);
}
274

275
276
277
278
279
280
281
282
283
284
//-----------------------------------------------------------------------------
// operator() 
//-----------------------------------------------------------------------------
void castor::log::LoggerImplementation::operator() (
  const int priority,
  const std::string &msg,
  const int numParams,
  const log::Param params[],
  const struct timeval &timeStamp) throw() {
  operator() (priority, msg, params, params+numParams, timeStamp);
285
286
287
288
289
}

//-----------------------------------------------------------------------------
// buildSyslogHeader
//-----------------------------------------------------------------------------
290
std::string castor::log::LoggerImplementation::buildSyslogHeader(
291
292
293
  const int priority,
  const struct timeval &timeStamp,
  const int pid) const throw() {
294
295
296
297
298
299
300
301
302
303
304
  char buf[80];
  int bufLen = sizeof(buf);
  int len = 0;
  std::ostringstream oss;

  oss << "<" << priority << ">";

  struct tm localTime;
  localtime_r(&(timeStamp.tv_sec), &localTime);
  len += strftime(buf, bufLen, "%Y-%m-%dT%T", &localTime);
  len += snprintf(buf + len, bufLen - len, ".%06ld",
305
    (unsigned long)timeStamp.tv_usec);
306
  len += strftime(buf + len, bufLen - len, "%z: ", &localTime);
307
  // dirty trick to have the proper timezone format (':' between hh and mm)
308
309
310
311
312
313
  buf[len-2] = buf[len-3];
  buf[len-3] = buf[len-4];
  buf[len-4] = ':';
  buf[sizeof(buf) - 1] = '\0';
  oss << buf << m_programName.c_str() << "[" << pid << "]: ";
  return oss.str();
314
315
316
317
318
}

//-----------------------------------------------------------------------------
// cleanString
//-----------------------------------------------------------------------------
319
std::string castor::log::LoggerImplementation::cleanString(const std::string &s,
320
  const bool replaceSpaces) throw() {
321
322
323
324
  const std::string& spaces="\t\n\v\f\r ";
  
  //find first non white char
  size_t beginpos = s.find_first_not_of(spaces);
325
326
327
328
329
  std::string::const_iterator it1;
  if (std::string::npos != beginpos)
    it1 = beginpos + s.begin();
  else
    it1 = s.begin();
330
331

  //find last non white char
332
  std::string::const_iterator it2;
333
  size_t endpos = s.find_last_not_of(spaces);
334
335
336
337
338
339
340
  if (std::string::npos != endpos) 
    it2 = endpos + 1 + s.begin();
  else 
    it2 = s.end();
  
  std::string result(it1, it2);
  
341
342
 // if (s.begin() == it1 && it2 == s.end()) 
 //   result="";
343
344
  
  for (std::string::iterator it = result.begin(); it != result.end(); ++it) {
345
346
    
    // Replace newline and tab with a space
347
348
349
350
351
352
    if (replaceSpaces) {
      if ('\t' == *it) 
        *it = ' ';
      
      if ('\n' == *it) 
        *it = ' ';
353
    }
354
    
355
    // Replace spaces with underscore
356
357
    if (' ' == *it) 
      *it = '_';
358
359
    
    // Replace double quotes with single quotes
360
361
    if ('"' == *it) 
      *it = '\'';
362
363
364
365
366
367
368
  }
  return result;
}

//-----------------------------------------------------------------------------
// reducedSyslog
//-----------------------------------------------------------------------------
369
void castor::log::LoggerImplementation::reducedSyslog(std::string msg)
370
  throw() {
371
372
373
374
375
376
  // Truncate the log message if it exceeds the permitted maximum
  if(msg.length() > m_maxMsgLen) {
    msg.resize(m_maxMsgLen);
    msg[msg.length() - 1] = '\n';
  }

377
378
379
380
381
382
383
  int send_flags = 0;
#ifndef __APPLE__
  // MAC has has no MSG_NOSIGNAL
  // but >= 10.2 comes with SO_NOSIGPIPE
  send_flags = MSG_NOSIGNAL;
#endif
  // enter critical section
384
385
386
387
388
  const int mutex_lock_rc = pthread_mutex_lock(&m_mutex);
  // Do nothing if we failed to enter the critical section
  if(0 != mutex_lock_rc) {
    return;
  }
389

390
391
  // Try to connect if not already connected
  if(!m_connected) {
392
393
394
    openLog();
  }

395
396
397
398
399
  // If connected
  if(m_connected) {
    // If sending the log message fails then try to reopen the syslog
    // connection and try again
    if(0 > send(m_logFile, msg.c_str(), msg.length(), send_flags)) {
400
401
      closeLog();
      openLog();
402
403
404
405
406
407
408
      if (m_connected) {
        // If the second attempt to send the log message fails then give up and
        // attempt re-open next time
        if(0 > send(m_logFile, msg.c_str(), msg.length(), send_flags)) {
          closeLog();
        }
      }
409
410
411
412
413
414
415
    }
  }

  // Leave critical section.
  pthread_mutex_unlock(&m_mutex);
}

416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
//-----------------------------------------------------------------------------
// operator() 
//-----------------------------------------------------------------------------
void castor::log::LoggerImplementation::operator() (
  const int priority,
  const std::string &msg,
  const std::vector<Param> &params) throw() {

  struct timeval timeStamp;
  gettimeofday(&timeStamp, NULL);

  operator() (priority, msg, params.begin(), params.end(), timeStamp);
}

//-----------------------------------------------------------------------------
// operator() 
//-----------------------------------------------------------------------------
void castor::log::LoggerImplementation::operator() (
  const int priority,
  const std::string &msg,
  const std::list<Param> &params) throw() {

  struct timeval timeStamp;
  gettimeofday(&timeStamp, NULL);

  operator() (priority, msg, params.begin(), params.end(), timeStamp);
}

444
//-----------------------------------------------------------------------------
445
// operator() 
446
//-----------------------------------------------------------------------------
447
void castor::log::LoggerImplementation::operator() (
448
  const int priority,
449
450
  const std::string &msg,
  const int numParams,
451
  const log::Param params[]) throw() {
452
453
454
455

  struct timeval timeStamp;
  gettimeofday(&timeStamp, NULL);

456
  operator() (priority, msg, numParams, params, timeStamp);
457
458
459
}

//-----------------------------------------------------------------------------
460
// operator() 
461
//-----------------------------------------------------------------------------
462
void castor::log::LoggerImplementation::operator() (
463
464
  const int priority,
  const std::string &msg) throw() {
465

466
  Param *emptyParams = NULL;
467
  operator() (priority, msg, 0, emptyParams);
468
}