Rewrite log_trace to be thread-safe and some cleanups

This commit is contained in:
2016-08-08 22:31:29 +03:00
parent e9f3673bfd
commit dcd58d8281
8 changed files with 127 additions and 74 deletions

View File

@@ -12,6 +12,7 @@ static int test_conf_perms();
static int test_conf_syntax(); static int test_conf_syntax();
struct conf_table conf = { struct conf_table conf = {
0, /* isvalid initial state */
{ {
"", /* db.type */ "", /* db.type */
"", /* db.hostname */ "", /* db.hostname */
@@ -22,7 +23,7 @@ struct conf_table conf = {
"7000", /* rmps.bind_on_port */ "7000", /* rmps.bind_on_port */
"/var/log/rmps/rmpsd.log", "/var/log/rmps/rmpsd.log",
"/var/log/rmps/rmpsd.err", "/var/log/rmps/rmpsd.err",
'1', /* rmps.loglevel */ '2', /* rmps.loglevel */
"/run/rmps/rmpsd.pid", "/run/rmps/rmpsd.pid",
"/etc/rmps/cert.pem", "/etc/rmps/cert.pem",
"/etc/rmps/key.pem", "/etc/rmps/key.pem",
@@ -82,8 +83,8 @@ static int fopen_and_mkdir(const char *dir) {
if(*p == '/') { if(*p == '/') {
*p = 0; *p = 0;
if (mkdir(tmp, S_IRWXU) == -1 && errno != EEXIST) { if (mkdir(tmp, S_IRWXU) == -1 && errno != EEXIST) {
fprintf( stderr, log_trace( ERROR,
"Permission denied to create directory: %s\n", "Permission denied to create directory: %s",
tmp ); tmp );
return 1; return 1;
} }
@@ -91,7 +92,7 @@ static int fopen_and_mkdir(const char *dir) {
} }
fd = fopen(dir, "a"); fd = fopen(dir, "a");
if (!fd) { if (!fd) {
fprintf(stderr, "Permission denied to write into: %s\n", dir); log_trace(ERROR, "Permission denied to write into: %s", dir);
return 1; return 1;
} }
fclose(fd); fclose(fd);
@@ -171,7 +172,6 @@ static int test_conf_perms()
log_trace(WARNING, confresult); log_trace(WARNING, confresult);
} }
} }
return 0; /* conf is readable */ return 0; /* conf is readable */
} }
@@ -198,8 +198,8 @@ static int test_conf_syntax()
if ((tmp = strstr(buf, "="))) if ((tmp = strstr(buf, "=")))
*tmp = '\0'; *tmp = '\0';
else { else {
fprintf( stderr, log_trace( ERROR,
"Bad entry in /etc/rmps/rmps.conf, line %d: %s\n", "Bad entry in /etc/rmps/rmps.conf, line %d: %s",
j, buf ); j, buf );
ok = 0; ok = 0;
failed = 1; failed = 1;
@@ -210,8 +210,8 @@ static int test_conf_syntax()
if (tmp[i] == '\n') if (tmp[i] == '\n')
tmp[i] = '\0'; tmp[i] = '\0';
if (tmp[strspn(tmp + 1, " \t\v\r\n") + 1] == '\0') { if (tmp[strspn(tmp + 1, " \t\v\r\n") + 1] == '\0') {
fprintf( stderr, log_trace( ERROR,
"Specified entry without value, line %d: %s\n", "Specified entry without value, line %d: %s",
j, buf ); j, buf );
failed = 1; failed = 1;
continue; continue;
@@ -278,29 +278,28 @@ static int test_conf_syntax()
failed = 1; failed = 1;
} else if (!strcmp(buf, "rmps.certfile")) { } else if (!strcmp(buf, "rmps.certfile")) {
if (access(tmp + 1, F_OK) == -1) { if (access(tmp + 1, F_OK) == -1) {
fprintf( stderr, log_trace( ERROR,
"%s is missing\n", tmp + 1); "%s is missing", tmp + 1);
failed = 1; failed = 1;
} }
else if (access(tmp + 1, R_OK) == -1) { else if (access(tmp + 1, R_OK) == -1) {
fprintf( stderr, log_trace( ERROR,
"%s is not readable\n", "%s is not readable",
tmp + 1 tmp + 1
); );
failed = 1; failed = 1;
} else } else
strncpy(conf.rmps.certfile, tmp + 1, sizeof(conf.rmps.certfile)); strncpy(conf.rmps.certfile, tmp + 1, sizeof(conf.rmps.certfile));
} }
else if (!strcmp(buf, "rmps.keyfile")) { else if (!strcmp(buf, "rmps.keyfile")) {
if (access(tmp + 1, F_OK) == -1) { if (access(tmp + 1, F_OK) == -1) {
fprintf( stderr, log_trace( ERROR,
"%s is missing\n", conf.rmps.keyfile); "%s is missing", conf.rmps.keyfile);
failed = 1; failed = 1;
} }
else if (access(tmp + 1, R_OK) == -1) { else if (access(tmp + 1, R_OK) == -1) {
fprintf( stderr, log_trace( ERROR,
"%s is not readable\n", "%s is not readable",
tmp + 1 tmp + 1
); );
failed = 1; failed = 1;
@@ -310,12 +309,12 @@ static int test_conf_syntax()
strncpy(conf.rmps.cipherlist, tmp + 1, sizeof(conf.rmps.cipherlist)); strncpy(conf.rmps.cipherlist, tmp + 1, sizeof(conf.rmps.cipherlist));
} else if (!strcmp(buf, "rmps.cafile")) { } else if (!strcmp(buf, "rmps.cafile")) {
if (access(tmp + 1, F_OK) == -1) { if (access(tmp + 1, F_OK) == -1) {
fprintf( stderr, log_trace( ERROR,
"%s is missing\n", tmp + 1); "%s is missing", tmp + 1);
failed = 1; failed = 1;
} }
else if (access(tmp + 1, R_OK) == -1) { else if (access(tmp + 1, R_OK) == -1) {
fprintf( stderr, log_trace( ERROR,
"%s is not readable\n", "%s is not readable\n",
tmp + 1 tmp + 1
); );
@@ -323,12 +322,12 @@ static int test_conf_syntax()
} else } else
strncpy(conf.rmps.cafile, tmp + 1, sizeof(conf.rmps.cafile)); strncpy(conf.rmps.cafile, tmp + 1, sizeof(conf.rmps.cafile));
} else } else
fprintf( stderr, log_trace( ERROR,
"Unknown config entry on line %d: %s\n", "Unknown config entry on line %d: %s",
j, buf ); j, buf );
if (!ok) { if (!ok) {
fprintf( stderr, log_trace( ERROR,
"Invalid value for \"%s\", line %d: \"%s\"\n", "Invalid value for \"%s\", line %d: \"%s\"",
buf, j, tmp + 1 ); buf, j, tmp + 1 );
ok = !ok; ok = !ok;
} }
@@ -337,6 +336,7 @@ static int test_conf_syntax()
if (failed) if (failed)
return 1; return 1;
conf.isvalid = 1;
return 0; return 0;
} }
@@ -351,6 +351,5 @@ int confparse()
result = test_conf_syntax(); result = test_conf_syntax();
if (result != 0) if (result != 0)
return 1; /* Bad conf syntax */ return 1; /* Bad conf syntax */
return 0; /* seems legit */ return 0; /* seems legit */
} }

View File

@@ -30,6 +30,7 @@ struct conf_nfs {
}; };
struct conf_table { struct conf_table {
int isvalid;
struct conf_db db; struct conf_db db;
struct conf_rmps rmps; struct conf_rmps rmps;
struct conf_nfs nfs; struct conf_nfs nfs;

View File

@@ -1,26 +1,45 @@
#include <time.h> #include <time.h>
#include <stdio.h> #include <stdio.h>
#include <stdarg.h> #include <stdarg.h>
#include <pthread.h>
#include "log_trace.h" #include "log_trace.h"
#include "confparser.h" #include "confparser.h"
static FILE *fderr = NULL;
static FILE *fdout = NULL;
static pthread_once_t once = PTHREAD_ONCE_INIT;
static void open_logs(void)
{
if (conf.rmps.errlog)
fderr = fopen(conf.rmps.errlog, "a");
if (conf.rmps.logfile)
fdout = fopen(conf.rmps.logfile, "a");
}
void log_trace(LOG_LEVEL lvl, char *fmt, ... ) void log_trace(LOG_LEVEL lvl, char *fmt, ... )
{ {
LOG_LEVEL cur_lvl = conf.rmps.loglevel - '0'; LOG_LEVEL cur_lvl = conf.rmps.loglevel - '0';
if (conf.isvalid)
pthread_once(&once, open_logs);
if (lvl <= cur_lvl) { if (lvl <= cur_lvl) {
va_list list; va_list list;
int fallback = 0;
FILE *fd; FILE *fd;
static const char *prefixes[] = {
"ERROR", "WARNING", "INFO", "VERBOSE"
};
time_t t = time(NULL); time_t t = time(NULL);
struct tm tm = *localtime(&t); struct tm tm = *localtime(&t);
if (lvl == ERROR || lvl == WARNING) { if (lvl == ERROR || lvl == WARNING)
fd = fopen(conf.rmps.errlog, "a"); fd = fderr;
else
fd = fdout;
if (!fd) { if (!fd) {
fprintf( stderr, fprintf( stderr,
"Failed to append errlog: %s. Redirecting to stderr:\n", "Failed to append errlog: %s. Redirecting to stderr:\n",
conf.rmps.errlog ); conf.rmps.errlog );
fd = stderr; fd = stderr;
fallback = 1;
} }
fprintf( fd, fprintf( fd,
"[%d-%02d-%02d %02d:%02d:%02d] %s: ", "[%d-%02d-%02d %02d:%02d:%02d] %s: ",
@@ -30,35 +49,14 @@ void log_trace(LOG_LEVEL lvl, char *fmt, ... )
tm.tm_hour, tm.tm_hour,
tm.tm_min, tm.tm_min,
tm.tm_sec, tm.tm_sec,
lvl == ERROR ? "ERROR" : "WARNING" ); prefixes[lvl-1] );
} else {
fd = fopen(conf.rmps.logfile, "a");
if (!fd) {
fprintf( stderr,
"Failed to append logfile: %s. Redirecting to stderr:\n",
conf.rmps.logfile );
fd = stderr;
fallback = 1;
}
fprintf( fd,
"[%d-%02d-%02d %02d:%02d:%02d] %s: ",
tm.tm_year + 1900,
tm.tm_mon + 1,
tm.tm_mday,
tm.tm_hour,
tm.tm_min,
tm.tm_sec,
lvl == INFO ? "INFO" : "VERBOSE" );
}
va_start(list, fmt); va_start(list, fmt);
vfprintf(fd, fmt, list); vfprintf(fd, fmt, list);
fprintf(fd, "\n"); fprintf(fd, "\n");
fflush(fd);
va_end(list); va_end(list);
if (!fallback)
fclose(fd);
} else } else
return; return;
fflush(stdout);
} }

5
main.c
View File

@@ -10,7 +10,7 @@
static void usage(char *argv) static void usage(char *argv)
{ {
fprintf( stderr, log_trace( ERROR,
"Usage:\n%s start|stop|restart [--daemonize=yes|no]\n", "Usage:\n%s start|stop|restart [--daemonize=yes|no]\n",
argv ); argv );
} }
@@ -45,9 +45,10 @@ int main(int argc, char *argv[])
} }
} }
if (confparse() != 0) { if (confparse() != 0) {
fprintf(stderr, "Failed to parse the conf!"); log_trace(ERROR, "Failed to parse the conf!");
exit(EXIT_FAILURE); exit(EXIT_FAILURE);
} }
log_trace(VERBOSE, "Conf parser finished successfully");
//confexport(); //confexport();
if (task == 2 || task == 3) { if (task == 2 || task == 3) {

7
rmps.c
View File

@@ -99,7 +99,6 @@ static void daemonize(const char *rundir)
} }
/* Fork*/ /* Fork*/
pid = fork(); pid = fork();
/*printf("fork() = %d\n", pid);*/
if (pid < 0) { if (pid < 0) {
/* Could not fork */ /* Could not fork */
log_trace(ERROR, "Failed to fork the parent process. Exiting!"); log_trace(ERROR, "Failed to fork the parent process. Exiting!");
@@ -119,9 +118,9 @@ static void daemonize(const char *rundir)
exit(EXIT_FAILURE); exit(EXIT_FAILURE);
} }
/* Close all file descriptors because we fork */ /* Close all file descriptors because we fork */
for (i = getdtablesize(); i >= 0; --i) close(0); /* stdin */
close(i); close(1); /* stdout */
close(2); /* stderr */
/* Route I/O connections */ /* Route I/O connections */
/* Open STDIN */ /* Open STDIN */
i = open("/dev/null", O_RDWR); i = open("/dev/null", O_RDWR);

View File

@@ -52,7 +52,7 @@ static void* servlet(void *args) /* Serve the connection -- threadable */
if (ret <= 0) { if (ret <= 0) {
char ret_str[1024]; char ret_str[1024];
ERR_error_string_n(SSL_get_error(agent->ssl, ret), ret_str, sizeof(ret_str)); ERR_error_string_n(SSL_get_error(agent->ssl, ret), ret_str, sizeof(ret_str));
log_trace(INFO, "SSL_accept() failed. Reason below:\n%s", ret_str); log_trace(WARNING, "SSL_accept() failed. Reason below:\n%s", ret_str);
} else { } else {
show_certs(agent->ssl); show_certs(agent->ssl);
do { do {

0
tmp/rmpsd.err Normal file
View File

55
tmp/rmpsd.log Normal file
View File

@@ -0,0 +1,55 @@
[2016-08-08 21:05:10] INFO: Starting up RMPS...
[2016-08-08 21:05:13] INFO: Received SIGTERM signal.
[2016-08-08 21:05:13] INFO: RMPS is shutting down...
[2016-08-08 21:05:13] INFO: RMPS has been stopped properly.
[2016-08-08 21:05:40] INFO: Starting up RMPS...
[2016-08-08 21:05:40] INFO: Child process created: 32737
[2016-08-08 21:05:50] INFO: Received SIGTERM signal.
[2016-08-08 21:05:50] INFO: RMPS is shutting down...
[2016-08-08 21:05:50] INFO: RMPS has been stopped properly.
[2016-08-08 21:05:54] INFO: Starting up RMPS...
[2016-08-08 21:05:54] INFO: Child process created: 32762
[2016-08-08 21:05:57] INFO: Received SIGTERM signal.
[2016-08-08 21:05:57] INFO: RMPS is shutting down...
[2016-08-08 21:05:57] INFO: RMPS has been stopped properly.
[2016-08-08 21:20:18] INFO: Starting up RMPS...
[2016-08-08 21:20:19] INFO: Received SIGTERM signal.
[2016-08-08 21:20:19] INFO: RMPS is shutting down...
[2016-08-08 21:20:19] INFO: RMPS has been stopped properly.
[2016-08-08 21:20:25] INFO: Starting up RMPS...
[2016-08-08 21:20:25] INFO: Child process created: 2371
[2016-08-08 21:20:28] INFO: Received SIGTERM signal.
[2016-08-08 21:20:28] INFO: RMPS is shutting down...
[2016-08-08 21:20:28] INFO: RMPS has been stopped properly.
[2016-08-08 22:01:35] INFO: Starting up RMPS...
[2016-08-08 22:01:38] INFO: Received SIGTERM signal.
[2016-08-08 22:01:38] INFO: RMPS is shutting down...
[2016-08-08 22:01:38] INFO: RMPS has been stopped properly.
[2016-08-08 22:01:43] INFO: Starting up RMPS...
[2016-08-08 22:01:44] INFO: Received SIGTERM signal.
[2016-08-08 22:01:44] INFO: RMPS is shutting down...
[2016-08-08 22:01:44] INFO: RMPS has been stopped properly.
[2016-08-08 22:02:19] INFO: Starting up RMPS...
[2016-08-08 22:02:19] INFO: Child process created: 6212
[2016-08-08 22:02:19] INFO: stdin.fd=0 stdout.fd=1 stderr.fd=2
[2016-08-08 22:02:22] INFO: Received SIGTERM signal.
[2016-08-08 22:02:22] INFO: RMPS is shutting down...
[2016-08-08 22:02:22] INFO: RMPS has been stopped properly.
[2016-08-08 22:03:21] INFO: Starting up RMPS...
[2016-08-08 22:03:26] INFO: Received SIGTERM signal.
[2016-08-08 22:03:26] INFO: RMPS is shutting down...
[2016-08-08 22:03:26] INFO: RMPS has been stopped properly.
[2016-08-08 22:03:32] INFO: Starting up RMPS...
[2016-08-08 22:03:32] INFO: Child process created: 6356
[2016-08-08 22:03:32] INFO: stdin.fd=0 stdout.fd=1 stderr.fd=2
[2016-08-08 22:03:32] INFO: stdin.fd=0 stdout.fd=1 stderr.fd=2
[2016-08-08 22:03:36] INFO: Received SIGTERM signal.
[2016-08-08 22:03:36] INFO: RMPS is shutting down...
[2016-08-08 22:03:36] INFO: RMPS has been stopped properly.
[2016-08-08 22:29:17] INFO: Starting up RMPS...
[2016-08-08 22:29:18] INFO: Received SIGTERM signal.
[2016-08-08 22:29:18] INFO: RMPS is shutting down...
[2016-08-08 22:29:18] INFO: RMPS has been stopped properly.