bughz/3proxy
1
0
Fork 0
mirror of https://github.com/3proxy/3proxy.git synced 2026-10-28 22:05:48 +08:00
Code Issues Actions 12 Packages Projects Releases Wiki Activity

Logs: a logger for each log string, shared and closed once unused

Browse Source 
A logger (struct logger) is identified by the string log or -l gives it:
"" stdout, "/dev/null" none, "@IDENT" syslog, "&DSN" ODBC, "radius",
anything else a file. Each type (struct logtype) has init, formatting of
a connection into a buffer, writing, close, and a periodic tick for
rotation and flushing; ODBC and RADIUS register their types from 3proxy,
which alone has them. Services and configurations hold the logger they
use; the last to let go closes it, except the standard ones (none,
stdout, stderr, syslog), which are opened at startup and kept.

-l takes every log type now, and a file named by several services or by
both log and -l is opened once. rotate and archiver are bound to the
logger of the last log command when its configuration comes into force,
and every file logger is rotated by the main loop.

Errors with no connection go to a new stderr logger; after daemon, or as
a Windows service, stdout logging writes nothing and errors go to the
last log configured. A log whose writes keep failing is closed and
reopened; while it cannot be, its lines go to stderr and it is retried
every minute. ODBC's own reconnection throttle gives way to this.

Formatting (logbuf) is separate from counting traffic and clearing the
statistics, done once by logdo(), the services' log function, so a later
step can format or copy a connection's line and write it from a thread
of its own. dologname() and timechanged() move to log.c, which the
standalone services link as well.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
Vladimir Dubrovin 2026-10-23 11:44:55 +03:00
parent 57818ad497
commit d613750b94
14 changed files with 996 additions and 415 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

15
doc/html/man5/3proxy.cfg.5.html
View File

@ -337,7 +337,20 @@ M</b> Monthly <b><br>
Y</b> Annually <br>
if logfile is not specified logging goes to stdout. You can
specify individual logging options for gateway by using -l
option in gateway configuration. <br>
option in gateway configuration: -l takes the same arguments,
-l@ident, -l&amp;odbc_string, -lradius or -lfilename, and -l
alone is stdout. <br>
A log is opened once for the same argument, whether given by
log or by -l, and shared by every service using it; it is kept
open over a configuration reload while some service still uses
it, and closed once none does. stdout, stderr and syslog are
opened at startup and never closed. rotate and archiver apply
to the file of the last log command. A log which fails to be
written is reopened, and if it cannot be, its records go to
stderr while it is retried every minute. Errors and warnings
with no connection go to stderr; after daemon (or as a Windows
service) nothing goes to stdout or stderr: logging to stdout is
none, and errors go to the last log configured. <br>
log command supports same format specifications for filename
template as &quot;logformat&quot; (if filename contains
&acute;%&acute; sign it&acute;s believed to be template). As

10
man/3proxy.cfg.5
View File

@ -344,7 +344,15 @@ proxy on a client with FTP proxy support. Username format is one of
\fBY\fR Annually
.br
if logfile is not specified logging goes to stdout. You can specify individual logging options for gateway by using -l
option in gateway configuration.
option in gateway configuration: -l takes the same arguments, -l@ident, -l&odbc_string, -lradius or -lfilename, and -l
alone is stdout.
.br
A log is opened once for the same argument, whether given by log or by -l, and shared by every service using it; it
is kept open over a configuration reload while some service still uses it, and closed once none does. stdout,
stderr and syslog are opened at startup and never closed. rotate and archiver apply to the file of the last log
command. A log which fails to be written is reopened, and if it cannot be, its records go to stderr while it is
retried every minute. Errors and warnings with no connection go to stderr; after daemon (or as a Windows service)
nothing goes to stdout or stderr: logging to stdout is none, and errors go to the last log configured.
.br
log command supports same format specifications for filename template
as "logformat" (if filename contains \'%\' sign it\'s believed to be template).

110
src/3proxy.c
View File

@ -101,11 +101,7 @@ void __stdcall ServiceMain(int argc, unsigned char* argv[] )
SetStatus( SERVICE_START_PENDING, 0, 1 );
SetStatus( SERVICE_RUNNING, 0, 0 );
cyclestep();
#ifdef WITH_ODBC
_3proxy_mutex_lock(&log_mutex);
close_sql();
_3proxy_mutex_unlock(&log_mutex);
#endif
logfinish();
/* the last thing: the process may be ended once this is reported */
SetStatus( SERVICE_STOPPED, 0, 0 );
}
@ -145,42 +141,6 @@ struct schedule *schedule;
int wday = 0;
int timechanged (time_t oldtime, time_t newtime, ROTATION lt){
struct tm tmold;
struct tm *tm;
tm = localtime(&oldtime);
if(!tm) return 0;
tmold = *tm;
tm = localtime(&newtime);
if(!tm) return 0;
switch(lt){
case MINUTELY:
if(tm->tm_min != tmold.tm_min)return 1;
break;
case HOURLY:
if(tm->tm_hour != tmold.tm_hour)return 1;
break;
case DAILY:
if(tm->tm_yday != tmold.tm_yday)return 1;
break;
case MONTHLY:
if(tm->tm_mon != tmold.tm_mon)return 1;
break;
case ANNUALLY:
if(tm->tm_year != tmold.tm_year)return 1;
break;
case WEEKLY:
if(((newtime - oldtime) > (60*60*24*7))
|| tm->tm_wday < tmold.tm_wday
|| (tm->tm_wday == tmold.tm_wday && (newtime - oldtime) > (60*60*24*6))
)return 1;
break;
default:
break;
}
return 0;
}
void doschedule(void){
struct schedule *sched, *prevsched = NULL, *nextsched;
int res;
@ -280,7 +240,6 @@ static void waitservices(void){
void cyclestep(void){
struct tm *tm;
time_t minutecounter;
unsigned char tmpbuf[8192];
minutecounter = time(0);
for(;;){
@ -294,7 +253,6 @@ void cyclestep(void){
}
doschedule();
sysdnscheck();
if(conf->stdlog)fflush(conf->stdlog);
if(timechanged(minutecounter, curtime, MINUTELY)) {
struct filemon *fm;
struct stat sb;
@ -317,55 +275,7 @@ void cyclestep(void){
basetime = mktime(tm);
}
}
if(conf->logname) {
if(timechanged(conf->logtime, curtime, conf->logtype)) {
if(conf->stdlog) conf->stdlog = freopen((char *)dologname (tmpbuf, conf->logname, NULL, conf->logtype, curtime), "a", conf->stdlog);
else conf->stdlog = fopen((char *)dologname (tmpbuf, conf->logname, NULL, conf->logtype, curtime), "a");
conf->logtime = curtime;
if(conf->logtype != NONE && conf->rotate) {
int t;
t = 1;
switch(conf->logtype){
case ANNUALLY:
t = t * 12;
case MONTHLY:
t = t * 4;
case WEEKLY:
t = t * 7;
case DAILY:
t = t * 24;
case HOURLY:
t = t * 60;
case MINUTELY:
t = t * 60;
default:
break;
}
dologname (tmpbuf, conf->logname, (conf->archiver)?conf->archiver[1]:NULL, conf->logtype, (conf->logtime - (time_t)t * conf->rotate));
remove ((char *) tmpbuf);
if(conf->archiver) {
int i;
*tmpbuf = 0;
for(i = 2; i < conf->archiverc && strlen((char *)tmpbuf) < 512; i++){
strcat((char *)tmpbuf, " ");
if(!strcmp((char *)conf->archiver[i], "%A")){
strcat((char *)tmpbuf, "\"");
dologname (tmpbuf + strlen((char *)tmpbuf), conf->logname, conf->archiver[1], conf->logtype, (conf->logtime - t));
strcat((char *)tmpbuf, "\"");
}
else if(!strcmp((char *)conf->archiver[i], "%F")){
strcat((char *)tmpbuf, "\"");
dologname (tmpbuf+strlen((char *)tmpbuf), conf->logname, NULL, conf->logtype, (conf->logtime-t));
strcat((char *)tmpbuf, "\"");
}
else
strcat((char *)tmpbuf, (char *)conf->archiver[i]);
}
if(system((char *)tmpbuf+1)){}
}
}
}
}
logtick(curtime);
if(conf->counterd >= 0 && conf->trafcounter) {
if(timechanged(cheader.updated, curtime, MINUTELY)){
dumpcounters(conf->trafcounter, conf->counterd);
@ -555,8 +465,18 @@ int WinMain(HINSTANCE hInstance, HINSTANCE hPrevInstance, LPWSTR lpCmdLine, int
#ifdef __linux__
nsopen(); /* before a chroot in the configuration takes /proc away */
#endif
loginit(); /* standard output and error, syslog, before a chroot too */
#if defined _WIN32 && !defined _WINCE
if(service) logstdclose();
#endif
sysdnsinit(); /* the system's name servers and hosts, before a chroot too */
#ifdef WITH_ODBC
logtypeadd(&logtype_odbc);
#endif
#ifndef NORADIUS
logtypeadd(&logtype_radius);
#endif
_3proxy_mutex_init(&config_mutex);
_3proxy_mutex_init(&confref_mutex);
_3proxy_mutex_init(&listener_mutex);
@ -566,7 +486,6 @@ int WinMain(HINSTANCE hInstance, HINSTANCE hPrevInstance, LPWSTR lpCmdLine, int
_3proxy_mutex_init(&bandlim_mutex);
_3proxy_mutex_init(&connlim_mutex);
_3proxy_mutex_init(&tc_mutex);
_3proxy_mutex_init(&log_mutex);
_3proxy_mutex_init(&tpool.mutex);
#ifndef NORADIUS
_3proxy_mutex_init(&rad_mutex);
@ -594,7 +513,10 @@ int WinMain(HINSTANCE hInstance, HINSTANCE hPrevInstance, LPWSTR lpCmdLine, int
/* numbered before it is read, as a reload numbers the new one */
conf->version++;
res = readconfig(fp);
if(!res) confdnscommit();
if(!res) {
confdnscommit();
logcommit(conf);
}
resolvmode = conf->resolvmode;
/* readconfig() names the failing line, which an exit status would cut

18
src/authradius.c
View File

@ -655,16 +655,24 @@ int radauth(struct clientparam * param){
int res;
/*radsend(param, 0, 0);*/
res = radsend(param, 1, 0);
if(!res && param->srv->logfunc == logradius)radsend(param, 0, 0);
if(!res && param->srv->logger && param->srv->logger->type == &logtype_radius)radsend(param, 0, 0);
return res;
}
void logradius(struct clientparam * param, const unsigned char *s) {
radsend(param, 0, 1);
if(param->trafcountfunc)(*param->trafcountfunc)(param);
clearstat(param);
/* Accounting: what is sent is taken from the connection, not a line. */
static int radmatch(const unsigned char *selector){
return !strcmp((char *)selector, "radius");
}
static int radwrite(struct logger *lg, struct clientparam *param, const unsigned char *buf, int len) {
radsend(param, 0, 1);
return 0;
}
const struct logtype logtype_radius = {
"radius", radmatch, NULL, NULL, radwrite, NULL, NULL, 0, 0, 0
};
#endif

133
src/conf.c
View File

@ -153,40 +153,6 @@ int getrotate(char c){
}
unsigned char * dologname (unsigned char *buf, unsigned char *name, const unsigned char *ext, ROTATION lt, time_t t) {
struct tm *ts;
static const char * const rot_fmt[] = {
[NONE] = "%s",
[ANNUALLY] = "%s.%04d",
[MONTHLY] = "%s.%04d.%02d",
[DAILY] = "%s.%04d.%02d.%02d",
[HOURLY] = "%s.%04d.%02d.%02d-%02d",
[MINUTELY] = "%s.%04d.%02d.%02d-%02d.%02d",
};
ts = localtime(&t);
if(strlen((char *)name) >= 4096){
*buf = 0;
return buf;
}
if(strchr((char *)name, '%')){
dobuf2(NULL, buf, NULL, NULL, ts, (char *)name);
}
else if(lt == WEEKLY){
t = t - (ts->tm_wday * (60*60*24));
ts = localtime(&t);
sprintf((char *)buf, "%s.%04d.%02d.%02d", name, ts->tm_year+1900, ts->tm_mon+1, ts->tm_mday);
}
else if((unsigned)lt < sizeof(rot_fmt)/sizeof(rot_fmt[0]) && rot_fmt[lt]){
sprintf((char *)buf, rot_fmt[lt], name, ts->tm_year+1900, ts->tm_mon+1, ts->tm_mday, ts->tm_hour, ts->tm_min);
}
if(ext){
strcat((char *)buf, ".");
strcat((char *)buf, (char *)ext);
}
return buf;
}
static int deferred_add(void *service);
static int startservice(void *service);
@ -412,74 +378,23 @@ static int h_external(int argc, unsigned char ** argv){
}
/* ODBC drivers require noticeably more stack than the file logger, raise
the client thread stack size unless a larger one is configured
explicitly. An explicit stacksize placed after the log command still wins.
*/
#define LOGSTACKSIZE 32768
/* A log whose writing needs more stack, ODBC, raises the client thread
stack size unless a larger one is configured; an explicit stacksize placed
after the log command still wins. */
static int h_log(int argc, unsigned char ** argv){
unsigned char tmpbuf[8192];
int notchanged = 0;
struct logger *lg;
ROTATION rotation = (argc > 2)? getrotate(*argv[2]) : NONE;
conf->havelog = 1;
if(argc > 1 && conf->logtarget && !strcmp((char *)conf->logtarget, (char *)argv[1])) {
notchanged = 1;
}
if(!notchanged && conf->logtarget){
free(conf->logtarget);
conf->logtarget = NULL;
}
if(argc > 1) {
if(!strcmp((char *) argv[1], "/dev/null")) {
conf->logfunc = lognone;
return 0;
}
if(!notchanged) conf->logtarget = (unsigned char *)strdup((char *)argv[1]);
if(*argv[1]=='@'){
#ifndef _WIN32
conf->logfunc = logsyslog;
if(notchanged) return 0;
/* connected now: after a chroot there is no /dev/log to find */
openlog((char *)conf->logtarget+1, LOG_PID | LOG_NDELAY, LOG_DAEMON);
#endif
}
#ifdef WITH_ODBC
else if(*argv[1]=='&'){
conf->logfunc = logsql;
if(conf->stacksize < LOGSTACKSIZE) conf->stacksize = LOGSTACKSIZE;
if(notchanged) return 0;
_3proxy_mutex_lock(&log_mutex);
close_sql();
init_sql((char *)argv[1]+1);
_3proxy_mutex_unlock(&log_mutex);
}
#endif
#ifndef NORADIUS
else if(!strcmp((char *)argv[1],"radius")){
conf->logfunc = logradius;
}
#endif
else {
if(argc > 2) {
conf->logtype = getrotate(*argv[2]);
}
conf->logfunc = logstdout;
if(notchanged) return 0;
conf->logtime = time(0);
if(conf->logname)free(conf->logname);
conf->logname = (unsigned char *)strdup((char *)argv[1]);
if(conf->stdlog) conf->stdlog = freopen((char *)dologname (tmpbuf, conf->logname, NULL, conf->logtype, conf->logtime), "a", conf->stdlog);
else conf->stdlog = fopen((char *)dologname (tmpbuf, conf->logname, NULL, conf->logtype, conf->logtime), "a");
if(!conf->stdlog){
perror((char *)tmpbuf);
/* the same log as before is not opened again */
lg = logget((argc > 1)? argv[1] : (unsigned char *)"", rotation);
if(!lg){
perror((argc > 1)? (char *)argv[1] : "log");
return 1;
}
}
}
else conf->logfunc = logstdout;
if(conf->stacksize < lg->type->stacksize) conf->stacksize = lg->type->stacksize;
logput(conf->logger);
conf->logger = lg;
conf->logtype = rotation;
return 0;
}
@ -510,7 +425,10 @@ static int h_service(int argc, unsigned char **argv){
}
static int h_daemon(int argc, unsigned char **argv){
if(!conf->demon)daemonize();
if(!conf->demon){
daemonize();
logstdclose();
}
conf->demon = 1;
return 0;
}
@ -2490,7 +2408,9 @@ void freeconf(struct extparam *confp){
_3proxy_mutex_unlock(&connlim_mutex);
if(confp->pwl_table.ihashtable) destroyhashtable(&confp->pwl_table);
confp->logfunc = lognone;
confp->logfunc = logdo;
logput(confp->logger);
confp->logger = NULL;
logformat = confp->logformat;
confp->logformat = NULL;
archiverc = confp->archiverc;
@ -2533,10 +2453,6 @@ void freeconf(struct extparam *confp){
if(confp->httprules) freehttprules(confp->httprules);
confp->httprules = NULL;
#endif
if(confp->logname) free(confp->logname);
confp->logname = NULL;
if(confp->logtarget) free(confp->logtarget);
confp->logtarget = NULL;
if(confp->counterfile) free(confp->counterfile);
confp->counterfile = NULL;
if(confp->conffile) free(confp->conffile);
@ -2618,12 +2534,11 @@ int reload (void){
if(!(new = malloc(sizeof(*new)))) return -1;
*new = confdefaults;
/* what belongs to the process rather than to one reading of the file:
the open log, which a log command reopens, and the filters, a list
of static entries the TLS, PCRE and transparent code link in once */
the filters, a list of static entries the TLS, PCRE and transparent
code link in once */
new->conffile = old->conffile;
new->stringtable = old->stringtable;
new->demon = old->demon;
new->stdlog = old->stdlog;
new->filters = old->filters;
new->version = old->version + 1;
new->refs = 1; /* this reload's, until it is done with it */
@ -2658,10 +2573,8 @@ int reload (void){
free(d);
}
old->conffile = new->conffile;
old->stdlog = new->stdlog;
old->filters = new->filters;
new->conffile = NULL;
new->stdlog = NULL;
new->filters = NULL;
new->stringtable = NULL;
conf = old;
@ -2672,7 +2585,6 @@ int reload (void){
}
old->conffile = NULL;
old->stdlog = NULL;
old->filters = NULL;
old->stringtable = NULL;
confhold(old);
@ -2680,6 +2592,7 @@ int reload (void){
runconf = new;
_3proxy_mutex_unlock(&confref_mutex);
confdnscommit();
logcommit(new);
resolvmode = new->resolvmode;
/* the new services take over the listening sockets of the old ones on
the same addresses, which then stop accepting, and start */

7
src/confinit.h
View File

@ -42,7 +42,6 @@
.gracenum = 0,
.gracedelay = 0,
.maxseg = 0,
.logname = NULL,
.archiver = NULL,
.logtype = NONE,
.countertype = NONE,
@ -58,17 +57,15 @@
.pwl = NULL,
.authenticate = NULL,
.authfunc = doconnect,
.logfunc = lognone,
.logfunc = logdo,
.bandlimfunc = NULL,
.trafcountfunc = NULL,
.logtarget = NULL,
.logger = NULL,
.logformat = NULL,
.fmon = NULL,
.filters = NULL,
.authfuncs = NULL,
.stdlog = NULL,
.stringtable = NULL,
.logtime = (time_t)0,
.logdumpsrv = 0,
.logdumpcli = 0,
.delimchar = '@',

20
src/datatypes.c
View File

@ -579,19 +579,9 @@ static void * ef_server_backlog(struct node * node){
}
static void * ef_server_log(struct node * node){
if(((struct srvparam *)node->value) -> logfunc == lognone) return "none";
#ifndef NORADIUS
else if(((struct srvparam *)node->value) -> logfunc == logradius) return "radius";
#endif
else if(((struct srvparam *)node->value) -> logfunc == logstdout)
return (((struct srvparam *)node->value) -> logtarget)?"file":"stdout";
#ifndef _WIN32
else if(((struct srvparam *)node->value) -> logfunc == logsyslog) return "syslog";
#endif
#ifdef WITH_ODBC
else if(((struct srvparam *)node->value) -> logfunc == logsql) return "odbc";
#endif
return NULL;
struct logger *lg = ((struct srvparam *)node->value) -> logger;
return lg? (void *)lg->type->name : NULL;
}
static void * ef_server_logformat(struct node * node){
@ -608,7 +598,9 @@ static void * ef_server_replacement(struct node * node){
}
static void * ef_server_logtarget(struct node * node){
return ((struct srvparam *)node->value) -> logtarget;
struct logger *lg = ((struct srvparam *)node->value) -> logger;
return (lg && *lg->selector)? lg->selector : NULL;
}

646
src/log.c
View File

@ -10,17 +10,22 @@
#include "proxy.h"
_3proxy_mutex_t log_mutex;
_3proxy_mutex_t log_mutex; /* the list of loggers and what they are held by */
/* the connection lines with no connection of their own are formatted for */
struct clientparam logparam;
struct srvparam logsrv;
/* writes failed in a row before a log is closed and opened again, and how
long one that could not be opened again waits before the next attempt */
#define LOGERRORS 3
#define LOGRETRY 60
void dolog(struct clientparam * param, const unsigned char *s){
if(param && param->srv)param->srv->logfunc(param, s);
else logstdout(NULL, s);
else logerror(s);
}
@ -71,12 +76,6 @@ int dobuf2(struct clientparam * param, unsigned char * buf, const unsigned char
struct timezone tz;
#endif
if(!logparam.srv) {
srvinit(&logsrv, &logparam);
/* not a service: it holds no configuration, and the first one
is never freed, only what it holds */
logsrv.config = &confboot;
}
if(!param) param = &logparam;
@ -317,51 +316,622 @@ int dobuf2(struct clientparam * param, unsigned char * buf, const unsigned char
return i;
}
int dobuf(struct clientparam * param, unsigned char * buf, const unsigned char *s, const unsigned char * doublec){
int timechanged (time_t oldtime, time_t newtime, ROTATION lt){
struct tm tmold;
struct tm *tm;
tm = localtime(&oldtime);
if(!tm) return 0;
tmold = *tm;
tm = localtime(&newtime);
if(!tm) return 0;
switch(lt){
case MINUTELY:
if(tm->tm_min != tmold.tm_min)return 1;
break;
case HOURLY:
if(tm->tm_hour != tmold.tm_hour)return 1;
break;
case DAILY:
if(tm->tm_yday != tmold.tm_yday)return 1;
break;
case MONTHLY:
if(tm->tm_mon != tmold.tm_mon)return 1;
break;
case ANNUALLY:
if(tm->tm_year != tmold.tm_year)return 1;
break;
case WEEKLY:
if(((newtime - oldtime) > (60*60*24*7))
|| tm->tm_wday < tmold.tm_wday
|| (tm->tm_wday == tmold.tm_wday && (newtime - oldtime) > (60*60*24*6))
)return 1;
break;
default:
break;
}
return 0;
}
unsigned char * dologname (unsigned char *buf, unsigned char *name, const unsigned char *ext, ROTATION lt, time_t t) {
struct tm *ts;
static const char * const rot_fmt[] = {
[NONE] = "%s",
[ANNUALLY] = "%s.%04d",
[MONTHLY] = "%s.%04d.%02d",
[DAILY] = "%s.%04d.%02d.%02d",
[HOURLY] = "%s.%04d.%02d.%02d-%02d",
[MINUTELY] = "%s.%04d.%02d.%02d-%02d.%02d",
};
ts = localtime(&t);
if(strlen((char *)name) >= 4096){
*buf = 0;
return buf;
}
if(strchr((char *)name, '%')){
dobuf2(NULL, buf, NULL, NULL, ts, (char *)name);
}
else if(lt == WEEKLY){
t = t - (ts->tm_wday * (60*60*24));
ts = localtime(&t);
sprintf((char *)buf, "%s.%04d.%02d.%02d", name, ts->tm_year+1900, ts->tm_mon+1, ts->tm_mday);
}
else if((unsigned)lt < sizeof(rot_fmt)/sizeof(rot_fmt[0]) && rot_fmt[lt]){
sprintf((char *)buf, rot_fmt[lt], name, ts->tm_year+1900, ts->tm_mon+1, ts->tm_mday, ts->tm_hour, ts->tm_min);
}
if(ext){
strcat((char *)buf, ".");
strcat((char *)buf, (char *)ext);
}
return buf;
}
/* The line for a connection, its length: with nothing else done, as a log
formats it. */
int logbuf(struct clientparam * param, unsigned char * buf, const unsigned char *s, const unsigned char * doublec){
struct tm* tm;
int i;
char * format;
time_t t;
int has_srv;
time(&t);
has_srv = param && param->srv;
if(has_srv){
if(param->trafcountfunc)(*param->trafcountfunc)(param);
format = param->srv->logformat?(char *)param->srv->logformat : DEFLOGFORMAT;
}
else {
format = DEFLOGFORMAT;
}
format = (param && param->srv && param->srv->logformat)?(char *)param->srv->logformat : DEFLOGFORMAT;
tm = (*format == 'G' || *format == 'g')?
gmtime(&t) : localtime(&t);
i = dobuf2(param, buf, s, doublec, tm, format + 1);
return dobuf2(param, buf, s, doublec, tm, format + 1);
}
/* The line, with the traffic counted and the statistics cleared, as logging
it does; for plugins. */
int dobuf(struct clientparam * param, unsigned char * buf, const unsigned char *s, const unsigned char * doublec){
int i;
int has_srv;
has_srv = param && param->srv;
if(has_srv && param->trafcountfunc)(*param->trafcountfunc)(param);
i = logbuf(param, buf, s, doublec);
if(has_srv) clearstat(param);
return i;
}
void lognone(struct clientparam * param, const unsigned char *s) {
static int logstdoff = 0; /* a daemon or a service: no standard output and error */
static int logticking = 0; /* logtick() runs, and flushes the files */
static struct logger *loggers = NULL;
/* the last log configured, where errors go with no standard error */
static struct logger *logerrlast = NULL;
static const struct logtype *logtypes[8];
static int nlogtypes = 0;
static int logtext(struct logger *lg, struct clientparam *param, const unsigned char *s, unsigned char *buf){
return logbuf(param, buf, s, NULL);
}
static int matchnull(const unsigned char *selector){
return !strcmp((char *)selector, "/dev/null");
}
static const struct logtype logtype_none = {
"none", matchnull, NULL, NULL, NULL, NULL, NULL, 0, 1, 0
};
static int matchstdout(const unsigned char *selector){
return !*selector;
}
static int stdwrite(FILE *fp, const unsigned char *buf){
if(logstdoff) return 0;
if(fprintf(fp, "%s\n", buf) < 0) return 1;
fflush(fp);
return 0;
}
static int stdoutwrite(struct logger *lg, struct clientparam *param, const unsigned char *buf, int len){
return stdwrite(stdout, buf);
}
static int stderrwrite(struct logger *lg, struct clientparam *param, const unsigned char *buf, int len){
return stdwrite(stderr, buf);
}
static const struct logtype logtype_stdout = {
"stdout", matchstdout, NULL, logtext, stdoutwrite, NULL, NULL, 0, 1, 1
};
/* errors and warnings, and the lines of a log which fails */
static const struct logtype logtype_stderr = {
"stderr", NULL, NULL, logtext, stderrwrite, NULL, NULL, 0, 1, 1
};
struct logger lognull = {NULL, &logtype_none, (unsigned char *)"/dev/null"};
static struct logger logstdout = {NULL, &logtype_stdout, (unsigned char *)""};
static struct logger logstderr = {NULL, &logtype_stderr, (unsigned char *)"stderr"};
#ifndef _WIN32
/* openlog() is one for the process: each syslog logger sets its own ident
before it writes */
static _3proxy_mutex_t syslog_mutex;
static const char *syslogident = NULL;
static int matchsyslog(const unsigned char *selector){
return *selector == '@';
}
static int sysloginit(struct logger *lg){
_3proxy_mutex_lock(&syslog_mutex);
/* connected now: after a chroot there is no /dev/log to find */
syslogident = (char *)lg->selector + 1;
openlog(syslogident, LOG_PID | LOG_NDELAY, LOG_DAEMON);
_3proxy_mutex_unlock(&syslog_mutex);
return 0;
}
static int syslogwrite(struct logger *lg, struct clientparam *param, const unsigned char *buf, int len){
_3proxy_mutex_lock(&syslog_mutex);
if(syslogident != (char *)lg->selector + 1){
syslogident = (char *)lg->selector + 1;
openlog(syslogident, LOG_PID | LOG_NDELAY, LOG_DAEMON);
}
syslog(LOG_INFO, "%s", buf);
_3proxy_mutex_unlock(&syslog_mutex);
return 0;
}
static const struct logtype logtype_syslog = {
"syslog", matchsyslog, sysloginit, logtext, syslogwrite, NULL, NULL, 0, 1, 1
};
#endif
/* a file, named after the time it was opened if rotated */
#define LOGNAMESIZE 8192
static int matchfile(const unsigned char *selector){
return 1;
}
static int fileinit(struct logger *lg){
unsigned char *name;
FILE *fp;
int err;
if(!(name = malloc(LOGNAMESIZE))) return 21;
dologname(name, lg->selector, NULL, lg->rotation, lg->rotated);
errno = ENAMETOOLONG;
fp = *name? fopen((char *)name, "a") : NULL;
err = errno;
free(name);
errno = err;
if(!fp) return 1;
lg->data = fp;
return 0;
}
static int filewrite(struct logger *lg, struct clientparam *param, const unsigned char *buf, int len){
FILE *fp = (FILE *)lg->data;
if(!fp) return 1;
if(fprintf(fp, "%s\n", buf) < 0) return 1;
/* with nobody to flush it later, a standalone service */
if(!logticking && fflush(fp)) return 1;
return 0;
}
static void fileclose(struct logger *lg){
if(lg->data) fclose((FILE *)lg->data);
lg->data = NULL;
}
/* the seconds in a period of rotation */
static time_t rotperiod(ROTATION rt){
time_t t = 1;
switch(rt){
case ANNUALLY:
t = t * 12;
case MONTHLY:
t = t * 4;
case WEEKLY:
t = t * 7;
case DAILY:
t = t * 24;
case HOURLY:
t = t * 60;
case MINUTELY:
t = t * 60;
default:
break;
}
return t;
}
/* Once the period changes, the file is reopened under its new name, the
one rotate periods old removed, and the one just closed passed to the
archiver. */
static void filetick(struct logger *lg, time_t t){
unsigned char *name, *cmd;
const unsigned char *ext;
FILE *fp;
time_t period;
size_t len, add;
int i;
if(lg->data) fflush((FILE *)lg->data);
if(!lg->reopen && !timechanged(lg->rotated, t, lg->rotation)) return;
if(!(name = malloc(LOGNAMESIZE))) return;
dologname(name, lg->selector, NULL, lg->rotation, t);
/* the old one kept if the new one cannot be opened */
if(*name && (fp = fopen((char *)name, "a"))){
if(lg->data) fclose((FILE *)lg->data);
lg->data = fp;
lg->failed = lg->errors = 0;
}
lg->rotated = t;
lg->reopen = 0;
ext = (lg->archiver && lg->archiverc > 1)? lg->archiver[1] : NULL;
/* a name is at most 4096 bytes, its rotation suffix and ext to come */
if(lg->rotation == NONE || !lg->rotate || (ext && strlen((char *)ext) > 255)){
free(name);
return;
}
period = rotperiod(lg->rotation);
dologname(name, lg->selector, ext, lg->rotation, (lg->rotated - period * lg->rotate));
remove((char *)name);
if(lg->archiver && (cmd = malloc(4 * LOGNAMESIZE))){
*cmd = 0;
len = 0;
for(i = 2; i < lg->archiverc && len < 512; i++){
cmd[len++] = ' ';
cmd[len] = 0;
if(!strcmp((char *)lg->archiver[i], "%A") || !strcmp((char *)lg->archiver[i], "%F")){
dologname(name, lg->selector, (lg->archiver[i][1] == 'A')? ext : NULL, lg->rotation, (lg->rotated - period));
add = strlen((char *)name);
if(len + add + 3 >= 4 * LOGNAMESIZE) break;
cmd[len++] = '\"';
memcpy(cmd + len, name, add);
len += add;
cmd[len++] = '\"';
}
else {
add = strlen((char *)lg->archiver[i]);
if(len + add + 1 >= 4 * LOGNAMESIZE) break;
memcpy(cmd + len, lg->archiver[i], add);
len += add;
}
cmd[len] = 0;
}
if(len > 1 && system((char *)cmd + 1)){}
free(cmd);
}
free(name);
}
static const struct logtype logtype_file = {
"file", matchfile, fileinit, logtext, filewrite, fileclose, filetick, 0, 0, 1
};
/* The types a selector is matched against, the file last: ODBC and RADIUS,
which only 3proxy itself has, are added by it. */
void logtypeadd(const struct logtype *type){
if(nlogtypes < (int)(sizeof(logtypes)/sizeof(logtypes[0]))) logtypes[nlogtypes++] = type;
}
static const struct logtype *logmatch(const unsigned char *selector){
static const struct logtype * const builtin[] = {
&logtype_none, &logtype_stdout,
#ifndef _WIN32
&logtype_syslog,
#endif
};
int i;
for(i = 0; i < (int)(sizeof(builtin)/sizeof(builtin[0])); i++)
if(builtin[i]->match(selector)) return builtin[i];
for(i = 0; i < nlogtypes; i++)
if(logtypes[i]->match && logtypes[i]->match(selector)) return logtypes[i];
return &logtype_file;
}
/* The standard loggers, before anything is logged. */
void loginit(void){
static int done = 0;
if(done) return;
done = 1;
_3proxy_mutex_init(&log_mutex);
_3proxy_mutex_init(&lognull.mutex);
_3proxy_mutex_init(&logstdout.mutex);
_3proxy_mutex_init(&logstderr.mutex);
lognull.next = &logstdout;
loggers = &lognull;
srvinit(&logsrv, &logparam);
/* not a service: it holds no configuration and no log, and the first
configuration is never freed, only what it holds */
logsrv.config = &confboot;
logsrv.logger = NULL;
#ifndef _WIN32
_3proxy_mutex_init(&syslog_mutex);
/* kept for the life of the process, as every syslog logger is */
(void)logget((const unsigned char *)"@3proxy", NONE);
#endif
}
/* The logger named so, opened if none is: held until logput(). NULL, with
errno set, if it cannot be opened. */
struct logger *logget(const unsigned char *selector, ROTATION rotation){
struct logger *lg;
int err = 0;
_3proxy_mutex_lock(&log_mutex);
for(lg = loggers; lg; lg = lg->next){
if(!strcmp((char *)lg->selector, (char *)selector)){
lg->refs++;
_3proxy_mutex_unlock(&log_mutex);
return lg;
}
}
if(!(lg = calloc(1, sizeof(*lg))) || !(lg->selector = (unsigned char *)strdup((char *)selector))){
if(lg) free(lg);
_3proxy_mutex_unlock(&log_mutex);
errno = ENOMEM;
return NULL;
}
lg->type = logmatch(selector);
lg->rotation = rotation;
lg->rotated = time(NULL);
_3proxy_mutex_init(&lg->mutex);
/* < 0: not to be reached now, and tried again later */
if(lg->type->init && (err = lg->type->init(lg)) < 0){
lg->failed = 1;
lg->failtime = lg->rotated;
}
else if(err){
err = errno;
_3proxy_mutex_unlock(&log_mutex);
_3proxy_mutex_destroy(&lg->mutex);
free(lg->selector);
free(lg);
errno = err;
return NULL;
}
lg->refs = 1;
lg->next = loggers;
loggers = lg;
_3proxy_mutex_unlock(&log_mutex);
return lg;
}
void logref(struct logger *lg){
if(!lg) return;
_3proxy_mutex_lock(&log_mutex);
lg->refs++;
_3proxy_mutex_unlock(&log_mutex);
}
static void logfreearchiver(struct logger *lg){
int i;
if(!lg->archiver) return;
for(i = 0; i < lg->archiverc; i++) if(lg->archiver[i]) free(lg->archiver[i]);
free(lg->archiver);
lg->archiver = NULL;
lg->archiverc = 0;
}
/* The last to let go of a logger closes it, unless it is a standard one. */
void logput(struct logger *lg){
struct logger **lp;
int gone = 0;
if(!lg) return;
_3proxy_mutex_lock(&log_mutex);
if(--lg->refs <= 0 && !lg->type->standard){
for(lp = &loggers; *lp; lp = &(*lp)->next){
if(*lp == lg){
*lp = lg->next;
gone = 1;
break;
}
}
}
_3proxy_mutex_unlock(&log_mutex);
if(!gone) return;
if(lg->type->close) lg->type->close(lg);
_3proxy_mutex_destroy(&lg->mutex);
logfreearchiver(lg);
free(lg->selector);
free(lg);
}
/* Where errors go: standard error, or for a daemon the last log
configured, which a text one has to be. Held until logput(). */
static struct logger *logerrget(void){
struct logger *lg;
_3proxy_mutex_lock(&log_mutex);
lg = logstdoff? logerrlast : &logstderr;
if(lg) lg->refs++;
_3proxy_mutex_unlock(&log_mutex);
return lg;
}
void logerrset(struct logger *lg){
struct logger *old;
if(lg && !lg->type->text) lg = NULL;
_3proxy_mutex_lock(&log_mutex);
if(lg) lg->refs++;
old = logerrlast;
logerrlast = lg;
_3proxy_mutex_unlock(&log_mutex);
logput(old);
}
/* For a daemon or a service: standard output is no log, and errors go to
the last log configured. */
void logstdclose(void){
if(logstdoff) return;
fflush(stdout);
fflush(stderr);
logstdoff = 1;
}
static void logwrite(struct logger *lg, struct clientparam *param, const unsigned char *buf, int len);
/* The line of a log which failed, to standard error, or to where errors go.
Not to another log of the same: once there it would come back. */
static void logfallback(struct logger *lg, struct clientparam *param, const unsigned char *buf, int len){
struct logger *to;
if(len < 0) return;
if(!(to = logerrget())) return;
if(to != lg && !to->failed) logwrite(to, param, buf, len);
logput(to);
}
static void logwrite(struct logger *lg, struct clientparam *param, const unsigned char *buf, int len){
int res = 0, failed, report = 0;
time_t t;
_3proxy_mutex_lock(&lg->mutex);
if(lg->failed && (t = time(NULL)) - lg->failtime >= LOGRETRY){
if(lg->type->init && lg->type->init(lg)) lg->failtime = t;
else lg->failed = lg->errors = 0;
}
if(!(failed = lg->failed) && lg->type->write){
if((res = lg->type->write(lg, param, buf, len))){
/* open again what keeps failing, and if it cannot be
opened, write elsewhere for a while */
if(++lg->errors >= LOGERRORS){
lg->errors = 0;
if(lg->type->close) lg->type->close(lg);
if(lg->type->init && lg->type->init(lg)){
lg->failed = 1;
lg->failtime = time(NULL);
report = 1;
}
}
}
else lg->errors = 0;
}
_3proxy_mutex_unlock(&lg->mutex);
if(failed || res) logfallback(lg, param, buf, len);
if(report){
unsigned char msg[300];
sprintf((char *)msg, "Log %.200s failed, its lines go to the error log", lg->selector);
logerror(msg);
}
}
/* The log function of the services, unless a plugin puts its own before
it: the traffic counted, the line written to the service's log, the
statistics cleared. */
void logdo(struct clientparam * param, const unsigned char *s){
struct logger *lg = param->srv? param->srv->logger : NULL;
int len = -1;
if(param->trafcountfunc)(*param->trafcountfunc)(param);
if(lg && !param->nolog && lg->type->write){
if(lg->type->format) len = lg->type->format(lg, param, s, param->tmpbuf);
if(len >= 0 || !lg->type->format) logwrite(lg, param, param->tmpbuf, len);
}
clearstat(param);
}
void logstdout(struct clientparam * param, const unsigned char *s) {
FILE *log;
unsigned char *tmpbuf;
/* An error or a warning, with no connection: where errors go. */
void logerror(const unsigned char *s){
struct logger *lg;
unsigned char *buf;
int len;
/* with no connection, an error from the main thread */
tmpbuf = param? param->tmpbuf : logparam.tmpbuf;
dobuf(param, tmpbuf, s, NULL);
log = (param && param->srv && param->srv->stdlog)?param->srv->stdlog:runconf->stdlog?runconf->stdlog:stdout;
if(!param || !param->nolog)if(fprintf(log, "%s\n", tmpbuf) < 0) {
perror("printf()");
};
if(log != runconf->stdlog)fflush(log);
if(!(lg = logerrget())) return;
if(lg->type->format && lg->type->write && (buf = malloc(CLIENTTMPBUFSIZE))){
len = lg->type->format(lg, &logparam, s, buf);
if(len >= 0) logwrite(lg, &logparam, buf, len);
free(buf);
}
logput(lg);
}
#ifndef _WIN32
void logsyslog(struct clientparam * param, const unsigned char *s) {
dobuf(param, param->tmpbuf, s, NULL);
if(!param->nolog)syslog(LOG_INFO, "%s", param->tmpbuf);
}
#endif
/* What a configuration says of its last log, once it is in force: the
rotation, and that errors go there for a daemon. */
void logcommit(struct extparam *c){
struct logger *lg = c->logger;
unsigned char **archiver = NULL;
int i, archiverc = 0;
logerrset(lg);
if(!lg || lg->type != &logtype_file) return;
if(c->archiver && c->archiverc > 0 && (archiver = calloc(c->archiverc, sizeof(*archiver)))){
for(archiverc = 0; archiverc < c->archiverc; archiverc++){
if(!(archiver[archiverc] = (unsigned char *)strdup((char *)c->archiver[archiverc]))) break;
}
if(archiverc < c->archiverc){
for(i = 0; i < archiverc; i++) free(archiver[i]);
free(archiver);
archiver = NULL;
archiverc = 0;
}
}
_3proxy_mutex_lock(&log_mutex);
_3proxy_mutex_lock(&lg->mutex);
if(lg->rotation != c->logtype) lg->reopen = 1;
lg->rotation = c->logtype;
lg->rotate = c->rotate;
logfreearchiver(lg);
lg->archiver = archiver;
lg->archiverc = archiverc;
_3proxy_mutex_unlock(&lg->mutex);
_3proxy_mutex_unlock(&log_mutex);
}
/* Rotation and flushing, for every logger: from the main loop. */
void logtick(time_t t){
struct logger *lg;
logticking = 1;
_3proxy_mutex_lock(&log_mutex);
for(lg = loggers; lg; lg = lg->next){
if(!lg->type->tick) continue;
_3proxy_mutex_lock(&lg->mutex);
lg->type->tick(lg, t);
_3proxy_mutex_unlock(&lg->mutex);
}
_3proxy_mutex_unlock(&log_mutex);
}
/* Closes every log as the process stops, its services done. */
void logfinish(void){
struct logger *lg;
_3proxy_mutex_lock(&log_mutex);
for(lg = loggers; lg; lg = lg->next){
if(!lg->type->close) continue;
_3proxy_mutex_lock(&lg->mutex);
lg->type->close(lg);
lg->failed = 1;
lg->failtime = time(NULL);
_3proxy_mutex_unlock(&lg->mutex);
}
_3proxy_mutex_unlock(&log_mutex);
}

54
src/mainconf.c
View File

@ -150,7 +150,6 @@ static void srvdiscard(struct srvstart *s){
srvfree(&s->srv);
if(s->cbc_string) free(s->cbc_string);
if(s->cbl_string) free(s->cbl_string);
if(s->fp) fclose(s->fp);
}
#ifndef STDMAIN
@ -178,7 +177,6 @@ static int srvprepare(struct srvstart *s, int argc, char **argv){
#ifdef STDMAIN
#ifndef _WIN32
" -I inetd mode (requires real socket, doesn't work with TTY)\n"
" -l@IDENT log to syslog IDENT\n"
#endif
" -d go to background (daemon)\n"
#else
@ -205,8 +203,11 @@ static int srvprepare(struct srvstart *s, int argc, char **argv){
#endif
"-g(GRACE_TRAFF,GRACE_NUM,GRACE_DELAY) - delay GRACE_DELAY milliseconds before polling if average polling size below GRACE_TRAFF bytes and GRACE_NUM read operations in single directions are detected within 1 second to minimize polling\n"
" -fFORMAT logging format (see documentation)\n"
" -l log to stderr\n"
" -l log to stdout\n"
" -lFILENAME log to FILENAME\n"
#ifndef _WIN32
" -l@IDENT log to syslog IDENT\n"
#endif
" -b(BUFSIZE) size of network buffer, at most and by default 16384\n"
" -S(STACKSIZE) value to add to default client thread stack size\n"
" -t be silent (do not log service start/stop)\n"
@ -228,7 +229,6 @@ static int srvprepare(struct srvstart *s, int argc, char **argv){
#endif
s->cbc_string = s->cbl_string = NULL;
s->fp = NULL;
s->iscbc = s->iscbl = 0;
#ifdef STDMAIN
#ifndef _WIN32
@ -236,6 +236,7 @@ static int srvprepare(struct srvstart *s, int argc, char **argv){
#endif
#endif
srvinit(srv, defparam);
logref(srv->logger); /* until srvfree() */
#ifndef STDMAIN
confhold(srv->config); /* until srvfree() */
#endif
@ -296,14 +297,16 @@ static int srvprepare(struct srvstart *s, int argc, char **argv){
}
#else
srv->needuser = 0;
_3proxy_mutex_init(&log_mutex);
#endif
for (i=1; i<argc; i++) {
if(*argv[i]=='-') {
switch(argv[i][1]) {
case 'd':
if(!conf->demon)daemonize();
if(!conf->demon){
daemonize();
logstdclose();
}
conf->demon = 1;
break;
#if defined SO_BINDTODEVICE || defined IP_BOUND_IF
@ -313,27 +316,18 @@ static int srvprepare(struct srvstart *s, int argc, char **argv){
break;
#endif
case 'l':
srv->logfunc = logstdout;
if(srv->logtarget) free(srv->logtarget);
srv->logtarget = (unsigned char *)strdup(argv[i] + 2);
if(argv[i][2]) {
if(argv[i][2]=='@'){
#ifdef STDMAIN
#ifndef _WIN32
openlog(argv[i]+3, LOG_PID, LOG_DAEMON);
srv->logfunc = logsyslog;
#endif
#endif
{
struct logger *lg;
/* the same log the log command, or another service,
opened is shared with it */
if(!(lg = logget((unsigned char *)argv[i] + 2, NONE))){
perror(argv[i] + 2);
return 1;
}
else {
s->fp = fopen(argv[i] + 2, "a");
if (s->fp) {
srv->stdlog = s->fp;
}
}
logput(srv->logger);
srv->logger = lg;
if(srv->stacksize < lg->type->stacksize) srv->stacksize = lg->type->stacksize;
}
break;
case 'i':
@ -704,7 +698,9 @@ void srvinit(struct srvparam * srv, struct clientparam *param){
memset(srv, 0, sizeof(struct srvparam));
srv->version = conf->version;
srv->paused = conf->paused;
srv->logfunc = conf->havelog?conf->logfunc:lognone;
srv->logfunc = conf->logfunc;
/* not held yet: srvprepare() takes it */
srv->logger = conf->logger? conf->logger : &lognull;
srv->noforce = conf->noforce;
srv->logformat = conf->logformat? (unsigned char *)strdup((char *)conf->logformat) : NULL;
srv->authfunc = conf->authfunc;
@ -719,9 +715,6 @@ void srvinit(struct srvparam * srv, struct clientparam *param){
srv->maxseg = conf->maxseg;
srv->delimchar = conf->delimchar;
srv->time_start = time(NULL);
if(conf->havelog && conf->logtarget){
srv->logtarget = (unsigned char *)strdup((char *)conf->logtarget);
}
srv->srvsock = INVALID_SOCKET;
srv->logdumpsrv = conf->logdumpsrv;
srv->logdumpcli = conf->logdumpcli;
@ -835,7 +828,8 @@ void srvfree(struct srvparam * srv){
_3proxy_mutex_destroy(&srv->counter_mutex);
_3proxy_sem_destroy(srv->childslots);
if(srv->target) free(srv->target);
if(srv->logtarget) free(srv->logtarget);
logput(srv->logger);
srv->logger = NULL;
if(srv->logformat) free(srv->logformat);
if(srv->nonprintable) free(srv->nonprintable);
#if defined SO_BINDTODEVICE || defined IP_BOUND_IF

27
src/proxy.h
View File

@ -341,16 +341,25 @@ int hascap(const unsigned char *line, const char *cap);
void dolog(struct clientparam * param, const unsigned char *s);
int dobuf(struct clientparam * param, unsigned char * buf, const unsigned char *s, const unsigned char * doublec);
int dobuf2(struct clientparam * param, unsigned char * buf, const unsigned char *s, const unsigned char * doublec, struct tm* tm, char * format);
void logstdout(struct clientparam * param, const unsigned char *s);
void logsyslog(struct clientparam * param, const unsigned char *s);
void lognone(struct clientparam * param, const unsigned char *s);
void logradius(struct clientparam * param, const unsigned char *s);
#ifndef NOSQL
void logsql(struct clientparam * param, const unsigned char *s);
int init_sql(char * s);
void close_sql();
int logbuf(struct clientparam * param, unsigned char * buf, const unsigned char *s, const unsigned char * doublec);
void logdo(struct clientparam * param, const unsigned char *s);
void logerror(const unsigned char *s);
void loginit(void);
void logtypeadd(const struct logtype *type);
struct logger *logget(const unsigned char *selector, ROTATION rotation);
void logref(struct logger *lg);
void logput(struct logger *lg);
void logcommit(struct extparam *c);
void logerrset(struct logger *lg);
void logstdclose(void);
void logtick(time_t t);
void logfinish(void);
int timechanged (time_t oldtime, time_t newtime, ROTATION lt);
extern struct logger lognull;
#ifdef WITH_ODBC
extern const struct logtype logtype_odbc;
#endif
extern const struct logtype logtype_radius;
int doconnect(struct clientparam * param);
int alwaysauth(struct clientparam * param);
int ipauth(struct clientparam * param);

4
src/proxymain.c
View File

@ -25,7 +25,6 @@ struct srvstart {
struct srvparam srv;
struct clientparam defparam;
unsigned char *cbc_string, *cbl_string;
FILE *fp;
int isudp, iscbc, iscbl;
const struct udpservice *udp;
#ifndef _WIN32
@ -220,8 +219,11 @@ int WinMain(HINSTANCE hInstance, HINSTANCE hPrevInstance, LPWSTR lpCmdLine, int
#endif
_3proxy_mutex_init(&tpool.mutex);
loginit();
if((res = srvprepare(&s, argc, argv))) return res;
/* errors go to the service's log once there is no standard error */
logerrset(s.srv.logger);
#ifndef _WIN32
if(s.inetd) {
fcntl(0,F_SETFL,O_NONBLOCK | fcntl(0,F_GETFL));

171
src/sql.c
View File

@ -1,152 +1,131 @@
#include "proxy.h"
#ifdef WITH_ODBC
SQLHENV henv = NULL;
SQLHSTMT hstmt = NULL;
SQLHDBC hdbc = NULL;
char * sqlstring = NULL;
/* ODBC drivers require noticeably more stack than the file logger */
#define LOGSTACKSIZE 32768
struct logodbc {
SQLHENV henv;
SQLHDBC hdbc;
SQLHSTMT hstmt;
};
void close_sql(){
if(hstmt) {
SQLFreeHandle(SQL_HANDLE_STMT, hstmt);
hstmt = NULL;
static void odbcdisconnect(struct logodbc *d){
if(d->hstmt) {
SQLFreeHandle(SQL_HANDLE_STMT, d->hstmt);
d->hstmt = NULL;
}
if(hdbc){
SQLDisconnect(hdbc);
SQLFreeHandle(SQL_HANDLE_DBC, hdbc);
hdbc = NULL;
if(d->hdbc){
SQLDisconnect(d->hdbc);
SQLFreeHandle(SQL_HANDLE_DBC, d->hdbc);
d->hdbc = NULL;
}
if(henv) {
SQLFreeHandle(SQL_HANDLE_ENV, henv);
henv = NULL;
if(d->henv) {
SQLFreeHandle(SQL_HANDLE_ENV, d->henv);
d->henv = NULL;
}
}
int attempt = 0;
time_t attempt_time = 0;
int init_sql(char * s){
/* &DATASOURCE,USERNAME,PASSWORD */
static int odbcconnect(struct logger *lg){
struct logodbc *d = (struct logodbc *)lg->data;
SQLRETURN retcode;
char * datasource;
char * username;
char * password;
char * string;
if(!s) return 0;
if(!sqlstring || strcmp(sqlstring, s)){
string = sqlstring;
sqlstring=strdup(s);
if(string)free(string);
}
if(hstmt || hdbc || henv) close_sql();
attempt++;
attempt_time = time(0);
if(!henv){
retcode = SQLAllocHandle(SQL_HANDLE_ENV, SQL_NULL_HANDLE, &henv);
if (!henv || (retcode != SQL_SUCCESS && retcode != SQL_SUCCESS_WITH_INFO)){
henv = NULL;
if(d->hstmt || d->hdbc || d->henv) odbcdisconnect(d);
if(!d->henv){
retcode = SQLAllocHandle(SQL_HANDLE_ENV, SQL_NULL_HANDLE, &d->henv);
if (!d->henv || (retcode != SQL_SUCCESS && retcode != SQL_SUCCESS_WITH_INFO)){
d->henv = NULL;
return 0;
}
retcode = SQLSetEnvAttr(henv, SQL_ATTR_ODBC_VERSION, (void*)SQL_OV_ODBC3, 0);
retcode = SQLSetEnvAttr(d->henv, SQL_ATTR_ODBC_VERSION, (void*)SQL_OV_ODBC3, 0);
if (retcode != SQL_SUCCESS && retcode != SQL_SUCCESS_WITH_INFO) {
return 0;
}
}
if(!hdbc){
retcode = SQLAllocHandle(SQL_HANDLE_DBC, henv, &hdbc);
if (!hdbc || (retcode != SQL_SUCCESS && retcode != SQL_SUCCESS_WITH_INFO)) {
hdbc = NULL;
SQLFreeHandle(SQL_HANDLE_ENV, henv);
henv = NULL;
if(!d->hdbc){
retcode = SQLAllocHandle(SQL_HANDLE_DBC, d->henv, &d->hdbc);
if (!d->hdbc || (retcode != SQL_SUCCESS && retcode != SQL_SUCCESS_WITH_INFO)) {
d->hdbc = NULL;
SQLFreeHandle(SQL_HANDLE_ENV, d->henv);
d->henv = NULL;
return 0;
}
SQLSetConnectAttr(hdbc, SQL_LOGIN_TIMEOUT, (void*)15, 0);
SQLSetConnectAttr(d->hdbc, SQL_LOGIN_TIMEOUT, (void*)15, 0);
}
string = strdup(sqlstring);
string = strdup((char *)lg->selector + 1);
if(!string) return 0;
datasource = strtok(string, ",");
username = strtok(NULL, ",");
password = strtok(NULL, ",");
if(!datasource) datasource = "";
/* Connect to data source */
retcode = SQLConnect(hdbc, (SQLCHAR*) datasource, (SQLSMALLINT)strlen(datasource),
retcode = SQLConnect(d->hdbc, (SQLCHAR*) datasource, (SQLSMALLINT)strlen(datasource),
(SQLCHAR*) username, (SQLSMALLINT)((username)?strlen(username):0),
(SQLCHAR*) password, (SQLSMALLINT)((password)?strlen(password):0));
free(string);
if (retcode != SQL_SUCCESS && retcode != SQL_SUCCESS_WITH_INFO){
SQLFreeHandle(SQL_HANDLE_DBC, hdbc);
hdbc = NULL;
SQLFreeHandle(SQL_HANDLE_ENV, henv);
henv = NULL;
SQLFreeHandle(SQL_HANDLE_DBC, d->hdbc);
d->hdbc = NULL;
SQLFreeHandle(SQL_HANDLE_ENV, d->henv);
d->henv = NULL;
return 0;
}
retcode = SQLAllocHandle(SQL_HANDLE_STMT, hdbc, &hstmt);
retcode = SQLAllocHandle(SQL_HANDLE_STMT, d->hdbc, &d->hstmt);
if (retcode != SQL_SUCCESS && retcode != SQL_SUCCESS_WITH_INFO){
close_sql();
odbcdisconnect(d);
return 0;
}
return 1;
}
void sqlerr (char *buf){
if(conf->stdlog){
fprintf(conf->stdlog, "%s\n", buf);
fflush(conf->stdlog);
}
_3proxy_mutex_unlock(&log_mutex);
static int odbcmatch(const unsigned char *selector){
return *selector == '&';
}
unsigned char statbuf[8192];
/* A data source down is not an error of the configuration: the log
connects again later. */
static int odbcinit(struct logger *lg){
if(!lg->data && !(lg->data = calloc(1, sizeof(struct logodbc)))) return 21;
return odbcconnect(lg)? 0 : -1;
}
void logsql(struct clientparam * param, const unsigned char *s) {
static int odbcformat(struct logger *lg, struct clientparam *param, const unsigned char *s, unsigned char *buf){
return logbuf(param, buf, s, (unsigned char *)"\'");
}
static int odbcwrite(struct logger *lg, struct clientparam *param, const unsigned char *buf, int len){
struct logodbc *d = (struct logodbc *)lg->data;
SQLRETURN ret;
int len;
if(param->nolog) return;
_3proxy_mutex_lock(&log_mutex);
len = dobuf(param, statbuf, s, (unsigned char *)"\'");
if(attempt > 5){
time_t t;
t = time(0);
if (t - attempt_time < 180){
sqlerr((char *)statbuf);
return;
}
}
if(!hstmt){
if(!init_sql(sqlstring)) {
sqlerr((char *)statbuf);
return;
}
}
if(hstmt){
ret = SQLExecDirect(hstmt, (SQLCHAR *)statbuf, (SQLINTEGER)len);
if(!d || !d->hstmt) return 1;
ret = SQLExecDirect(d->hstmt, (SQLCHAR *)buf, (SQLINTEGER)len);
if(ret != SQL_SUCCESS && ret != SQL_SUCCESS_WITH_INFO){
close_sql();
if(!init_sql(sqlstring)){
sqlerr((char *)statbuf);
return;
/* the connection may be gone: once more on a new one */
if(!odbcconnect(lg)) return 1;
ret = SQLExecDirect(d->hstmt, (SQLCHAR *)buf, (SQLINTEGER)len);
if(ret != SQL_SUCCESS && ret != SQL_SUCCESS_WITH_INFO) return 1;
}
if(hstmt) {
ret = SQLExecDirect(hstmt, (SQLCHAR *)statbuf, (SQLINTEGER)len);
if(ret != SQL_SUCCESS && ret != SQL_SUCCESS_WITH_INFO){
sqlerr((char *)statbuf);
return;
}
attempt = 0;
}
}
attempt = 0;
}
_3proxy_mutex_unlock(&log_mutex);
return 0;
}
static void odbcclose(struct logger *lg){
if(!lg->data) return;
odbcdisconnect((struct logodbc *)lg->data);
free(lg->data);
lg->data = NULL;
}
const struct logtype logtype_odbc = {
"odbc", odbcmatch, odbcinit, odbcformat, odbcwrite, odbcclose, NULL, LOGSTACKSIZE, 0, 0
};
#endif

55
src/structures.h
View File

@ -244,6 +244,7 @@ struct symbol;
struct pluginlink;
struct srvparam;
struct listener;
struct logger;
typedef void (*LOGFUNC)(struct clientparam * param, const unsigned char *);
typedef int (*AUTHFUNC)(struct clientparam * param);
@ -624,6 +625,47 @@ struct hashtable {
uint32_t entropy;
};
/* A log, named by the string the log command or -l gives it: "" standard
output, "/dev/null" none, "@IDENT" syslog, "&DSN" ODBC, "radius" RADIUS
accounting, anything else a file. One logger serves every service and
configuration naming it the same way, and is closed once none uses it,
the standard ones (none, standard output and error, syslog) excepted. */
struct logtype {
const char *name;
int (*match)(const unsigned char *selector);
/* opens what it writes to, lg->data: 0, an error, or < 0 if it cannot
be reached now but is to be tried again */
int (*init)(struct logger *lg);
/* the line for a connection into buf, CLIENTTMPBUFSIZE: its length, -1
for nothing to write; NULL if write() takes the connection itself */
int (*format)(struct logger *lg, struct clientparam *param, const unsigned char *s, unsigned char *buf);
/* 0, or an error */
int (*write)(struct logger *lg, struct clientparam *param, const unsigned char *buf, int len);
void (*close)(struct logger *lg);
/* every second or so: rotation, flushing */
void (*tick)(struct logger *lg, time_t t);
int stacksize; /* the client thread stack its writing needs */
int standard; /* kept open for the life of the process */
int text; /* writes a line of text: errors can go there */
};
struct logger {
struct logger *next;
const struct logtype *type;
unsigned char *selector;
void *data; /* the type's own */
int refs;
int errors; /* writes failed in a row */
int failed; /* could not be reopened: lines go to standard error */
time_t failtime;
ROTATION rotation;
int rotate, archiverc;
unsigned char **archiver;
time_t rotated; /* when the file in use was opened */
int reopen; /* the rotation changed: the file name too */
_3proxy_mutex_t mutex; /* writing, reopening */
};
struct srvparam {
struct sockfuncs so;
struct srvparam *next;
@ -684,7 +726,7 @@ struct srvparam {
_3proxy_mutex_t counter_mutex;
_3proxy_sem_t childslots; /* maxchild of them, one held by each child */
struct pollfd fds;
FILE *stdlog;
struct logger *logger; /* the log it writes to, held until srvfree() */
unsigned char * target;
#if defined SO_BINDTODEVICE || defined IP_BOUND_IF
char * ibindtodevice;
@ -705,7 +747,6 @@ struct srvparam {
struct auth *authfuncs;
struct filter *filter;
unsigned char * logformat;
unsigned char * logtarget;
unsigned char * nonprintable;
uint16_t targetport;
unsigned char replace;
@ -902,8 +943,8 @@ struct extparam {
int poolmax, pooltimeout; /* threadpool: idle workers kept, -1 automatic */
int gracetraf, gracenum, gracedelay;
int maxseg;
unsigned char *logname, **archiver;
ROTATION logtype, countertype;
unsigned char **archiver;
ROTATION logtype, countertype; /* logtype: the rotation of the last log */
char * counterfile;
PROXYSOCKADDRTYPE intsa;
#ifndef NOIPV6
@ -916,13 +957,12 @@ struct extparam {
LOGFUNC logfunc;
BANDLIMFUNC bandlimfunc;
TRAFCOUNTFUNC trafcountfunc;
unsigned char *logtarget, *logformat;
unsigned char *logformat;
struct logger *logger; /* the last log, the services' default */
struct filemon * fmon;
struct filter * filters;
struct auth *authfuncs;
FILE *stdlog;
unsigned char **stringtable;
time_t logtime;
unsigned logdumpsrv, logdumpcli;
char delimchar;
struct nserver authnserver;
@ -933,7 +973,6 @@ struct extparam {
freed when none does and it is no longer the one in force */
int refs;
struct hashtable pwl_table; /* users */
int havelog; /* log was configured */
int resolvmode; /* RESOLVE_*: the last read, each service taking the one read before it */
};

135
tests/cases/logs.py Normal file
View File

@ -0,0 +1,135 @@
"""Logs: one for each log string, shared by every service naming it, kept
over a reload while something uses it and closed once nothing does. A log
which cannot be written passes its lines to standard error."""
import os
import time
def _read(path):
try:
with open(path, "rb") as fp:
return fp.read().decode("utf-8", "replace")
except OSError:
return ""
def _proxied(path, mark):
"""Whether a proxy, not the origin, logged the request marked so."""
return any(line.startswith("LOG PROXY") and mark in line
for line in _read(path).splitlines())
def _wait(cond, timeout=10.0):
deadline = time.time() + timeout
while time.time() < deadline:
if cond():
return True
time.sleep(0.05)
return cond()
def _opened(pid, path):
"""How many times the process has the file open, None without /proc."""
fds = f"/proc/{pid}/fd"
if not os.path.isdir(fds):
return None
n = 0
for fd in os.listdir(fds):
try:
if os.readlink(os.path.join(fds, fd)) == path:
n += 1
except OSError:
pass
return n
def config(origin, p1, p2, p3, adm, main, shared=None):
"""p2 and p3 log to shared with -l, if it is given, or are not there."""
lines = [f"log {main}", 'logformat "LLOG %N %T"', "auth iponly", "allow *",
"http data * /data", f"httpsrv -p{origin}", f"proxy -p{p1}"]
if shared:
lines += [f"proxy -p{p2} -l{shared}", f"proxy -p{p3} -l{shared}"]
lines.append(f"admin -p{adm}")
return "\n".join(lines) + "\n"
def run(t):
origin, p1, p2, p3, adm = (t.free_port() for _ in range(5))
first = os.path.join(t.tmpdir, "logs-first.log")
second = os.path.join(t.tmpdir, "logs-second.log")
shared = os.path.join(t.tmpdir, "logs-shared.log")
server = t.start("logs", config(origin, p1, p2, p3, adm, first, shared),
ports=[origin, p1, p2, p3, adm])
pid = server.proc.pid
def get(port, mark):
return t.http(f"http://127.0.0.1:{origin}/data?size=10&{mark}",
proxy=f"127.0.0.1:{port}").status
# --- the log command and -l ----------------------------------------
t.eq(200, get(p1, "one"), "a request through the first proxy")
t.eq(200, get(p2, "two"), "one through the second")
t.eq(200, get(p3, "three"), "one through the third")
t.eq(True, _wait(lambda: _proxied(first, "one")), "the log command's file gets its line")
t.eq(True, _wait(lambda: _proxied(shared, "two") and _proxied(shared, "three")),
"the two services with the same -l write to the same file")
t.eq(False, _proxied(first, "two"), "and not to the log command's")
t.eq(False, _proxied(shared, "one"), "nor the other way round")
n = _opened(pid, shared)
if n is not None:
t.eq(1, n, "the file named by both is opened once")
t.eq(1, _opened(pid, first), "the log command's file is open")
def reload(main, until):
t.write_config("logs", config(origin, p1, p2, p3, adm, main))
t.http(f"http://127.0.0.1:{adm}/R")
return _wait(until)
# --- a reload to another file: the old one is closed once unused -----
t.eq(True, reload(second, lambda: "Accepting connections" in _read(second)),
"the new configuration logs to the new file")
t.eq(200, get(p1, "four"), "a request after the reload")
t.eq(True, _wait(lambda: _proxied(second, "four")), "goes to the new file")
t.eq(False, _proxied(first, "four"), "not to the old one")
if n is not None:
t.eq(True, _wait(lambda: _opened(pid, first) == 0),
"the old file is closed once its services are gone")
t.eq(True, _wait(lambda: _opened(pid, shared) == 0),
"and so is the file of -l nobody names any more")
t.eq(1, _opened(pid, second), "the new one is open")
# --- the same file, rotated daily: reopened under the day's name -----
dated = second + "." + time.strftime("%Y.%m.%d")
t.eq(True, reload(second + " D", lambda: os.path.exists(dated)),
"a rotation given to the log reopens it under the dated name")
t.eq(200, get(p1, "five"), "a request after that")
t.eq(True, _wait(lambda: _proxied(dated, "five")), "goes to the dated file")
t.eq(False, _proxied(second, "five"), "not to the undated one")
# --- a log which fails ------------------------------------------------
if os.path.exists("/dev/full"):
o2, q = t.free_port(), t.free_port()
full = t.start("logs_full", f"""
log /dev/full
logformat "LLOG %N %T"
auth iponly
allow *
http data * /data
httpsrv -p{o2}
proxy -p{q}
""", ports=[o2, q])
# a buffer's worth, at least, before writing it fails
for i in range(80):
t.http(f"http://127.0.0.1:{o2}/data?size=10&{'x' * 40}{i}",
proxy=f"127.0.0.1:{q}")
t.eq(True, _wait(lambda: "LOG PROXY" in full.output()),
"the lines a full device refuses go to standard error")
# --- a log which cannot be opened is an error in the configuration ---
out = t.run_config("logs_bad", f"""
log {os.path.join(t.tmpdir, "no", "such", "dir", "x.log")}
proxy -p{t.free_port()}
""")
t.contains(out, "x.log", "a log which cannot be opened is named")