Logging/debug improvements: __WHENCE__, __whence

Introduce __WHENCE__ macro and a block comment in log.h explaining it.

In "primitive" kinds of functions, rename 'whence' arguments to '__whence' and
use WHYF(), WARNF(), DEBUGF() macros instead of calling logMessage() directly.
This commit is contained in:
Andrew Bettison 2012-10-16 16:46:52 +10:30
parent 2bef619723
commit 259b9a9d24
10 changed files with 238 additions and 214 deletions

48
log.c
View File

@ -39,6 +39,8 @@ Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
#include "strbuf.h" #include "strbuf.h"
#include "strbuf_helpers.h" #include "strbuf_helpers.h"
const struct __sourceloc __whence = __NOWHERE__;
debugflags_t debug = 0; debugflags_t debug = 0;
static FILE *logfile = NULL; static FILE *logfile = NULL;
@ -131,7 +133,7 @@ static const char *_trimbuildpath(const char *path)
return &path[lastsep]; return &path[lastsep];
} }
static int _log_prepare(int level, struct __sourceloc where) static int _log_prepare(int level, struct __sourceloc whence)
{ {
if (level == LOG_LEVEL_SILENT) if (level == LOG_LEVEL_SILENT)
return 0; return 0;
@ -164,15 +166,15 @@ static int _log_prepare(int level, struct __sourceloc where)
strbuf_sprintf(&logbuf, "%s.%03u ", buf, tv.tv_usec / 1000); strbuf_sprintf(&logbuf, "%s.%03u ", buf, tv.tv_usec / 1000);
} }
} }
if (where.file) { if (whence.file) {
strbuf_sprintf(&logbuf, "%s", _trimbuildpath(where.file)); strbuf_sprintf(&logbuf, "%s", _trimbuildpath(whence.file));
if (where.line) if (whence.line)
strbuf_sprintf(&logbuf, ":%u", where.line); strbuf_sprintf(&logbuf, ":%u", whence.line);
if (where.function) if (whence.function)
strbuf_sprintf(&logbuf, ":%s()", where.function); strbuf_sprintf(&logbuf, ":%s()", whence.function);
strbuf_putc(&logbuf, ' '); strbuf_putc(&logbuf, ' ');
} else if (where.function) { } else if (whence.function) {
strbuf_sprintf(&logbuf, "%s() ", where.function); strbuf_sprintf(&logbuf, "%s() ", whence.function);
} }
strbuf_putc(&logbuf, ' '); strbuf_putc(&logbuf, ' ');
return 1; return 1;
@ -213,9 +215,9 @@ void set_log_implementation(void (*log_function)(int level, struct strbuf *buf))
_log_implementation=log_function; _log_implementation=log_function;
} }
void logArgv(int level, struct __sourceloc where, const char *label, int argc, const char *const *argv) void logArgv(int level, struct __sourceloc whence, const char *label, int argc, const char *const *argv)
{ {
if (_log_prepare(level, where)) { if (_log_prepare(level, whence)) {
if (label) { if (label) {
strbuf_puts(&logbuf, label); strbuf_puts(&logbuf, label);
strbuf_putc(&logbuf, ' '); strbuf_putc(&logbuf, ' ');
@ -233,47 +235,47 @@ void logArgv(int level, struct __sourceloc where, const char *label, int argc, c
} }
} }
void logString(int level, struct __sourceloc where, const char *str) void logString(int level, struct __sourceloc whence, const char *str)
{ {
const char *s = str; const char *s = str;
const char *p; const char *p;
for (p = str; *p; ++p) { for (p = str; *p; ++p) {
if (*p == '\n') { if (*p == '\n') {
if (_log_prepare(level, where)) { if (_log_prepare(level, whence)) {
strbuf_ncat(&logbuf, s, p - s); strbuf_ncat(&logbuf, s, p - s);
_log_finish(level); _log_finish(level);
} }
s = p + 1; s = p + 1;
} }
} }
if (p > s && _log_prepare(level, where)) { if (p > s && _log_prepare(level, whence)) {
strbuf_ncat(&logbuf, s, p - s); strbuf_ncat(&logbuf, s, p - s);
_log_finish(level); _log_finish(level);
} }
} }
void logMessage(int level, struct __sourceloc where, const char *fmt, ...) void logMessage(int level, struct __sourceloc whence, const char *fmt, ...)
{ {
va_list ap; va_list ap;
va_start(ap, fmt); va_start(ap, fmt);
vlogMessage(level, where, fmt, ap); vlogMessage(level, whence, fmt, ap);
va_end(ap); va_end(ap);
} }
void vlogMessage(int level, struct __sourceloc where, const char *fmt, va_list ap) void vlogMessage(int level, struct __sourceloc whence, const char *fmt, va_list ap)
{ {
if (_log_prepare(level, where)) { if (_log_prepare(level, whence)) {
strbuf_vsprintf(&logbuf, fmt, ap); strbuf_vsprintf(&logbuf, fmt, ap);
_log_finish(level); _log_finish(level);
} }
} }
int logDump(int level, struct __sourceloc where, char *name, const unsigned char *addr, size_t len) int logDump(int level, struct __sourceloc whence, char *name, const unsigned char *addr, size_t len)
{ {
char buf[100]; char buf[100];
size_t i; size_t i;
if (name) if (name)
logMessage(level, where, "Dump of %s", name); logMessage(level, whence, "Dump of %s", name);
for(i = 0; i < len; i += 16) { for(i = 0; i < len; i += 16) {
strbuf b = strbuf_local(buf, sizeof buf); strbuf b = strbuf_local(buf, sizeof buf);
strbuf_sprintf(b, " %04x :", i); strbuf_sprintf(b, " %04x :", i);
@ -285,7 +287,7 @@ int logDump(int level, struct __sourceloc where, char *name, const unsigned char
strbuf_puts(b, " "); strbuf_puts(b, " ");
for (j = 0; j < 16 && i + j < len; j++) for (j = 0; j < 16 && i + j < len; j++)
strbuf_sprintf(b, "%c", addr[i+j] >= ' ' && addr[i+j] < 0x7f ? addr[i+j] : '.'); strbuf_sprintf(b, "%c", addr[i+j] >= ' ' && addr[i+j] < 0x7f ? addr[i+j] : '.');
logMessage(level, where, "%s", strbuf_str(b)); logMessage(level, whence, "%s", strbuf_str(b));
} }
return 0; return 0;
} }
@ -422,7 +424,7 @@ ssize_t get_self_executable_path(char *buf, size_t len)
#endif #endif
} }
int log_backtrace(struct __sourceloc where) int log_backtrace(struct __sourceloc whence)
{ {
open_logging(); open_logging();
char execpath[MAXPATHLEN]; char execpath[MAXPATHLEN];
@ -476,7 +478,7 @@ int log_backtrace(struct __sourceloc where)
} }
// parent // parent
close(stdout_fds[1]); close(stdout_fds[1]);
logMessage(LOG_LEVEL_DEBUG, where, "GDB BACKTRACE"); logMessage(LOG_LEVEL_DEBUG, whence, "GDB BACKTRACE");
char buf[1024]; char buf[1024];
char *const bufe = buf + sizeof buf; char *const bufe = buf + sizeof buf;
char *linep = buf; char *linep = buf;

74
log.h
View File

@ -66,27 +66,73 @@ extern debugflags_t debug;
struct strbuf; struct strbuf;
/*
* Every log message identifies the location in the source code at which the
* message was produced. This location is represented by a struct __sourceloc,
* which is passed by value to the logMessage() function and its ilk.
*
* A struct __sourceloc value is generated by the __HERE__ macro, which uses
* the cpp(1) built-in macros __FILE__, __LINE__ and __FUNCTION__ to generate
* its elements. The __NOWHERE__ macro creates a struct __sourceloc with NULL
* and zero fields. If you pass __NOWHERE__ to logMessage(), it will omit
* location information from the log line.
*
* Sometimes, a function wants to log a message as though its caller were the
* origin of the message. This is typical of "primitive" type functions that
* are used in many places throughout the code, and whose internal workings are
* generally well-debugged and of little interest for ongoing development. In
* this case, the code pattern is to declare the underscore-prefixed function
* as taking a struct __sourceloc argument, and a macro that invokes the
* function, passing the __HERE__ macro for that argument:
*
* int _primitive(struct __sourceloc __whence, int arg1, const char *arg2);
*
* #define primitive(arg1, arg2) _primitive(__HERE__, (arg1), (arg2))
*
* Within the _primitive() function, the standard logging macros defined below
* (WHYF(), WARNF(), INFOF(), DEBUGF() etc.) will use the __whence argument
* instead of __HERE__ when logging their message. This is achieved using a
* dirty trick: in the function *definition*, the __sourceloc argument MUST be
* named '__whence'. The trick is that there is a global variable called
* '__whence' which always contains the value of __NOWHERE__. If that variable
* is lexically obscured by a local variable or parameter called '__whence',
* then the DEBUG macros will use __whence, otherwise they will use __HERE__.
* This logic is encapsulated in the __WHENCE__ macro, to make it available to
* for other purposes. For example, a better definition of the primitive()
* macro above would be:
*
* #define primitive(arg1, arg2) _primitive(__WHENCE__, (arg1), (arg2))
*
* Then, if it were invoked from within another primitive-type function, it
* would log messages with the __sourceloc of that primitive's caller, which is
* probably the most useful for diagnosis.
*
* @author Andrew Bettison <andrew@servalproject.com>
*/
struct __sourceloc { struct __sourceloc {
const char *file; const char *file;
unsigned int line; unsigned int line;
const char *function; const char *function;
}; };
extern const struct __sourceloc __whence; // see above
void set_logging(FILE *f); void set_logging(FILE *f);
FILE *open_logging(); FILE *open_logging();
void close_logging(); void close_logging();
void logArgv(int level, struct __sourceloc where, const char *label, int argc, const char *const *argv); void logArgv(int level, struct __sourceloc whence, const char *label, int argc, const char *const *argv);
void logString(int level, struct __sourceloc where, const char *str); void logString(int level, struct __sourceloc whence, const char *str);
void logMessage(int level, struct __sourceloc where, const char *fmt, ...); void logMessage(int level, struct __sourceloc whence, const char *fmt, ...);
void vlogMessage(int level, struct __sourceloc where, const char *fmt, va_list); void vlogMessage(int level, struct __sourceloc whence, const char *fmt, va_list);
debugflags_t debugFlagMask(const char *flagname); debugflags_t debugFlagMask(const char *flagname);
int logDump(int level, struct __sourceloc where, char *name, const unsigned char *addr, size_t len); int logDump(int level, struct __sourceloc whence, char *name, const unsigned char *addr, size_t len);
char *toprint(char *dstStr, ssize_t dstBufSiz, const char *srcBuf, size_t srcBytes, const char quotes[2]); char *toprint(char *dstStr, ssize_t dstBufSiz, const char *srcBuf, size_t srcBytes, const char quotes[2]);
char *toprint_str(char *dstStr, ssize_t dstBufSiz, const char *srcStr, const char quotes[2]); char *toprint_str(char *dstStr, ssize_t dstBufSiz, const char *srcStr, const char quotes[2]);
size_t toprint_len(const char *srcBuf, size_t srcBytes, const char quotes[2]); size_t toprint_len(const char *srcBuf, size_t srcBytes, const char quotes[2]);
size_t toprint_str_len(const char *srcStr, const char quotes[2]); size_t toprint_str_len(const char *srcStr, const char quotes[2]);
ssize_t get_self_executable_path(char *buf, size_t len); ssize_t get_self_executable_path(char *buf, size_t len);
int log_backtrace(struct __sourceloc where); int log_backtrace(struct __sourceloc whence);
void set_log_implementation(void (*log_function)(int level, struct strbuf *buf)); void set_log_implementation(void (*log_function)(int level, struct strbuf *buf));
#define alloca_toprint(dstlen,buf,len) toprint((char *)alloca((dstlen) == -1 ? toprint_len((buf),(len), "``") + 1 : (dstlen)), (dstlen), (buf), (len), "``") #define alloca_toprint(dstlen,buf,len) toprint((char *)alloca((dstlen) == -1 ? toprint_len((buf),(len), "``") + 1 : (dstlen)), (dstlen), (buf), (len), "``")
@ -95,11 +141,13 @@ void set_log_implementation(void (*log_function)(int level, struct strbuf *buf))
#define __HERE__ ((struct __sourceloc){ .file = __FILE__, .line = __LINE__, .function = __FUNCTION__ }) #define __HERE__ ((struct __sourceloc){ .file = __FILE__, .line = __LINE__, .function = __FUNCTION__ })
#define __NOWHERE__ ((struct __sourceloc){ .file = NULL, .line = 0, .function = NULL }) #define __NOWHERE__ ((struct __sourceloc){ .file = NULL, .line = 0, .function = NULL })
#define LOGF(L,F,...) logMessage(L, __HERE__, F, ##__VA_ARGS__) #define __WHENCE__ (__whence.file ? __whence : __HERE__)
#define LOGF_perror(L,F,...) logMessage_perror(L, __HERE__, F, ##__VA_ARGS__)
#define LOGF(L,F,...) logMessage(L, __WHENCE__, F, ##__VA_ARGS__)
#define LOGF_perror(L,F,...) logMessage_perror(L, __WHENCE__, F, ##__VA_ARGS__)
#define LOG_perror(L,X) LOGF_perror(L, "%s", (X)) #define LOG_perror(L,X) LOGF_perror(L, "%s", (X))
#define logMessage_perror(L,where,F,...) (logMessage(L, where, F ": %s [errno=%d]", ##__VA_ARGS__, strerror(errno), errno)) #define logMessage_perror(L,whence,F,...) (logMessage(L, whence, F ": %s [errno=%d]", ##__VA_ARGS__, strerror(errno), errno))
#define FATALF(F,...) do { LOGF(LOG_LEVEL_FATAL, F, ##__VA_ARGS__); exit(-1); } while (1) #define FATALF(F,...) do { LOGF(LOG_LEVEL_FATAL, F, ##__VA_ARGS__); exit(-1); } while (1)
#define FATAL(X) FATALF("%s", (X)) #define FATAL(X) FATALF("%s", (X))
@ -117,7 +165,7 @@ void set_log_implementation(void (*log_function)(int level, struct strbuf *buf))
#define WARN(X) WARNF("%s", (X)) #define WARN(X) WARNF("%s", (X))
#define WARNF_perror(F,...) LOGF_perror(LOG_LEVEL_WARN, F, ##__VA_ARGS__) #define WARNF_perror(F,...) LOGF_perror(LOG_LEVEL_WARN, F, ##__VA_ARGS__)
#define WARN_perror(X) WARNF_perror("%s", (X)) #define WARN_perror(X) WARNF_perror("%s", (X))
#define WHY_argv(X,ARGC,ARGV) logArgv(LOG_LEVEL_ERROR, __HERE__, (X), (ARGC), (ARGV)) #define WHY_argv(X,ARGC,ARGV) logArgv(LOG_LEVEL_ERROR, __WHENCE__, (X), (ARGC), (ARGV))
#define INFOF(F,...) LOGF(LOG_LEVEL_INFO, F, ##__VA_ARGS__) #define INFOF(F,...) LOGF(LOG_LEVEL_INFO, F, ##__VA_ARGS__)
#define INFO(X) INFOF("%s", (X)) #define INFO(X) INFOF("%s", (X))
@ -127,10 +175,10 @@ void set_log_implementation(void (*log_function)(int level, struct strbuf *buf))
#define DEBUGF_perror(F,...) LOGF_perror(LOG_LEVEL_DEBUG, F, ##__VA_ARGS__) #define DEBUGF_perror(F,...) LOGF_perror(LOG_LEVEL_DEBUG, F, ##__VA_ARGS__)
#define DEBUG_perror(X) DEBUGF_perror("%s", (X)) #define DEBUG_perror(X) DEBUGF_perror("%s", (X))
#define D DEBUG("D") #define D DEBUG("D")
#define DEBUG_argv(X,ARGC,ARGV) logArgv(LOG_LEVEL_DEBUG, __HERE__, (X), (ARGC), (ARGV)) #define DEBUG_argv(X,ARGC,ARGV) logArgv(LOG_LEVEL_DEBUG, __WHENCE__, (X), (ARGC), (ARGV))
#define dump(X,A,N) logDump(LOG_LEVEL_DEBUG, __HERE__, (X), (const unsigned char *)(A), (size_t)(N)) #define dump(X,A,N) logDump(LOG_LEVEL_DEBUG, __WHENCE__, (X), (const unsigned char *)(A), (size_t)(N))
#define BACKTRACE log_backtrace(__HERE__) #define BACKTRACE log_backtrace(__WHENCE__)
#endif // __SERVALD_LOG_H #endif // __SERVALD_LOG_H

70
net.c
View File

@ -26,35 +26,27 @@ Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
#include "net.h" #include "net.h"
#include "serval.h" #include "serval.h"
int _set_nonblock(int fd, struct __sourceloc where) int _set_nonblock(int fd, struct __sourceloc __whence)
{ {
int flags; int flags;
if ((flags = fcntl(fd, F_GETFL, NULL)) == -1) { if ((flags = fcntl(fd, F_GETFL, NULL)) == -1)
logMessage_perror(LOG_LEVEL_ERROR, where, "set_nonblock: fcntl(%d,F_GETFL,NULL)", fd); return WHYF_perror("set_nonblock: fcntl(%d,F_GETFL,NULL)", fd);
return -1; if (fcntl(fd, F_SETFL, flags | O_NONBLOCK) == -1)
} return WHYF_perror("set_nonblock: fcntl(%d,F_SETFL,0x%x|O_NONBLOCK)", fd, flags);
if (fcntl(fd, F_SETFL, flags | O_NONBLOCK) == -1) {
logMessage_perror(LOG_LEVEL_ERROR, where, "set_nonblock: fcntl(%d,F_SETFL,0x%x|O_NONBLOCK)", fd, flags);
return -1;
}
return 0; return 0;
} }
int _set_block(int fd, struct __sourceloc where) int _set_block(int fd, struct __sourceloc __whence)
{ {
int flags; int flags;
if ((flags = fcntl(fd, F_GETFL, NULL)) == -1) { if ((flags = fcntl(fd, F_GETFL, NULL)) == -1)
logMessage_perror(LOG_LEVEL_ERROR, where, "set_block: fcntl(%d,F_GETFL,NULL)", fd); return WHYF_perror("set_block: fcntl(%d,F_GETFL,NULL)", fd);
return -1; if (fcntl(fd, F_SETFL, flags & ~O_NONBLOCK) == -1)
} return WHYF_perror("set_block: fcntl(%d,F_SETFL,0x%x&~O_NONBLOCK)", fd, flags);
if (fcntl(fd, F_SETFL, flags & ~O_NONBLOCK) == -1) {
logMessage_perror(LOG_LEVEL_ERROR, where, "set_block: fcntl(%d,F_SETFL,0x%x&~O_NONBLOCK)", fd, flags);
return -1;
}
return 0; return 0;
} }
ssize_t _read_nonblock(int fd, void *buf, size_t len, struct __sourceloc where) ssize_t _read_nonblock(int fd, void *buf, size_t len, struct __sourceloc __whence)
{ {
ssize_t nread = read(fd, buf, len); ssize_t nread = read(fd, buf, len);
if (nread == -1) { if (nread == -1) {
@ -66,30 +58,24 @@ ssize_t _read_nonblock(int fd, void *buf, size_t len, struct __sourceloc where)
#endif #endif
return 0; return 0;
} }
logMessage_perror(LOG_LEVEL_ERROR, where, "read_nonblock: read(%d,%p,%lu)", return WHYF_perror("read_nonblock: read(%d,%p,%lu)", fd, buf, (unsigned long)len);
fd, buf, (unsigned long)len);
return -1;
} }
return nread; return nread;
} }
ssize_t _write_all(int fd, const void *buf, size_t len, struct __sourceloc where) ssize_t _write_all(int fd, const void *buf, size_t len, struct __sourceloc __whence)
{ {
ssize_t written = write(fd, buf, len); ssize_t written = write(fd, buf, len);
if (written == -1) { if (written == -1)
logMessage_perror(LOG_LEVEL_ERROR, where, "write_all: write(%d,%p %s,%lu)", return WHYF_perror("write_all: write(%d,%p %s,%lu)",
fd, buf, alloca_toprint(30, buf, len), (unsigned long)len); fd, buf, alloca_toprint(30, buf, len), (unsigned long)len);
return -1; if (written != len)
} return WHYF_perror("write_all: write(%d,%p %s,%lu) returned %ld",
if (written != len) {
logMessage(LOG_LEVEL_ERROR, where, "write_all: write(%d,%p %s,%lu) returned %ld",
fd, buf, alloca_toprint(30, buf, len), (unsigned long)len, (long)written); fd, buf, alloca_toprint(30, buf, len), (unsigned long)len, (long)written);
return -1;
}
return written; return written;
} }
ssize_t _write_nonblock(int fd, const void *buf, size_t len, struct __sourceloc where) ssize_t _write_nonblock(int fd, const void *buf, size_t len, struct __sourceloc __whence)
{ {
ssize_t written = write(fd, buf, len); ssize_t written = write(fd, buf, len);
if (written == -1) { if (written == -1) {
@ -101,32 +87,30 @@ ssize_t _write_nonblock(int fd, const void *buf, size_t len, struct __sourceloc
#endif #endif
return 0; return 0;
} }
logMessage_perror(LOG_LEVEL_ERROR, where, "write_nonblock: write(%d,%p %s,%lu)", return WHYF_perror("write_nonblock: write(%d,%p %s,%lu)",
fd, buf, alloca_toprint(30, buf, len), (unsigned long)len); fd, buf, alloca_toprint(30, buf, len), (unsigned long)len);
return -1; return -1;
} }
return written; return written;
} }
ssize_t _write_all_nonblock(int fd, const void *buf, size_t len, struct __sourceloc where) ssize_t _write_all_nonblock(int fd, const void *buf, size_t len, struct __sourceloc __whence)
{ {
ssize_t written = _write_nonblock(fd, buf, len, where); ssize_t written = _write_nonblock(fd, buf, len, __whence);
if (written != -1 && written != len) { if (written != -1 && written != len)
logMessage(LOG_LEVEL_ERROR, where, "write_all_nonblock: write(%d,%p %s,%lu) returned %ld", return WHYF("write_all_nonblock: write(%d,%p %s,%lu) returned %ld",
fd, buf, alloca_toprint(30, buf, len), (unsigned long)len, (long)written); fd, buf, alloca_toprint(30, buf, len), (unsigned long)len, (long)written);
return -1;
}
return written; return written;
} }
ssize_t _write_str(int fd, const char *str, struct __sourceloc where) ssize_t _write_str(int fd, const char *str, struct __sourceloc __whence)
{ {
return _write_all(fd, str, strlen(str), where); return _write_all(fd, str, strlen(str), __whence);
} }
ssize_t _write_str_nonblock(int fd, const char *str, struct __sourceloc where) ssize_t _write_str_nonblock(int fd, const char *str, struct __sourceloc __whence)
{ {
return _write_all_nonblock(fd, str, strlen(str), where); return _write_all_nonblock(fd, str, strlen(str), __whence);
} }
ssize_t recvwithttl(int sock,unsigned char *buffer, size_t bufferlen,int *ttl, ssize_t recvwithttl(int sock,unsigned char *buffer, size_t bufferlen,int *ttl,

34
net.h
View File

@ -20,24 +20,24 @@ Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
#define __SERVALD_NET_H #define __SERVALD_NET_H
#include <sys/types.h> // for size_t, ssize_t #include <sys/types.h> // for size_t, ssize_t
#include "log.h" // for __HERE__ and struct __sourceloc #include "log.h" // for __WHENCE__ and struct __sourceloc
#define set_nonblock(fd) (_set_nonblock(fd, __HERE__)) #define set_nonblock(fd) (_set_nonblock(fd, __WHENCE__))
#define set_block(fd) (_set_block(fd, __HERE__)) #define set_block(fd) (_set_block(fd, __WHENCE__))
#define read_nonblock(fd,buf,len) (_read_nonblock(fd, buf, len, __HERE__)) #define read_nonblock(fd,buf,len) (_read_nonblock(fd, buf, len, __WHENCE__))
#define write_all(fd,buf,len) (_write_all(fd, buf, len, __HERE__)) #define write_all(fd,buf,len) (_write_all(fd, buf, len, __WHENCE__))
#define write_nonblock(fd,buf,len) (_write_nonblock(fd, buf, len, __HERE__)) #define write_nonblock(fd,buf,len) (_write_nonblock(fd, buf, len, __WHENCE__))
#define write_all_nonblock(fd,buf,len) (_write_all_nonblock(fd, buf, len, __HERE__)) #define write_all_nonblock(fd,buf,len) (_write_all_nonblock(fd, buf, len, __WHENCE__))
#define write_str(fd,str) (_write_str(fd, str, __HERE__)) #define write_str(fd,str) (_write_str(fd, str, __WHENCE__))
#define write_str_nonblock(fd,str) (_write_str_nonblock(fd, str, __HERE__)) #define write_str_nonblock(fd,str) (_write_str_nonblock(fd, str, __WHENCE__))
int _set_nonblock(int fd, struct __sourceloc where); int _set_nonblock(int fd, struct __sourceloc __whence);
int _set_block(int fd, struct __sourceloc where); int _set_block(int fd, struct __sourceloc __whence);
ssize_t _read_nonblock(int fd, void *buf, size_t len, struct __sourceloc where); ssize_t _read_nonblock(int fd, void *buf, size_t len, struct __sourceloc __whence);
ssize_t _write_all(int fd, const void *buf, size_t len, struct __sourceloc where); ssize_t _write_all(int fd, const void *buf, size_t len, struct __sourceloc __whence);
ssize_t _write_nonblock(int fd, const void *buf, size_t len, struct __sourceloc where); ssize_t _write_nonblock(int fd, const void *buf, size_t len, struct __sourceloc __whence);
ssize_t _write_all_nonblock(int fd, const void *buf, size_t len, struct __sourceloc where); ssize_t _write_all_nonblock(int fd, const void *buf, size_t len, struct __sourceloc __whence);
ssize_t _write_str(int fd, const char *str, struct __sourceloc where); ssize_t _write_str(int fd, const char *str, struct __sourceloc __whence);
ssize_t _write_str_nonblock(int fd, const char *str, struct __sourceloc where); ssize_t _write_str_nonblock(int fd, const char *str, struct __sourceloc __whence);
#endif // __SERVALD_NET_H #endif // __SERVALD_NET_H

View File

@ -460,22 +460,22 @@ int ob_dump(struct overlay_buffer *b,char *desc)
#undef realloc #undef realloc
#define SDM_GUARD_AFTER 16384 #define SDM_GUARD_AFTER 16384
void *_serval_debug_malloc(unsigned int bytes, struct __sourceloc where) void *_serval_debug_malloc(unsigned int bytes, struct __sourceloc __whence)
{ {
void *r=malloc(bytes+SDM_GUARD_AFTER); void *r=malloc(bytes+SDM_GUARD_AFTER);
logMessage(LOG_LEVEL_DEBUG, where, "malloc(%d) -> %p", bytes, r); DEBUGF("malloc(%d) -> %p", bytes, r);
return r; return r;
} }
void *_serval_debug_calloc(unsigned int bytes, unsigned int count, struct __sourceloc where) void *_serval_debug_calloc(unsigned int bytes, unsigned int count, struct __sourceloc __whence)
{ {
void *r=calloc((bytes*count)+SDM_GUARD_AFTER,1); void *r=calloc((bytes*count)+SDM_GUARD_AFTER,1);
logMessage(LOG_LEVEL_DEBUG, where, "calloc(%d,%d) -> %p", bytes, count, r); DEBUGF("calloc(%d,%d) -> %p", bytes, count, r);
return r; return r;
} }
void _serval_debug_free(void *p, struct __sourceloc where) void _serval_debug_free(void *p, struct __sourceloc __whence)
{ {
free(p); free(p);
logMessage(LOG_LEVEL_DEBUG, where, "free(%p)", p); DEBUGF("free(%p)", p);
} }

View File

@ -68,9 +68,11 @@ struct profile_total send_packet;
static int overlay_tick_interface(int i, time_ms_t now); static int overlay_tick_interface(int i, time_ms_t now);
static void overlay_interface_poll(struct sched_ent *alarm); static void overlay_interface_poll(struct sched_ent *alarm);
static void logServalPacket(int level, struct __sourceloc where, const char *message, const unsigned char *packet, size_t len); static void logServalPacket(int level, struct __sourceloc __whence, const char *message, const unsigned char *packet, size_t len);
static long long parse_quantity(char *q); static long long parse_quantity(char *q);
#define DEBUG_packet_visualise(M,P,N) logServalPacket(LOG_LEVEL_DEBUG, __WHENCE__, (M), (P), (N))
unsigned char magic_header[]={/* Magic */ 'O',0x10, unsigned char magic_header[]={/* Magic */ 'O',0x10,
/* Version */ 0x00,0x01}; /* Version */ 0x00,0x01};
@ -1314,14 +1316,14 @@ parse_quantity(char *q) {
} }
static void static void
logServalPacket(int level, struct __sourceloc where, const char *message, const unsigned char *packet, size_t len) { logServalPacket(int level, struct __sourceloc __whence, const char *message, const unsigned char *packet, size_t len) {
struct mallocbuf mb = STRUCT_MALLOCBUF_NULL; struct mallocbuf mb = STRUCT_MALLOCBUF_NULL;
if (serval_packetvisualise(XPRINTF_MALLOCBUF(&mb), message, packet, len) == -1) if (serval_packetvisualise(XPRINTF_MALLOCBUF(&mb), message, packet, len) == -1)
WHY("serval_packetvisualise() failed"); WHY("serval_packetvisualise() failed");
else if (mb.buffer == NULL) else if (mb.buffer == NULL)
WHYF("serval_packetvisualise() output buffer missing, message=%s packet=%p len=%lu", alloca_toprint(-1, message, strlen(message)), packet, len); WHYF("serval_packetvisualise() output buffer missing, message=%s packet=%p len=%lu", alloca_toprint(-1, message, strlen(message)), packet, len);
else else
logString(level, where, mb.buffer); logString(level, __whence, mb.buffer);
if (mb.buffer) if (mb.buffer)
free(mb.buffer); free(mb.buffer);
} }

View File

@ -210,10 +210,10 @@ int rhizome_manifest_set_ll(rhizome_manifest *m,char *var,long long value);
int rhizome_manifest_set(rhizome_manifest *m, const char *var, const char *value); int rhizome_manifest_set(rhizome_manifest *m, const char *var, const char *value);
int rhizome_manifest_del(rhizome_manifest *m, const char *var); int rhizome_manifest_del(rhizome_manifest *m, const char *var);
long long rhizome_file_size(char *filename); long long rhizome_file_size(char *filename);
void _rhizome_manifest_free(struct __sourceloc where, rhizome_manifest *m); void _rhizome_manifest_free(struct __sourceloc __whence, rhizome_manifest *m);
#define rhizome_manifest_free(m) _rhizome_manifest_free(__HERE__,m) #define rhizome_manifest_free(m) _rhizome_manifest_free(__WHENCE__,m)
rhizome_manifest *_rhizome_new_manifest(struct __sourceloc where); rhizome_manifest *_rhizome_new_manifest(struct __sourceloc __whence);
#define rhizome_new_manifest() _rhizome_new_manifest(__HERE__) #define rhizome_new_manifest() _rhizome_new_manifest(__WHENCE__)
int rhizome_manifest_pack_variables(rhizome_manifest *m); int rhizome_manifest_pack_variables(rhizome_manifest *m);
int rhizome_store_bundle(rhizome_manifest *m); int rhizome_store_bundle(rhizome_manifest *m);
int rhizome_manifest_add_group(rhizome_manifest *m,char *groupid); int rhizome_manifest_add_group(rhizome_manifest *m,char *groupid);
@ -248,11 +248,11 @@ __RHIZOME_INLINE int sqlite_code_busy(int code)
debugflags_t sqlite_set_debugmask(debugflags_t newmask); debugflags_t sqlite_set_debugmask(debugflags_t newmask);
sqlite3_stmt *_sqlite_prepare(struct __sourceloc where, sqlite_retry_state *retry, const char *sqlformat, ...); sqlite3_stmt *_sqlite_prepare(struct __sourceloc __whence, sqlite_retry_state *retry, const char *sqlformat, ...);
sqlite3_stmt *_sqlite_prepare_loglevel(struct __sourceloc where, int log_level, sqlite_retry_state *retry, strbuf stmt); sqlite3_stmt *_sqlite_prepare_loglevel(struct __sourceloc __whence, int log_level, sqlite_retry_state *retry, strbuf stmt);
int _sqlite_retry(struct __sourceloc where, sqlite_retry_state *retry, const char *action); int _sqlite_retry(struct __sourceloc __whence, sqlite_retry_state *retry, const char *action);
void _sqlite_retry_done(struct __sourceloc where, sqlite_retry_state *retry, const char *action); void _sqlite_retry_done(struct __sourceloc __whence, sqlite_retry_state *retry, const char *action);
int _sqlite_step_retry(struct __sourceloc where, int log_level, sqlite_retry_state *retry, sqlite3_stmt *statement); int _sqlite_step_retry(struct __sourceloc __whence, int log_level, sqlite_retry_state *retry, sqlite3_stmt *statement);
int _sqlite_exec_void(struct __sourceloc, const char *sqlformat, ...); int _sqlite_exec_void(struct __sourceloc, const char *sqlformat, ...);
int _sqlite_exec_void_loglevel(struct __sourceloc, int log_level, const char *sqlformat, ...); int _sqlite_exec_void_loglevel(struct __sourceloc, int log_level, const char *sqlformat, ...);
int _sqlite_exec_void_retry(struct __sourceloc, sqlite_retry_state *retry, const char *sqlformat, ...); int _sqlite_exec_void_retry(struct __sourceloc, sqlite_retry_state *retry, const char *sqlformat, ...);
@ -260,18 +260,18 @@ int _sqlite_exec_int64(struct __sourceloc, long long *result, const char *sqlfor
int _sqlite_exec_int64_retry(struct __sourceloc, sqlite_retry_state *retry, long long *result, const char *sqlformat,...); int _sqlite_exec_int64_retry(struct __sourceloc, sqlite_retry_state *retry, long long *result, const char *sqlformat,...);
int _sqlite_exec_strbuf(struct __sourceloc, strbuf sb, const char *sqlformat,...); int _sqlite_exec_strbuf(struct __sourceloc, strbuf sb, const char *sqlformat,...);
#define sqlite_prepare(rs,fmt,...) _sqlite_prepare(__HERE__, (rs), (fmt), ##__VA_ARGS__) #define sqlite_prepare(rs,fmt,...) _sqlite_prepare(__WHENCE__, (rs), (fmt), ##__VA_ARGS__)
#define sqlite_prepare_loglevel(ll,rs,sb) _sqlite_prepare_loglevel(__HERE__, (ll), (rs), (sb)) #define sqlite_prepare_loglevel(ll,rs,sb) _sqlite_prepare_loglevel(__WHENCE__, (ll), (rs), (sb))
#define sqlite_retry(rs,action) _sqlite_retry(__HERE__, (rs), (action)) #define sqlite_retry(rs,action) _sqlite_retry(__WHENCE__, (rs), (action))
#define sqlite_retry_done(rs,action) _sqlite_retry_done(__HERE__, (rs), (action)) #define sqlite_retry_done(rs,action) _sqlite_retry_done(__WHENCE__, (rs), (action))
#define sqlite_step(stmt) _sqlite_step_retry(__HERE__, LOG_LEVEL_ERROR, NULL, (stmt)) #define sqlite_step(stmt) _sqlite_step_retry(__WHENCE__, LOG_LEVEL_ERROR, NULL, (stmt))
#define sqlite_step_retry(rs,stmt) _sqlite_step_retry(__HERE__, LOG_LEVEL_ERROR, (rs), (stmt)) #define sqlite_step_retry(rs,stmt) _sqlite_step_retry(__WHENCE__, LOG_LEVEL_ERROR, (rs), (stmt))
#define sqlite_exec_void(fmt,...) _sqlite_exec_void(__HERE__, (fmt), ##__VA_ARGS__) #define sqlite_exec_void(fmt,...) _sqlite_exec_void(__WHENCE__, (fmt), ##__VA_ARGS__)
#define sqlite_exec_void_loglevel(ll,fmt,...) _sqlite_exec_void_loglevel(__HERE__, (ll), (fmt), ##__VA_ARGS__) #define sqlite_exec_void_loglevel(ll,fmt,...) _sqlite_exec_void_loglevel(__WHENCE__, (ll), (fmt), ##__VA_ARGS__)
#define sqlite_exec_void_retry(rs,fmt,...) _sqlite_exec_void_retry(__HERE__, (rs), (fmt), ##__VA_ARGS__) #define sqlite_exec_void_retry(rs,fmt,...) _sqlite_exec_void_retry(__WHENCE__, (rs), (fmt), ##__VA_ARGS__)
#define sqlite_exec_int64(res,fmt,...) _sqlite_exec_int64(__HERE__, (res), (fmt), ##__VA_ARGS__) #define sqlite_exec_int64(res,fmt,...) _sqlite_exec_int64(__WHENCE__, (res), (fmt), ##__VA_ARGS__)
#define sqlite_exec_int64_retry(rs,res,fmt,...) _sqlite_exec_int64_retry(__HERE__, (rs), (res), (fmt), ##__VA_ARGS__) #define sqlite_exec_int64_retry(rs,res,fmt,...) _sqlite_exec_int64_retry(__WHENCE__, (rs), (res), (fmt), ##__VA_ARGS__)
#define sqlite_exec_strbuf(sb,fmt,...) _sqlite_exec_strbuf(__HERE__, (sb), (fmt), ##__VA_ARGS__) #define sqlite_exec_strbuf(sb,fmt,...) _sqlite_exec_strbuf(__WHENCE__, (sb), (fmt), ##__VA_ARGS__)
double rhizome_manifest_get_double(rhizome_manifest *m,char *var,double default_value); double rhizome_manifest_get_double(rhizome_manifest *m,char *var,double default_value);
int rhizome_manifest_extract_signature(rhizome_manifest *m,int *ofs); int rhizome_manifest_extract_signature(rhizome_manifest *m,int *ofs);

View File

@ -430,27 +430,27 @@ int rhizome_manifest_set_ll(rhizome_manifest *m,char *var,long long value)
rhizome_manifest manifests[MAX_RHIZOME_MANIFESTS]; rhizome_manifest manifests[MAX_RHIZOME_MANIFESTS];
char manifest_free[MAX_RHIZOME_MANIFESTS]; char manifest_free[MAX_RHIZOME_MANIFESTS];
int manifest_first_free=-1; int manifest_first_free=-1;
struct __sourceloc manifest_alloc_where[MAX_RHIZOME_MANIFESTS]; struct __sourceloc manifest_alloc_whence[MAX_RHIZOME_MANIFESTS];
struct __sourceloc manifest_free_where[MAX_RHIZOME_MANIFESTS]; struct __sourceloc manifest_free_whence[MAX_RHIZOME_MANIFESTS];
static void _log_manifest_trace(struct __sourceloc where, const char *operation) static void _log_manifest_trace(struct __sourceloc __whence, const char *operation)
{ {
int count_free = 0; int count_free = 0;
int i; int i;
for (i = 0; i != MAX_RHIZOME_MANIFESTS; ++i) for (i = 0; i != MAX_RHIZOME_MANIFESTS; ++i)
if (manifest_free[i]) if (manifest_free[i])
++count_free; ++count_free;
logMessage(LOG_LEVEL_DEBUG, where, "%s(): count_free = %d", operation, count_free); DEBUGF("%s(): count_free = %d", operation, count_free);
} }
rhizome_manifest *_rhizome_new_manifest(struct __sourceloc where) rhizome_manifest *_rhizome_new_manifest(struct __sourceloc __whence)
{ {
if (manifest_first_free<0) { if (manifest_first_free<0) {
/* Setup structures */ /* Setup structures */
int i; int i;
for(i=0;i<MAX_RHIZOME_MANIFESTS;i++) { for(i=0;i<MAX_RHIZOME_MANIFESTS;i++) {
manifest_alloc_where[i]=__NOWHERE__; manifest_alloc_whence[i]=__NOWHERE__;
manifest_free_where[i]=__NOWHERE__; manifest_free_whence[i]=__NOWHERE__;
manifest_free[i]=1; manifest_free[i]=1;
} }
manifest_first_free=0; manifest_first_free=0;
@ -460,14 +460,14 @@ rhizome_manifest *_rhizome_new_manifest(struct __sourceloc where)
if (manifest_first_free>=MAX_RHIZOME_MANIFESTS) if (manifest_first_free>=MAX_RHIZOME_MANIFESTS)
{ {
int i; int i;
logMessage(LOG_LEVEL_ERROR, where, "%s(): no free manifest records, this probably indicates a memory leak", __FUNCTION__); WHYF("%s(): no free manifest records, this probably indicates a memory leak", __FUNCTION__);
WHYF(" Slot# | Last allocated by"); WHYF(" Slot# | Last allocated by");
for(i=0;i<MAX_RHIZOME_MANIFESTS;i++) { for(i=0;i<MAX_RHIZOME_MANIFESTS;i++) {
WHYF(" %-5d | %s:%d in %s()", WHYF(" %-5d | %s:%d in %s()",
i, i,
manifest_alloc_where[i].file, manifest_alloc_whence[i].file,
manifest_alloc_where[i].line, manifest_alloc_whence[i].line,
manifest_alloc_where[i].function manifest_alloc_whence[i].function
); );
} }
return NULL; return NULL;
@ -479,40 +479,38 @@ rhizome_manifest *_rhizome_new_manifest(struct __sourceloc where)
/* Indicate where manifest was allocated, and that it is no longer /* Indicate where manifest was allocated, and that it is no longer
free. */ free. */
manifest_alloc_where[manifest_first_free]=where; manifest_alloc_whence[manifest_first_free]=__whence;
manifest_free[manifest_first_free]=0; manifest_free[manifest_first_free]=0;
manifest_free_where[manifest_first_free]=__NOWHERE__; manifest_free_whence[manifest_first_free]=__NOWHERE__;
/* Work out where next free manifest record lives */ /* Work out where next free manifest record lives */
for (; manifest_first_free < MAX_RHIZOME_MANIFESTS && !manifest_free[manifest_first_free]; ++manifest_first_free) for (; manifest_first_free < MAX_RHIZOME_MANIFESTS && !manifest_free[manifest_first_free]; ++manifest_first_free)
; ;
if (debug & DEBUG_MANIFESTS) _log_manifest_trace(where, __FUNCTION__); if (debug & DEBUG_MANIFESTS) _log_manifest_trace(__whence, __FUNCTION__);
return m; return m;
} }
void _rhizome_manifest_free(struct __sourceloc where, rhizome_manifest *m) void _rhizome_manifest_free(struct __sourceloc __whence, rhizome_manifest *m)
{ {
if (!m) return; if (!m) return;
int i; int i;
int mid=m->manifest_record_number; int mid=m->manifest_record_number;
if (m!=&manifests[mid]) { if (m!=&manifests[mid]) {
logMessage(LOG_LEVEL_ERROR, where, WHYF("%s(): asked to free manifest %p, which claims to be manifest slot #%d (%p), but isn't",
"%s(): asked to free manifest %p, which claims to be manifest slot #%d (%p), but isn't",
__FUNCTION__, m, mid, &manifests[mid] __FUNCTION__, m, mid, &manifests[mid]
); );
exit(-1); exit(-1);
} }
if (manifest_free[mid]) { if (manifest_free[mid]) {
logMessage(LOG_LEVEL_ERROR, where, WHYF("%s(): asked to free manifest slot #%d (%p), which was already freed at %s:%d:%s()",
"%s(): asked to free manifest slot #%d (%p), which was already freed at %s:%d:%s()",
__FUNCTION__, mid, m, __FUNCTION__, mid, m,
manifest_free_where[mid].file, manifest_free_whence[mid].file,
manifest_free_where[mid].line, manifest_free_whence[mid].line,
manifest_free_where[mid].function manifest_free_whence[mid].function
); );
exit(-1); exit(-1);
} }
@ -531,10 +529,10 @@ void _rhizome_manifest_free(struct __sourceloc where, rhizome_manifest *m)
m->dataFileName=NULL; m->dataFileName=NULL;
manifest_free[mid]=1; manifest_free[mid]=1;
manifest_free_where[mid]=where; manifest_free_whence[mid]=__whence;
if (mid<manifest_first_free) manifest_first_free=mid; if (mid<manifest_first_free) manifest_first_free=mid;
if (debug & DEBUG_MANIFESTS) _log_manifest_trace(where, __FUNCTION__); if (debug & DEBUG_MANIFESTS) _log_manifest_trace(__whence, __FUNCTION__);
return; return;
} }

View File

@ -121,12 +121,12 @@ int rhizome_manifest_priority(sqlite_retry_state *retry, const char *id)
} }
debugflags_t sqlite_trace_debug = DEBUG_RHIZOME; debugflags_t sqlite_trace_debug = DEBUG_RHIZOME;
const struct __sourceloc *sqlite_trace_where = NULL; const struct __sourceloc *sqlite_trace_whence = NULL;
static void sqlite_trace_callback(void *context, const char *rendered_sql) static void sqlite_trace_callback(void *context, const char *rendered_sql)
{ {
if (debug & sqlite_trace_debug) if (debug & sqlite_trace_debug)
logMessage(LOG_LEVEL_DEBUG, sqlite_trace_where ? *sqlite_trace_where : __HERE__, "%s", rendered_sql); logMessage(LOG_LEVEL_DEBUG, sqlite_trace_whence ? *sqlite_trace_whence : __HERE__, "%s", rendered_sql);
} }
/* This function allows code like: /* This function allows code like:
@ -277,7 +277,7 @@ sqlite_retry_state sqlite_retry_state_init(int serverLimit, int serverSleep, int
}; };
} }
int _sqlite_retry(struct __sourceloc where, sqlite_retry_state *retry, const char *action) int _sqlite_retry(struct __sourceloc __whence, sqlite_retry_state *retry, const char *action)
{ {
time_ms_t now = gettime_ms(); time_ms_t now = gettime_ms();
++retry->busytries; ++retry->busytries;
@ -285,8 +285,7 @@ int _sqlite_retry(struct __sourceloc where, sqlite_retry_state *retry, const cha
retry->start = now; retry->start = now;
else else
retry->elapsed += now - retry->start; retry->elapsed += now - retry->start;
logMessage(LOG_LEVEL_INFO, where, INFOF("%s on try %u after %.3f seconds (%.3f elapsed): %s",
"%s on try %u after %.3f seconds (%.3f elapsed): %s",
sqlite3_errmsg(rhizome_db), sqlite3_errmsg(rhizome_db),
retry->busytries, retry->busytries,
(now - retry->start) / 1e3, (now - retry->start) / 1e3,
@ -305,12 +304,11 @@ int _sqlite_retry(struct __sourceloc where, sqlite_retry_state *retry, const cha
return 1; // tell caller to try again return 1; // tell caller to try again
} }
void _sqlite_retry_done(struct __sourceloc where, sqlite_retry_state *retry, const char *action) void _sqlite_retry_done(struct __sourceloc __whence, sqlite_retry_state *retry, const char *action)
{ {
if (retry->busytries) { if (retry->busytries) {
time_ms_t now = gettime_ms(); time_ms_t now = gettime_ms();
logMessage(LOG_LEVEL_INFO, where, INFOF("succeeded on try %u after %.3f seconds (%.3f elapsed): %s",
"succeeded on try %u after %.3f seconds (%.3f elapsed): %s",
retry->busytries + 1, retry->busytries + 1,
(now - retry->start) / 1e3, (now - retry->start) / 1e3,
retry->elapsed / 1e3, retry->elapsed / 1e3,
@ -328,20 +326,18 @@ void _sqlite_retry_done(struct __sourceloc where, sqlite_retry_state *retry, con
Returns -1 if an error occurs (logged as an error), otherwise zero with the prepared Returns -1 if an error occurs (logged as an error), otherwise zero with the prepared
statement in *statement. statement in *statement.
*/ */
sqlite3_stmt *_sqlite_prepare(struct __sourceloc where, sqlite_retry_state *retry, const char *sqlformat, ...) sqlite3_stmt *_sqlite_prepare(struct __sourceloc __whence, sqlite_retry_state *retry, const char *sqlformat, ...)
{ {
strbuf sql = strbuf_alloca(8192); strbuf sql = strbuf_alloca(8192);
strbuf_va_printf(sql, sqlformat); strbuf_va_printf(sql, sqlformat);
return _sqlite_prepare_loglevel(where, LOG_LEVEL_ERROR, retry, sql); return _sqlite_prepare_loglevel(__whence, LOG_LEVEL_ERROR, retry, sql);
} }
sqlite3_stmt *_sqlite_prepare_loglevel(struct __sourceloc where, int log_level, sqlite_retry_state *retry, strbuf stmt) sqlite3_stmt *_sqlite_prepare_loglevel(struct __sourceloc __whence, int log_level, sqlite_retry_state *retry, strbuf stmt)
{ {
sqlite3_stmt *statement = NULL; sqlite3_stmt *statement = NULL;
if (strbuf_overrun(stmt)) { if (strbuf_overrun(stmt))
logMessage(LOG_LEVEL_ERROR, where, "SQL overrun: %s", strbuf_str(stmt)); return WHYFNULL("SQL overrun: %s", strbuf_str(stmt));
return NULL;
}
if (!rhizome_db && rhizome_opendb() == -1) if (!rhizome_db && rhizome_opendb() == -1)
return NULL; return NULL;
while (1) { while (1) {
@ -351,22 +347,22 @@ sqlite3_stmt *_sqlite_prepare_loglevel(struct __sourceloc where, int log_level,
return statement; return statement;
case SQLITE_BUSY: case SQLITE_BUSY:
case SQLITE_LOCKED: case SQLITE_LOCKED:
if (retry && _sqlite_retry(where, retry, strbuf_str(stmt))) { if (retry && _sqlite_retry(__whence, retry, strbuf_str(stmt))) {
break; // back to sqlite3_prepare_v2() break; // back to sqlite3_prepare_v2()
} }
// fall through... // fall through...
default: default:
logMessage(log_level, where, "query invalid, %s: %s", sqlite3_errmsg(rhizome_db), strbuf_str(stmt)); LOGF(log_level, "query invalid, %s: %s", sqlite3_errmsg(rhizome_db), strbuf_str(stmt));
sqlite3_finalize(statement); sqlite3_finalize(statement);
return NULL; return NULL;
} }
} }
} }
int _sqlite_step_retry(struct __sourceloc where, int log_level, sqlite_retry_state *retry, sqlite3_stmt *statement) int _sqlite_step_retry(struct __sourceloc __whence, int log_level, sqlite_retry_state *retry, sqlite3_stmt *statement)
{ {
int ret = -1; int ret = -1;
sqlite_trace_where = &where; sqlite_trace_whence = &__whence;
while (statement) { while (statement) {
int stepcode = sqlite3_step(statement); int stepcode = sqlite3_step(statement);
switch (stepcode) { switch (stepcode) {
@ -374,25 +370,25 @@ int _sqlite_step_retry(struct __sourceloc where, int log_level, sqlite_retry_sta
case SQLITE_DONE: case SQLITE_DONE:
case SQLITE_ROW: case SQLITE_ROW:
if (retry) if (retry)
_sqlite_retry_done(where, retry, sqlite3_sql(statement)); _sqlite_retry_done(__whence, retry, sqlite3_sql(statement));
ret = stepcode; ret = stepcode;
statement = NULL; statement = NULL;
break; break;
case SQLITE_BUSY: case SQLITE_BUSY:
case SQLITE_LOCKED: case SQLITE_LOCKED:
if (retry && _sqlite_retry(where, retry, sqlite3_sql(statement))) { if (retry && _sqlite_retry(__whence, retry, sqlite3_sql(statement))) {
sqlite3_reset(statement); sqlite3_reset(statement);
break; // back to sqlite3_step() break; // back to sqlite3_step()
} }
// fall through... // fall through...
default: default:
logMessage(log_level, where, "query failed, %s: %s", sqlite3_errmsg(rhizome_db), sqlite3_sql(statement)); LOGF(log_level, "query failed, %s: %s", sqlite3_errmsg(rhizome_db), sqlite3_sql(statement));
ret = -1; ret = -1;
statement = NULL; statement = NULL;
break; break;
} }
} }
sqlite_trace_where = NULL; sqlite_trace_whence = NULL;
return ret; return ret;
} }
@ -403,37 +399,37 @@ int _sqlite_step_retry(struct __sourceloc where, int log_level, sqlite_retry_sta
the statement and retries while sqlite_retry() returns true. If sqlite_retry() returns false the statement and retries while sqlite_retry() returns true. If sqlite_retry() returns false
then returns -1. Otherwise returns zero. Always finalises the statement before returning. then returns -1. Otherwise returns zero. Always finalises the statement before returning.
*/ */
static int _sqlite_exec_void_prepared(struct __sourceloc where, int log_level, sqlite_retry_state *retry, sqlite3_stmt *statement) static int _sqlite_exec_void_prepared(struct __sourceloc __whence, int log_level, sqlite_retry_state *retry, sqlite3_stmt *statement)
{ {
if (!statement) if (!statement)
return -1; return -1;
int rowcount = 0; int rowcount = 0;
int stepcode; int stepcode;
while ((stepcode = _sqlite_step_retry(where, log_level, retry, statement)) == SQLITE_ROW) while ((stepcode = _sqlite_step_retry(__whence, log_level, retry, statement)) == SQLITE_ROW)
++rowcount; ++rowcount;
if (rowcount) if (rowcount)
logMessage(LOG_LEVEL_WARN, where, "void query unexpectedly returned %d row%s", rowcount, rowcount == 1 ? "" : "s"); WARNF("void query unexpectedly returned %d row%s", rowcount, rowcount == 1 ? "" : "s");
sqlite3_finalize(statement); sqlite3_finalize(statement);
return sqlite_code_ok(stepcode) ? 0 : -1; return sqlite_code_ok(stepcode) ? 0 : -1;
} }
static int _sqlite_vexec_void(struct __sourceloc where, int log_level, sqlite_retry_state *retry, const char *sqlformat, va_list ap) static int _sqlite_vexec_void(struct __sourceloc __whence, int log_level, sqlite_retry_state *retry, const char *sqlformat, va_list ap)
{ {
strbuf stmt = strbuf_alloca(8192); strbuf stmt = strbuf_alloca(8192);
strbuf_vsprintf(stmt, sqlformat, ap); strbuf_vsprintf(stmt, sqlformat, ap);
return _sqlite_exec_void_prepared(where, log_level, retry, _sqlite_prepare_loglevel(where, log_level, retry, stmt)); return _sqlite_exec_void_prepared(__whence, log_level, retry, _sqlite_prepare_loglevel(__whence, log_level, retry, stmt));
} }
/* Convenience wrapper for executing an SQL command that returns no value. /* Convenience wrapper for executing an SQL command that returns no value.
If an error occurs then logs it at ERROR level and returns -1. Otherwise returns zero. If an error occurs then logs it at ERROR level and returns -1. Otherwise returns zero.
@author Andrew Bettison <andrew@servalproject.com> @author Andrew Bettison <andrew@servalproject.com>
*/ */
int _sqlite_exec_void(struct __sourceloc where, const char *sqlformat, ...) int _sqlite_exec_void(struct __sourceloc __whence, const char *sqlformat, ...)
{ {
va_list ap; va_list ap;
va_start(ap, sqlformat); va_start(ap, sqlformat);
sqlite_retry_state retry = SQLITE_RETRY_STATE_DEFAULT; sqlite_retry_state retry = SQLITE_RETRY_STATE_DEFAULT;
int ret = _sqlite_vexec_void(where, LOG_LEVEL_ERROR, &retry, sqlformat, ap); int ret = _sqlite_vexec_void(__whence, LOG_LEVEL_ERROR, &retry, sqlformat, ap);
va_end(ap); va_end(ap);
return ret; return ret;
} }
@ -441,12 +437,12 @@ int _sqlite_exec_void(struct __sourceloc where, const char *sqlformat, ...)
/* Same as sqlite_exec_void(), but logs any error at the given level instead of ERROR. /* Same as sqlite_exec_void(), but logs any error at the given level instead of ERROR.
@author Andrew Bettison <andrew@servalproject.com> @author Andrew Bettison <andrew@servalproject.com>
*/ */
int _sqlite_exec_void_loglevel(struct __sourceloc where, int log_level, const char *sqlformat, ...) int _sqlite_exec_void_loglevel(struct __sourceloc __whence, int log_level, const char *sqlformat, ...)
{ {
va_list ap; va_list ap;
va_start(ap, sqlformat); va_start(ap, sqlformat);
sqlite_retry_state retry = SQLITE_RETRY_STATE_DEFAULT; sqlite_retry_state retry = SQLITE_RETRY_STATE_DEFAULT;
int ret = _sqlite_vexec_void(where, log_level, &retry, sqlformat, ap); int ret = _sqlite_vexec_void(__whence, log_level, &retry, sqlformat, ap);
va_end(ap); va_end(ap);
return ret; return ret;
} }
@ -457,36 +453,34 @@ int _sqlite_exec_void_loglevel(struct __sourceloc where, int log_level, const ch
all in the event of a busy condition, but will log it as an error and return immediately. all in the event of a busy condition, but will log it as an error and return immediately.
@author Andrew Bettison <andrew@servalproject.com> @author Andrew Bettison <andrew@servalproject.com>
*/ */
int _sqlite_exec_void_retry(struct __sourceloc where, sqlite_retry_state *retry, const char *sqlformat, ...) int _sqlite_exec_void_retry(struct __sourceloc __whence, sqlite_retry_state *retry, const char *sqlformat, ...)
{ {
va_list ap; va_list ap;
va_start(ap, sqlformat); va_start(ap, sqlformat);
int ret = _sqlite_vexec_void(where, LOG_LEVEL_ERROR, retry, sqlformat, ap); int ret = _sqlite_vexec_void(__whence, LOG_LEVEL_ERROR, retry, sqlformat, ap);
va_end(ap); va_end(ap);
return ret; return ret;
} }
static int _sqlite_vexec_int64(struct __sourceloc where, sqlite_retry_state *retry, long long *result, const char *sqlformat, va_list ap) static int _sqlite_vexec_int64(struct __sourceloc __whence, sqlite_retry_state *retry, long long *result, const char *sqlformat, va_list ap)
{ {
strbuf stmt = strbuf_alloca(8192); strbuf stmt = strbuf_alloca(8192);
strbuf_vsprintf(stmt, sqlformat, ap); strbuf_vsprintf(stmt, sqlformat, ap);
sqlite3_stmt *statement = _sqlite_prepare_loglevel(where, LOG_LEVEL_ERROR, retry, stmt); sqlite3_stmt *statement = _sqlite_prepare_loglevel(__whence, LOG_LEVEL_ERROR, retry, stmt);
if (!statement) if (!statement)
return -1; return -1;
int ret = 0; int ret = 0;
int rowcount = 0; int rowcount = 0;
int stepcode; int stepcode;
while ((stepcode = _sqlite_step_retry(where, LOG_LEVEL_ERROR, retry, statement)) == SQLITE_ROW) { while ((stepcode = _sqlite_step_retry(__whence, LOG_LEVEL_ERROR, retry, statement)) == SQLITE_ROW) {
int columncount = sqlite3_column_count(statement); int columncount = sqlite3_column_count(statement);
if (columncount != 1) { if (columncount != 1)
logMessage(LOG_LEVEL_ERROR, where, "incorrect column count %d (should be 1): %s", columncount, sqlite3_sql(statement)); ret = WHYF("incorrect column count %d (should be 1): %s", columncount, sqlite3_sql(statement));
ret = -1;
}
else if (++rowcount == 1) else if (++rowcount == 1)
*result = sqlite3_column_int64(statement, 0); *result = sqlite3_column_int64(statement, 0);
} }
if (rowcount > 1) if (rowcount > 1)
logMessage(LOG_LEVEL_WARN, where, "query unexpectedly returned %d rows, ignored all but first", rowcount); WARNF("query unexpectedly returned %d rows, ignored all but first", rowcount);
sqlite3_finalize(statement); sqlite3_finalize(statement);
return sqlite_code_ok(stepcode) && ret != -1 ? rowcount : -1; return sqlite_code_ok(stepcode) && ret != -1 ? rowcount : -1;
} }
@ -499,12 +493,12 @@ static int _sqlite_vexec_int64(struct __sourceloc where, sqlite_retry_state *ret
If more than one row is found, then logs a warning, assigns the value of the first row to *result If more than one row is found, then logs a warning, assigns the value of the first row to *result
and returns the number of rows. and returns the number of rows.
*/ */
int _sqlite_exec_int64(struct __sourceloc where, long long *result, const char *sqlformat,...) int _sqlite_exec_int64(struct __sourceloc __whence, long long *result, const char *sqlformat,...)
{ {
va_list ap; va_list ap;
va_start(ap, sqlformat); va_start(ap, sqlformat);
sqlite_retry_state retry = SQLITE_RETRY_STATE_DEFAULT; sqlite_retry_state retry = SQLITE_RETRY_STATE_DEFAULT;
int ret = _sqlite_vexec_int64(where, &retry, result, sqlformat, ap); int ret = _sqlite_vexec_int64(__whence, &retry, result, sqlformat, ap);
va_end(ap); va_end(ap);
return ret; return ret;
} }
@ -515,11 +509,11 @@ int _sqlite_exec_int64(struct __sourceloc where, long long *result, const char *
all in the event of a busy condition, but will log it as an error and return immediately. all in the event of a busy condition, but will log it as an error and return immediately.
@author Andrew Bettison <andrew@servalproject.com> @author Andrew Bettison <andrew@servalproject.com>
*/ */
int _sqlite_exec_int64_retry(struct __sourceloc where, sqlite_retry_state *retry, long long *result, const char *sqlformat,...) int _sqlite_exec_int64_retry(struct __sourceloc __whence, sqlite_retry_state *retry, long long *result, const char *sqlformat,...)
{ {
va_list ap; va_list ap;
va_start(ap, sqlformat); va_start(ap, sqlformat);
int ret = _sqlite_vexec_int64(where, retry, result, sqlformat, ap); int ret = _sqlite_vexec_int64(__whence, retry, result, sqlformat, ap);
va_end(ap); va_end(ap);
return ret; return ret;
} }
@ -532,28 +526,26 @@ int _sqlite_exec_int64_retry(struct __sourceloc where, sqlite_retry_state *retry
2 more than one row, logs a warning and appends the first row's column to the strbuf 2 more than one row, logs a warning and appends the first row's column to the strbuf
@author Andrew Bettison <andrew@servalproject.com> @author Andrew Bettison <andrew@servalproject.com>
*/ */
int _sqlite_exec_strbuf(struct __sourceloc where, strbuf sb, const char *sqlformat,...) int _sqlite_exec_strbuf(struct __sourceloc __whence, strbuf sb, const char *sqlformat,...)
{ {
strbuf stmt = strbuf_alloca(8192); strbuf stmt = strbuf_alloca(8192);
strbuf_va_printf(stmt, sqlformat); strbuf_va_printf(stmt, sqlformat);
sqlite_retry_state retry = SQLITE_RETRY_STATE_DEFAULT; sqlite_retry_state retry = SQLITE_RETRY_STATE_DEFAULT;
sqlite3_stmt *statement = _sqlite_prepare_loglevel(where, LOG_LEVEL_ERROR, &retry, stmt); sqlite3_stmt *statement = _sqlite_prepare_loglevel(__whence, LOG_LEVEL_ERROR, &retry, stmt);
if (!statement) if (!statement)
return -1; return -1;
int ret = 0; int ret = 0;
int rowcount = 0; int rowcount = 0;
int stepcode; int stepcode;
while ((stepcode = _sqlite_step_retry(where, LOG_LEVEL_ERROR, &retry, statement)) == SQLITE_ROW) { while ((stepcode = _sqlite_step_retry(__whence, LOG_LEVEL_ERROR, &retry, statement)) == SQLITE_ROW) {
int columncount = sqlite3_column_count(statement); int columncount = sqlite3_column_count(statement);
if (columncount != 1) { if (columncount != 1)
logMessage(LOG_LEVEL_ERROR, where, "incorrect column count %d (should be 1): %s", columncount, sqlite3_sql(statement)); ret - WHYF("incorrect column count %d (should be 1): %s", columncount, sqlite3_sql(statement));
ret = -1;
}
else if (++rowcount == 1) else if (++rowcount == 1)
strbuf_puts(sb, (const char *)sqlite3_column_text(statement, 0)); strbuf_puts(sb, (const char *)sqlite3_column_text(statement, 0));
} }
if (rowcount > 1) if (rowcount > 1)
logMessage(LOG_LEVEL_WARN, where, "query unexpectedly returned %d rows, ignored all but first", rowcount); WARNF("query unexpectedly returned %d rows, ignored all but first", rowcount);
sqlite3_finalize(statement); sqlite3_finalize(statement);
return sqlite_code_ok(stepcode) && ret != -1 ? rowcount : -1; return sqlite_code_ok(stepcode) && ret != -1 ? rowcount : -1;
} }
@ -1034,7 +1026,7 @@ int rhizome_store_file(rhizome_manifest *m,const unsigned char *key)
goto insert_row_fail; goto insert_row_fail;
} }
/* Do actual insert, and abort if it fails */ /* Do actual insert, and abort if it fails */
if (_sqlite_exec_void_prepared(__HERE__, LOG_LEVEL_ERROR, &retry, statement) == -1) { if (_sqlite_exec_void_prepared(__WHENCE__, LOG_LEVEL_ERROR, &retry, statement) == -1) {
insert_row_fail: insert_row_fail:
WHYF("Failed to insert row for fileid=%s", hash); WHYF("Failed to insert row for fileid=%s", hash);
goto error; goto error;

View File

@ -566,8 +566,6 @@ int overlay_frame_resolve_addresses(struct overlay_frame *f);
time_ms_t overlay_time_until_next_tick(); time_ms_t overlay_time_until_next_tick();
int overlay_rx_messages(); int overlay_rx_messages();
#define DEBUG_packet_visualise(M,P,N) logServalPacket(LOG_LEVEL_DEBUG, __HERE__, (M), (P), (N))
int overlay_add_selfannouncement(); int overlay_add_selfannouncement();
int overlay_frame_append_payload(overlay_interface *interface, struct overlay_frame *p, struct subscriber *next_hop, struct overlay_buffer *b); int overlay_frame_append_payload(overlay_interface *interface, struct overlay_frame *p, struct subscriber *next_hop, struct overlay_buffer *b);
int overlay_interface_args(const char *arg); int overlay_interface_args(const char *arg);
@ -766,13 +764,13 @@ int dump_payload(struct overlay_frame *p, char *message);
int urandombytes(unsigned char *x,unsigned long long xlen); int urandombytes(unsigned char *x,unsigned long long xlen);
#ifdef MALLOC_PARANOIA #ifdef MALLOC_PARANOIA
#define malloc(X) _serval_debug_malloc(X,__HERE__) #define malloc(X) _serval_debug_malloc(X,__WHENCE__)
#define calloc(X,Y) _serval_debug_calloc(X,Y,__HERE__) #define calloc(X,Y) _serval_debug_calloc(X,Y,__WHENCE__)
#define free(X) _serval_debug_free(X,__HERE__) #define free(X) _serval_debug_free(X,__WHENCE__)
void *_serval_debug_malloc(unsigned int bytes, struct __sourceloc where); void *_serval_debug_malloc(unsigned int bytes, struct __sourceloc whence);
void *_serval_debug_calloc(unsigned int bytes, unsigned int count, struct __sourceloc where); void *_serval_debug_calloc(unsigned int bytes, unsigned int count, struct __sourceloc whence);
void _serval_debug_free(void *p, struct __sourceloc where); void _serval_debug_free(void *p, struct __sourceloc whence);
#endif #endif