From fe7a7f30a9fdccedb894834a5fa62601dd53d1ff Mon Sep 17 00:00:00 2001 From: bol-van Date: Fri, 23 Aug 2024 21:15:27 +0300 Subject: [PATCH] tpws: --debug to syslog and file --- tpws/hostlist.c | 24 ++-- tpws/params.c | 140 +++++++++++++++++++++++ tpws/params.h | 25 ++--- tpws/redirect.c | 32 +++--- tpws/resolver.c | 14 ++- tpws/sec.c | 31 +++--- tpws/sec.h | 2 + tpws/tamper.c | 76 ++++++------- tpws/tpws.c | 253 ++++++++++++++++++++++++------------------ tpws/tpws_conn.c | 283 ++++++++++++++++++++++++----------------------- 10 files changed, 537 insertions(+), 343 deletions(-) create mode 100644 tpws/params.c diff --git a/tpws/hostlist.c b/tpws/hostlist.c index 618b6de..f4d9d2b 100644 --- a/tpws/hostlist.c +++ b/tpws/hostlist.c @@ -31,11 +31,11 @@ bool AppendHostList(strpool **hostlist, char *filename) FILE *F; int r; - printf("Loading hostlist %s\n",filename); + DLOG_CONDUP("Loading hostlist %s\n",filename); if (!(F = fopen(filename, "rb"))) { - fprintf(stderr, "Could not open %s\n", filename); + DLOG_ERR("Could not open %s\n", filename); return false; } @@ -45,7 +45,7 @@ bool AppendHostList(strpool **hostlist, char *filename) fclose(F); if (r==Z_OK) { - printf("zlib compression detected. uncompressed size : %zu\n", zsize); + DLOG_CONDUP("zlib compression detected. uncompressed size : %zu\n", zsize); p = zbuf; e = zbuf + zsize; @@ -54,7 +54,7 @@ bool AppendHostList(strpool **hostlist, char *filename) if ( *p == '#' || *p == ';' || *p == '/' || *p == '\n' ) continue; if (!addpool(hostlist,&p,e)) { - fprintf(stderr, "Not enough memory to store host list : %s\n", filename); + DLOG_ERR("Not enough memory to store host list : %s\n", filename); free(zbuf); return false; } @@ -64,13 +64,13 @@ bool AppendHostList(strpool **hostlist, char *filename) } else { - fprintf(stderr, "zlib decompression failed : result %d\n",r); + DLOG_ERR("zlib decompression failed : result %d\n",r); return false; } } else { - printf("loading plain text list\n"); + DLOG_CONDUP("loading plain text list\n"); while (fgets(s, 256, F)) { @@ -78,7 +78,7 @@ bool AppendHostList(strpool **hostlist, char *filename) if ( *p == '#' || *p == ';' || *p == '/' || *p == '\n' ) continue; if (!addpool(hostlist,&p,p+strlen(p))) { - fprintf(stderr, "Not enough memory to store host list : %s\n", filename); + DLOG_ERR("Not enough memory to store host list : %s\n", filename); fclose(F); return false; } @@ -87,7 +87,7 @@ bool AppendHostList(strpool **hostlist, char *filename) fclose(F); } - printf("Loaded %d hosts from %s\n", ct, filename); + DLOG_CONDUP("Loaded %d hosts from %s\n", ct, filename); return true; } @@ -124,7 +124,7 @@ bool SearchHostList(strpool *hostlist, const char *host) while (p) { bInHostList = StrPoolCheckStr(hostlist, p); - if (params.debug) printf("Hostlist check for %s : %s\n", p, bInHostList ? "positive" : "negative"); + VPRINT("Hostlist check for %s : %s\n", p, bInHostList ? "positive" : "negative"); if (bInHostList) return true; p = strchr(p, '.'); if (p) p++; @@ -139,7 +139,7 @@ static bool HostlistCheck_(strpool *hostlist, strpool *hostlist_exclude, const c if (excluded) *excluded = false; if (hostlist_exclude) { - if (params.debug) printf("Checking exclude hostlist\n"); + VPRINT("Checking exclude hostlist\n"); if (SearchHostList(hostlist_exclude, host)) { if (excluded) *excluded = true; @@ -148,7 +148,7 @@ static bool HostlistCheck_(strpool *hostlist, strpool *hostlist_exclude, const c } if (hostlist) { - if (params.debug) printf("Checking include hostlist\n"); + VPRINT("Checking include hostlist\n"); return SearchHostList(hostlist, host); } return true; @@ -162,7 +162,7 @@ bool HostlistCheck(const char *host, bool *excluded) time_t t = file_mod_time(params.hostlist_auto_filename); if (t!=params.hostlist_auto_mod_time) { - printf("Autohostlist was modified by another process. Reloading include hostslist.\n"); + DLOG_CONDUP("Autohostlist was modified by another process. Reloading include hostslist.\n"); if (!LoadIncludeHostLists()) { // what will we do without hostlist ?? sure, gonna die diff --git a/tpws/params.c b/tpws/params.c new file mode 100644 index 0000000..f2741aa --- /dev/null +++ b/tpws/params.c @@ -0,0 +1,140 @@ +#include "params.h" +#include +#include +#include + +int DLOG_FILE(FILE *F, const char *format, va_list args) +{ + return vfprintf(F, format, args); +} +int DLOG_CON(const char *format, int syslog_priority, va_list args) +{ + return DLOG_FILE(syslog_priority==LOG_ERR ? stderr : stdout, format, args); +} +int DLOG_FILENAME(const char *filename, const char *format, va_list args) +{ + int r; + FILE *F = fopen(filename,"at"); + if (F) + { + r = DLOG_FILE(F, format, args); + fclose(F); + } + else + r=-1; + return r; +} + +static char syslog_buf[1024]; +static size_t syslog_buf_sz=0; +static void syslog_buffered(int priority, const char *format, va_list args) +{ + if (vsnprintf(syslog_buf+syslog_buf_sz,sizeof(syslog_buf)-syslog_buf_sz,format,args)>0) + { + syslog_buf_sz=strlen(syslog_buf); + // log when buffer is full or buffer ends with \n + if (syslog_buf_sz>=(sizeof(syslog_buf)-1) || (syslog_buf_sz && syslog_buf[syslog_buf_sz-1]=='\n')) + { + syslog(priority,"%s",syslog_buf); + syslog_buf_sz = 0; + } + } +} + +static int DLOG_VA(const char *format, int syslog_priority, bool condup, int level, va_list args) +{ + int r=0; + va_list args2; + + if (condup && !(params.debug>=level && params.debug_target==LOG_TARGET_CONSOLE)) + { + va_copy(args2,args); + DLOG_CON(format,syslog_priority,args2); + } + if (params.debug>=level) + { + switch(params.debug_target) + { + case LOG_TARGET_CONSOLE: + r = DLOG_CON(format,syslog_priority,args); + break; + case LOG_TARGET_FILE: + r = DLOG_FILENAME(params.debug_logfile,format,args); + break; + case LOG_TARGET_SYSLOG: + // skip newlines + syslog_buffered(syslog_priority,format,args); + r = 1; + break; + default: + break; + } + } + return r; +} + +int DLOG(const char *format, int level, ...) +{ + int r; + va_list args; + va_start(args, level); + r = DLOG_VA(format, LOG_DEBUG, false, level, args); + va_end(args); + return r; +} +int DLOG_CONDUP(const char *format, ...) +{ + int r; + va_list args; + va_start(args, format); + r = DLOG_VA(format, LOG_DEBUG, true, 1, args); + va_end(args); + return r; +} +int DLOG_ERR(const char *format, ...) +{ + int r; + va_list args; + va_start(args, format); + r = DLOG_VA(format, LOG_ERR, true, 1, args); + va_end(args); + return r; +} +int DLOG_PERROR(const char *s) +{ + return DLOG_ERR("%s: %s\n", s, strerror(errno)); +} + + +int LOG_APPEND(const char *filename, const char *format, va_list args) +{ + int r; + FILE *F = fopen(filename,"at"); + if (F) + { + fprint_localtime(F); + fprintf(F, " : "); + r = vfprintf(F, format, args); + fprintf(F, "\n"); + fclose(F); + } + else + r=-1; + return r; +} + +int HOSTLIST_DEBUGLOG_APPEND(const char *format, ...) +{ + if (*params.hostlist_auto_debuglog) + { + int r; + va_list args; + + va_start(args, format); + r = LOG_APPEND(params.hostlist_auto_debuglog, format, args); + va_end(args); + return r; + } + else + return 0; +} diff --git a/tpws/params.h b/tpws/params.h index 309cfca..95105d9 100644 --- a/tpws/params.h +++ b/tpws/params.h @@ -25,6 +25,8 @@ struct bind_s int bind_wait_ifup,bind_wait_ip,bind_wait_ip_ll; }; +enum log_target { LOG_TARGET_CONSOLE=0, LOG_TARGET_FILE, LOG_TARGET_SYSLOG }; + struct params_s { struct bind_s binds[MAX_BINDS]; @@ -77,6 +79,8 @@ struct params_s char connect_bind6_ifname[IF_NAMESIZE]; int debug; + enum log_target debug_target; + char debug_logfile[PATH_MAX]; #if defined(BSD) bool pf_enable; @@ -88,18 +92,11 @@ struct params_s extern struct params_s params; -#define _DBGPRINT(format, level, ...) { if (params.debug>=level) printf(format "\n", ##__VA_ARGS__); } -#define VPRINT(format, ...) _DBGPRINT(format,1,##__VA_ARGS__) -#define DBGPRINT(format, ...) _DBGPRINT(format,2,##__VA_ARGS__) +int DLOG(const char *format, int level, ...); +int DLOG_CONDUP(const char *format, ...); +int DLOG_ERR(const char *format, ...); +int DLOG_PERROR(const char *s); +int HOSTLIST_DEBUGLOG_APPEND(const char *format, ...); -#define LOG_APPEND(filename, format, ...) \ -{ \ - FILE *F = fopen(filename,"at"); \ - if (F) \ - { \ - fprint_localtime(F); \ - fprintf(F, " : " format "\n", ##__VA_ARGS__); \ - fclose(F); \ - } \ -} -#define HOSTLIST_DEBUGLOG_APPEND(format, ...) if (*params.hostlist_auto_debuglog) LOG_APPEND(params.hostlist_auto_debuglog, format, ##__VA_ARGS__) +#define VPRINT(format, ...) DLOG(format, 1, ##__VA_ARGS__) +#define DBGPRINT(format, ...) DLOG(format, 2, ##__VA_ARGS__) diff --git a/tpws/redirect.c b/tpws/redirect.c index 666fe55..ecfc8b2 100644 --- a/tpws/redirect.c +++ b/tpws/redirect.c @@ -31,7 +31,7 @@ void redir_close(void) { close(redirector_fd); redirector_fd = -1; - DBGPRINT("closed redirector"); + DBGPRINT("closed redirector\n"); } } static bool redir_open_private(const char *fname, int flags) @@ -40,10 +40,10 @@ static bool redir_open_private(const char *fname, int flags) redirector_fd = open(fname, flags); if (redirector_fd < 0) { - perror("redir_openv_private"); + DLOG_PERROR("redir_openv_private"); return false; } - DBGPRINT("opened redirector %s",fname); + DBGPRINT("opened redirector %s\n",fname); return true; } bool redir_init(void) @@ -63,7 +63,7 @@ static bool destination_from_pf(const struct sockaddr *accept_sa, struct sockadd char s[48],s2[48]; *s=0; ntop46_port(accept_sa, s, sizeof(s)); *s2=0; ntop46_port((struct sockaddr *)orig_dst, s2, sizeof(s2)); - DBGPRINT("destination_from_pf %s %s",s,s2); + DBGPRINT("destination_from_pf %s %s\n",s,s2); } saconvmapped(orig_dst); @@ -79,12 +79,12 @@ static bool destination_from_pf(const struct sockaddr *accept_sa, struct sockadd char s[48],s2[48]; *s=0; ntop46_port(accept_sa, s, sizeof(s)); *s2=0; ntop46_port((struct sockaddr *)orig_dst, s2, sizeof(s2)); - DBGPRINT("destination_from_pf (saconvmapped) %s %s",s,s2); + DBGPRINT("destination_from_pf (saconvmapped) %s %s\n",s,s2); } if (accept_sa->sa_family!=orig_dst->ss_family) { - DBGPRINT("accept_sa and orig_dst sa_family mismatch : %d %d", accept_sa->sa_family, orig_dst->ss_family); + DBGPRINT("accept_sa and orig_dst sa_family mismatch : %d %d\n", accept_sa->sa_family, orig_dst->ss_family); return false; } @@ -123,16 +123,16 @@ static bool destination_from_pf(const struct sockaddr *accept_sa, struct sockadd } break; default: - DBGPRINT("destination_from_pf : unexpected address family %d",orig_dst->ss_family); + DBGPRINT("destination_from_pf : unexpected address family %d\n",orig_dst->ss_family); return false; } if (ioctl(redirector_fd, DIOCNATLOOK, &nl) < 0) { - DBGPRINT("ioctl(DIOCNATLOOK) failed: %s",strerror(errno)); + DLOG_PERROR("ioctl(DIOCNATLOOK) failed"); return false; } - DBGPRINT("destination_from_pf : got orig dest addr from pf"); + DBGPRINT("destination_from_pf : got orig dest addr from pf\n"); switch(nl.af) { @@ -155,7 +155,7 @@ static bool destination_from_pf(const struct sockaddr *accept_sa, struct sockadd ((struct sockaddr_in6*)orig_dst)->sin6_addr = nl.rdaddr.v6; break; default: - DBGPRINT("destination_from_pf : DIOCNATLOOK returned unexpected address family %d",nl.af); + DBGPRINT("destination_from_pf : DIOCNATLOOK returned unexpected address family %d\n",nl.af); return false; } @@ -192,38 +192,38 @@ bool get_dest_addr(int sockfd, const struct sockaddr *accept_sa, struct sockaddr r = getsockopt(sockfd, SOL_IPV6, IP6T_SO_ORIGINAL_DST, (struct sockaddr*) orig_dst, &addrlen); if (r<0) { - DBGPRINT("both SO_ORIGINAL_DST and IP6T_SO_ORIGINAL_DST failed !"); + DBGPRINT("both SO_ORIGINAL_DST and IP6T_SO_ORIGINAL_DST failed !\n"); #endif // TPROXY : socket is bound to original destination r=getsockname(sockfd, (struct sockaddr*) orig_dst, &addrlen); if (r<0) { - perror("getsockname"); + DLOG_PERROR("getsockname"); return false; } if (orig_dst->ss_family==AF_INET6) ((struct sockaddr_in6*)orig_dst)->sin6_scope_id=0; // or MacOS will not connect() #ifdef BSD if (params.pf_enable && !destination_from_pf(accept_sa, orig_dst)) - DBGPRINT("pf filter destination_from_pf failed"); + DBGPRINT("pf filter destination_from_pf failed\n"); #endif #ifdef __linux__ } #endif if (saconvmapped(orig_dst)) - DBGPRINT("Original destination : converted ipv6 mapped address to ipv4"); + DBGPRINT("Original destination : converted ipv6 mapped address to ipv4\n"); if (params.debug) { if (orig_dst->ss_family == AF_INET) { inet_ntop(AF_INET, &(((struct sockaddr_in*) orig_dst)->sin_addr), orig_dst_str, INET_ADDRSTRLEN); - VPRINT("Original destination for socket fd=%d : %s:%d", sockfd,orig_dst_str, htons(((struct sockaddr_in*) orig_dst)->sin_port)) + VPRINT("Original destination for socket fd=%d : %s:%d\n", sockfd,orig_dst_str, htons(((struct sockaddr_in*) orig_dst)->sin_port)); } else if (orig_dst->ss_family == AF_INET6) { inet_ntop(AF_INET6,&(((struct sockaddr_in6*) orig_dst)->sin6_addr), orig_dst_str, INET6_ADDRSTRLEN); - VPRINT("Original destination for socket fd=%d : [%s]:%d", sockfd,orig_dst_str, htons(((struct sockaddr_in6*) orig_dst)->sin6_port)) + VPRINT("Original destination for socket fd=%d : [%s]:%d\n", sockfd,orig_dst_str, htons(((struct sockaddr_in6*) orig_dst)->sin6_port)); } } return true; diff --git a/tpws/resolver.c b/tpws/resolver.c index 920821c..52fdd8e 100644 --- a/tpws/resolver.c +++ b/tpws/resolver.c @@ -1,6 +1,8 @@ #define _GNU_SOURCE #include "resolver.h" +#include "params.h" + #include #include #include @@ -74,7 +76,7 @@ static void *resolver_thread(void *arg) { if (errno!=EINTR) { - perror("sem_wait (resolver_thread)"); + DLOG_PERROR("sem_wait (resolver_thread)"); break; // fatal err } } @@ -112,13 +114,13 @@ static void *resolver_thread(void *arg) if (wr<0) { free(ri); - perror("write resolve_pipe"); + DLOG_PERROR("write resolve_pipe"); } else if (wr!=sizeof(void*)) { // partial pointer write is FATAL. in any case it will cause pointer corruption and coredump free(ri); - fprintf(stderr,"write resolve_pipe : not full write\n"); + DLOG_ERR("write resolve_pipe : not full write\n"); exit(1000); } pthread_sigmask(SIG_UNBLOCK, &signal_mask, NULL); @@ -181,7 +183,7 @@ bool resolver_init(int threads, int fd_signal_pipe) resolver.sem = sem_open(sn,O_CREAT,0600,0); if (resolver.sem==SEM_FAILED) { - perror("sem_open"); + DLOG_PERROR("sem_open"); goto ex; } // unlink immediately to remove tails @@ -189,7 +191,7 @@ bool resolver_init(int threads, int fd_signal_pipe) #else if (sem_init(&resolver._sem,0,0)==-1) { - perror("sem_init"); + DLOG_PERROR("sem_init"); goto ex; } resolver.sem = &resolver._sem; @@ -252,7 +254,7 @@ struct resolve_item *resolver_queue(const char *dom, uint16_t port, void *ptr) rlist_unlock; if (sem_post(resolver.sem)<0) { - perror("resolver_queue sem_post"); + DLOG_PERROR("resolver_queue sem_post"); free(ri); return NULL; } diff --git a/tpws/sec.c b/tpws/sec.c index b5fba25..3a6c210 100644 --- a/tpws/sec.c +++ b/tpws/sec.c @@ -169,14 +169,14 @@ bool sec_harden(void) { if (prctl(PR_SET_NO_NEW_PRIVS, 1, 0, 0, 0)) { - perror("PR_SET_NO_NEW_PRIVS(prctl)"); + DLOG_PERROR("PR_SET_NO_NEW_PRIVS(prctl)"); return false; } #if ARCH_NR!=0 if (!set_seccomp()) { - perror("seccomp"); - if (errno==EINVAL) fprintf(stderr,"seccomp: this can be safely ignored if kernel does not support seccomp\n"); + DLOG_PERROR("seccomp"); + if (errno==EINVAL) DLOG_ERR("seccomp: this can be safely ignored if kernel does not support seccomp\n"); return false; } #endif @@ -232,15 +232,15 @@ bool dropcaps(void) { if (prctl(PR_CAPBSET_DROP, cap)<0) { - fprintf(stderr, "could not drop bound cap %d\n", cap); - perror("cap_drop_bound"); + DLOG_ERR("could not drop bound cap %d\n", cap); + DLOG_PERROR("cap_drop_bound"); } } } // now without CAP_SETPCAP if (!setpcap(caps)) { - perror("setpcap"); + DLOG_PERROR("setpcap"); return checkpcap(caps); } return true; @@ -273,24 +273,24 @@ bool droproot(uid_t uid, gid_t gid) #ifdef __linux__ if (prctl(PR_SET_KEEPCAPS, 1L)) { - perror("prctl(PR_SET_KEEPCAPS)"); + DLOG_PERROR("prctl(PR_SET_KEEPCAPS)"); return false; } #endif // drop all SGIDs if (setgroups(0,NULL)) { - perror("setgroups"); + DLOG_PERROR("setgroups"); return false; } if (setgid(gid)) { - perror("setgid"); + DLOG_PERROR("setgid"); return false; } if (setuid(uid)) { - perror("setuid"); + DLOG_PERROR("setuid"); return false; } #ifdef __linux__ @@ -304,16 +304,17 @@ void print_id(void) { int i,N; gid_t g[128]; - printf("Running as UID=%u GID=",getuid()); + + DLOG_CONDUP("Running as UID=%u GID=",getuid()); N=getgroups(sizeof(g)/sizeof(*g),g); if (N>0) { for(i=0;i #include diff --git a/tpws/tamper.c b/tpws/tamper.c index 56ad6ba..c70e6cc 100644 --- a/tpws/tamper.c +++ b/tpws/tamper.c @@ -17,7 +17,7 @@ void tamper_out(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,si bool bBypass = false, bHaveHost = false, bHostExcluded = false; char *pc, Host[256]; - DBGPRINT("tamper_out") + DBGPRINT("tamper_out\n"); *split_pos=0; *split_flags=0; @@ -25,7 +25,7 @@ void tamper_out(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,si if ((method = HttpMethod(segment,*size))) { method_len = strlen(method)-2; - VPRINT("Data block looks like http request start : %s", method) + VPRINT("Data block looks like http request start : %s\n", method); if (!ctrack->l7proto) ctrack->l7proto=HTTP; // cpu saving : we search host only if and when required. we do not research host every time we need its position if ((params.hostlist || params.hostlist_exclude) && HttpFindHost(&pHost,segment,*size)) @@ -37,7 +37,7 @@ void tamper_out(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,si memcpy(Host, p, pp - p); Host[pp - p] = '\0'; bHaveHost = true; - VPRINT("Requested Host is : %s", Host) + VPRINT("Requested Host is : %s\n", Host); for(pc = Host; *pc; pc++) *pc=tolower(*pc); bBypass = !HostlistCheck(Host, &bHostExcluded); } @@ -54,7 +54,7 @@ void tamper_out(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,si if (pp == (p - 1)) { // probably end of http headers - VPRINT("Found double EOL at pos %td. Stop replacing.", pp - segment) + VPRINT("Found double EOL at pos %td. Stop replacing.\n", pp - segment); break; } pp = p; @@ -63,7 +63,7 @@ void tamper_out(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,si } if (params.methodeol && (*size+1+!params.unixeol)<=segment_buffer_size) { - VPRINT("Adding EOL before method") + VPRINT("Adding EOL before method\n"); if (params.unixeol) { memmove(segment + 1, segment, *size); @@ -82,7 +82,7 @@ void tamper_out(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,si if (params.methodspace && *size '%c%c%c%c:' at pos %td", params.hostspell[0], params.hostspell[1], params.hostspell[2], params.hostspell[3], pHost - segment) + VPRINT("Changing 'Host:' => '%c%c%c%c:' at pos %td\n", params.hostspell[0], params.hostspell[1], params.hostspell[2], params.hostspell[3], pHost - segment); memcpy(pHost, params.hostspell, 4); } if (params.hostpad && HttpFindHost(&pHost,segment,*size)) @@ -132,16 +132,16 @@ void tamper_out(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,si size_t hostpad = params.hostpadsegment_buffer_size) - VPRINT("could not add host padding : buffer too small") + VPRINT("could not add host padding : buffer too small\n"); else { if ((hostpad+*size)>segment_buffer_size) { hostpad=segment_buffer_size-*size; - VPRINT("host padding reduced to %zu bytes : buffer too small", hostpad) + VPRINT("host padding reduced to %zu bytes : buffer too small\n", hostpad); } else - VPRINT("host padding with %zu bytes", hostpad) + VPRINT("host padding with %zu bytes\n", hostpad); p = pHost; pos = p - segment; @@ -177,7 +177,7 @@ void tamper_out(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,si } else { - VPRINT("Not acting on this request") + VPRINT("Not acting on this request\n"); } } else if (IsTLSClientHello(segment,*size,false)) @@ -186,17 +186,17 @@ void tamper_out(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,si if (!ctrack->l7proto) ctrack->l7proto=TLS; - VPRINT("packet contains TLS ClientHello") + VPRINT("packet contains TLS ClientHello\n"); // we need host only if hostlist is present if ((params.hostlist || params.hostlist_exclude) && TLSHelloExtractHost((uint8_t*)segment,*size,Host,sizeof(Host),false)) { - VPRINT("hostname: %s",Host) + VPRINT("hostname: %s\n",Host); bHaveHost = true; bBypass = !HostlistCheck(Host, &bHostExcluded); } if (bBypass) { - VPRINT("Not acting on this request") + VPRINT("Not acting on this request\n"); } else { @@ -213,7 +213,7 @@ void tamper_out(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,si { // length is checked in IsTLSClientHello and cannot exceed buffer size if ((tpos-5)>=l) tpos=5+1; - VPRINT("making 2 TLS records at pos %zu",tpos) + VPRINT("making 2 TLS records at pos %zu\n",tpos); memmove(segment+tpos+5,segment+tpos,*size-tpos); segment[tpos] = segment[0]; segment[tpos+1] = segment[1]; @@ -229,7 +229,7 @@ void tamper_out(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,si if (spos && spos < *size) { - VPRINT("split pos %zu",spos); + VPRINT("split pos %zu\n",spos); *split_pos = spos; } @@ -242,7 +242,7 @@ void tamper_out(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,si if (bHaveHost && bBypass && !bHostExcluded && *params.hostlist_auto_filename) { - DBGPRINT("tamper_out put hostname : %s", Host) + DBGPRINT("tamper_out put hostname : %s\n", Host); if (ctrack->hostname) free(ctrack->hostname); ctrack->hostname=strdup(Host); } @@ -260,7 +260,7 @@ static void auto_hostlist_reset_fail_counter(const char *hostname) if (fail_counter) { HostFailPoolDel(¶ms.hostlist_auto_fail_counters, fail_counter); - VPRINT("auto hostlist : %s : fail counter reset. website is working.", hostname); + VPRINT("auto hostlist : %s : fail counter reset. website is working.\n", hostname); HOSTLIST_DEBUGLOG_APPEND("%s : fail counter reset. website is working.", hostname); } } @@ -276,39 +276,39 @@ static void auto_hostlist_failed(const char *hostname) fail_counter = HostFailPoolAdd(¶ms.hostlist_auto_fail_counters, hostname, params.hostlist_auto_fail_time); if (!fail_counter) { - fprintf(stderr, "HostFailPoolAdd: out of memory\n"); + DLOG_ERR("HostFailPoolAdd: out of memory\n"); return; } } fail_counter->counter++; - VPRINT("auto hostlist : %s : fail counter %d/%d", hostname, fail_counter->counter, params.hostlist_auto_fail_threshold); + VPRINT("auto hostlist : %s : fail counter %d/%d\n", hostname, fail_counter->counter, params.hostlist_auto_fail_threshold); HOSTLIST_DEBUGLOG_APPEND("%s : fail counter %d/%d", hostname, fail_counter->counter, params.hostlist_auto_fail_threshold); if (fail_counter->counter >= params.hostlist_auto_fail_threshold) { - VPRINT("auto hostlist : fail threshold reached. adding %s to auto hostlist", hostname); + VPRINT("auto hostlist : fail threshold reached. adding %s to auto hostlist\n", hostname); HostFailPoolDel(¶ms.hostlist_auto_fail_counters, fail_counter); - VPRINT("auto hostlist : rechecking %s to avoid duplicates", hostname); + VPRINT("auto hostlist : rechecking %s to avoid duplicates\n", hostname); bool bExcluded=false; if (!HostlistCheck(hostname, &bExcluded) && !bExcluded) { - VPRINT("auto hostlist : adding %s", hostname); + VPRINT("auto hostlist : adding %s\n", hostname); HOSTLIST_DEBUGLOG_APPEND("%s : adding", hostname); if (!StrPoolAddStr(¶ms.hostlist, hostname)) { - fprintf(stderr, "StrPoolAddStr out of memory\n"); + DLOG_ERR("StrPoolAddStr out of memory\n"); return; } if (!append_to_list_file(params.hostlist_auto_filename, hostname)) { - perror("write to auto hostlist:"); + DLOG_PERROR("write to auto hostlist:"); return; } params.hostlist_auto_mod_time = file_mod_time(params.hostlist_auto_filename); } else { - VPRINT("auto hostlist : NOT adding %s", hostname); + VPRINT("auto hostlist : NOT adding %s\n", hostname); HOSTLIST_DEBUGLOG_APPEND("%s : NOT adding, duplicate detected", hostname); } } @@ -318,7 +318,7 @@ void tamper_in(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,siz { bool bFail=false; - DBGPRINT("tamper_in hostname=%s", ctrack->hostname) + DBGPRINT("tamper_in hostname=%s\n", ctrack->hostname); if (*params.hostlist_auto_filename) { @@ -328,20 +328,20 @@ void tamper_in(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,siz { if (IsHttpReply(segment,*size)) { - VPRINT("incoming HTTP reply detected for hostname %s", ctrack->hostname); + VPRINT("incoming HTTP reply detected for hostname %s\n", ctrack->hostname); bFail = HttpReplyLooksLikeDPIRedirect(segment, *size, ctrack->hostname); if (bFail) { - VPRINT("redirect to another domain detected. possibly DPI redirect.") + VPRINT("redirect to another domain detected. possibly DPI redirect.\n"); HOSTLIST_DEBUGLOG_APPEND("%s : redirect to another domain", ctrack->hostname); } else - VPRINT("local or in-domain redirect detected. it's not a DPI redirect.") + VPRINT("local or in-domain redirect detected. it's not a DPI redirect.\n"); } else { // received not http reply. do not monitor this connection anymore - VPRINT("incoming unknown HTTP data detected for hostname %s", ctrack->hostname); + VPRINT("incoming unknown HTTP data detected for hostname %s\n", ctrack->hostname); } if (bFail) auto_hostlist_failed(ctrack->hostname); @@ -354,7 +354,7 @@ void tamper_in(t_ctrack *ctrack, uint8_t *segment,size_t segment_buffer_size,siz void rst_in(t_ctrack *ctrack) { - DBGPRINT("rst_in hostname=%s", ctrack->hostname) + DBGPRINT("rst_in hostname=%s\n", ctrack->hostname); if (!*params.hostlist_auto_filename) return; @@ -362,14 +362,14 @@ void rst_in(t_ctrack *ctrack) if (!ctrack->bTamperInCutoff && ctrack->hostname) { - VPRINT("incoming RST detected for hostname %s", ctrack->hostname); + VPRINT("incoming RST detected for hostname %s\n", ctrack->hostname); HOSTLIST_DEBUGLOG_APPEND("%s : incoming RST", ctrack->hostname); auto_hostlist_failed(ctrack->hostname); } } void hup_out(t_ctrack *ctrack) { - DBGPRINT("hup_out hostname=%s", ctrack->hostname) + DBGPRINT("hup_out hostname=%s\n", ctrack->hostname); if (!*params.hostlist_auto_filename) return; @@ -378,7 +378,7 @@ void hup_out(t_ctrack *ctrack) if (!ctrack->bTamperInCutoff && ctrack->hostname) { // local leg dropped connection after first request. probably due to timeout. - VPRINT("local leg closed connection after first request (timeout ?). hostname: %s", ctrack->hostname); + VPRINT("local leg closed connection after first request (timeout ?). hostname: %s\n", ctrack->hostname); HOSTLIST_DEBUGLOG_APPEND("%s : client closed connection without server reply", ctrack->hostname); auto_hostlist_failed(ctrack->hostname); } diff --git a/tpws/tpws.c b/tpws/tpws.c index 14ea24f..bf44fde 100644 --- a/tpws/tpws.c +++ b/tpws/tpws.c @@ -23,6 +23,7 @@ #include #include #include +#include #include "tpws.h" @@ -78,17 +79,17 @@ static int8_t block_sigpipe(void) //Get the old sigset, add SIGPIPE and update sigset if (sigprocmask(SIG_BLOCK, NULL, &sigset) == -1) { - perror("sigprocmask (get)"); + DLOG_PERROR("sigprocmask (get)"); return -1; } if (sigaddset(&sigset, SIGPIPE) == -1) { - perror("sigaddset"); + DLOG_PERROR("sigaddset"); return -1; } if (sigprocmask(SIG_BLOCK, &sigset, NULL) == -1) { - perror("sigprocmask (set)"); + DLOG_PERROR("sigprocmask (set)"); return -1; } @@ -163,7 +164,8 @@ static void exithelp(void) #if defined(BSD) && !defined(__OpenBSD__) && !defined(__APPLE__) " --enable-pf\t\t\t\t; enable PF redirector support. required in FreeBSD when used with PF firewall.\n" #endif - " --debug=0|1|2\t\t\t\t; 0(default)=silent 1=verbose 2=debug\n" + " --debug=0|1|2|syslog|@\t\t1 and 2 means log to console and set debug level. for other targets use --debug-level.\n" + " --debug-level=0|1|2\t\t\t; specify debug level\n" "\nFILTER:\n" " --hostlist=\t\t\t; only act on hosts in the list (one host per line, subdomains auto apply, gzip supported, multiple hostlists allowed)\n" " --hostlist-exclude=\t\t; do not act on hosts in the list (one host per line, subdomains auto apply, gzip supported, multiple hostlists allowed)\n" @@ -228,7 +230,7 @@ static void nextbind_clean(void) params.binds_last++; if (params.binds_last>=MAX_BINDS) { - fprintf(stderr,"maximum of %d binds are supported\n",MAX_BINDS); + DLOG_ERR("maximum of %d binds are supported\n",MAX_BINDS); exit_clean(1); } } @@ -236,7 +238,7 @@ static void checkbind_clean(void) { if (params.binds_last<0) { - fprintf(stderr,"start new bind with --bind-addr,--bind-iface*\n"); + DLOG_ERR("start new bind with --bind-addr,--bind-iface*\n"); exit_clean(1); } } @@ -249,7 +251,7 @@ void save_default_ttl(void) params.ttl_default = get_default_ttl(); if (!params.ttl_default) { - fprintf(stderr, "could not get default ttl\n"); + DLOG_ERR("could not get default ttl\n"); exit_clean(1); } } @@ -346,24 +348,25 @@ void parse_params(int argc, char *argv[]) { "hostlist-auto-debug",required_argument,0,0}, // optidx=41 { "pidfile",required_argument,0,0 },// optidx=42 { "debug",optional_argument,0,0 },// optidx=43 - { "local-rcvbuf",required_argument,0,0 },// optidx=44 - { "local-sndbuf",required_argument,0,0 },// optidx=45 - { "remote-rcvbuf",required_argument,0,0 },// optidx=46 - { "remote-sndbuf",required_argument,0,0 },// optidx=47 - { "socks",no_argument,0,0 },// optidx=48 - { "no-resolve",no_argument,0,0 },// optidx=49 - { "resolver-threads",required_argument,0,0 },// optidx=50 - { "skip-nodelay",no_argument,0,0 },// optidx=51 - { "tamper-start",required_argument,0,0 },// optidx=52 - { "tamper-cutoff",required_argument,0,0 },// optidx=53 - { "connect-bind-addr",required_argument,0,0 },// optidx=54 + { "debug-level",required_argument,0,0 },// optidx=44 + { "local-rcvbuf",required_argument,0,0 },// optidx=45 + { "local-sndbuf",required_argument,0,0 },// optidx=46 + { "remote-rcvbuf",required_argument,0,0 },// optidx=47 + { "remote-sndbuf",required_argument,0,0 },// optidx=48 + { "socks",no_argument,0,0 },// optidx=40 + { "no-resolve",no_argument,0,0 },// optidx=50 + { "resolver-threads",required_argument,0,0 },// optidx=51 + { "skip-nodelay",no_argument,0,0 },// optidx=52 + { "tamper-start",required_argument,0,0 },// optidx=53 + { "tamper-cutoff",required_argument,0,0 },// optidx=54 + { "connect-bind-addr",required_argument,0,0 },// optidx=55 #if defined(BSD) && !defined(__OpenBSD__) && !defined(__APPLE__) - { "enable-pf",no_argument,0,0 },// optidx=55 + { "enable-pf",no_argument,0,0 },// optidx=56 #elif defined(__linux__) - { "mss",required_argument,0,0 },// optidx=55 - { "mss-pf",required_argument,0,0 },// optidx=56 + { "mss",required_argument,0,0 },// optidx=56 + { "mss-pf",required_argument,0,0 },// optidx=57 #ifdef SPLICE_PRESENT - { "nosplice",no_argument,0,0 },// optidx=57 + { "nosplice",no_argument,0,0 },// optidx=58 #endif #endif { "hostlist-auto-retrans-threshold",optional_argument,0,0}, // ignored. for nfqws command line compatibility @@ -416,7 +419,7 @@ void parse_params(int argc, char *argv[]) params.binds[params.binds_last].bindll=unwanted; else { - fprintf(stderr, "invalid parameter in bind-linklocal : %s\n",optarg); + DLOG_ERR("invalid parameter in bind-linklocal : %s\n",optarg); exit_clean(1); } break; @@ -439,7 +442,7 @@ void parse_params(int argc, char *argv[]) i = atoi(optarg); if (i <= 0 || i > 65535) { - fprintf(stderr, "bad port number\n"); + DLOG_ERR("bad port number\n"); exit_clean(1); } params.port = (uint16_t)i; @@ -452,7 +455,7 @@ void parse_params(int argc, char *argv[]) struct passwd *pwd = getpwnam(optarg); if (!pwd) { - fprintf(stderr, "non-existent username supplied\n"); + DLOG_ERR("non-existent username supplied\n"); exit_clean(1); } params.uid = pwd->pw_uid; @@ -465,7 +468,7 @@ void parse_params(int argc, char *argv[]) params.droproot = true; if (sscanf(optarg,"%u:%u",¶ms.uid,¶ms.gid)<1) { - fprintf(stderr, "--uid should be : uid[:gid]\n"); + DLOG_ERR("--uid should be : uid[:gid]\n"); exit_clean(1); } break; @@ -473,7 +476,7 @@ void parse_params(int argc, char *argv[]) params.maxconn = atoi(optarg); if (params.maxconn <= 0 || params.maxconn > 10000) { - fprintf(stderr, "bad maxconn\n"); + DLOG_ERR("bad maxconn\n"); exit_clean(1); } break; @@ -481,7 +484,7 @@ void parse_params(int argc, char *argv[]) params.maxfiles = atoi(optarg); if (params.maxfiles < 0) { - fprintf(stderr, "bad maxfiles\n"); + DLOG_ERR("bad maxfiles\n"); exit_clean(1); } break; @@ -489,7 +492,7 @@ void parse_params(int argc, char *argv[]) params.max_orphan_time = atoi(optarg); if (params.max_orphan_time < 0) { - fprintf(stderr, "bad max_orphan_time\n"); + DLOG_ERR("bad max_orphan_time\n"); exit_clean(1); } break; @@ -500,7 +503,7 @@ void parse_params(int argc, char *argv[]) case 18: /* hostspell */ if (strlen(optarg) != 4) { - fprintf(stderr, "hostspell must be exactly 4 chars long\n"); + DLOG_ERR("hostspell must be exactly 4 chars long\n"); exit_clean(1); } params.hostcase = true; @@ -526,7 +529,7 @@ void parse_params(int argc, char *argv[]) case 23: /* split-http-req */ if (!parse_httpreqpos(optarg, ¶ms.split_http_req)) { - fprintf(stderr, "Invalid argument for split-http-req\n"); + DLOG_ERR("Invalid argument for split-http-req\n"); exit_clean(1); } params.tamper = true; @@ -534,7 +537,7 @@ void parse_params(int argc, char *argv[]) case 24: /* split-tls */ if (!parse_tlspos(optarg, ¶ms.split_tls)) { - fprintf(stderr, "Invalid argument for split-tls\n"); + DLOG_ERR("Invalid argument for split-tls\n"); exit_clean(1); } params.tamper = true; @@ -545,7 +548,7 @@ void parse_params(int argc, char *argv[]) params.split_pos = i; else { - fprintf(stderr, "Invalid argument for split-pos\n"); + DLOG_ERR("Invalid argument for split-pos\n"); exit_clean(1); } params.tamper = true; @@ -560,7 +563,7 @@ void parse_params(int argc, char *argv[]) else if (!strcmp(optarg,"tls")) params.disorder_tls=true; else { - fprintf(stderr, "Invalid argument for disorder\n"); + DLOG_ERR("Invalid argument for disorder\n"); exit_clean(1); } } @@ -575,7 +578,7 @@ void parse_params(int argc, char *argv[]) else if (!strcmp(optarg,"tls")) params.oob_tls=true; else { - fprintf(stderr, "Invalid argument for oob\n"); + DLOG_ERR("Invalid argument for oob\n"); exit_clean(1); } } @@ -589,7 +592,7 @@ void parse_params(int argc, char *argv[]) if (l==1) params.oob_byte = (uint8_t)*optarg; else if (l!=4 || sscanf(optarg,"0x%02X",&bt)!=1) { - fprintf(stderr, "Invalid argument for oob-data\n"); + DLOG_ERR("Invalid argument for oob-data\n"); exit_clean(1); } else params.oob_byte = (uint8_t)bt; @@ -614,7 +617,7 @@ void parse_params(int argc, char *argv[]) case 34: /* tlsrec */ if (!parse_tlspos(optarg, ¶ms.tlsrec)) { - fprintf(stderr, "Invalid argument for tlsrec\n"); + DLOG_ERR("Invalid argument for tlsrec\n"); exit_clean(1); } params.tamper = true; @@ -624,7 +627,7 @@ void parse_params(int argc, char *argv[]) params.tlsrec = tlspos_pos; else { - fprintf(stderr, "Invalid argument for tlsrec-pos\n"); + DLOG_ERR("Invalid argument for tlsrec-pos\n"); exit_clean(1); } params.tamper = true; @@ -632,7 +635,7 @@ void parse_params(int argc, char *argv[]) case 36: /* hostlist */ if (!strlist_add(¶ms.hostlist_files, optarg)) { - fprintf(stderr, "strlist_add failed\n"); + DLOG_ERR("strlist_add failed\n"); exit_clean(1); } params.tamper = true; @@ -640,7 +643,7 @@ void parse_params(int argc, char *argv[]) case 37: /* hostlist-exclude */ if (!strlist_add(¶ms.hostlist_exclude_files, optarg)) { - fprintf(stderr, "strlist_add failed\n"); + DLOG_ERR("strlist_add failed\n"); exit_clean(1); } params.tamper = true; @@ -648,29 +651,29 @@ void parse_params(int argc, char *argv[]) case 38: /* hostlist-auto */ if (*params.hostlist_auto_filename) { - fprintf(stderr, "only one auto hostlist is supported\n"); + DLOG_ERR("only one auto hostlist is supported\n"); exit_clean(1); } { FILE *F = fopen(optarg,"a+t"); if (!F) { - fprintf(stderr, "cannot create %s\n", optarg); + DLOG_ERR("cannot create %s\n", optarg); exit_clean(1); } bool bGzip = is_gzip(F); fclose(F); if (bGzip) { - fprintf(stderr, "gzipped auto hostlists are not supported\n"); + DLOG_ERR("gzipped auto hostlists are not supported\n"); exit_clean(1); } if (params.droproot && chown(optarg, params.uid, -1)) - fprintf(stderr, "could not chown %s. auto hostlist file may not be writable after privilege drop\n", optarg); + DLOG_ERR("could not chown %s. auto hostlist file may not be writable after privilege drop\n", optarg); } if (!strlist_add(¶ms.hostlist_files, optarg)) { - fprintf(stderr, "strlist_add failed\n"); + DLOG_ERR("strlist_add failed\n"); exit_clean(1); } strncpy(params.hostlist_auto_filename, optarg, sizeof(params.hostlist_auto_filename)); @@ -681,7 +684,7 @@ void parse_params(int argc, char *argv[]) params.hostlist_auto_fail_threshold = (uint8_t)atoi(optarg); if (params.hostlist_auto_fail_threshold<1 || params.hostlist_auto_fail_threshold>20) { - fprintf(stderr, "auto hostlist fail threshold must be within 1..20\n"); + DLOG_ERR("auto hostlist fail threshold must be within 1..20\n"); exit_clean(1); } break; @@ -689,7 +692,7 @@ void parse_params(int argc, char *argv[]) params.hostlist_auto_fail_time = (uint8_t)atoi(optarg); if (params.hostlist_auto_fail_time<1) { - fprintf(stderr, "auto hostlist fail time is not valid\n"); + DLOG_ERR("auto hostlist fail time is not valid\n"); exit_clean(1); } break; @@ -698,12 +701,12 @@ void parse_params(int argc, char *argv[]) FILE *F = fopen(optarg,"a+t"); if (!F) { - fprintf(stderr, "cannot create %s\n", optarg); + DLOG_ERR("cannot create %s\n", optarg); exit_clean(1); } fclose(F); if (params.droproot && chown(optarg, params.uid, -1)) - fprintf(stderr, "could not chown %s. auto hostlist debug log may not be writable after privilege drop\n", optarg); + DLOG_ERR("could not chown %s. auto hostlist debug log may not be writable after privilege drop\n", optarg); strncpy(params.hostlist_auto_debuglog, optarg, sizeof(params.hostlist_auto_debuglog)); params.hostlist_auto_debuglog[sizeof(params.hostlist_auto_debuglog) - 1] = '\0'; } @@ -712,55 +715,93 @@ void parse_params(int argc, char *argv[]) strncpy(params.pidfile,optarg,sizeof(params.pidfile)); params.pidfile[sizeof(params.pidfile)-1]='\0'; break; - case 43: - params.debug = optarg ? atoi(optarg) : 1; + case 43: /* debug */ + if (optarg) + { + if (*optarg=='@') + { + strncpy(params.debug_logfile,optarg+1,sizeof(params.debug_logfile)); + params.debug_logfile[sizeof(params.debug_logfile)-1] = 0; + FILE *F = fopen(params.debug_logfile,"wt"); + if (!F) + { + fprintf(stderr, "cannot create %s\n", params.debug_logfile); + exit_clean(1); + } +#ifndef __CYGWIN__ + if (params.droproot && chown(params.debug_logfile, params.uid, -1)) + fprintf(stderr, "could not chown %s. log file may not be writable after privilege drop\n", params.debug_logfile); +#endif + params.debug = 1; + params.debug_target = LOG_TARGET_FILE; + } + else if (!strcmp(optarg,"syslog")) + { + params.debug = 1; + params.debug_target = LOG_TARGET_SYSLOG; + openlog("tpws",LOG_PID,LOG_USER); + } + else + { + params.debug = atoi(optarg); + params.debug_target = LOG_TARGET_CONSOLE; + } + } + else + { + params.debug = 1; + params.debug_target = LOG_TARGET_CONSOLE; + } break; - case 44: /* local-rcvbuf */ + case 44: /* debug-level */ + params.debug = atoi(optarg); + break; + case 45: /* local-rcvbuf */ #ifdef __linux__ params.local_rcvbuf = atoi(optarg)/2; #else params.local_rcvbuf = atoi(optarg); #endif break; - case 45: /* local-sndbuf */ + case 46: /* local-sndbuf */ #ifdef __linux__ params.local_sndbuf = atoi(optarg)/2; #else params.local_sndbuf = atoi(optarg); #endif break; - case 46: /* remote-rcvbuf */ + case 47: /* remote-rcvbuf */ #ifdef __linux__ params.remote_rcvbuf = atoi(optarg)/2; #else params.remote_rcvbuf = atoi(optarg); #endif break; - case 47: /* remote-sndbuf */ + case 48: /* remote-sndbuf */ #ifdef __linux__ params.remote_sndbuf = atoi(optarg)/2; #else params.remote_sndbuf = atoi(optarg); #endif break; - case 48: /* socks */ + case 49: /* socks */ params.proxy_type = CONN_TYPE_SOCKS; break; - case 49: /* no-resolve */ + case 50: /* no-resolve */ params.no_resolve = true; break; - case 50: /* resolver-threads */ + case 51: /* resolver-threads */ params.resolver_threads = atoi(optarg); if (params.resolver_threads<1 || params.resolver_threads>300) { - fprintf(stderr, "resolver-threads must be within 1..300\n"); + DLOG_ERR("resolver-threads must be within 1..300\n"); exit_clean(1); } break; - case 51: /* skip-nodelay */ + case 52: /* skip-nodelay */ params.skip_nodelay = true; break; - case 52: /* tamper-start */ + case 53: /* tamper-start */ { const char *p=optarg; if (*p=='n') @@ -773,7 +814,7 @@ void parse_params(int argc, char *argv[]) params.tamper_start = atoi(p); } break; - case 53: /* tamper-cutoff */ + case 54: /* tamper-cutoff */ { const char *p=optarg; if (*p=='n') @@ -786,7 +827,7 @@ void parse_params(int argc, char *argv[]) params.tamper_cutoff = atoi(p); } break; - case 54: /* connect-bind-addr */ + case 55: /* connect-bind-addr */ { char *p = strchr(optarg,'%'); if (p) *p++=0; @@ -807,34 +848,34 @@ void parse_params(int argc, char *argv[]) } else { - fprintf(stderr, "bad bind addr : %s\n", optarg); + DLOG_ERR("bad bind addr : %s\n", optarg); exit_clean(1); } } break; #if defined(BSD) && !defined(__OpenBSD__) && !defined(__APPLE__) - case 55: /* enable-pf */ + case 56: /* enable-pf */ params.pf_enable = true; break; #elif defined(__linux__) - case 55: /* mss */ + case 56: /* mss */ // this option does not work in any BSD and MacOS. OS may accept but it changes nothing params.mss = atoi(optarg); if (params.mss<88 || params.mss>32767) { - fprintf(stderr, "Invalid value for MSS. Linux accepts MSS 88-32767.\n"); + DLOG_ERR("Invalid value for MSS. Linux accepts MSS 88-32767.\n"); exit_clean(1); } break; - case 56: /* mss-pf */ + case 57: /* mss-pf */ if (!pf_parse(optarg,¶ms.mss_pf)) { - fprintf(stderr, "Invalid MSS port filter.\n"); + DLOG_ERR("Invalid MSS port filter.\n"); exit_clean(1); } break; #ifdef SPLICE_PRESENT - case 57: /* nosplice */ + case 58: /* nosplice */ params.nosplice = true; break; #endif @@ -843,7 +884,7 @@ void parse_params(int argc, char *argv[]) } if (!params.bind_wait_only && !params.port) { - fprintf(stderr, "Need port number\n"); + DLOG_ERR("Need port number\n"); exit_clean(1); } if (params.binds_last<=0) @@ -852,7 +893,7 @@ void parse_params(int argc, char *argv[]) } if (params.skip_nodelay && (params.split_http_req || params.split_pos)) { - fprintf(stderr, "Cannot split with --skip-nodelay\n"); + DLOG_ERR("Cannot split with --skip-nodelay\n"); exit_clean(1); } if (!params.resolver_threads) params.resolver_threads = 5 + params.maxconn/50; @@ -862,13 +903,13 @@ void parse_params(int argc, char *argv[]) if (*params.hostlist_auto_filename) params.hostlist_auto_mod_time = file_mod_time(params.hostlist_auto_filename); if (!LoadIncludeHostLists()) { - fprintf(stderr, "Include hostlist load failed\n"); + DLOG_ERR("Include hostlist load failed\n"); exit_clean(1); } if (*params.hostlist_auto_filename) NonEmptyHostlist(¶ms.hostlist); if (!LoadExcludeHostLists()) { - fprintf(stderr, "Exclude hostlist load failed\n"); + DLOG_ERR("Exclude hostlist load failed\n"); exit_clean(1); } } @@ -991,24 +1032,24 @@ static bool set_ulimit(void) else fdmax = params.maxfiles; fdmin_system = fdmax + 4096; - DBGPRINT("set_ulimit : fdmax=%ju fdmin_system=%ju",(uintmax_t)fdmax,(uintmax_t)fdmin_system) + DBGPRINT("set_ulimit : fdmax=%ju fdmin_system=%ju\n",(uintmax_t)fdmax,(uintmax_t)fdmin_system); if (!read_system_maxfiles(&cur_lim)) return false; - DBGPRINT("set_ulimit : current system file-max=%ju",(uintmax_t)cur_lim) + DBGPRINT("set_ulimit : current system file-max=%ju\n",(uintmax_t)cur_lim); if (cur_lim=params.binds[i].bind_wait_ifup) { - printf("wait timed out\n"); + DLOG_CONDUP("wait timed out\n"); goto exiterr; } } } if (!(if_index = if_nametoindex(params.binds[i].bindiface)) && params.binds[i].bind_wait_ip<=0) { - printf("bad iface %s\n",params.binds[i].bindiface); + DLOG_CONDUP("bad iface %s\n",params.binds[i].bindiface); goto exiterr; } } @@ -1087,7 +1128,7 @@ int main(int argc, char *argv[]) } else { - printf("bad bind addr : %s\n", params.binds[i].bindaddr); + DLOG_CONDUP("bad bind addr : %s\n", params.binds[i].bindaddr); goto exiterr; } } @@ -1101,13 +1142,13 @@ int main(int argc, char *argv[]) if (params.binds[i].bind_wait_ip > 0) { - printf("waiting for ip on %s for up to %d second(s)...\n", *params.binds[i].bindiface ? params.binds[i].bindiface : "", params.binds[i].bind_wait_ip); + DLOG_CONDUP("waiting for ip on %s for up to %d second(s)...\n", *params.binds[i].bindiface ? params.binds[i].bindiface : "", params.binds[i].bind_wait_ip); if (params.binds[i].bind_wait_ip_ll>0) { if (params.binds[i].bindll==prefer) - printf("during the first %d second(s) accepting only link locals...\n", params.binds[i].bind_wait_ip_ll); + DLOG_CONDUP("during the first %d second(s) accepting only link locals...\n", params.binds[i].bind_wait_ip_ll); else if (params.binds[i].bindll==unwanted) - printf("during the first %d second(s) accepting only ipv6 globals...\n", params.binds[i].bind_wait_ip_ll); + DLOG_CONDUP("during the first %d second(s) accepting only ipv6 globals...\n", params.binds[i].bind_wait_ip_ll); } } @@ -1120,9 +1161,9 @@ int main(int argc, char *argv[]) if (sec && sec==params.binds[i].bind_wait_ip_ll) { if (params.binds[i].bindll==prefer) - printf("link local address wait timeout. now accepting globals\n"); + DLOG_CONDUP("link local address wait timeout. now accepting globals\n"); else if (params.binds[i].bindll==unwanted) - printf("global ipv6 address wait timeout. now accepting link locals\n"); + DLOG_CONDUP("global ipv6 address wait timeout. now accepting link locals\n"); } found = find_listen_addr(&list[i].salisten,params.binds[i].bindiface,params.binds[i].bind_if6,bindll_1,&if_index); if (found) break; @@ -1136,7 +1177,7 @@ int main(int argc, char *argv[]) if (!found) { - printf("suitable ip address not found\n"); + DLOG_CONDUP("suitable ip address not found\n"); goto exiterr; } list[i].bind_wait_ip_left = params.binds[i].bind_wait_ip - sec; @@ -1164,14 +1205,14 @@ int main(int argc, char *argv[]) if (params.bind_wait_only) { - printf("bind wait condition satisfied\n"); + DLOG_CONDUP("bind wait condition satisfied\n"); exit_v = 0; goto exiterr; } if (params.proxy_type==CONN_TYPE_TRANSPARENT && !redir_init()) { - fprintf(stderr,"could not initialize redirector !!!\n"); + DLOG_ERR("could not initialize redirector !!!\n"); goto exiterr; } @@ -1180,11 +1221,11 @@ int main(int argc, char *argv[]) if (params.debug) { ntop46_port((struct sockaddr *)&list[i].salisten, ip_port, sizeof(ip_port)); - VPRINT("Binding %d to %s",i,ip_port); + VPRINT("Binding %d to %s\n",i,ip_port); } if ((listen_fd[i] = socket(list[i].salisten.ss_family, SOCK_STREAM, 0)) == -1) { - perror("socket"); + DLOG_PERROR("socket"); goto exiterr; } @@ -1192,14 +1233,14 @@ int main(int argc, char *argv[]) // in OpenBSD always IPV6_ONLY for wildcard sockets if ((list[i].salisten.ss_family == AF_INET6) && setsockopt(listen_fd[i], IPPROTO_IPV6, IPV6_V6ONLY, &list[i].ipv6_only, sizeof(int)) == -1) { - perror("setsockopt (IPV6_ONLY)"); + DLOG_PERROR("setsockopt (IPV6_ONLY)"); goto exiterr; } #endif if (setsockopt(listen_fd[i], SOL_SOCKET, SO_REUSEADDR, &yes, sizeof(yes)) == -1) { - perror("setsockopt (SO_REUSEADDR)"); + DLOG_PERROR("setsockopt (SO_REUSEADDR)"); goto exiterr; } @@ -1210,13 +1251,13 @@ int main(int argc, char *argv[]) #ifdef __linux__ if (setsockopt(listen_fd[i], SOL_IP, IP_TRANSPARENT, &yes, sizeof(yes)) == -1) { - perror("setsockopt (IP_TRANSPARENT)"); + DLOG_PERROR("setsockopt (IP_TRANSPARENT)"); goto exiterr; } #elif defined(BSD) && defined(SO_BINDANY) if (setsockopt(listen_fd[i], SOL_SOCKET, SO_BINDANY, &yes, sizeof(yes)) == -1) { - perror("setsockopt (SO_BINDANY)"); + DLOG_PERROR("setsockopt (SO_BINDANY)"); goto exiterr; } #endif @@ -1249,21 +1290,21 @@ int main(int argc, char *argv[]) if (!bBindBug) { ntop46_port((struct sockaddr *)&list[i].salisten, ip_port, sizeof(ip_port)); - printf("address %s is not available. will retry for %d sec\n",ip_port,list[i].bind_wait_ip_left); + DLOG_CONDUP("address %s is not available. will retry for %d sec\n",ip_port,list[i].bind_wait_ip_left); bBindBug=true; } sleep(1); list[i].bind_wait_ip_left--; continue; } - perror("bind"); + DLOG_PERROR("bind"); goto exiterr; } break; } if (listen(listen_fd[i], BACKLOG) == -1) { - perror("listen"); + DLOG_PERROR("listen"); goto exiterr; } } @@ -1278,19 +1319,19 @@ int main(int argc, char *argv[]) //example a socket) is closed during splice(). I would rather have splice() //fail and return -1, so blocking SIGPIPE. if (block_sigpipe() == -1) { - fprintf(stderr, "Could not block SIGPIPE signal\n"); + DLOG_ERR("Could not block SIGPIPE signal\n"); goto exiterr; } - printf(params.proxy_type==CONN_TYPE_SOCKS ? "socks mode\n" : "transparent proxy mode\n"); - if (!params.tamper) printf("TCP proxy mode (no tampering)\n"); + DLOG_CONDUP(params.proxy_type==CONN_TYPE_SOCKS ? "socks mode\n" : "transparent proxy mode\n"); + if (!params.tamper) DLOG_CONDUP("TCP proxy mode (no tampering)\n"); signal(SIGHUP, onhup); signal(SIGUSR2, onusr2); retval = event_loop(listen_fd,params.binds_last+1); exit_v = retval < 0 ? EXIT_FAILURE : EXIT_SUCCESS; - printf("Exiting\n"); + DLOG_CONDUP("Exiting\n"); exiterr: redir_close(); diff --git a/tpws/tpws_conn.c b/tpws/tpws_conn.c index 1222c0a..9ee4e29 100644 --- a/tpws/tpws_conn.c +++ b/tpws/tpws_conn.c @@ -40,7 +40,7 @@ static void count_legs(struct tailhead *conn_list) */ static void print_legs(void) { - VPRINT("Legs : local:%d remote:%d", legs_local, legs_remote) + VPRINT("Legs : local:%d remote:%d\n", legs_local, legs_remote); } @@ -99,17 +99,17 @@ ssize_t send_with_ttl(int fd, const void *buf, size_t len, int flags, int ttl) if (ttl) { - DBGPRINT("send_with_ttl %d fd=%d",ttl,fd); + DBGPRINT("send_with_ttl %d fd=%d\n",ttl,fd); if (!set_ttl_hl(fd, ttl)) - //fprintf(stderr,"could not set ttl %d to fd=%d\n",ttl,fd); - fprintf(stderr,"could not set ttl %d to fd=%d\n",ttl,fd); + //DLOG_ERR("could not set ttl %d to fd=%d\n",ttl,fd); + DLOG_ERR("could not set ttl %d to fd=%d\n",ttl,fd); } wr = send(fd, buf, len, flags); if (ttl) { int e=errno; if (!set_ttl_hl(fd, params.ttl_default)) - fprintf(stderr,"could not set ttl %d to fd=%d\n",params.ttl_default,fd); + DLOG_ERR("could not set ttl %d to fd=%d\n",params.ttl_default,fd); errno=e; } return wr; @@ -120,13 +120,13 @@ static bool send_buffer_create(send_buffer_t *sb, const void *data, size_t len, { if (sb->data) { - fprintf(stderr,"FATAL : send_buffer_create but buffer is not empty\n"); + DLOG_ERR("FATAL : send_buffer_create but buffer is not empty\n"); exit(1); } sb->data = malloc(len + extra_bytes); if (!sb->data) { - DBGPRINT("send_buffer_create failed. errno=%d",errno) + DBGPRINT("send_buffer_create failed\n"); return false; } if (data) memcpy(sb->data,data,len); @@ -144,12 +144,12 @@ static bool send_buffer_realloc(send_buffer_t *sb, size_t extra_bytes) if (p) { sb->data = p; - DBGPRINT("reallocated send_buffer from %zd to %zd", sb->len, sb->len + extra_bytes) + DBGPRINT("reallocated send_buffer from %zd to %zd\n", sb->len, sb->len + extra_bytes); return true; } else { - DBGPRINT("failed to realloc send_buffer from %zd to %zd", sb->len, sb->len + extra_bytes) + DBGPRINT("failed to realloc send_buffer from %zd to %zd\n", sb->len, sb->len + extra_bytes); } } return false; @@ -188,7 +188,7 @@ static ssize_t send_buffer_send(send_buffer_t *sb, int fd) ssize_t wr; wr = send_with_ttl(fd, sb->data + sb->pos, sb->len - sb->pos, sb->flags, sb->ttl); - DBGPRINT("send_buffer_send len=%zu pos=%zu wr=%zd err=%d",sb->len,sb->pos,wr,errno) + DBGPRINT("send_buffer_send len=%zu pos=%zu wr=%zd err=%d\n",sb->len,sb->pos,wr,errno); if (wr>0) { sb->pos += wr; @@ -210,7 +210,7 @@ static ssize_t send_buffers_send(send_buffer_t *sb_array, int count, int fd, siz if (send_buffer_present(sb_array+i)) { wr = send_buffer_send(sb_array+i, fd); - DBGPRINT("send_buffers_send(%d) wr=%zd err=%d",i,wr,errno) + DBGPRINT("send_buffers_send(%d) wr=%zd err=%d\n",i,wr,errno); if (wr<0) { if (real_wr) *real_wr = twr; @@ -285,25 +285,25 @@ static void dbgprint_socket_buffers(int fd) socklen_t sz; sz=sizeof(int); if (!getsockopt(fd,SOL_SOCKET,SO_RCVBUF,&v,&sz)) - DBGPRINT("fd=%d SO_RCVBUF=%d",fd,v) + DBGPRINT("fd=%d SO_RCVBUF=%d\n",fd,v); sz=sizeof(int); if (!getsockopt(fd,SOL_SOCKET,SO_SNDBUF,&v,&sz)) - DBGPRINT("fd=%d SO_SNDBUF=%d",fd,v) + DBGPRINT("fd=%d SO_SNDBUF=%d\n",fd,v); } } bool set_socket_buffers(int fd, int rcvbuf, int sndbuf) { - DBGPRINT("set_socket_buffers fd=%d rcvbuf=%d sndbuf=%d",fd,rcvbuf,sndbuf) + DBGPRINT("set_socket_buffers fd=%d rcvbuf=%d sndbuf=%d\n",fd,rcvbuf,sndbuf); if (rcvbuf && setsockopt(fd, SOL_SOCKET, SO_RCVBUF, &rcvbuf, sizeof(int)) <0) { - perror("setsockopt (SO_RCVBUF)"); + DLOG_PERROR("setsockopt (SO_RCVBUF)"); close(fd); return false; } if (sndbuf && setsockopt(fd, SOL_SOCKET, SO_SNDBUF, &sndbuf, sizeof(int)) <0) { - perror("setsockopt (SO_SNDBUF)"); + DLOG_PERROR("setsockopt (SO_SNDBUF)"); close(fd); return false; } @@ -324,7 +324,7 @@ static bool proxy_remote_conn_ack(tproxy_conn_t *conn, int sock_err) { conn->partner->socks_state=S_TCP; bres = socks_send_rep_errno(conn->partner->socks_ver,conn->partner->fd,sock_err); - DBGPRINT("socks connection acknowledgement. bres=%d remote_errn=%d remote_fd=%d local_fd=%d",bres,sock_err,conn->fd,conn->partner->fd) + DBGPRINT("socks connection acknowledgement. bres=%d remote_errn=%d remote_fd=%d local_fd=%d\n",bres,sock_err,conn->fd,conn->partner->fd); } break; } @@ -341,20 +341,20 @@ static int connect_remote(const struct sockaddr *remote_addr, bool bApplyConnect if((remote_fd = socket(remote_addr->sa_family, SOCK_STREAM, 0)) < 0) { - perror("socket (connect_remote)"); + DLOG_PERROR("socket (connect_remote)"); return -1; } // Use NONBLOCK to avoid slow connects affecting the performance of other connections // separate fcntl call to comply with macos if (fcntl(remote_fd, F_SETFL, O_NONBLOCK)<0) { - perror("socket set O_NONBLOCK (connect_remote)"); + DLOG_PERROR("socket set O_NONBLOCK (connect_remote)"); close(remote_fd); return -1; } if (setsockopt(remote_fd, SOL_SOCKET, SO_REUSEADDR, &yes, sizeof(yes)) < 0) { - perror("setsockopt (SO_REUSEADDR, connect_remote)"); + DLOG_PERROR("setsockopt (SO_REUSEADDR, connect_remote)"); close(remote_fd); return -1; } @@ -362,13 +362,13 @@ static int connect_remote(const struct sockaddr *remote_addr, bool bApplyConnect return -1; if (!set_keepalive(remote_fd)) { - perror("set_keepalive"); + DLOG_PERROR("set_keepalive"); close(remote_fd); return -1; } if (setsockopt(remote_fd, IPPROTO_TCP, TCP_NODELAY, params.skip_nodelay ? &no : &yes, sizeof(int)) <0) { - perror("setsockopt (TCP_NODELAY, connect_remote)"); + DLOG_PERROR("setsockopt (TCP_NODELAY, connect_remote)"); close(remote_fd); return -1; } @@ -377,17 +377,17 @@ static int connect_remote(const struct sockaddr *remote_addr, bool bApplyConnect uint16_t port = saport(remote_addr); if (pf_in_range(port,¶ms.mss_pf)) { - VPRINT("Setting MSS %d",params.mss) + VPRINT("Setting MSS %d\n",params.mss); if (setsockopt(remote_fd, IPPROTO_TCP, TCP_MAXSEG, ¶ms.mss, sizeof(int)) <0) { - perror("setsockopt (TCP_MAXSEG, connect_remote)"); + DLOG_PERROR("setsockopt (TCP_MAXSEG, connect_remote)"); close(remote_fd); return -1; } } else { - VPRINT("Not setting MSS. Port %u is out of MSS port range.",port) + VPRINT("Not setting MSS. Port %u is out of MSS port range.\n",port); } } @@ -396,7 +396,7 @@ static int connect_remote(const struct sockaddr *remote_addr, bool bApplyConnect { if (bind(remote_fd, (struct sockaddr *)¶ms.connect_bind4, sizeof(struct sockaddr_in)) == -1) { - perror("bind on connect"); + DLOG_PERROR("bind on connect"); close(remote_fd); return -1; } @@ -408,7 +408,7 @@ static int connect_remote(const struct sockaddr *remote_addr, bool bApplyConnect params.connect_bind6.sin6_scope_id=if_nametoindex(params.connect_bind6_ifname); if (!params.connect_bind6.sin6_scope_id) { - fprintf(stderr, "interface name not found : %s\n", params.connect_bind6_ifname); + DLOG_ERR("interface name not found : %s\n", params.connect_bind6_ifname); close(remote_fd); return -1; } @@ -416,7 +416,7 @@ static int connect_remote(const struct sockaddr *remote_addr, bool bApplyConnect if (bind(remote_fd, (struct sockaddr *)¶ms.connect_bind6, sizeof(struct sockaddr_in6)) == -1) { - perror("bind on connect"); + DLOG_PERROR("bind on connect"); close(remote_fd); return -1; } @@ -426,12 +426,12 @@ static int connect_remote(const struct sockaddr *remote_addr, bool bApplyConnect { if(errno != EINPROGRESS) { - perror("connect (connect_remote)"); + DLOG_PERROR("connect (connect_remote)"); close(remote_fd); return -1; } } - DBGPRINT("Connecting remote fd=%d",remote_fd) + DBGPRINT("Connecting remote fd=%d\n",remote_fd); return remote_fd; } @@ -460,7 +460,7 @@ static tproxy_conn_t *new_conn(int fd, bool remote) //Create connection object and fill in information if((conn = (tproxy_conn_t*) malloc(sizeof(tproxy_conn_t))) == NULL) { - fprintf(stderr, "Could not allocate memory for connection\n"); + DLOG_ERR("Could not allocate memory for connection\n"); return NULL; } @@ -474,7 +474,7 @@ static tproxy_conn_t *new_conn(int fd, bool remote) // otherwise create pipe only in local leg if (!params.nosplice && ( !remote || !params.tamper || params.tamper_start || params.tamper_cutoff ) && pipe2(conn->splice_pipe, O_NONBLOCK) != 0) { - fprintf(stderr, "Could not create the splice pipe\n"); + DLOG_ERR("Could not create the splice pipe\n"); free_conn(conn); return NULL; } @@ -490,11 +490,11 @@ static bool epoll_set(tproxy_conn_t *conn, uint32_t events) memset(&ev, 0, sizeof(ev)); ev.events = events; ev.data.ptr = (void*) conn; - DBGPRINT("epoll_set fd=%d events=%08X",conn->fd,events); + DBGPRINT("epoll_set fd=%d events=%08X\n",conn->fd,events); if(epoll_ctl(conn->efd, EPOLL_CTL_MOD, conn->fd, &ev)==-1 && epoll_ctl(conn->efd, EPOLL_CTL_ADD, conn->fd, &ev)==-1) { - perror("epoll_ctl (add/mod)"); + DLOG_PERROR("epoll_ctl (add/mod)"); return false; } return true; @@ -505,10 +505,10 @@ static bool epoll_del(tproxy_conn_t *conn) memset(&ev, 0, sizeof(ev)); - DBGPRINT("epoll_del fd=%d",conn->fd); + DBGPRINT("epoll_del fd=%d\n",conn->fd); if(epoll_ctl(conn->efd, EPOLL_CTL_DEL, conn->fd, &ev)==-1) { - perror("epoll_ctl (del)"); + DLOG_PERROR("epoll_ctl (del)"); return false; } return true; @@ -521,7 +521,7 @@ static bool epoll_update_flow(tproxy_conn_t *conn) uint32_t evtmask = (conn->state==CONN_RDHUP ? 0 : EPOLLRDHUP)|(conn->bFlowIn?EPOLLIN:0)|(conn->bFlowOut?EPOLLOUT:0); if (!epoll_set(conn, evtmask)) return false; - DBGPRINT("SET FLOW fd=%d to in=%d out=%d state_rdhup=%d",conn->fd,conn->bFlowIn,conn->bFlowOut,conn->state==CONN_RDHUP) + DBGPRINT("SET FLOW fd=%d to in=%d out=%d state_rdhup=%d\n",conn->fd,conn->bFlowIn,conn->bFlowOut,conn->state==CONN_RDHUP); conn->bFlowInPrev = conn->bFlowIn; conn->bFlowOutPrev = conn->bFlowOut; conn->bPrevRdhup = (conn->state==CONN_RDHUP); @@ -546,13 +546,13 @@ static tproxy_conn_t* add_tcp_connection(int efd, struct tailhead *conn_list,int { if(!get_dest_addr(local_fd, accept_sa, &orig_dst)) { - fprintf(stderr, "Could not get destination address\n"); + DLOG_ERR("Could not get destination address\n"); close(local_fd); return NULL; } if (check_local_ip((struct sockaddr*)&orig_dst) && saport((struct sockaddr*)&orig_dst)==listen_port) { - VPRINT("Dropping connection to local address to the same port to avoid loop") + VPRINT("Dropping connection to local address to the same port to avoid loop\n"); close(local_fd); return NULL; } @@ -563,7 +563,7 @@ static tproxy_conn_t* add_tcp_connection(int efd, struct tailhead *conn_list,int if(!set_keepalive(local_fd)) { - perror("set_keepalive"); + DLOG_PERROR("set_keepalive"); close(local_fd); return 0; } @@ -572,7 +572,7 @@ static tproxy_conn_t* add_tcp_connection(int efd, struct tailhead *conn_list,int { if ((remote_fd = connect_remote((struct sockaddr *)&orig_dst, true)) < 0) { - fprintf(stderr, "Failed to connect\n"); + DLOG_ERR("Failed to connect\n"); close(local_fd); return NULL; } @@ -651,12 +651,23 @@ static bool check_connection_attempt(tproxy_conn_t *conn, int efd) // check the connection was sucessfull. it means its not in in SO_ERROR state if(getsockopt(conn->fd, SOL_SOCKET, SO_ERROR, &errn, &optlen) == -1) { - perror("getsockopt (SO_ERROR)"); + DLOG_PERROR("getsockopt (SO_ERROR)"); return false; } if (!errn) { - VPRINT("Socket fd=%d (remote) connected", conn->fd) + if (params.debug>=1) + { + struct sockaddr_storage sa; + socklen_t salen=sizeof(sa); + char ip_port[48]; + + if (getsockname(conn->fd,(struct sockaddr *)&sa,&salen)) + *ip_port=0; + else + ntop46_port((struct sockaddr*)&sa,ip_port,sizeof(ip_port)); + VPRINT("Socket fd=%d (remote) connected from : %s\n", conn->fd, ip_port); + } if (!epoll_set_flow(conn, true, false) || (conn_partner_alive(conn) && !epoll_set_flow(conn->partner, true, false))) { return false; @@ -675,8 +686,8 @@ static bool epoll_set_flow_pair(tproxy_conn_t *conn) bool bHasUnsent = conn_has_unsent(conn); bool bHasUnsentPartner = conn_partner_alive(conn) ? conn_has_unsent(conn->partner) : false; - DBGPRINT("epoll_set_flow_pair fd=%d remote=%d partner_fd=%d bHasUnsent=%d bHasUnsentPartner=%d state_rdhup=%d", - conn->fd , conn->remote, conn_partner_alive(conn) ? conn->partner->fd : 0, bHasUnsent, bHasUnsentPartner, conn->state==CONN_RDHUP) + DBGPRINT("epoll_set_flow_pair fd=%d remote=%d partner_fd=%d bHasUnsent=%d bHasUnsentPartner=%d state_rdhup=%d\n", + conn->fd , conn->remote, conn_partner_alive(conn) ? conn->partner->fd : 0, bHasUnsent, bHasUnsentPartner, conn->state==CONN_RDHUP); if (!epoll_set_flow(conn, !bHasUnsentPartner && (conn->state!=CONN_RDHUP), bHasUnsent || conn->state==CONN_RDHUP)) return false; if (conn_partner_alive(conn)) @@ -691,13 +702,13 @@ static bool handle_unsent(tproxy_conn_t *conn) { ssize_t wr; - DBGPRINT("+handle_unsent, fd=%d has_unsent=%d has_unsent_partner=%d",conn->fd,conn_has_unsent(conn),conn_partner_alive(conn) ? conn_has_unsent(conn->partner) : false) + DBGPRINT("+handle_unsent, fd=%d has_unsent=%d has_unsent_partner=%d\n",conn->fd,conn_has_unsent(conn),conn_partner_alive(conn) ? conn_has_unsent(conn->partner) : false); #ifdef SPLICE_PRESENT if (!params.nosplice && conn->wr_unsent) { wr = splice(conn->splice_pipe[0], NULL, conn->fd, NULL, conn->wr_unsent, SPLICE_F_MOVE | SPLICE_F_NONBLOCK); - DBGPRINT("splice unsent=%zd wr=%zd err=%d",conn->wr_unsent,wr,errno) + DBGPRINT("splice unsent=%zd wr=%zd err=%d\n",conn->wr_unsent,wr,errno); if (wr<0) { if (errno==EAGAIN) wr=0; @@ -710,7 +721,7 @@ static bool handle_unsent(tproxy_conn_t *conn) if (!conn->wr_unsent && conn_buffers_present(conn)) { wr=conn_buffers_send(conn); - DBGPRINT("conn_buffers_send wr=%zd",wr) + DBGPRINT("conn_buffers_send wr=%zd\n",wr); if (wr<0) return false; } return epoll_set_flow_pair(conn); @@ -723,13 +734,13 @@ bool proxy_mode_connect_remote(const struct sockaddr *sa, tproxy_conn_t *conn, s if (params.debug>=1) { - printf("socks target for fd=%d is : ", conn->fd); - print_sockaddr(sa); - printf("\n"); + char ip_port[48]; + ntop46_port(sa,ip_port,sizeof(ip_port)); + VPRINT("socks target for fd=%d is : %s\n", conn->fd, ip_port); } if (check_local_ip((struct sockaddr *)sa)) { - VPRINT("Dropping connection to local address for security reasons") + VPRINT("Dropping connection to local address for security reasons\n"); socks_send_rep(conn->socks_ver, conn->fd, S5_REP_NOT_ALLOWED_BY_RULESET); return false; } @@ -739,19 +750,19 @@ bool proxy_mode_connect_remote(const struct sockaddr *sa, tproxy_conn_t *conn, s { bConnFooling=HostlistCheck(conn->track.hostname, NULL); if (!bConnFooling) - VPRINT("0-phase desync hostlist check negative. not acting on this connection.") + VPRINT("0-phase desync hostlist check negative. not acting on this connection.\n"); } if ((remote_fd = connect_remote(sa, bConnFooling)) < 0) { - fprintf(stderr, "socks failed to connect (1) errno=%d\n", errno); + DLOG_ERR("socks failed to connect (1) errno=%d\n", errno); socks_send_rep_errno(conn->socks_ver, conn->fd, errno); return false; } if (!(conn->partner = new_conn(remote_fd, true))) { close(remote_fd); - fprintf(stderr, "socks out-of-memory (1)\n"); + DLOG_ERR("socks out-of-memory (1)\n"); socks_send_rep(conn->socks_ver, conn->fd, S5_REP_GENERAL_FAILURE); return false; } @@ -759,7 +770,7 @@ bool proxy_mode_connect_remote(const struct sockaddr *sa, tproxy_conn_t *conn, s conn->partner->efd = conn->efd; if (!epoll_set(conn->partner, EPOLLOUT)) { - fprintf(stderr, "socks epoll_set error %d\n", errno); + DLOG_ERR("socks epoll_set error %d\n", errno); free_conn(conn->partner); conn->partner = NULL; socks_send_rep(conn->socks_ver, conn->fd, S5_REP_GENERAL_FAILURE); @@ -768,7 +779,7 @@ bool proxy_mode_connect_remote(const struct sockaddr *sa, tproxy_conn_t *conn, s TAILQ_INSERT_HEAD(conn_list, conn->partner, conn_ptrs); legs_remote++; print_legs(); - DBGPRINT("S_WAIT_CONNECTION") + DBGPRINT("S_WAIT_CONNECTION\n"); conn->socks_state = S_WAIT_CONNECTION; return true; } @@ -784,7 +795,7 @@ static bool handle_proxy_mode(tproxy_conn_t *conn, struct tailhead *conn_list) // receive proxy control message rd=recv(conn->fd, buf, sizeof(buf), MSG_DONTWAIT); - DBGPRINT("handle_proxy_mode rd=%zd",rd) + DBGPRINT("handle_proxy_mode rd=%zd\n",rd); if (rd<1) return false; // hangup switch(conn->conn_type) { @@ -792,10 +803,10 @@ static bool handle_proxy_mode(tproxy_conn_t *conn, struct tailhead *conn_list) switch(conn->socks_state) { case S_WAIT_HANDSHAKE: - DBGPRINT("S_WAIT_HANDSHAKE") + DBGPRINT("S_WAIT_HANDSHAKE\n"); if (buf[0] != 5 && buf[0] != 4) return false; // unknown socks version conn->socks_ver = buf[0]; - DBGPRINT("socks version %u", conn->socks_ver) + DBGPRINT("socks version %u\n", conn->socks_ver); if (conn->socks_ver==5) { s5_handshake *m = (s5_handshake*)buf; @@ -805,26 +816,26 @@ static bool handle_proxy_mode(tproxy_conn_t *conn, struct tailhead *conn_list) ack.ver=5; if (!S5_REQ_HANDHSHAKE_VALID(m,rd)) { - DBGPRINT("socks5 proxy handshake invalid") + DBGPRINT("socks5 proxy handshake invalid\n"); return false; } for (k=0;knmethods;k++) if (m->methods[k]==S5_AUTH_NONE) break; if (k>=m->nmethods) { - DBGPRINT("socks5 client wants authentication but we dont support") + DBGPRINT("socks5 client wants authentication but we dont support\n"); ack.method=S5_AUTH_UNACCEPTABLE; wr=send(conn->fd,&ack,sizeof(ack),MSG_DONTWAIT); return false; } - DBGPRINT("socks5 recv valid handshake") + DBGPRINT("socks5 recv valid handshake\n"); ack.method=S5_AUTH_NONE; wr=send(conn->fd,&ack,sizeof(ack),MSG_DONTWAIT); if (wr!=sizeof(ack)) { - DBGPRINT("socks5 handshake ack send error. wr=%zd errno=%d",wr,errno) + DBGPRINT("socks5 handshake ack send error. wr=%zd errno=%d\n",wr,errno); return false; } - DBGPRINT("socks5 send handshake ack OK") + DBGPRINT("socks5 send handshake ack OK\n"); conn->socks_state=S_WAIT_REQUEST; return true; } @@ -835,31 +846,31 @@ static bool handle_proxy_mode(tproxy_conn_t *conn, struct tailhead *conn_list) s4_req *m = (s4_req*)buf; if (!S4_REQ_HEADER_VALID(m, rd)) { - DBGPRINT("socks4 request invalid") + DBGPRINT("socks4 request invalid\n"); return false; } if (m->cmd!=S4_CMD_CONNECT) { // BIND is not supported - DBGPRINT("socks4 unsupported command %02X", m->cmd) + DBGPRINT("socks4 unsupported command %02X\n", m->cmd); socks4_send_rep(conn->fd, S4_REP_FAILED); return false; } if (!S4_REQ_CONNECT_VALID(m, rd)) { - DBGPRINT("socks4 connect request invalid") + DBGPRINT("socks4 connect request invalid\n"); socks4_send_rep(conn->fd, S4_REP_FAILED); return false; } if (!m->port) { - DBGPRINT("socks4 zero port") + DBGPRINT("socks4 zero port\n"); socks4_send_rep(conn->fd, S4_REP_FAILED); return false; } if (m->ip==htonl(1)) // special ip 0.0.0.1 { - VPRINT("socks4a protocol not supported") + VPRINT("socks4a protocol not supported\n"); socks4_send_rep(conn->fd, S4_REP_FAILED); return false; } @@ -870,28 +881,28 @@ static bool handle_proxy_mode(tproxy_conn_t *conn, struct tailhead *conn_list) } break; case S_WAIT_REQUEST: - DBGPRINT("S_WAIT_REQUEST") + DBGPRINT("S_WAIT_REQUEST\n"); { s5_req *m = (s5_req*)buf; if (!S5_REQ_HEADER_VALID(m,rd)) { - DBGPRINT("socks5 request invalid") + DBGPRINT("socks5 request invalid\n"); return false; } if (m->cmd!=S5_CMD_CONNECT) { // BIND and UDP are not supported - DBGPRINT("socks5 unsupported command %02X", m->cmd) + DBGPRINT("socks5 unsupported command %02X\n", m->cmd); socks5_send_rep(conn->fd,S5_REP_COMMAND_NOT_SUPPORTED); return false; } if (!S5_REQ_CONNECT_VALID(m,rd)) { - DBGPRINT("socks5 connect request invalid") + DBGPRINT("socks5 connect request invalid\n"); return false; } - DBGPRINT("socks5 recv valid connect request") + DBGPRINT("socks5 recv valid connect request\n"); switch(m->atyp) { case S5_ATYP_IP4: @@ -912,28 +923,28 @@ static bool handle_proxy_mode(tproxy_conn_t *conn, struct tailhead *conn_list) if (params.no_resolve) { - VPRINT("socks5 hostname resolving disabled") + VPRINT("socks5 hostname resolving disabled\n"); socks5_send_rep(conn->fd,S5_REP_NOT_ALLOWED_BY_RULESET); return false; } port=S5_PORT_FROM_DD(m,rd); if (!port) { - VPRINT("socks5 no port is given") + VPRINT("socks5 no port is given\n"); socks5_send_rep(conn->fd,S5_REP_HOST_UNREACHABLE); return false; } m->dd.domport[m->dd.len] = 0; - DBGPRINT("socks5 queue resolve hostname '%s' port '%u'",m->dd.domport,port) + DBGPRINT("socks5 queue resolve hostname '%s' port '%u'\n",m->dd.domport,port); conn->socks_ri = resolver_queue(m->dd.domport,port,conn); if (!conn->socks_ri) { - VPRINT("socks5 could not queue resolve item") + VPRINT("socks5 could not queue resolve item\n"); socks5_send_rep(conn->fd,S5_REP_GENERAL_FAILURE); return false; } conn->socks_state=S_WAIT_RESOLVE; - DBGPRINT("S_WAIT_RESOLVE") + DBGPRINT("S_WAIT_RESOLVE\n"); return true; } break; @@ -945,13 +956,13 @@ static bool handle_proxy_mode(tproxy_conn_t *conn, struct tailhead *conn_list) } break; case S_WAIT_RESOLVE: - DBGPRINT("socks received message while in S_WAIT_RESOLVE. hanging up") + DBGPRINT("socks received message while in S_WAIT_RESOLVE. hanging up\n"); break; case S_WAIT_CONNECTION: - DBGPRINT("socks received message while in S_WAIT_CONNECTION. hanging up") + DBGPRINT("socks received message while in S_WAIT_CONNECTION. hanging up\n"); break; default: - DBGPRINT("socks received message while in an unexpected connection state") + DBGPRINT("socks received message while in an unexpected connection state\n"); break; } break; @@ -967,7 +978,7 @@ static bool resolve_complete(struct resolve_item *ri, struct tailhead *conn_list { if (conn->socks_state==S_WAIT_RESOLVE) { - DBGPRINT("resolve_complete %s. getaddrinfo result %d", ri->dom, ri->ga_res); + DBGPRINT("resolve_complete %s. getaddrinfo result %d\n", ri->dom, ri->ga_res); if (ri->ga_res) { socks5_send_rep(conn->fd,S5_REP_HOST_UNREACHABLE); @@ -977,17 +988,17 @@ static bool resolve_complete(struct resolve_item *ri, struct tailhead *conn_list { if (!conn->track.hostname) { - DBGPRINT("resolve_complete put hostname : %s", ri->dom) + DBGPRINT("resolve_complete put hostname : %s\n", ri->dom); conn->track.hostname = strdup(ri->dom); } return proxy_mode_connect_remote((struct sockaddr *)&ri->ss,conn,conn_list); } } else - fprintf(stderr, "resolve_complete: conn in wrong socks_state !!! (%s)\n", ri->dom); + DLOG_ERR("resolve_complete: conn in wrong socks_state !!! (%s)\n", ri->dom); } else - DBGPRINT("resolve_complete: orphaned resolve for %s", ri->dom); + DBGPRINT("resolve_complete: orphaned resolve for %s\n", ri->dom); return true; } @@ -1014,11 +1025,11 @@ static void tamper(tproxy_conn_t *conn, uint8_t *segment, size_t segment_buffer_ else { bool in_range = in_tamper_out_range(conn); - DBGPRINT("tamper_out stream pos %" PRIu64 "(n%" PRIu64 "). tamper range %s%u-%s%u (%s)", + DBGPRINT("tamper_out stream pos %" PRIu64 "(n%" PRIu64 "). tamper range %s%u-%s%u (%s)\n", conn->trd, conn->tnrd+1, params.tamper_start_n ? "n" : "" , params.tamper_start, params.tamper_cutoff_n ? "n" : "" , params.tamper_cutoff, - in_range ? "IN RANGE" : "OUT OF RANGE") + in_range ? "IN RANGE" : "OUT OF RANGE"); if (in_range) tamper_out(&conn->track,segment,segment_buffer_size,segment_size,split_pos,split_flags); } } @@ -1030,7 +1041,7 @@ static ssize_t send_or_buffer_oob(send_buffer_t *sb, int fd, uint8_t *buf, size_ ssize_t wr; if (oob) { - VPRINT("Sending OOB byte %02X", params.oob_byte) + VPRINT("Sending OOB byte %02X\n", params.oob_byte); uint8_t oob_save; oob_save = buf[len]; buf[len] = params.oob_byte; @@ -1052,7 +1063,7 @@ static bool handle_epoll(tproxy_conn_t *conn, struct tailhead *conn_list, uint32 size_t bs; - DBGPRINT("+handle_epoll") + DBGPRINT("+handle_epoll\n"); if (!conn_in_tcp_mode(conn)) { @@ -1080,7 +1091,7 @@ static bool handle_epoll(tproxy_conn_t *conn, struct tailhead *conn_list, uint32 trd+=rd; conn->trd+=rd; } - DBGPRINT("wasted recv=%zd all_rd=%" PRIu64 " err=%d",rd,trd,errno) + DBGPRINT("wasted recv=%zd all_rd=%" PRIu64 " err=%d\n",rd,trd,errno); return true; } @@ -1091,10 +1102,10 @@ static bool handle_epoll(tproxy_conn_t *conn, struct tailhead *conn_list, uint32 bool oom=false; numbytes=conn_bytes_unread(conn); - DBGPRINT("numbytes=%d",numbytes) + DBGPRINT("numbytes=%d\n",numbytes); if (numbytes>0) { - DBGPRINT("%s leg fd=%d stream pos : %" PRIu64 "(n%" PRIu64 ")/%" PRIu64, conn->remote ? "remote" : "local", conn->fd, conn->trd,conn->tnrd+1,conn->twr) + DBGPRINT("%s leg fd=%d stream pos : %" PRIu64 "(n%" PRIu64 ")/%" PRIu64 "\n", conn->remote ? "remote" : "local", conn->fd, conn->trd,conn->tnrd+1,conn->twr); #ifdef SPLICE_PRESENT if (!params.nosplice && (!params.tamper || (conn->remote && conn->partner->track.bTamperInCutoff) || (!conn->remote && !in_tamper_out_range(conn)))) { @@ -1103,7 +1114,7 @@ static bool handle_epoll(tproxy_conn_t *conn, struct tailhead *conn_list, uint32 // if we dont tamper - splice both legs rd = splice(conn->fd, NULL, conn->partner->splice_pipe[1], NULL, SPLICE_LEN, SPLICE_F_MOVE | SPLICE_F_NONBLOCK); - DBGPRINT("splice fd=%d remote=%d len=%d rd=%zd err=%d",conn->fd,conn->remote,SPLICE_LEN,rd,errno) + DBGPRINT("splice fd=%d remote=%d len=%d rd=%zd err=%d\n",conn->fd,conn->remote,SPLICE_LEN,rd,errno); if (rd<0 && errno==EAGAIN) rd=0; if (rd>0) { @@ -1111,7 +1122,7 @@ static bool handle_epoll(tproxy_conn_t *conn, struct tailhead *conn_list, uint32 conn->trd += rd; conn->partner->wr_unsent += rd; wr = splice(conn->partner->splice_pipe[0], NULL, conn->partner->fd, NULL, conn->partner->wr_unsent, SPLICE_F_MOVE | SPLICE_F_NONBLOCK); - DBGPRINT("splice fd=%d remote=%d wr=%zd err=%d",conn->partner->fd,conn->partner->remote,wr,errno) + DBGPRINT("splice fd=%d remote=%d wr=%zd err=%d\n",conn->partner->fd,conn->partner->remote,wr,errno); if (wr<0 && errno==EAGAIN) wr=0; if (wr>0) { @@ -1127,7 +1138,7 @@ static bool handle_epoll(tproxy_conn_t *conn, struct tailhead *conn_list, uint32 uint8_t buf[RD_BLOCK_SIZE + 5]; rd = recv(conn->fd, buf, RD_BLOCK_SIZE, MSG_DONTWAIT); - DBGPRINT("recv fd=%d rd=%zd err=%d",conn->fd, rd,errno) + DBGPRINT("recv fd=%d rd=%zd err=%d\n",conn->fd, rd,errno); if (rd<0 && errno==EAGAIN) rd=0; if (rd>0) { @@ -1144,22 +1155,22 @@ static bool handle_epoll(tproxy_conn_t *conn, struct tailhead *conn_list, uint32 if (split_pos && bspartner->wr_buf, conn->partner->fd, buf, split_pos, !!(split_flags & SPLIT_FLAG_DISORDER), !!(split_flags & SPLIT_FLAG_OOB)); - DBGPRINT("send_or_buffer(1) fd=%d wr=%zd err=%d",conn->partner->fd,wr,errno) + DBGPRINT("send_or_buffer(1) fd=%d wr=%zd err=%d\n",conn->partner->fd,wr,errno); if (wr >= 0) { conn->partner->twr += wr; wr = send_or_buffer(conn->partner->wr_buf + 1, conn->partner->fd, buf + split_pos, bs - split_pos, 0, 0); - DBGPRINT("send_or_buffer(2) fd=%d wr=%zd err=%d",conn->partner->fd,wr,errno) + DBGPRINT("send_or_buffer(2) fd=%d wr=%zd err=%d\n",conn->partner->fd,wr,errno); if (wr>0) conn->partner->twr += wr; } } else { wr = send_or_buffer(conn->partner->wr_buf, conn->partner->fd, buf, bs, 0, 0); - DBGPRINT("send_or_buffer(3) fd=%d wr=%zd err=%d",conn->partner->fd,wr,errno) + DBGPRINT("send_or_buffer(3) fd=%d wr=%zd err=%d\n",conn->partner->fd,wr,errno); if (wr>0) conn->partner->twr += wr; } if (wr<0 && errno==ENOMEM) oom=true; @@ -1170,8 +1181,8 @@ static bool handle_epoll(tproxy_conn_t *conn, struct tailhead *conn_list, uint32 return false; } - DBGPRINT("-handle_epoll rd=%zd wr=%zd",rd,wr) - if (oom) DBGPRINT("handle_epoll: OUT_OF_MEMORY") + DBGPRINT("-handle_epoll rd=%zd wr=%zd\n",rd,wr); + if (oom) DBGPRINT("handle_epoll: OUT_OF_MEMORY\n"); // do not fail if partner fails. // if partner fails there will be another epoll event with EPOLLHUP or EPOLLERR @@ -1189,8 +1200,8 @@ static bool remove_closed_connections(int efd, struct tailhead *close_list) shutdown(conn->fd,SHUT_RDWR); epoll_del(conn); - VPRINT("Socket fd=%d (partner_fd=%d, remote=%d) closed, connection removed. total_read=%" PRIu64 " total_write=%" PRIu64 " event_count=%u", - conn->fd, conn->partner ? conn->partner->fd : 0, conn->remote, conn->trd, conn->twr, conn->event_count) + VPRINT("Socket fd=%d (partner_fd=%d, remote=%d) closed, connection removed. total_read=%" PRIu64 " total_write=%" PRIu64 " event_count=%u\n", + conn->fd, conn->partner ? conn->partner->fd : 0, conn->remote, conn->trd, conn->twr, conn->event_count); if (conn->remote) legs_remote--; else legs_local--; free_conn(conn); bRemoved = true; @@ -1215,7 +1226,7 @@ static bool read_all_and_buffer(tproxy_conn_t *conn, int buffer_number) if (conn_partner_alive(conn)) { int numbytes=conn_bytes_unread(conn); - DBGPRINT("read_all_and_buffer(%d) numbytes=%d",buffer_number,numbytes) + DBGPRINT("read_all_and_buffer(%d) numbytes=%d\n",buffer_number,numbytes); if (numbytes>0) { if (send_buffer_create(conn->partner->wr_buf+buffer_number, NULL, numbytes, 5, 0, 0)) @@ -1259,7 +1270,7 @@ static void conn_close_timed_out(struct tailhead *conn_list, struct tailhead *cl { tproxy_conn_t *c,*cnext = NULL; - DBGPRINT("conn_close_timed_out") + DBGPRINT("conn_close_timed_out\n"); c = TAILQ_FIRST(conn_list); while(c) @@ -1267,7 +1278,7 @@ static void conn_close_timed_out(struct tailhead *conn_list, struct tailhead *cl cnext = TAILQ_NEXT(c,conn_ptrs); if (conn_timed_out(c)) { - DBGPRINT("closing timed out connection: fd=%d remote=%d",c->fd,c->remote) + DBGPRINT("closing timed out connection: fd=%d remote=%d\n",c->fd,c->remote); close_tcp_conn(conn_list,close_list,c); } c = cnext; @@ -1301,13 +1312,13 @@ static bool handle_resolve_pipe(tproxy_conn_t **conn, struct tailhead *conn_list rd = read(fd,&ri,sizeof(void*)); if (rd<0) { - perror("resolve_pipe read"); + DLOG_PERROR("resolve_pipe read"); return false; } else if (rd!=sizeof(void*)) { // partial pointer read is FATAL. in any case it will cause pointer corruption and coredump - fprintf(stderr,"resolve_pipe not full read %zu\n",rd); + DLOG_ERR("resolve_pipe not full read %zu\n",rd); exit(1000); } b = resolve_complete(ri, conn_list); @@ -1342,13 +1353,13 @@ int event_loop(const int *listen_fd, size_t listen_fd_ct) TAILQ_INIT(&close_list); if ((efd = epoll_create(1)) == -1) { - perror("epoll_create"); + DLOG_PERROR("epoll_create"); return -1; } if (!(listen_conn=calloc(listen_fd_ct,sizeof(*listen_conn)))) { - perror("calloc listen_conn"); + DLOG_PERROR("calloc listen_conn"); return -1; } @@ -1361,7 +1372,7 @@ int event_loop(const int *listen_fd, size_t listen_fd_ct) listen_conn[sct].fd = listen_fd[sct]; ev.data.ptr = listen_conn + sct; if (epoll_ctl(efd, EPOLL_CTL_ADD, listen_conn[sct].fd, &ev) == -1) { - perror("epoll_ctl (listen socket)"); + DLOG_PERROR("epoll_ctl (listen socket)"); retval = -1; goto ex; } @@ -1370,39 +1381,39 @@ int event_loop(const int *listen_fd, size_t listen_fd_ct) { if (pipe(resolve_pipe)==-1) { - perror("pipe (resolve_pipe)"); + DLOG_PERROR("pipe (resolve_pipe)"); retval = -1; goto ex; } if (fcntl(resolve_pipe[0], F_SETFL, O_NONBLOCK) < 0) { - perror("resolve_pipe set O_NONBLOCK"); + DLOG_PERROR("resolve_pipe set O_NONBLOCK"); retval = -1; goto ex; } ev.data.ptr = NULL; if (epoll_ctl(efd, EPOLL_CTL_ADD, resolve_pipe[0], &ev) == -1) { - perror("epoll_ctl (listen socket)"); + DLOG_PERROR("epoll_ctl (listen socket)"); retval = -1; goto ex; } if (!resolver_init(params.resolver_threads,resolve_pipe[1])) { - fprintf(stderr,"could not initialize multithreaded resolver\n"); + DLOG_ERR("could not initialize multithreaded resolver\n"); retval = -1; goto ex; } - VPRINT("initialized multi threaded resolver with %d threads",resolver_thread_count()); + VPRINT("initialized multi threaded resolver with %d threads\n",resolver_thread_count()); } for(;;) { - DBGPRINT("epoll_wait") + DBGPRINT("epoll_wait\n"); if ((num_events = epoll_wait(efd, events, MAX_EPOLL_EVENTS, -1)) == -1) { if (errno == EINTR) continue; // system call was interrupted - perror("epoll_wait"); + DLOG_PERROR("epoll_wait"); retval = -1; break; } @@ -1414,13 +1425,13 @@ int event_loop(const int *listen_fd, size_t listen_fd_ct) conn = (tproxy_conn_t*)events[i].data.ptr; if (!conn) { - DBGPRINT("\nEVENT mask %08X resolve_pipe",events[i].events) + DBGPRINT("\nEVENT mask %08X resolve_pipe\n",events[i].events); if (events[i].events & EPOLLIN) { - DBGPRINT("EPOLLIN") + DBGPRINT("EPOLLIN\n"); if (!handle_resolve_pipe(&conn, &conn_list, resolve_pipe[0])) { - DBGPRINT("handle_resolve_pipe false") + DBGPRINT("handle_resolve_pipe false\n"); if (conn) close_tcp_conn(&conn_list,&close_list,conn); } } @@ -1429,7 +1440,7 @@ int event_loop(const int *listen_fd, size_t listen_fd_ct) conn->event_count++; if (conn->listener) { - DBGPRINT("\nEVENT mask %08X fd=%d accept",events[i].events,conn->fd) + DBGPRINT("\nEVENT mask %08X fd=%d accept\n",events[i].events,conn->fd); accept_salen = sizeof(accept_sa); //Accept new connection @@ -1441,35 +1452,35 @@ int event_loop(const int *listen_fd, size_t listen_fd_ct) #endif if (tmp_fd < 0) { - perror("Failed to accept connection"); + DLOG_PERROR("Failed to accept connection"); } else if (legs_local >= params.maxconn) // each connection has 2 legs - local and remote { close(tmp_fd); - VPRINT("Too many local legs : %d", legs_local) + VPRINT("Too many local legs : %d\n", legs_local); } #if defined (__APPLE__) // separate fcntl call to comply with macos else if (fcntl(tmp_fd, F_SETFL, O_NONBLOCK) < 0) { - perror("socket set O_NONBLOCK (accept)"); + DLOG_PERROR("socket set O_NONBLOCK (accept)"); close(tmp_fd); } #endif else if (!(conn=add_tcp_connection(efd, &conn_list, tmp_fd, (struct sockaddr*)&accept_sa, params.port, params.proxy_type))) { // add_tcp_connection closes fd in case of failure - VPRINT("Failed to add connection"); + VPRINT("Failed to add connection\n"); } else { print_legs(); - VPRINT("Socket fd=%d (local) connected", conn->fd) + VPRINT("Socket fd=%d (local) connected\n", conn->fd); } } else { - DBGPRINT("\nEVENT mask %08X fd=%d remote=%d fd_partner=%d",events[i].events,conn->fd,conn->remote,conn_partner_alive(conn) ? conn->partner->fd : 0) + DBGPRINT("\nEVENT mask %08X fd=%d remote=%d fd_partner=%d\n",events[i].events,conn->fd,conn->remote,conn_partner_alive(conn) ? conn->partner->fd : 0); if (conn->state != CONN_CLOSED) { @@ -1484,7 +1495,7 @@ int event_loop(const int *listen_fd, size_t listen_fd_ct) case EPOLLHUP|EPOLLERR: se="EPOLLERR EPOLLHUP"; break; default: se=NULL; } - VPRINT("Socket fd=%d (partner_fd=%d, remote=%d) %s so_error=%d (%s)",conn->fd,conn->partner ? conn->partner->fd : 0,conn->remote,se,errn,strerror(errn)); + VPRINT("Socket fd=%d (partner_fd=%d, remote=%d) %s so_error=%d (%s)\n",conn->fd,conn->partner ? conn->partner->fd : 0,conn->remote,se,errn,strerror(errn)); proxy_remote_conn_ack(conn,errn); read_all_and_buffer(conn,3); if (errn==ECONNRESET && conn->remote && params.tamper && conn_partner_alive(conn)) rst_in(&conn->partner->track); @@ -1496,26 +1507,26 @@ int event_loop(const int *listen_fd, size_t listen_fd_ct) { if (!check_connection_attempt(conn, efd)) { - VPRINT("Connection attempt failed for fd=%d", conn->fd) + VPRINT("Connection attempt failed for fd=%d\n", conn->fd); conn_close_both(&conn_list,&close_list,conn); continue; } } if (events[i].events & EPOLLRDHUP) { - DBGPRINT("EPOLLRDHUP") + DBGPRINT("EPOLLRDHUP\n"); read_all_and_buffer(conn,2); if (!conn->remote && params.tamper) hup_out(&conn->track); if (conn_has_unsent(conn)) { - DBGPRINT("conn fd=%d has unsent, not closing", conn->fd) + DBGPRINT("conn fd=%d has unsent, not closing\n", conn->fd); conn->state = CONN_RDHUP; // only writes epoll_set_flow(conn,false,true); } else { - DBGPRINT("conn fd=%d has no unsent, closing", conn->fd) + DBGPRINT("conn fd=%d has no unsent, closing\n", conn->fd); conn_close_with_partner_check(&conn_list,&close_list,conn); } continue; @@ -1526,7 +1537,7 @@ int event_loop(const int *listen_fd, size_t listen_fd_ct) // will not receive this until successful check_connection_attempt() if (!handle_epoll(conn, &conn_list, events[i].events)) { - DBGPRINT("handle_epoll false") + DBGPRINT("handle_epoll false\n"); conn_close_with_partner_check(&conn_list,&close_list,conn); continue; }