From 91bc83e5c6c083792c0043b244128fe7281baa4b Mon Sep 17 00:00:00 2001 From: Victor Julien Date: Sun, 27 Sep 2009 14:08:00 +0200 Subject: [PATCH] More logging API usage changes. --- src/alert-unified2-alert.c | 6 +- src/app-layer-parser.c | 24 +-- src/debug.h | 7 - src/decode-ethernet.c | 2 +- src/decode-icmpv4.c | 5 +- src/decode-icmpv6.c | 2 +- src/decode-ipv4.c | 6 +- src/decode-ipv6.c | 2 +- src/decode-tcp.c | 2 +- src/decode-udp.c | 2 +- src/decode.c | 2 +- src/detect-content.c | 68 +++----- src/detect-engine-iponly.c | 6 +- src/detect-isdataat.c | 26 ++-- src/detect-msg.c | 11 +- src/detect-parse.c | 12 +- src/detect-pcre.c | 3 +- src/detect-uricontent.c | 57 +++---- src/detect.c | 168 ++++++++++---------- src/eidps.c | 19 ++- src/flow-hash.c | 2 +- src/flow.c | 66 +++++--- src/source-pcap.c | 3 +- src/stream-tcp-reassemble.c | 212 ++++++++++++------------- src/stream-tcp.c | 299 ++++++++++++++++++------------------ src/stream.c | 2 +- src/tm-modules.c | 9 +- src/tm-queues.c | 7 +- src/tm-threads.c | 40 ++--- src/util-binsearch.c | 26 +--- src/util-debug.c | 2 +- src/util-debug.h | 16 +- src/util-mpm-b2g.c | 2 +- src/util-mpm.c | 4 +- src/util-pool.c | 3 +- src/util-time.c | 8 +- 36 files changed, 527 insertions(+), 604 deletions(-) diff --git a/src/alert-unified2-alert.c b/src/alert-unified2-alert.c index 8b2f0e3e46..32334c82dc 100644 --- a/src/alert-unified2-alert.c +++ b/src/alert-unified2-alert.c @@ -17,6 +17,8 @@ #include "alert-unified2-alert.h" #include "decode-ipv4.h" +#include "util-debug.h" + /*prototypes*/ int Unified2Alert (ThreadVars *, Packet *, void *, PacketQueue *); int Unified2AlertThreadInit(ThreadVars *, void *, void **); @@ -140,9 +142,7 @@ int Unified2AlertCreateFile(ThreadVars *t, Unified2AlertThread *aun) { log_dir = DEFAULT_LOG_DIR; snprintf(filename, sizeof(filename), "%s/%s.%" PRIu32, log_dir, "unified2.alert", (uint32_t)ts.tv_sec); -#ifdef DEBUG - printf("Creating unified2 file %s\n",filename); -#endif + SCLogInfo("creating unified2 file %s",filename); /* XXX filename & location */ aun->fp = fopen(filename, "wb"); diff --git a/src/app-layer-parser.c b/src/app-layer-parser.c index 593f0da7df..3adb29c5e8 100644 --- a/src/app-layer-parser.c +++ b/src/app-layer-parser.c @@ -16,6 +16,8 @@ #include "util-binsearch.h" +#include "util-debug.h" + static Pool *al_result_pool = NULL; /** \brief Alloc a AppLayerParserResultElmt func for the pool */ @@ -356,7 +358,7 @@ int AppLayerRegisterParser(char *name, uint16_t proto, uint16_t parser_id, int ( al_parser_table[al_max_parsers].parser_local_id = parser_id; al_parser_table[al_max_parsers].AppLayerParser = AppLayerParser; - printf("AppLayerRegisterParser: registered %p at proto %" PRIu32 ", al_proto_table idx %" PRIu32 ", storage_id %" PRIu32 ", parser_local_id %" PRIu32 "\n", + SCLogDebug("registered %p at proto %" PRIu32 ", al_proto_table idx %" PRIu32 ", storage_id %" PRIu32 ", parser_local_id %" PRIu32 "", AppLayerParser, proto, al_max_parsers, al_proto_table[proto].storage_id, parser_id); return 0; } @@ -388,7 +390,7 @@ int AppLayerRegisterProto(char *name, uint8_t proto, uint8_t flags, int (*AppLay al_proto_table[proto].storage_id = StreamL7RegisterModule(); } - printf("AppLayerRegisterProto: registered %p at proto %" PRIu32 " flags %02X, al_proto_table idx %" PRIu32 ", storage_id %" PRIu32 "\n", + SCLogDebug("registered %p at proto %" PRIu32 " flags %02X, al_proto_table idx %" PRIu32 ", storage_id %" PRIu32 "", AppLayerParser, proto, flags, al_max_parsers, al_proto_table[proto].storage_id); return 0; } @@ -499,8 +501,7 @@ static int AppLayerDoParse(void *app_layer_state, AppLayerParserState *parser_st * \retval 0 ok */ int AppLayerParse(Flow *f, uint8_t proto, uint8_t flags, uint8_t *input, uint32_t input_len, char need_lock) { - //printf("AppLayerParse: proto %" PRIu32 ", flags %02X\n", proto, flags); - //PrintRawDataFp(stdout, input,input_len); + SCEnter(); uint16_t parser_idx = 0; AppLayerProto *p = &al_proto_table[proto]; @@ -508,7 +509,7 @@ int AppLayerParse(Flow *f, uint8_t proto, uint8_t flags, uint8_t *input, uint32_ TcpSession *ssn = f->protoctx; if (ssn == NULL) { printf("AppLayerParse: no session\n"); - return -1; + goto error; } /* Get the parser state (if any) */ @@ -516,7 +517,7 @@ int AppLayerParse(Flow *f, uint8_t proto, uint8_t flags, uint8_t *input, uint32_ if (parser_state_store == NULL) { parser_state_store = AppLayerParserStateStoreAlloc(); if (parser_state_store == NULL) - return -1; + goto error; if (need_lock == TRUE) mutex_lock(&f->m); ssn->aldata[app_layer_sid] = (void *)parser_state_store; @@ -548,7 +549,7 @@ int AppLayerParse(Flow *f, uint8_t proto, uint8_t flags, uint8_t *input, uint32_ if (parser_idx == 0 || parser_state->flags & APP_LAYER_PARSER_DONE) { //printf("AppLayerParse: no parser for protocol %" PRIu32 "\n", proto); - return 0; + SCReturnInt(0); } if (flags & STREAM_EOF) @@ -563,7 +564,7 @@ int AppLayerParse(Flow *f, uint8_t proto, uint8_t flags, uint8_t *input, uint32_ if (app_layer_state == NULL) { app_layer_state = p->StateAlloc(); if (app_layer_state == NULL) - return -1; + goto error; if (need_lock == TRUE) mutex_lock(&f->m); ssn->aldata[p->storage_id] = app_layer_state; @@ -573,9 +574,11 @@ int AppLayerParse(Flow *f, uint8_t proto, uint8_t flags, uint8_t *input, uint32_ /* invoke the recursive parser */ int r = AppLayerDoParse(app_layer_state, parser_state, input, input_len, parser_idx, proto); if (r < 0) - return -1; + goto error; - return 0; + SCReturnInt(0); +error: + SCReturnInt(-1); } void RegisterAppLayerParsers(void) { @@ -628,7 +631,6 @@ void AppLayerParserCleanupState(TcpSession *ssn) { * */ void AppLayerParsersInitPostProcess(void) { - printf("AppLayerParsersInitPostProcess: start\n"); uint16_t u16 = 0; /* build local->global mapping */ diff --git a/src/debug.h b/src/debug.h index d3d064bec0..4c5c9ff389 100644 --- a/src/debug.h +++ b/src/debug.h @@ -5,13 +5,6 @@ #ifdef DEBUG -#define DEBUGPRINT(format, args...) \ - printf("[%s:%" PRId32 "](%s) " format "\n", __FILE__, __LINE__, __FUNCTION__, ## args) - -#else - -#define DEBUGPRINT(format, args...) - #endif /* DEBUG */ #endif /* __DEBUG_H__ */ diff --git a/src/decode-ethernet.c b/src/decode-ethernet.c index 439e0bbede..2b0bd68dff 100644 --- a/src/decode-ethernet.c +++ b/src/decode-ethernet.c @@ -21,7 +21,7 @@ void DecodeEthernet(ThreadVars *tv, DecodeThreadVars *dtv, Packet *p, uint8_t *p if (ethh == NULL) return; - SCDebug("p %p pkt %p ether type %04x", p, pkt, ntohs(ethh->eth_type)); + SCLogDebug("p %p pkt %p ether type %04x", p, pkt, ntohs(ethh->eth_type)); if (ntohs(ethh->eth_type) == ETHERNET_TYPE_IP) { //printf("DecodeEthernet ip4\n"); diff --git a/src/decode-icmpv4.c b/src/decode-icmpv4.c index be6c8477ac..df316ab39e 100644 --- a/src/decode-icmpv4.c +++ b/src/decode-icmpv4.c @@ -5,6 +5,7 @@ #include "decode-events.h" #include "decode-icmpv4.h" #include "util-unittest.h" +#include "util-debug.h" /** * \brief Calculates the checksum for the ICMP packet @@ -80,9 +81,7 @@ void DecodeICMPV4(ThreadVars *tv, DecodeThreadVars *dtv, Packet *p, uint8_t *pkt p->icmpv4h = (ICMPV4Hdr *)pkt; -#ifdef DEBUG - printf("ICMPV4 TYPE %" PRIu32 " CODE %" PRIu32 "\n", p->icmpv4h->type, p->icmpv4h->code); -#endif + SCLogDebug("ICMPV4 TYPE %" PRIu32 " CODE %" PRIu32 "", p->icmpv4h->type, p->icmpv4h->code); p->proto = IPPROTO_ICMP; diff --git a/src/decode-icmpv6.c b/src/decode-icmpv6.c index c43a499416..a3bdf652cb 100644 --- a/src/decode-icmpv6.c +++ b/src/decode-icmpv6.c @@ -88,7 +88,7 @@ void DecodeICMPV6(ThreadVars *tv, DecodeThreadVars *dtv, Packet *p, uint8_t *pkt p->icmpv6h = (ICMPV6Hdr *)pkt; - SCDebug("ICMPV6 TYPE %" PRIu32 " CODE %" PRIu32 "", p->icmpv6h->type, p->icmpv6h->code); + SCLogDebug("ICMPV6 TYPE %" PRIu32 " CODE %" PRIu32 "", p->icmpv6h->type, p->icmpv6h->code); p->proto = IPPROTO_ICMPV6; return; diff --git a/src/decode-ipv4.c b/src/decode-ipv4.c index 74615447d8..1e758aceca 100644 --- a/src/decode-ipv4.c +++ b/src/decode-ipv4.c @@ -551,12 +551,12 @@ void DecodeIPV4(ThreadVars *tv, DecodeThreadVars *dtv, Packet *p, uint8_t *pkt, /* reset the decoder cache flags */ IPV4_CACHE_INIT(p); - SCDebug("pkt %p len %"PRIu16"", pkt, len); + SCLogDebug("pkt %p len %"PRIu16"", pkt, len); /* do the actual decoding */ ret = DecodeIPV4Packet (tv, p, pkt, len); if (ret < 0) { - SCDebug("decoding IPv4 packet failed"); + SCLogDebug("decoding IPv4 packet failed"); p->ip4h = NULL; return; } @@ -568,7 +568,7 @@ void DecodeIPV4(ThreadVars *tv, DecodeThreadVars *dtv, Packet *p, uint8_t *pkt, char s[16], d[16]; inet_ntop(AF_INET, (const void *)GET_IPV4_SRC_ADDR_PTR(p), s, sizeof(s)); inet_ntop(AF_INET, (const void *)GET_IPV4_DST_ADDR_PTR(p), d, sizeof(d)); - SCDebug("IPV4 %s->%s PROTO: %" PRIu32 " OFFSET: %" PRIu32 " RF: %" PRIu32 " DF: %" PRIu32 " MF: %" PRIu32 " ID: %" PRIu32 "", s,d, + SCLogDebug("IPV4 %s->%s PROTO: %" PRIu32 " OFFSET: %" PRIu32 " RF: %" PRIu32 " DF: %" PRIu32 " MF: %" PRIu32 " ID: %" PRIu32 "", s,d, IPV4_GET_IPPROTO(p), IPV4_GET_IPOFFSET(p), IPV4_GET_RF(p), IPV4_GET_DF(p), IPV4_GET_MF(p), IPV4_GET_IPID(p)); #endif /* DEBUG */ diff --git a/src/decode-ipv6.c b/src/decode-ipv6.c index 59d3eea862..4da7187891 100644 --- a/src/decode-ipv6.c +++ b/src/decode-ipv6.c @@ -381,7 +381,7 @@ void DecodeIPV6(ThreadVars *tv, DecodeThreadVars *dtv, Packet *p, uint8_t *pkt, char s[46], d[46]; inet_ntop(AF_INET6, (const void *)GET_IPV6_SRC_ADDR(p), s, sizeof(s)); inet_ntop(AF_INET6, (const void *)GET_IPV6_DST_ADDR(p), d, sizeof(d)); - SCDebug("IPV6 %s->%s - CLASS: %" PRIu32 " FLOW: %" PRIu32 " NH: %" PRIu32 " PLEN: %" PRIu32 " HLIM: %" PRIu32 "", s,d, + SCLogDebug("IPV6 %s->%s - CLASS: %" PRIu32 " FLOW: %" PRIu32 " NH: %" PRIu32 " PLEN: %" PRIu32 " HLIM: %" PRIu32 "", s,d, IPV6_GET_CLASS(p), IPV6_GET_FLOW(p), IPV6_GET_NH(p), IPV6_GET_PLEN(p), IPV6_GET_HLIM(p)); #endif /* DEBUG */ diff --git a/src/decode-tcp.c b/src/decode-tcp.c index 188e6810d9..18713cd889 100644 --- a/src/decode-tcp.c +++ b/src/decode-tcp.c @@ -267,7 +267,7 @@ void DecodeTCP(ThreadVars *tv, DecodeThreadVars *dtv, Packet *p, uint8_t *pkt, u } #ifdef DEBUG - SCDebug("TCP sp: %" PRIu32 " -> dp: %" PRIu32 " - HLEN: %" PRIu32 " LEN: %" PRIu32 " %s%s%s%s", + SCLogDebug("TCP sp: %" PRIu32 " -> dp: %" PRIu32 " - HLEN: %" PRIu32 " LEN: %" PRIu32 " %s%s%s%s", GET_TCP_SRC_PORT(p), GET_TCP_DST_PORT(p), p->tcpvars.hlen, len, p->tcpvars.sackok ? "SACKOK " : "", p->tcpvars.ws ? "WS " : "", diff --git a/src/decode-udp.c b/src/decode-udp.c index 1dea903042..10de36a1ec 100644 --- a/src/decode-udp.c +++ b/src/decode-udp.c @@ -168,7 +168,7 @@ void DecodeUDP(ThreadVars *tv, DecodeThreadVars *dtv, Packet *p, uint8_t *pkt, u return; } - SCDebug("UDP sp: %" PRIu32 " -> dp: %" PRIu32 " - HLEN: %" PRIu32 " LEN: %" PRIu32 "", + SCLogDebug("UDP sp: %" PRIu32 " -> dp: %" PRIu32 " - HLEN: %" PRIu32 " LEN: %" PRIu32 "", UDP_GET_SRC_PORT(p), UDP_GET_DST_PORT(p), UDP_HEADER_LEN, p->payload_len); /* Flow is an integral part of us */ diff --git a/src/decode.c b/src/decode.c index dd1fe9c0a9..3ee08b0ade 100644 --- a/src/decode.c +++ b/src/decode.c @@ -17,7 +17,7 @@ void DecodeTunnel(ThreadVars *tv, DecodeThreadVars *dtv, Packet *p, uint8_t *pkt case IPPROTO_IPV6: return DecodeIPV6(tv, dtv, p, pkt, len, pq); default: - SCInfo("FIXME: DecodeTunnel: protocol %" PRIu32 " not supported.", p->tunnel_proto); + SCLogInfo("FIXME: DecodeTunnel: protocol %" PRIu32 " not supported.", p->tunnel_proto); break; } } diff --git a/src/detect-content.c b/src/detect-content.c index ca704a7c57..c96e29fc3a 100644 --- a/src/detect-content.c +++ b/src/detect-content.c @@ -38,38 +38,19 @@ #include "detect-flow.h" #include "util-unittest.h" #include "util-print.h" +#include "util-debug.h" #include "threads.h" int DetectContentMatch (ThreadVars *, DetectEngineThreadCtx *, Packet *, Signature *, SigMatch *); int DetectContentSetup (DetectEngineCtx *, Signature *, SigMatch *, char *); void DetectContentRegisterTests(void); -uint8_t nocasetable[256]; -#define _nc(c) nocasetable[(c)] - void DetectContentRegister (void) { sigmatch_table[DETECT_CONTENT].name = "content"; sigmatch_table[DETECT_CONTENT].Match = DetectContentMatch; sigmatch_table[DETECT_CONTENT].Setup = DetectContentSetup; sigmatch_table[DETECT_CONTENT].Free = DetectContentFree; sigmatch_table[DETECT_CONTENT].RegisterTests = DetectContentRegisterTests; - - /* create table for O(1) case conversion lookup */ - uint8_t c = 0; - for ( ; c < 255; c++) { - if ( c >= 'a' && c <= 'z') - nocasetable[c] = (c - ('a' - 'A')); - else if (c >= 'A' && c <= 'Z') - nocasetable[c] = (c + ('a' - 'A')); - else - nocasetable[c] = c; - } -#ifdef DEBUG - for (c = 0; c < 255; c++) { - if (isprint(nocasetable[c])) - printf("nocasetable[%c]: %c\n", c, nocasetable[c]); - } -#endif /* DEBUG */ } /* pass on the content_max_id */ @@ -237,21 +218,19 @@ DoDetectContent(ThreadVars *t, DetectEngineThreadCtx *det_ctx, Packet *p, Signat } /* If it has matched, check if it's set a "isdataat" option and process it */ - if( match == 1 && co->flags & DETECT_CONTENT_ISDATAAT_RELATIVE ) + if (match == 1 && co->flags & DETECT_CONTENT_ISDATAAT_RELATIVE) { /* if the rest of the payload (from the last match) is less than the "isdataat" there is no data where the rule expected so match=0 */ - SCDebug("isdataat: payload_len: %u, used %u, rest %u, isdataat? %u", p->payload_len, (m->offset + co->content_len),p->payload_len - (m->offset + co->content_len), co->isdataat); - if( ! (p->payload_len - (m->offset + co->content_len) >= co->isdataat) ) - match=0; - if(match) - { - #ifdef DEBUG - printf("detect-content: MATCHED\n"); - #endif + SCLogDebug("isdataat: payload_len: %u, used %u, rest %u, isdataat? %u", p->payload_len, (m->offset + co->content_len),p->payload_len - (m->offset + co->content_len), co->isdataat); + if(!(p->payload_len - (m->offset + co->content_len) >= co->isdataat)) + match = 0; + + if (match) { + SCLogDebug("still matching after isdataat check"); } } @@ -279,15 +258,17 @@ int DetectContentMatch (ThreadVars *t, DetectEngineThreadCtx *det_ctx, Packet *p if (len == 0) return 0; -#ifdef DEBUG - printf("content \""); PrintRawUriFp(stdout, co->content, co->content_len); - printf("\" matched %" PRIu32 " time(s) at offsets: ", len); +#if 0 + if (SCLogDebugEnabled()) { + printf("content \""); PrintRawUriFp(stdout, co->content, co->content_len); + printf("\" matched %" PRIu32 " time(s) at offsets: ", len); - MpmMatch *tmpm = NULL; - for (tmpm = det_ctx->mtc.match[co->id].top; tmpm != NULL; tmpm = tmpm->next) { - printf("%" PRIu32 " ", tmpm->offset); + MpmMatch *tmpm = NULL; + for (tmpm = det_ctx->mtc.match[co->id].top; tmpm != NULL; tmpm = tmpm->next) { + printf("%" PRIu32 " ", tmpm->offset); + } + printf("\n"); } - printf("\n"); #endif return DoDetectContent(t, det_ctx, p, s, m, co); @@ -357,9 +338,6 @@ DetectContentData *DetectContentParse (char *contentstr) if (binpos == 2) { uint8_t c = strtol((char *)binstr, (char **) NULL, 16) & 0xFF; -#ifdef DEBUG - printf("Binstr %" PRIX32 "\n", c); -#endif binpos = 0; str[x] = c; x++; @@ -388,12 +366,14 @@ DetectContentData *DetectContentParse (char *contentstr) } } } -#ifdef DEBUG - for (i = 0; i < x; i++) { - if (isprint(str[i])) printf("%c", str[i]); - else printf("\\x%02u", str[i]); +#if 0//def DEBUG + if (SCLogDebugEnabled()) { + for (i = 0; i < x; i++) { + if (isprint(str[i])) printf("%c", str[i]); + else printf("\\x%02u", str[i]); + } + printf("\n"); } - printf("\n"); #endif if (converted) { diff --git a/src/detect-engine-iponly.c b/src/detect-engine-iponly.c index 908aa5837c..b58a2b5191 100644 --- a/src/detect-engine-iponly.c +++ b/src/detect-engine-iponly.c @@ -23,6 +23,8 @@ #include "detect-engine-port.h" #include "detect-engine-mpm.h" +#include "util-debug.h" + /* build a lookup tree for src, if we have one: save * build a lookup tree for dst, if we have one: save * compare tree's: if they have one (or more) matching @@ -238,9 +240,9 @@ void DetectEngineIPOnlyThreadInit(DetectEngineCtx *de_ctx, DetectEngineIPOnlyThr void IPOnlyPrint(DetectEngineCtx *de_ctx, DetectEngineIPOnlyCtx *io_ctx) { if (!(de_ctx->flags & DE_QUIET)) { - printf(" * IP ONLY (SRC): %" PRIu32 " /16's in our hash, %" PRIu32 " total address ranges in them\n", + SCLogInfo("IP ONLY (SRC): %" PRIu32 " /16's in our hash, %" PRIu32 " total address ranges", io_ctx->a_src_uniq16, io_ctx->a_src_uniq16 + io_ctx->a_src_total16); - printf(" * IP ONLY (DST): %" PRIu32 " /16's in our hash, %" PRIu32 " total address ranges in them\n", + SCLogInfo("IP ONLY (DST): %" PRIu32 " /16's in our hash, %" PRIu32 " total address ranges", io_ctx->a_dst_uniq16, io_ctx->a_dst_uniq16 + io_ctx->a_dst_total16); /* printf(" * IP ONLY (SRC): %" PRIu32 " /24's in our hash, %" PRIu32 " total address ranges in them\n", diff --git a/src/detect-isdataat.c b/src/detect-isdataat.c index 071b2041e8..b8667fb535 100644 --- a/src/detect-isdataat.c +++ b/src/detect-isdataat.c @@ -18,6 +18,7 @@ #include "flow.h" #include "flow-var.h" +#include "util-debug.h" /** * \brief Regex for parsing our isdataat options @@ -83,23 +84,17 @@ int DetectIsdataatMatch (ThreadVars *t, DetectEngineThreadCtx *det_ctx, Packet * DetectIsdataatData *idad = (DetectIsdataatData *)m->ctx; int ret=0; - #ifdef DEBUG - printf("detect-isdataat: payload len : %u , dataat? %u ; relative? %u ...\n", p->payload_len,idad->dataat,idad->flags &ISDATAAT_RELATIVE); - #endif + SCLogDebug("payload_len: %u , dataat? %u ; relative? %u...", p->payload_len,idad->dataat,idad->flags &ISDATAAT_RELATIVE); if(idad->flags & ISDATAAT_RELATIVE) { /* Relative to the last matched content, is not performed here */ - #ifdef DEBUG - printf("detect-isdataat: Nothing now, this is checked in detect-content.c!\n"); - #endif } else - if( !(idad->flags & ISDATAAT_RELATIVE) && p->payload_len >= idad->dataat) { - ret=1; /* its not relative and we have more data in the packet than the offset of isdataat */ - #ifdef DEBUG - printf("detect-isdataat: matched with payload len : %u , dataat? %u ; relative? %u ...\n", p->payload_len,idad->dataat,idad->flags &ISDATAAT_RELATIVE); - #endif + if(!(idad->flags & ISDATAAT_RELATIVE) && p->payload_len >= idad->dataat) { + ret = 1; /* its not relative and we have more data in the packet than the offset of isdataat */ + + SCLogDebug("matched with payload_len: %u , dataat? %u ; relative? %u...", p->payload_len,idad->dataat,idad->flags &ISDATAAT_RELATIVE); } return ret; @@ -225,9 +220,7 @@ int DetectIsdataatSetup (DetectEngineCtx *de_ctx, Signature *s, SigMatch *m, cha if(idad->flags & ISDATAAT_RELATIVE) { /// Set it in the last parsed contet because it is relative to that content match - #ifdef DEBUG - printf("detect-isdataat: Set it in the last parsed contet because it is relative to that content match\n"); - #endif + SCLogDebug("set it in the last parsed content because it is relative to that content match"); if( m == NULL ) { @@ -272,9 +265,8 @@ int DetectIsdataatSetup (DetectEngineCtx *de_ctx, Signature *s, SigMatch *m, cha } else { - #ifdef DEBUG - printf("detect-isdataat: Set it as a normal SigMatch\n"); - #endif + SCLogDebug("set it as a normal SigMatch"); + /// else Set it as a normal SigMatch sm = SigMatchAlloc(); if (sm == NULL) diff --git a/src/detect-msg.c b/src/detect-msg.c index 2dbcd5dc5d..076219fe5b 100644 --- a/src/detect-msg.c +++ b/src/detect-msg.c @@ -2,6 +2,7 @@ #include "eidps-common.h" #include "detect.h" +#include "util-debug.h" int DetectMsgSetup (DetectEngineCtx *de_ctx, Signature *s, SigMatch *m, char *msgstr); @@ -69,11 +70,13 @@ int DetectMsgSetup (DetectEngineCtx *de_ctx, Signature *s, SigMatch *m, char *ms x++; } } -#ifdef DEBUG - for (i = 0; i < x; i++) { - printf("%c", str[i]); +#if 0 //def DEBUG + if (SCLogDebugEnabled()) { + for (i = 0; i < x; i++) { + printf("%c", str[i]); + } + printf("\n"); } - printf("\n"); #endif if (converted) { diff --git a/src/detect-parse.c b/src/detect-parse.c index 57b27b10e0..582bf48c80 100644 --- a/src/detect-parse.c +++ b/src/detect-parse.c @@ -11,6 +11,7 @@ #include "flow.h" #include "util-unittest.h" +#include "util-debug.h" static pcre *config_pcre = NULL; static pcre *option_pcre = NULL; @@ -389,7 +390,6 @@ int SigParseBasics(Signature *s, char *sigstr, char ***result) { printf("SigParseBasics: pcre_exec failed: ret %" PRId32 ", sigstr \"%s\"\n", ret, sigstr); goto error; } - DEBUGPRINT("SigParseBasics: pcre_exec returned %" PRId32, ret); for (i = 1; i <= ret-1; i++) { pcre_get_substring(sigstr, ov, MAX_SUBSTRINGS, i, &arr[i-1]); @@ -424,7 +424,6 @@ int SigParseBasics(Signature *s, char *sigstr, char ***result) { goto error; *result = (char **)arr; - DEBUGPRINT("SigParseBasics: %p %p", arr, *result); return 0; error: @@ -443,10 +442,11 @@ int SigParse(DetectEngineCtx *de_ctx, Signature *s, char *sigstr) { } #ifdef DEBUG - DEBUGPRINT("SigParse: %p", basics); - int i; - for (i = 0; basics[i] != NULL; i++) { - DEBUGPRINT("SigParse: basics[%" PRId32 "]: %p, %s", i, basics[i], basics[i]); + if (SCLogDebugEnabled()) { + int i; + for (i = 0; basics[i] != NULL; i++) { + SCLogDebug("basics[%" PRId32 "]: %p, %s", i, basics[i], basics[i]); + } } #endif /* DEBUG */ diff --git a/src/detect-pcre.c b/src/detect-pcre.c index 8768b41e71..ae0535d78a 100644 --- a/src/detect-pcre.c +++ b/src/detect-pcre.c @@ -13,6 +13,7 @@ #include "detect-engine-mpm.h" #include "util-var-name.h" +#include "util-debug.h" #define PARSE_CAPTURE_REGEX "\\(\\?P\\<([A-z]+)\\_([A-z0-9_]+)\\>" #define PARSE_REGEX "(?= 'a' && c <= 'z') - nocasetable[c] = (c - ('a' - 'A')); - else if (c >= 'A' && c <= 'Z') - nocasetable[c] = (c + ('a' - 'A')); - else - nocasetable[c] = c; - } -#ifdef DEBUG - for (c = 0; c < 255; c++) { - if (isprint(nocasetable[c])) - printf("nocasetable[%c]: %c\n", c, nocasetable[c]); - } -#endif /* DEBUG */ } /* pass on the uricontent_max_id */ @@ -206,16 +186,18 @@ int DetectUricontentMatch (ThreadVars *t, DetectEngineThreadCtx *det_ctx, Packet if (len == 0) return 0; -#ifdef DEBUG - printf("uricontent \'"); - PrintRawUriFp(stdout, co->uricontent, co->uricontent_len); - printf("\' matched %" PRIu32 " time(s) at offsets: ", len); +#if 0 + if (SCLogDebugEnabled()) { + printf("uricontent \'"); + PrintRawUriFp(stdout, co->uricontent, co->uricontent_len); + printf("\' matched %" PRIu32 " time(s) at offsets: ", len); - MpmMatch *tmpm = NULL; - for (tmpm = det_ctx->mtcu.match[co->id].top; tmpm != NULL; tmpm = tmpm->next) { - printf("%" PRIu32 " ", tmpm->offset); + MpmMatch *tmpm = NULL; + for (tmpm = det_ctx->mtcu.match[co->id].top; tmpm != NULL; tmpm = tmpm->next) { + printf("%" PRIu32 " ", tmpm->offset); + } + printf("\n"); } - printf("\n"); #endif return DoDetectUricontent(t, det_ctx, p, m, co); @@ -276,9 +258,6 @@ int DetectUricontentSetup (DetectEngineCtx *de_ctx, Signature *s, SigMatch *m, c if (binpos == 2) { uint8_t c = strtol((char *)binstr, (char **) NULL, 16) & 0xFF; -#ifdef DEBUG - printf("Binstr %" PRIX32 "\n", c); -#endif binpos = 0; str[x] = c; x++; @@ -294,20 +273,20 @@ int DetectUricontentSetup (DetectEngineCtx *de_ctx, Signature *s, SigMatch *m, c } } #ifdef DEBUG - for (i = 0; i < x; i++) { - if (isprint(str[i])) printf("%c", str[i]); - else printf("\\x%02u", str[i]); + if (SCLogDebugEnabled()) { + for (i = 0; i < x; i++) { + if (isprint(str[i])) printf("%c", str[i]); + else printf("\\x%02u", str[i]); + } + printf("\n"); } - printf("\n"); #endif if (converted) len = x; } -#ifdef DEBUG - printf("DetectUricontentSetup: len %" PRIu32 "\n", len); -#endif + SCLogDebug("len %" PRIu32 "", len); cd->uricontent = malloc(len); if (cd->uricontent == NULL) diff --git a/src/detect.c b/src/detect.c index 7dbf57e679..52d4ae26c8 100644 --- a/src/detect.c +++ b/src/detect.c @@ -58,7 +58,7 @@ #include "util-print.h" #include "util-unittest.h" - +#include "util-debug.h" #include "util-hashlist.h" SigMatch *SigMatchAlloc(void); @@ -87,62 +87,62 @@ void DetectExitPrintStats(ThreadVars *tv, void *data) { if (det_ctx == NULL) return; - printf(" - (%s) (1byte) Pkts %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.\n", tv->name, + SCLogInfo(" - (%s) (1byte) Pkts %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.", tv->name, det_ctx->pkts, det_ctx->pkts_scanned1, (float)(det_ctx->pkts_scanned1/(float)(det_ctx->pkts)*100), det_ctx->pkts_searched1, (float)(det_ctx->pkts_searched1/(float)(det_ctx->pkts)*100), (float)(det_ctx->pkts_searched1/(float)(det_ctx->pkts_scanned1)*100)); - printf(" - (%s) (2byte) Pkts %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.\n", tv->name, + SCLogInfo(" - (%s) (2byte) Pkts %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.", tv->name, det_ctx->pkts, det_ctx->pkts_scanned2, (float)(det_ctx->pkts_scanned2/(float)(det_ctx->pkts)*100), det_ctx->pkts_searched2, (float)(det_ctx->pkts_searched2/(float)(det_ctx->pkts)*100), (float)(det_ctx->pkts_searched2/(float)(det_ctx->pkts_scanned2)*100)); - printf(" - (%s) (3byte) Pkts %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.\n", tv->name, + SCLogInfo(" - (%s) (3byte) Pkts %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.", tv->name, det_ctx->pkts, det_ctx->pkts_scanned3, (float)(det_ctx->pkts_scanned3/(float)(det_ctx->pkts)*100), det_ctx->pkts_searched3, (float)(det_ctx->pkts_searched3/(float)(det_ctx->pkts)*100), (float)(det_ctx->pkts_searched3/(float)(det_ctx->pkts_scanned3)*100)); - printf(" - (%s) (4byte) Pkts %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.\n", tv->name, + SCLogInfo(" - (%s) (4byte) Pkts %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.", tv->name, det_ctx->pkts, det_ctx->pkts_scanned4, (float)(det_ctx->pkts_scanned4/(float)(det_ctx->pkts)*100), det_ctx->pkts_searched4, (float)(det_ctx->pkts_searched4/(float)(det_ctx->pkts)*100), (float)(det_ctx->pkts_searched4/(float)(det_ctx->pkts_scanned4)*100)); - printf(" - (%s) (+byte) Pkts %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.\n", tv->name, + SCLogInfo(" - (%s) (+byte) Pkts %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.", tv->name, det_ctx->pkts, det_ctx->pkts_scanned, (float)(det_ctx->pkts_scanned/(float)(det_ctx->pkts)*100), det_ctx->pkts_searched, (float)(det_ctx->pkts_searched/(float)(det_ctx->pkts)*100), (float)(det_ctx->pkts_searched/(float)(det_ctx->pkts_scanned)*100)); - printf(" - (%s) URI (1byte) Uri's %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.\n", tv->name, + SCLogInfo(" - (%s) URI (1byte) Uri's %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.", tv->name, det_ctx->uris, det_ctx->pkts_uri_scanned1, (float)(det_ctx->pkts_uri_scanned1/(float)(det_ctx->uris)*100), det_ctx->pkts_uri_searched1, (float)(det_ctx->pkts_uri_searched1/(float)(det_ctx->uris)*100), (float)(det_ctx->pkts_uri_searched1/(float)(det_ctx->pkts_uri_scanned1)*100)); - printf(" - (%s) URI (2byte) Uri's %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.\n", tv->name, + SCLogInfo(" - (%s) URI (2byte) Uri's %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.", tv->name, det_ctx->uris, det_ctx->pkts_uri_scanned2, (float)(det_ctx->pkts_uri_scanned2/(float)(det_ctx->uris)*100), det_ctx->pkts_uri_searched2, (float)(det_ctx->pkts_uri_searched2/(float)(det_ctx->uris)*100), (float)(det_ctx->pkts_uri_searched2/(float)(det_ctx->pkts_uri_scanned2)*100)); - printf(" - (%s) URI (3byte) Uri's %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.\n", tv->name, + SCLogInfo(" - (%s) URI (3byte) Uri's %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.", tv->name, det_ctx->uris, det_ctx->pkts_uri_scanned3, (float)(det_ctx->pkts_uri_scanned3/(float)(det_ctx->uris)*100), det_ctx->pkts_uri_searched3, (float)(det_ctx->pkts_uri_searched3/(float)(det_ctx->uris)*100), (float)(det_ctx->pkts_uri_searched3/(float)(det_ctx->pkts_uri_scanned3)*100)); - printf(" - (%s) URI (4byte) Uri's %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.\n", tv->name, + SCLogInfo(" - (%s) URI (4byte) Uri's %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.", tv->name, det_ctx->uris, det_ctx->pkts_uri_scanned4, (float)(det_ctx->pkts_uri_scanned4/(float)(det_ctx->uris)*100), det_ctx->pkts_uri_searched4, (float)(det_ctx->pkts_uri_searched4/(float)(det_ctx->uris)*100), (float)(det_ctx->pkts_uri_searched4/(float)(det_ctx->pkts_uri_scanned4)*100)); - printf(" - (%s) URI (+byte) Uri's %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.\n", tv->name, + SCLogInfo(" - (%s) URI (+byte) Uri's %" PRIu32 ", Scanned %" PRIu32 " (%02.1f), Searched %" PRIu32 " (%02.1f): %02.1f%%.", tv->name, det_ctx->uris, det_ctx->pkts_uri_scanned, (float)(det_ctx->pkts_uri_scanned/(float)(det_ctx->uris)*100), det_ctx->pkts_uri_searched, @@ -181,9 +181,8 @@ int DetectLoadSigFile(DetectEngineCtx *de_ctx, char *sig_file) { sig = SigInit(de_ctx, line); if (sig != NULL) { -#ifdef DEBUG - printf("Sig %"PRIu32" loaded\n", sig->id); -#endif + SCLogDebug("signature %"PRIu32" loaded", sig->id); + if (de_ctx->sig_list == NULL) { de_ctx->sig_list = sig; } else { @@ -196,8 +195,8 @@ int DetectLoadSigFile(DetectEngineCtx *de_ctx, char *sig_file) { } } fclose(fp); - printf("DetectLoadSigFile: %" PRId32 " successfully loaded from file. %" PRId32 " sigs failed to load\n", good, bad); + SCLogInfo("%" PRId32 " successfully loaded from file. %" PRId32 " sigs failed to load", good, bad); return 0; } @@ -591,7 +590,7 @@ static int SignatureIsIPOnly(DetectEngineCtx *de_ctx, Signature *s) { iponly: if (!(de_ctx->flags & DE_QUIET)) { - printf("IP-ONLY (%" PRIu32 "): source %s, dest %s\n", s->id, + SCLogDebug("IP-ONLY (%" PRIu32 "): source %s, dest %s", s->id, s->flags & SIG_FLAG_SRC_ANY ? "ANY" : "SET", s->flags & SIG_FLAG_DST_ANY ? "ANY" : "SET"); } @@ -609,8 +608,8 @@ int SigAddressPrepareStage1(DetectEngineCtx *de_ctx) { //DetectPortPrintMemory(); if (!(de_ctx->flags & DE_QUIET)) { - printf("* Building signature grouping structure, stage 1: " - "adding signatures to signature source addresses...\n"); + SCLogDebug("building signature grouping structure, stage 1: " + "adding signatures to signature source addresses..."); } de_ctx->sig_array_len = DetectEngineGetMaxSigId(de_ctx); @@ -620,10 +619,8 @@ int SigAddressPrepareStage1(DetectEngineCtx *de_ctx) { goto error; memset(de_ctx->sig_array,0,de_ctx->sig_array_size); - if (!(de_ctx->flags & DE_QUIET)) { - printf(" - Signature lookup array: %" PRIu32 " sigs, %" PRIu32 " bytes.\n", + SCLogDebug("signature lookup array: %" PRIu32 " sigs, %" PRIu32 " bytes", de_ctx->sig_array_len, de_ctx->sig_array_size); - } /* now for every rule add the source group */ for (tmp_s = de_ctx->sig_list; tmp_s != NULL; tmp_s = tmp_s->next) { @@ -643,31 +640,32 @@ int SigAddressPrepareStage1(DetectEngineCtx *de_ctx) { //} } -/* DEBUG */ - uint16_t colen = 0; - char copresent = 0; - SigMatch *sm; - DetectContentData *co; - for (sm = tmp_s->match; sm != NULL; sm = sm->next) { - if (sm->type != DETECT_CONTENT) - continue; +#ifdef DEBUG + if (SCLogDebugEnabled()) { + uint16_t colen = 0; + char copresent = 0; + SigMatch *sm; + DetectContentData *co; + for (sm = tmp_s->match; sm != NULL; sm = sm->next) { + if (sm->type != DETECT_CONTENT) + continue; - copresent = 1; - co = (DetectContentData *)sm->ctx; - if (co->content_len > colen) - colen = co->content_len; - } + copresent = 1; + co = (DetectContentData *)sm->ctx; + if (co->content_len > colen) + colen = co->content_len; + } - if (copresent && colen == 1) { - printf("==> Signature %8u content maxlen 1: ", tmp_s->id); - int proto; - for (proto = 0; proto < 256; proto++) { - if (tmp_s->proto.proto[(proto/8)] & (1<<(proto%8))) - printf ("%" PRId32 " ", proto); + if (copresent && colen == 1) { + SCLogDebug("signature %8u content maxlen 1", tmp_s->id); + int proto; + for (proto = 0; proto < 256; proto++) { + if (tmp_s->proto.proto[(proto/8)] & (1<<(proto%8))) + SCLogDebug("=> proto %" PRId32 "", proto); + } } - printf("\n"); } -/* DEBUG */ +#endif /* DEBUG */ for (gr = tmp_s->src.ipv4_head; gr != NULL; gr = gr->next) { @@ -697,10 +695,10 @@ int SigAddressPrepareStage1(DetectEngineCtx *de_ctx) { //DetectPortPrintMemory(); if (!(de_ctx->flags & DE_QUIET)) { - printf(" * %" PRIu32 " signatures processed. %" PRIu32 " are IP-only rules.\n", + SCLogInfo("%" PRIu32 " signatures processed. %" PRIu32 " are IP-only rules", de_ctx->sig_cnt, cnt_iponly); - printf("* Building signature grouping structure, stage 1: " - "adding signatures to signature source addresses... done\n"); + SCLogInfo("building signature grouping structure, stage 1: " + "adding signatures to signature source addresses... done"); } return 0; error: @@ -1155,9 +1153,11 @@ int CreateGroupedAddrList(DetectEngineCtx *de_ctx, DetectAddressGroup *srchead, #endif } -#ifdef DEBUG - for (gr = newhead->ipv4_head; gr != NULL; gr = gr->next) { - printf(" 4 -= R Address "); DetectAddressDataPrint(gr->ad); printf(" : "); DbgPrintSigs2(de_ctx, gr->sh); +#if 0//def DEBUG + if (SCLogDebugEnabled()) { + for (gr = newhead->ipv4_head; gr != NULL; gr = gr->next) { + printf(" 4 -= R Address "); DetectAddressDataPrint(gr->ad); printf(" : "); DbgPrintSigs2(de_ctx, gr->sh); + } } #endif @@ -1206,8 +1206,10 @@ int CreateGroupedPortList(DetectEngineCtx *de_ctx,HashListTable *port_hash, Dete unique_groups++; groups++; -#ifdef DEBUG - printf(" -= 1:Port "); DetectPortPrint(gr); printf(" : "); DbgPrintSigs2(de_ctx, gr->sh); +#if 0//def DEBUG + if (SCLogDebugEnabled()) { + printf(" -= 1:Port "); DetectPortPrint(gr); printf(" : "); DbgPrintSigs2(de_ctx, gr->sh); + } #endif /* alloc a copy */ DetectPort *newtmp = DetectPortCopySingle(de_ctx,gr); @@ -1306,10 +1308,12 @@ int CreateGroupedPortList(DetectEngineCtx *de_ctx,HashListTable *port_hash, Dete DetectPortInsert(de_ctx,newhead,joingr); } -#ifdef DEBUG - for (gr = *newhead; gr != NULL; gr = gr->next) { - //printf(":-:9:-: Port "); DetectPortPrint(gr); printf(" (cnt %" PRIu32 "", gr->cnt); DbgSghContainsSig(de_ctx,gr->sh,489); - printf(" -= 9:Port "); DetectPortPrint(gr); printf(" : "); DbgPrintSigs2(de_ctx, gr->sh); +#if 0//def DEBUG + if (SCLogDebugEnabled()) { + for (gr = *newhead; gr != NULL; gr = gr->next) { + //printf(":-:9:-: Port "); DetectPortPrint(gr); printf(" (cnt %" PRIu32 "", gr->cnt); DbgSghContainsSig(de_ctx,gr->sh,489); + printf(" -= 9:Port "); DetectPortPrint(gr); printf(" : "); DbgPrintSigs2(de_ctx, gr->sh); + } } #endif return 0; @@ -1324,8 +1328,8 @@ int SigAddressPrepareStage2(DetectEngineCtx *de_ctx) { uint32_t sigs = 0; if (!(de_ctx->flags & DE_QUIET)) { - printf("* Building signature grouping structure, stage 2: " - "building source address list...\n"); + SCLogInfo("building signature grouping structure, stage 2: " + "building source address list..."); } IPOnlyInit(de_ctx, &de_ctx->io_ctx); @@ -1396,21 +1400,21 @@ int SigAddressPrepareStage2(DetectEngineCtx *de_ctx) { IPOnlyPrint(de_ctx, &de_ctx->io_ctx); if (!(de_ctx->flags & DE_QUIET)) { - printf("* %" PRIu32 " total signatures:\n", sigs); - printf(" * %5u in ipv4 small group, %" PRIu32 " in rest\n", g_detectengine_ip4_small,g_detectengine_ip4_big); - printf(" * %5u in ipv6 small group, %" PRIu32 " in rest\n", g_detectengine_ip6_small,g_detectengine_ip6_big); - printf(" * %5u in any small group, %" PRIu32 " in rest\n", g_detectengine_any_small,g_detectengine_any_big); - printf(" * Small %5u in ipv4 toserver group, %" PRIu32 " in toclient\n", + SCLogInfo("%" PRIu32 " total signatures:", sigs); + SCLogInfo("%"PRIu32" in ipv4 small group, %" PRIu32 " in rest", g_detectengine_ip4_small,g_detectengine_ip4_big); + SCLogInfo("%"PRIu32" in ipv6 small group, %" PRIu32 " in rest", g_detectengine_ip6_small,g_detectengine_ip6_big); + SCLogInfo("%"PRIu32" in any small group, %" PRIu32 " in rest", g_detectengine_any_small,g_detectengine_any_big); + SCLogInfo("small: %"PRIu32" in ipv4 toserver group, %" PRIu32 " in toclient", g_detectengine_ip4_small_toserver,g_detectengine_ip4_small_toclient); - printf(" * %5u in ipv6 toserver group, %" PRIu32 " in toclient\n", + SCLogInfo("small: %"PRIu32" in ipv6 toserver group, %" PRIu32 " in toclient", g_detectengine_ip6_small_toserver,g_detectengine_ip6_small_toclient); - printf(" * %5u in any toserver group, %" PRIu32 " in toclient\n", + SCLogInfo("small: %"PRIu32" in any toserver group, %" PRIu32 " in toclient", g_detectengine_any_small_toserver,g_detectengine_any_small_toclient); - printf(" * Big %5u in ipv4 toserver group, %" PRIu32 " in toclient\n", + SCLogInfo("big: %"PRIu32" in ipv4 toserver group, %" PRIu32 " in toclient", g_detectengine_ip4_big_toserver,g_detectengine_ip4_big_toclient); - printf(" * %5u in ipv6 toserver group, %" PRIu32 " in toclient\n", + SCLogInfo("big: %"PRIu32" in ipv6 toserver group, %" PRIu32 " in toclient", g_detectengine_ip6_big_toserver,g_detectengine_ip6_big_toclient); - printf(" * %5u in any toserver group, %" PRIu32 " in toclient\n", + SCLogInfo("big: %"PRIu32" in any toserver group, %" PRIu32 " in toclient", g_detectengine_any_big_toserver,g_detectengine_any_big_toclient); } @@ -1438,7 +1442,7 @@ int SigAddressPrepareStage2(DetectEngineCtx *de_ctx) { } } if (!(de_ctx->flags & DE_QUIET)) { - printf(" * TCP Source address blocks: any: %4u, ipv4: %4u, ipv6: %4u.\n", cnt_any, cnt_ipv4, cnt_ipv6); + SCLogInfo("TCP Source address blocks: any: %4u, ipv4: %4u, ipv6: %4u.", cnt_any, cnt_ipv4, cnt_ipv6); } cnt_any = 0, cnt_ipv4 = 0, cnt_ipv6 = 0; @@ -1464,7 +1468,7 @@ int SigAddressPrepareStage2(DetectEngineCtx *de_ctx) { } } if (!(de_ctx->flags & DE_QUIET)) { - printf(" * UDP Source address blocks: any: %4u, ipv4: %4u, ipv6: %4u.\n", cnt_any, cnt_ipv4, cnt_ipv6); + SCLogInfo("UDP Source address blocks: any: %4u, ipv4: %4u, ipv6: %4u.", cnt_any, cnt_ipv4, cnt_ipv6); } cnt_any = 0, cnt_ipv4 = 0, cnt_ipv6 = 0; @@ -1490,11 +1494,11 @@ int SigAddressPrepareStage2(DetectEngineCtx *de_ctx) { } } if (!(de_ctx->flags & DE_QUIET)) { - printf(" * ICMP Source address blocks: any: %4u, ipv4: %4u, ipv6: %4u.\n", cnt_any, cnt_ipv4, cnt_ipv6); + SCLogInfo("ICMP Source address blocks: any: %4u, ipv4: %4u, ipv6: %4u.", cnt_any, cnt_ipv4, cnt_ipv6); } if (!(de_ctx->flags & DE_QUIET)) { - printf("* Building signature grouping structure, stage 2: building source address list... done\n"); + SCLogInfo("building signature grouping structure, stage 2: building source address list... done"); } return 0; @@ -1996,8 +2000,8 @@ int SigAddressPrepareStage3(DetectEngineCtx *de_ctx) { int r; if (!(de_ctx->flags & DE_QUIET)) { - printf("* Building signature grouping structure, stage 3: " - "building destination address lists...\n"); + SCLogInfo("building signature grouping structure, stage 3: " + "building destination address lists..."); } //DetectAddressGroupPrintMemory(); //DetectSigGroupPrintMemory(); @@ -2079,22 +2083,22 @@ int SigAddressPrepareStage3(DetectEngineCtx *de_ctx) { DetectPortSpHashFree(de_ctx); if (!(de_ctx->flags & DE_QUIET)) { - printf("* MPM memory %" PRIuMAX " (dynamic %" PRIu32 ", ctxs %" PRIuMAX ", avg per ctx %" PRIu32 ")\n", + SCLogInfo("MPM memory %" PRIuMAX " (dynamic %" PRIu32 ", ctxs %" PRIuMAX ", avg per ctx %" PRIu32 ")", de_ctx->mpm_memory_size + ((de_ctx->mpm_unique + de_ctx->mpm_uri_unique) * (uintmax_t)sizeof(MpmCtx)), de_ctx->mpm_memory_size, ((de_ctx->mpm_unique + de_ctx->mpm_uri_unique) * (uintmax_t)sizeof(MpmCtx)), de_ctx->mpm_unique ? de_ctx->mpm_memory_size / de_ctx->mpm_unique: 0); - printf(" * Max sig id %" PRIu32 ", array size %" PRIu32 "\n", DetectEngineGetMaxSigId(de_ctx), DetectEngineGetMaxSigId(de_ctx) / 8 + 1); - printf("* Signature group heads: unique %" PRIu32 ", copies %" PRIu32 ".\n", de_ctx->gh_unique, de_ctx->gh_reuse); - printf("* MPM instances: %" PRIu32 " unique, copies %" PRIu32 " (none %" PRIu32 ").\n", + SCLogInfo("max sig id %" PRIu32 ", array size %" PRIu32 "", DetectEngineGetMaxSigId(de_ctx), DetectEngineGetMaxSigId(de_ctx) / 8 + 1); + SCLogInfo("signature group heads: unique %" PRIu32 ", copies %" PRIu32 ".", de_ctx->gh_unique, de_ctx->gh_reuse); + SCLogInfo("MPM instances: %" PRIu32 " unique, copies %" PRIu32 " (none %" PRIu32 ").", de_ctx->mpm_unique, de_ctx->mpm_reuse, de_ctx->mpm_none); - printf("* MPM (URI) instances: %" PRIu32 " unique, copies %" PRIu32 " (none %" PRIu32 ").\n", + SCLogInfo("MPM (URI) instances: %" PRIu32 " unique, copies %" PRIu32 " (none %" PRIu32 ").", de_ctx->mpm_uri_unique, de_ctx->mpm_uri_reuse, de_ctx->mpm_uri_none); - printf("* MPM max patcnt %" PRIu32 ", avg %" PRIu32 "\n", de_ctx->mpm_max_patcnt, de_ctx->mpm_unique?de_ctx->mpm_tot_patcnt/de_ctx->mpm_unique:0); + SCLogInfo("MPM max patcnt %" PRIu32 ", avg %" PRIu32 "", de_ctx->mpm_max_patcnt, de_ctx->mpm_unique?de_ctx->mpm_tot_patcnt/de_ctx->mpm_unique:0); if (de_ctx->mpm_uri_tot_patcnt && de_ctx->mpm_uri_unique) - printf("* MPM (URI) max patcnt %" PRIu32 ", avg %" PRIu32 " (%" PRIu32 "/%" PRIu32 ")\n", de_ctx->mpm_uri_max_patcnt, de_ctx->mpm_uri_tot_patcnt/de_ctx->mpm_uri_unique, de_ctx->mpm_uri_tot_patcnt, de_ctx->mpm_uri_unique); - printf(" = port maxgroups: %" PRIu32 ", avg %" PRIu32 ", tot %" PRIu32 "\n", g_groupportlist_maxgroups, g_groupportlist_totgroups/g_groupportlist_groupscnt, g_groupportlist_totgroups); - printf("* Building signature grouping structure, stage 3: building destination address lists... done\n"); + SCLogInfo("MPM (URI) max patcnt %" PRIu32 ", avg %" PRIu32 " (%" PRIu32 "/%" PRIu32 ")", de_ctx->mpm_uri_max_patcnt, de_ctx->mpm_uri_tot_patcnt/de_ctx->mpm_uri_unique, de_ctx->mpm_uri_tot_patcnt, de_ctx->mpm_uri_unique); + SCLogInfo("port maxgroups: %" PRIu32 ", avg %" PRIu32 ", tot %" PRIu32 "", g_groupportlist_maxgroups, g_groupportlist_totgroups/g_groupportlist_groupscnt, g_groupportlist_totgroups); + SCLogInfo("building signature grouping structure, stage 3: building destination address lists... done"); } return 0; error: @@ -2520,7 +2524,7 @@ void SigTableSetup(void) { uint8_t i = 0; for (i = 0; i < DETECT_TBLSIZE; i++) { if (sigmatch_table[i].RegisterTests == NULL) { - printf("Warning: detection plugin %s has no unittest " + SCLogDebug("detection plugin %s has no unittest " "registration function.\n", sigmatch_table[i].name); } } diff --git a/src/eidps.c b/src/eidps.c index 0f61efe2f7..dcee4a19dd 100644 --- a/src/eidps.c +++ b/src/eidps.c @@ -158,7 +158,7 @@ Packet *SetupPkt (void) pthread_mutex_init(&p->mutex_rtv_cnt, NULL); - printf("SetupPkt: allocated a new packet...\n"); + SCLogDebug("allocated a new packet..."); } /* reset the packet csum fields */ @@ -444,7 +444,7 @@ int main(int argc, char **argv) memset(&trans_q, 0,sizeof(trans_q)); /* pre allocate packets */ - printf("Preallocating packets... packet size %" PRIuMAX "\n", (uintmax_t)sizeof(Packet)); + SCLogInfo("preallocating packets... packet size %" PRIuMAX "", (uintmax_t)sizeof(Packet)); int i = 0; for (i = 0; i < MAX_PENDING; i++) { /* XXX pkt alloc function */ @@ -458,7 +458,7 @@ int main(int argc, char **argv) PacketEnqueue(&packet_q,p); } - printf("Preallocating packets... done\n"); + SCLogInfo("preallocating packets... done: total memory %"PRIuMAX"", (uintmax_t)(MAX_PENDING*sizeof(Packet))); FlowInitConfig(FLOW_VERBOSE); @@ -520,10 +520,10 @@ int main(int argc, char **argv) while(1) { if (sigflags) { - printf("signal received\n"); + SCLogInfo("signal received"); if (sigflags & EIDPS_STOP) { - printf ("SIGINT or EngineStop received\n"); + SCLogInfo("SIGINT or EngineStop received"); /* Stop the engine so it quits after processing the pcap file * but first make sure all packets are processed by all other @@ -543,20 +543,19 @@ int main(int argc, char **argv) } } while (done == 0); - printf("main: all packets processed by threads, stopping engine\n"); + SCLogInfo("all packets processed by threads, stopping engine"); } - if (sigflags & EIDPS_SIGHUP) printf ("SIGHUP\n"); - if (sigflags & EIDPS_SIGTERM) printf ("SIGTERM\n"); + if (sigflags & EIDPS_SIGHUP) SCLogInfo("SIGHUP received"); + if (sigflags & EIDPS_SIGTERM) SCLogInfo("SIGTERM received"); struct timeval end_time; memset(&end_time, 0, sizeof(end_time)); gettimeofday(&end_time, NULL); - printf("time elapsed %" PRIuMAX "s\n", (uintmax_t)(end_time.tv_sec - start_time.tv_sec)); + SCLogInfo("time elapsed %" PRIuMAX "s", (uintmax_t)(end_time.tv_sec - start_time.tv_sec)); TmThreadKillThreads(); PerfReleaseResources(); - break; } diff --git a/src/flow-hash.c b/src/flow-hash.c index 24f8916ae1..0e60b295a5 100644 --- a/src/flow-hash.c +++ b/src/flow-hash.c @@ -79,7 +79,7 @@ Flow *FlowGetFlowFromHash (Packet *p) FlowBucket *fb = &flow_hash[key]; mutex_lock(&fb->m); - SCDebug("FlowGetFlowFromHash: fb %p fb->f %p", fb, fb->f); + SCLogDebug("FlowGetFlowFromHash: fb %p fb->f %p", fb, fb->f); /* see if the bucket already has a flow */ if (fb->f == NULL) { diff --git a/src/flow.c b/src/flow.c index d2d6bb253a..8b20a90a3f 100644 --- a/src/flow.c +++ b/src/flow.c @@ -171,7 +171,7 @@ static int FlowPrune (FlowQueue *q, struct timeval *ts) } } - SCDebug("got lock, now check: %" PRIdMAX "+%" PRIu32 "=(%" PRIdMAX ") < %" PRIdMAX "", (intmax_t)f->lastts.tv_sec, + SCLogDebug("got lock, now check: %" PRIdMAX "+%" PRIu32 "=(%" PRIdMAX ") < %" PRIdMAX "", (intmax_t)f->lastts.tv_sec, timeout, (intmax_t)f->lastts.tv_sec + timeout, (intmax_t)ts->tv_sec); /* do the timeout check */ @@ -184,7 +184,7 @@ static int FlowPrune (FlowQueue *q, struct timeval *ts) /** never prune a flow that is used by a packet or stream msg * we are currently processing in one of the threads */ if (f->use_cnt > 0) { - SCDebug("timed out but use_cnt > 0: %"PRIu16", %p, proto %"PRIu8"", f->use_cnt, f, f->proto); + SCLogDebug("timed out but use_cnt > 0: %"PRIu16", %p, proto %"PRIu8"", f->use_cnt, f, f->proto); mutex_unlock(&f->fb->m); mutex_unlock(&f->m); return 0; @@ -352,7 +352,7 @@ void FlowHandlePacket (ThreadVars *tv, Packet *p) void FlowInitConfig (char quiet) { if (quiet == FALSE) - printf("Initializing Flow:\n"); + SCLogInfo("initializing flow engine..."); memset(&flow_config, 0, sizeof(flow_config)); memset(&flow_spare_q, 0, sizeof(flow_spare_q)); @@ -382,7 +382,7 @@ void FlowInitConfig (char quiet) flow_config.memuse += (flow_config.hash_size * sizeof(FlowBucket)); if (quiet == FALSE) - printf("* Allocated %" PRIu32 " bytes of memory for the flow hash... %" PRIu32 " buckets of size %" PRIuMAX "\n", + SCLogInfo("allocated %" PRIu32 " bytes of memory for the flow hash... %" PRIu32 " buckets of size %" PRIuMAX "", flow_config.memuse, flow_config.hash_size, (uintmax_t)sizeof(FlowBucket)); /* pre allocate flows */ @@ -397,9 +397,9 @@ void FlowInitConfig (char quiet) } if (quiet == FALSE) { - printf("* Preallocated %" PRIu32 " flows of size %" PRIuMAX "\n", + SCLogInfo("preallocated %" PRIu32 " flows of size %" PRIuMAX "", flow_spare_q.len, (uintmax_t)sizeof(Flow)); - printf("* Flow memory usage: %" PRIu32 " bytes. Maximum: %" PRIu32 "\n", + SCLogInfo("flow memory usage: %" PRIu32 " bytes, maximum: %" PRIu32 "", flow_config.memuse, flow_config.memcap); } @@ -412,28 +412,46 @@ void FlowInitConfig (char quiet) void FlowPrintQueueInfo (void) { int i; - printf("* Flow Queue info:\n"); - printf(" - SPARE %" PRIu32 " (", flow_spare_q.len); + SCLogInfo("flow queue info:"); + SCLogInfo("spare flow queue %" PRIu32 "", flow_spare_q.len); #ifdef DBG_PERF - printf("flow_spare_q.dbg_maxlen %" PRIu32 ")\n", flow_spare_q.dbg_maxlen); + SCLogInfo("flow_spare_q.dbg_maxlen %" PRIu32 "", flow_spare_q.dbg_maxlen); #endif for (i = 0; i < FLOW_PROTO_MAX; i++) { - printf(" - NEW %" PRIu32 " (", flow_new_q[i].len); + SCLogInfo("proto [%"PRId32"] new flow queue %" PRIu32 " " #ifdef DBG_PERF - printf("flow_new_q.dbg_maxlen %" PRIu32 ")\n", flow_new_q[i].dbg_maxlen); + " - flow_new_q.dbg_maxlen %" PRIu32 "" #endif - printf(" - ESTABLISHED %" PRIu32 " (", flow_est_q[i].len); + ,i,flow_new_q[i].len #ifdef DBG_PERF - printf("flow_est_q.dbg_maxlen %" PRIu32 ")\n", flow_est_q[i].dbg_maxlen); + ,flow_new_q[i].dbg_maxlen #endif - printf(" - CLOSING %" PRIu32 " (", flow_close_q[i].len); + ); + + SCLogInfo("proto [%"PRId32"] establised flow queue %" PRIu32 " " +#ifdef DBG_PERF + " - flow_est_q.dbg_maxlen %" PRIu32 "" +#endif + ,i,flow_est_q[i].len +#ifdef DBG_PERF + ,flow_est_q[i].dbg_maxlen +#endif + ); + + SCLogInfo("proto [%"PRId32"] closing flow queue %" PRIu32 " " +#ifdef DBG_PERF + " - flow_closing_q.dbg_maxlen %" PRIu32 "" +#endif + ,i,flow_close_q[i].len #ifdef DBG_PERF - printf("flow_closing_q.dbg_maxlen %" PRIu32 ")\n", flow_close_q[i].dbg_maxlen); + ,flow_close_q[i].dbg_maxlen #endif + ); + } #ifdef FLOWBITS_STATS - printf("* Flowbits added: %" PRIu32 ", removed: %" PRIu32 ", ", flowbits_added, flowbits_removed); - printf("max memory usage: %" PRIu32 "\n", flowbits_memuse_max); + SCLogInfo("flowbits added: %" PRIu32 ", removed: %" PRIu32 ", max memory usage: %" PRIu32 "", + flowbits_added, flowbits_removed, flowbits_memuse_max); #endif /* FLOWBITS_STATS */ } @@ -491,9 +509,7 @@ void *FlowManagerThread(void *td) uint32_t sleeping = 0; uint8_t emerg = FALSE; -#ifdef DEBUG - printf("%s started...\n", th_v->name); -#endif + SCLogDebug("%s started...", th_v->name); TmThreadsSetFlag(th_v, THV_INIT_DONE); while (1) @@ -513,7 +529,7 @@ void *FlowManagerThread(void *td) /* Get the time */ memset(&ts, 0, sizeof(ts)); TimeGet(&ts); - SCDebug("ts %" PRIdMAX "", (intmax_t)ts.tv_sec); + SCLogDebug("ts %" PRIdMAX "", (intmax_t)ts.tv_sec); /* see if we still have enough spare flows */ FlowUpdateSpareFlows(); @@ -523,21 +539,21 @@ void *FlowManagerThread(void *td) /* prune closing list */ nowcnt = FlowPruneFlows(&flow_close_q[i], &ts); if (nowcnt) { - SCDebug("Pruned %" PRIu32 " closing flows...", nowcnt); + SCLogDebug("Pruned %" PRIu32 " closing flows...", nowcnt); closing_cnt += nowcnt; } /* prune new list */ nowcnt = FlowPruneFlows(&flow_new_q[i], &ts); if (nowcnt) { - SCDebug("Pruned %" PRIu32 " new flows...", nowcnt); + SCLogDebug("Pruned %" PRIu32 " new flows...", nowcnt); new_cnt += nowcnt; } /* prune established list */ nowcnt = FlowPruneFlows(&flow_est_q[i], &ts); if (nowcnt) { - SCDebug("Pruned %" PRIu32 " established flows...", nowcnt); + SCLogDebug("Pruned %" PRIu32 " established flows...", nowcnt); established_cnt += nowcnt; } } @@ -562,7 +578,7 @@ void *FlowManagerThread(void *td) sleeping += 10; } - printf("* %s ended: %" PRIu32 " new flows, %" PRIu32 " established flows were pruned\n", th_v->name, new_cnt, established_cnt); + SCLogInfo("%" PRIu32 " new flows, %" PRIu32 " established flows were timed out", new_cnt, established_cnt); pthread_exit((void *) 0); } diff --git a/src/source-pcap.c b/src/source-pcap.c index 187153d450..6a32be1138 100644 --- a/src/source-pcap.c +++ b/src/source-pcap.c @@ -16,6 +16,7 @@ #include "tm-modules.h" #include "tm-threads.h" #include "source-pcap.h" +#include "util-debug.h" /** * \brief Structure to hold thread specific variables. @@ -170,7 +171,7 @@ int ReceivePcapThreadInit(ThreadVars *tv, void *initdata, void **data) { ptv->tv = tv; - printf("ReceivePcapThreadInit: using interface %s\n", (char *)initdata); + SCLogInfo("using interface %s", (char *)initdata); /* XXX create a general pcap setup function */ char errbuf[PCAP_ERRBUF_SIZE]; diff --git a/src/stream-tcp-reassemble.c b/src/stream-tcp-reassemble.c index 37cf9ab409..68a0f6d46e 100644 --- a/src/stream-tcp-reassemble.c +++ b/src/stream-tcp-reassemble.c @@ -141,7 +141,7 @@ void StreamTcpReassembleFree(char quiet) { for (u16 = 0; u16 < segment_pool_num; u16++) { if (quiet == FALSE) { PoolPrintSaturation(segment_pool[u16]); - printf("segment_pool[u16]->empty_list_size %"PRIu32", segment_pool[u16]->alloc_list_size %"PRIu32", alloced %"PRIu32"\n", segment_pool[u16]->empty_list_size, segment_pool[u16]->alloc_list_size, segment_pool[u16]->allocated); + SCLogDebug("segment_pool[u16]->empty_list_size %"PRIu32", segment_pool[u16]->alloc_list_size %"PRIu32", alloced %"PRIu32"", segment_pool[u16]->empty_list_size, segment_pool[u16]->alloc_list_size, segment_pool[u16]->allocated); } PoolFree(segment_pool[u16]); @@ -149,9 +149,9 @@ void StreamTcpReassembleFree(char quiet) { } #ifdef DEBUG - printf("segment_pool_cnt %"PRIu64"\n", segment_pool_cnt); - printf("segment_pool_memuse %"PRIu64"\n", segment_pool_memuse); - printf("segment_pool_memcnt %"PRIu64"\n", segment_pool_memcnt); + SCLogDebug("segment_pool_cnt %"PRIu64"", segment_pool_cnt); + SCLogDebug("segment_pool_memuse %"PRIu64"", segment_pool_memuse); + SCLogDebug("segment_pool_memcnt %"PRIu64"", segment_pool_memcnt); #endif StreamMsgQueuesDeinit(quiet); @@ -189,25 +189,25 @@ void PrintList2(TcpSegment *seg) { while (seg != NULL) { if (SEQ_LT(next_seq,seg->seq)) { - SCDebug("missing segment(s) for %" PRIu32 " bytes of data", (seg->seq - next_seq)); + SCLogDebug("missing segment(s) for %" PRIu32 " bytes of data", (seg->seq - next_seq)); } - SCDebug("seg %10"PRIu32" len %" PRIu16 ", seg %p, prev %p, next %p", seg->seq, seg->payload_len, seg, seg->prev, seg->next); + SCLogDebug("seg %10"PRIu32" len %" PRIu16 ", seg %p, prev %p, next %p", seg->seq, seg->payload_len, seg, seg->prev, seg->next); if (seg->prev != NULL && SEQ_LT(seg->seq,seg->prev->seq)) { - SCDebug("inconsistant list: SEQ_LT(seg->seq,seg->prev->seq)) == TRUE, seg->seq %" PRIu32 ", seg->prev->seq %" PRIu32 "", seg->seq, seg->prev->seq); + SCLogDebug("inconsistant list: SEQ_LT(seg->seq,seg->prev->seq)) == TRUE, seg->seq %" PRIu32 ", seg->prev->seq %" PRIu32 "", seg->seq, seg->prev->seq); } if (SEQ_LT(seg->seq,next_seq)) { - SCDebug("inconsistant list: SEQ_LT(seg->seq,next_seq)) == TRUE, seg->seq %" PRIu32 ", next_seq %" PRIu32 "", seg->seq, next_seq); + SCLogDebug("inconsistant list: SEQ_LT(seg->seq,next_seq)) == TRUE, seg->seq %" PRIu32 ", next_seq %" PRIu32 "", seg->seq, next_seq); } if (prev_seg != seg->prev) { - SCDebug("inconsistant list: prev_seg %p != seg->prev %p", prev_seg, seg->prev); + SCLogDebug("inconsistant list: prev_seg %p != seg->prev %p", prev_seg, seg->prev); } next_seq = seg->seq + seg->payload_len; - SCDebug("next_seq is now %"PRIu32"", next_seq); + SCLogDebug("next_seq is now %"PRIu32"", next_seq); prev_seg = seg; seg = seg->next; } @@ -224,31 +224,31 @@ void PrintList(TcpSegment *seg) { while (seg != NULL) { if (SEQ_LT(next_seq,seg->seq)) { - SCDebug("missing segment(s) for %" PRIu32 " bytes of data", (seg->seq - next_seq)); + SCLogDebug("missing segment(s) for %" PRIu32 " bytes of data", (seg->seq - next_seq)); } - SCDebug("seg %10"PRIu32" len %" PRIu16 ", seg %p, prev %p, next %p", seg->seq, seg->payload_len, seg, seg->prev, seg->next); + SCLogDebug("seg %10"PRIu32" len %" PRIu16 ", seg %p, prev %p, next %p", seg->seq, seg->payload_len, seg, seg->prev, seg->next); if (seg->prev != NULL && SEQ_LT(seg->seq,seg->prev->seq)) { - SCDebug("inconsistant list: SEQ_LT(seg->seq,seg->prev->seq)) == TRUE, seg->seq %" PRIu32 ", seg->prev->seq %" PRIu32 "", seg->seq, seg->prev->seq); + SCLogDebug("inconsistant list: SEQ_LT(seg->seq,seg->prev->seq)) == TRUE, seg->seq %" PRIu32 ", seg->prev->seq %" PRIu32 "", seg->seq, seg->prev->seq); PrintList2(head_seg); abort(); } if (SEQ_LT(seg->seq,next_seq)) { - SCDebug("inconsistant list: SEQ_LT(seg->seq,next_seq)) == TRUE, seg->seq %" PRIu32 ", next_seq %" PRIu32 "", seg->seq, next_seq); + SCLogDebug("inconsistant list: SEQ_LT(seg->seq,next_seq)) == TRUE, seg->seq %" PRIu32 ", next_seq %" PRIu32 "", seg->seq, next_seq); PrintList2(head_seg); abort(); } if (prev_seg != seg->prev) { - SCDebug("inconsistant list: prev_seg %p != seg->prev %p", prev_seg, seg->prev); + SCLogDebug("inconsistant list: prev_seg %p != seg->prev %p", prev_seg, seg->prev); PrintList2(head_seg); abort(); } next_seq = seg->seq + seg->payload_len; - SCDebug("next_seq is now %"PRIu32"", next_seq); + SCLogDebug("next_seq is now %"PRIu32"", next_seq); prev_seg = seg; seg = seg->next; } @@ -270,7 +270,7 @@ static int ReassembleInsertSegment(TcpStream *stream, TcpSegment *seg) { char return_seg = FALSE; if (list_seg == NULL) { - SCDebug("empty list, inserting seg %p seq %" PRIu32 ", len %" PRIu32 "", + SCLogDebug("empty list, inserting seg %p seq %" PRIu32 ", len %" PRIu32 "", seg, seg->seq, seg->payload_len); stream->seg_list = seg; seg->prev = NULL; @@ -278,14 +278,14 @@ static int ReassembleInsertSegment(TcpStream *stream, TcpSegment *seg) { } for (; list_seg != NULL; list_seg = list_seg->next) { - SCDebug("seg %p, list_seg %p, list_prev %p list_seg->next %p, segment length %" PRIu32 "", + SCLogDebug("seg %p, list_seg %p, list_prev %p list_seg->next %p, segment length %" PRIu32 "", seg, list_seg, list_seg->prev, list_seg->next, seg->payload_len); /* segment starts before list */ if (SEQ_LT(seg->seq, list_seg->seq)) { /* seg is entirely before list_seg */ if (SEQ_LEQ((seg->seq + seg->payload_len), list_seg->seq)) { - SCDebug("before list seg: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 ", list_seg->prev %p", seg->seq, list_seg->seq, list_seg->payload_len, list_seg->prev); + SCLogDebug("before list seg: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 ", list_seg->prev %p", seg->seq, list_seg->seq, list_seg->payload_len, list_seg->prev); seg->next = list_seg; if (list_seg->prev == NULL) { stream->seg_list = seg; @@ -328,7 +328,7 @@ static int ReassembleInsertSegment(TcpStream *stream, TcpSegment *seg) { if (((SEQ_GEQ(seg->seq, (list_seg->seq + list_seg->payload_len)))) && SEQ_GT((seg->seq + seg->payload_len), (list_seg->seq + list_seg->payload_len))) { - SCDebug("starts beyond list end, ends after list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " (%" PRIu32 ")", seg->seq, list_seg->seq, list_seg->payload_len, list_seg->seq + list_seg->payload_len); + SCLogDebug("starts beyond list end, ends after list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " (%" PRIu32 ")", seg->seq, list_seg->seq, list_seg->payload_len, list_seg->seq + list_seg->payload_len); if (list_seg->next == NULL) { list_seg->next = seg; @@ -382,7 +382,7 @@ static int HandleSegmentStartsBeforeListSegment(TcpStream *stream, TcpSegment *l char end_after = FALSE; char end_same = FALSE; #ifdef DEBUG - SCDebug("seg->seq %" PRIu32 ", seg->payload_len %" PRIu32 "", seg->seq, seg->payload_len); + SCLogDebug("seg->seq %" PRIu32 ", seg->payload_len %" PRIu32 "", seg->seq, seg->payload_len); PrintList(stream->seg_list); #endif @@ -395,7 +395,7 @@ static int HandleSegmentStartsBeforeListSegment(TcpStream *stream, TcpSegment *l * We know seg->seq + seg->payload_len is bigger than list_seg->seq */ overlap = (seg->seq + seg->payload_len) - list_seg->seq; overlap_point = list_seg->seq; - SCDebug("starts before list seg, ends before list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu16 " overlap is %" PRIu32 ", overlap point %"PRIu32"", seg->seq, list_seg->seq, list_seg->payload_len, overlap, overlap_point); + SCLogDebug("starts before list seg, ends before list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu16 " overlap is %" PRIu32 ", overlap point %"PRIu32"", seg->seq, list_seg->seq, list_seg->payload_len, overlap, overlap_point); } else if (SEQ_EQ((seg->seq + seg->payload_len), (list_seg->seq + list_seg->payload_len))) { /* seg fully overlaps list_seg, starts before, at end point * [aaa[ababab]] where a = seg, b = list_seg @@ -403,7 +403,7 @@ static int HandleSegmentStartsBeforeListSegment(TcpStream *stream, TcpSegment *l overlap = list_seg->payload_len; end_same = TRUE; overlap_point = list_seg->seq; - SCDebug("starts before list seg, ends at list end: list prev %p seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " overlap is %" PRIu32 "", list_seg->prev, seg->seq, list_seg->seq, list_seg->payload_len, overlap); + SCLogDebug("starts before list seg, ends at list end: list prev %p seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " overlap is %" PRIu32 "", list_seg->prev, seg->seq, list_seg->seq, list_seg->payload_len, overlap); /* seg fully overlaps list_seg, starts before, ends after list endpoint */ } else if (SEQ_GT((seg->seq + seg->payload_len), (list_seg->seq + list_seg->payload_len))) { /* seg fully overlaps list_seg, starts before, ends after list endpoint @@ -412,14 +412,14 @@ static int HandleSegmentStartsBeforeListSegment(TcpStream *stream, TcpSegment *l overlap = list_seg->payload_len; end_after = TRUE; overlap_point = list_seg->seq; - SCDebug("starts before list seg, ends after list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " overlap is %" PRIu32 "", seg->seq, list_seg->seq, list_seg->payload_len, overlap); + SCLogDebug("starts before list seg, ends after list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " overlap is %" PRIu32 "", seg->seq, list_seg->seq, list_seg->payload_len, overlap); } if (overlap > 0) { /* Handling case when the packet starts before the first packet in the list */ if (list_seg->prev == NULL) { packet_length = seg->payload_len + (list_seg->payload_len - overlap); - SCDebug("entered here pkt len %" PRIu32 ", seg %" PRIu32 ", list %" PRIu32 "", + SCLogDebug("entered here pkt len %" PRIu32 ", seg %" PRIu32 ", list %" PRIu32 "", packet_length, seg->payload_len, list_seg->payload_len); TcpSegment *new_seg = StreamTcpGetSegment(packet_length); @@ -451,7 +451,7 @@ static int HandleSegmentStartsBeforeListSegment(TcpStream *stream, TcpSegment *l } stream->seg_list = new_seg; - SCDebug("list_seg now %p, stream->seg_list now %p", list_seg, stream->seg_list); + SCLogDebug("list_seg now %p, stream->seg_list now %p", list_seg, stream->seg_list); } else if (end_before == TRUE || end_same == TRUE) { /* Handling overlapping with more than one segment and filling gap */ if (SEQ_LEQ(seg->seq, (list_seg->prev->seq + list_seg->prev->payload_len))) { @@ -473,7 +473,7 @@ static int HandleSegmentStartsBeforeListSegment(TcpStream *stream, TcpSegment *l StreamTcpSegmentDataCopy(new_seg, list_seg); uint16_t copy_len = (uint16_t) (list_seg->seq - (list_seg->prev->seq + list_seg->prev->payload_len)); - SCDebug("copy_len %" PRIu32 " (%" PRIu32 " - %" PRIu32 ")", copy_len, list_seg->seq, (list_seg->prev->seq + list_seg->prev->payload_len)); + SCLogDebug("copy_len %" PRIu32 " (%" PRIu32 " - %" PRIu32 ")", copy_len, list_seg->seq, (list_seg->prev->seq + list_seg->prev->payload_len)); StreamTcpSegmentDataReplace(new_seg, seg, (list_seg->prev->seq + list_seg->prev->payload_len), copy_len); StreamTcpSegmentReturntoPool(list_seg); @@ -537,12 +537,12 @@ static int HandleSegmentStartsBeforeListSegment(TcpStream *stream, TcpSegment *l StreamTcpSegmentDataReplace(list_seg, seg, overlap_point, overlap); end_after = FALSE; } else { - SCDebug("using old data in starts before list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "", list_seg->seq, os_policy, overlap); + SCLogDebug("using old data in starts before list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "", list_seg->seq, os_policy, overlap); } break; case OS_POLICY_VISTA: case OS_POLICY_FIRST: - SCDebug("using old data in starts before list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "", list_seg->seq, os_policy, overlap); + SCLogDebug("using old data in starts before list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "", list_seg->seq, os_policy, overlap); break; case OS_POLICY_BSD: case OS_POLICY_HPUX10: @@ -554,7 +554,7 @@ static int HandleSegmentStartsBeforeListSegment(TcpStream *stream, TcpSegment *l case OS_POLICY_MACOS: case OS_POLICY_LAST: default: - SCDebug("replacing old data in starts before list seg list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "", list_seg->seq, os_policy, overlap); + SCLogDebug("replacing old data in starts before list seg list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "", list_seg->seq, os_policy, overlap); StreamTcpSegmentDataReplace(list_seg, seg, overlap_point, overlap); break; } @@ -595,9 +595,7 @@ static int HandleSegmentStartsAtSameListSegment(TcpStream *stream, TcpSegment *l * overlap is the [ababab] part, which equals seg->payload_len. */ overlap = seg->payload_len; end_before = TRUE; -#ifdef DEBUG - printf("HandleSegmentStartsAtSameListSegment: starts at list seq, ends before list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " overlap is%" PRIu32 "\n", seg->seq, list_seg->seq, list_seg->payload_len, overlap); -#endif + SCLogDebug("starts at list seq, ends before list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " overlap is%" PRIu32 "", seg->seq, list_seg->seq, list_seg->payload_len, overlap); } else if (SEQ_EQ((seg->seq + seg->payload_len), (list_seg->seq + list_seg->payload_len))) { /* seg starts at seq, ends at seq, retransmission. @@ -607,9 +605,8 @@ static int HandleSegmentStartsAtSameListSegment(TcpStream *stream, TcpSegment *l /* check csum, ack, other differences? */ overlap = seg->payload_len; end_same = TRUE; -#ifdef DEBUG - printf("HandleSegmentStartsAtSameListSegment: (retransmission) starts at list seq, ends at list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " overlap is %"PRIu32"\n", seg->seq, list_seg->seq, list_seg->payload_len, overlap); -#endif + SCLogDebug("(retransmission) starts at list seq, ends at list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " overlap is %"PRIu32"", seg->seq, list_seg->seq, list_seg->payload_len, overlap); + } else if (SEQ_GT((seg->seq + seg->payload_len), (list_seg->seq + list_seg->payload_len))) { /* seg starts at seq, ends beyond seq. */ @@ -618,9 +615,7 @@ static int HandleSegmentStartsAtSameListSegment(TcpStream *stream, TcpSegment *l * overlap is the [ababab] part, which equals list_seg->payload_len. */ overlap = list_seg->payload_len; end_after = TRUE; -#ifdef DEBUG - printf("HandleSegmentStartsAtSameListSegment: starts at list seq, ends beyond list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " overlap is %" PRIu32 "\n", seg->seq, list_seg->seq, list_seg->payload_len, overlap); -#endif + SCLogDebug("starts at list seq, ends beyond list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " overlap is %" PRIu32 "", seg->seq, list_seg->seq, list_seg->payload_len, overlap); } if (overlap > 0) { /*Handle the case when newly arrived segment ends after original @@ -641,19 +636,15 @@ static int HandleSegmentStartsAtSameListSegment(TcpStream *stream, TcpSegment *l } } -#ifdef DEBUG - printf("HandleSegmentStartsAtSameListSegment: fill_gap %s, handle_beyond %s\n", fill_gap?"TRUE":"FALSE", handle_beyond?"TRUE":"FALSE"); -#endif + SCLogDebug("fill_gap %s, handle_beyond %s", fill_gap?"TRUE":"FALSE", handle_beyond?"TRUE":"FALSE"); if (fill_gap == TRUE) { /* if there is a gap after this list_seg we fill it now with a new seg */ -#ifdef DEBUG - printf("HandleSegmentStartsAtSameListSegment: filling gap: list_seg->next->seq %"PRIu32"\n", list_seg->next?list_seg->next->seq:0); -#endif + SCLogDebug("filling gap: list_seg->next->seq %"PRIu32"", list_seg->next?list_seg->next->seq:0); + packet_length = seg->payload_len - list_seg->payload_len; -#ifdef DEBUG - printf("HandleSegmentStartsAtSameListSegment: packet_length %"PRIu16"\n", packet_length); -#endif + SCLogDebug("packet_length %"PRIu16"", packet_length); + TcpSegment *new_seg = StreamTcpGetSegment(packet_length); if (new_seg == NULL) { return -1; @@ -665,10 +656,7 @@ static int HandleSegmentStartsAtSameListSegment(TcpStream *stream, TcpSegment *l new_seg->next->prev = new_seg; new_seg->prev = list_seg; list_seg->next = new_seg; -#ifdef DEBUG - printf("HandleSegmentStartsAtSameListSegment: new_seg %p, new_seg->next %p, new_seg->prev %p, list_seg->next %p\n", new_seg, new_seg->next, new_seg->prev, list_seg->next); -#endif - + SCLogDebug("new_seg %p, new_seg->next %p, new_seg->prev %p, list_seg->next %p", new_seg, new_seg->next, new_seg->prev, list_seg->next); StreamTcpSegmentDataReplace(new_seg, seg, new_seg->seq, new_seg->payload_len); } } @@ -680,9 +668,7 @@ static int HandleSegmentStartsAtSameListSegment(TcpStream *stream, TcpSegment *l StreamTcpSegmentDataReplace(list_seg, seg, seg->seq, overlap); end_after = FALSE; } else { -#ifdef DEBUG - printf("Using Old Data in starts at list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "\n", list_seg->seq, os_policy, overlap); -#endif + SCLogDebug("using old data in starts at list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "", list_seg->seq, os_policy, overlap); } break; case OS_POLICY_LAST: @@ -692,9 +678,7 @@ static int HandleSegmentStartsAtSameListSegment(TcpStream *stream, TcpSegment *l if (end_after == TRUE) { StreamTcpSegmentDataReplace(list_seg, seg, seg->seq, overlap); } else { -#ifdef DEBUG - printf("Using Old Data in starts at list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "\n", list_seg->seq, os_policy, overlap); -#endif + SCLogDebug("using old data in starts at list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "", list_seg->seq, os_policy, overlap); } break; case OS_POLICY_BSD: @@ -706,9 +690,7 @@ static int HandleSegmentStartsAtSameListSegment(TcpStream *stream, TcpSegment *l case OS_POLICY_MACOS: case OS_POLICY_FIRST: default: -#ifdef DEBUG - printf("Using Old Data in starts at list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "\n", list_seg->seq, os_policy, overlap); -#endif + SCLogDebug("using old data in starts at list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "", list_seg->seq, os_policy, overlap); break; } @@ -746,9 +728,12 @@ static int HandleSegmentStartsAfterListSegment(TcpStream *stream, TcpSegment *li * overlap is the part [ababab] which is seg->payload_len */ overlap = seg->payload_len; end_before = TRUE; -#ifdef DEBUG - printf("HandleSegmentStartsAfterListSegment: starts beyond list seq, ends before list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " overlap is %" PRIu32 "\n", seg->seq, list_seg->seq, list_seg->payload_len, overlap); -#endif + + SCLogDebug("starts beyond list seq, ends before list end: seg->seq" + " %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len " + "%" PRIu32 " overlap is %" PRIu32 "", seg->seq, list_seg->seq, + list_seg->payload_len, overlap); + } else if (SEQ_EQ((seg->seq + seg->payload_len), (list_seg->seq + list_seg->payload_len))) { /* seg starts after seq, before end, ends at seq @@ -756,9 +741,12 @@ static int HandleSegmentStartsAfterListSegment(TcpStream *stream, TcpSegment *li * overlapping part is [ababab], thus seg->payload_len */ overlap = seg->payload_len; end_same = TRUE; -#ifdef DEBUG - printf("HandleSegmentStartsAfterListSegment: starts beyond list seq, ends at list end: seg->seq %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " overlap is %" PRIu32 "\n", seg->seq, list_seg->seq, list_seg->payload_len, overlap); -#endif + + SCLogDebug("starts beyond list seq, ends at list end: seg->seq" + " %" PRIu32 ", list_seg->seq %" PRIu32 ", list_seg->payload_len " + "%" PRIu32 " overlap is %" PRIu32 "", seg->seq, list_seg->seq, + list_seg->payload_len, overlap); + } else if (SEQ_LT(seg->seq, list_seg->seq + list_seg->payload_len) && SEQ_GT((seg->seq + seg->payload_len), (list_seg->seq + list_seg->payload_len))) { /* seg starts after seq, before end, ends beyond seq. @@ -768,9 +756,13 @@ static int HandleSegmentStartsAfterListSegment(TcpStream *stream, TcpSegment *li * (list_seg->seq + list_seg->payload_len) - seg->seg */ overlap = (list_seg->seq + list_seg->payload_len) - seg->seq; end_after = TRUE; -#ifdef DEBUG - printf("HandleSegmentStartsAfterListSegment: starts beyond list seq, before list end, ends at list end: seg->seq %" PRIu32 ", seg->payload_len %"PRIu16" (%"PRIu32") list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " (%"PRIu32") overlap is %" PRIu32 "\n", seg->seq, seg->payload_len, seg->seq + seg->payload_len, list_seg->seq, list_seg->payload_len, list_seg->seq + list_seg->payload_len, overlap); -#endif + + SCLogDebug("starts beyond list seq, before list end, ends at list end: " + "seg->seq %" PRIu32 ", seg->payload_len %"PRIu16" (%"PRIu32") " + "list_seg->seq %" PRIu32 ", list_seg->payload_len %" PRIu32 " " + "(%"PRIu32") overlap is %" PRIu32 "", seg->seq, seg->payload_len, + seg->seq + seg->payload_len, list_seg->seq, list_seg->payload_len, + list_seg->seq + list_seg->payload_len, overlap); } if (overlap > 0) { /*Handle the case when newly arrived segment ends after original @@ -790,21 +782,18 @@ static int HandleSegmentStartsAfterListSegment(TcpStream *stream, TcpSegment *li } } -#ifdef DEBUG - printf("HandleSegmentStartsAfterListSegment: fill_gap %s, handle_beyond %s\n", fill_gap?"TRUE":"FALSE", handle_beyond?"TRUE":"FALSE"); -#endif + SCLogDebug("fill_gap %s, handle_beyond %s", fill_gap?"TRUE":"FALSE", handle_beyond?"TRUE":"FALSE"); if (fill_gap == TRUE) { /* if there is a gap after this list_seg we fill it now with a new seg */ -#ifdef DEBUG - printf("HandleSegmentStartsAfterListSegment: filling gap: list_seg->next->seq %"PRIu32"\n", list_seg->next?list_seg->next->seq:0); -#endif + SCLogDebug("filling gap: list_seg->next->seq %"PRIu32"", list_seg->next?list_seg->next->seq:0); + packet_length = list_seg->next->seq - (list_seg->seq + list_seg->payload_len); - if (packet_length > (seg->payload_len - overlap)) + if (packet_length > (seg->payload_len - overlap)) { packet_length = seg->payload_len - overlap; -#ifdef DEBUG - printf("HandleSegmentStartsAfterListSegment: packet_length %"PRIu16"\n", packet_length); -#endif + } + SCLogDebug("packet_length %"PRIu16"", packet_length); + TcpSegment *new_seg = StreamTcpGetSegment(packet_length); if (new_seg == NULL) { return -1; @@ -816,9 +805,8 @@ static int HandleSegmentStartsAfterListSegment(TcpStream *stream, TcpSegment *li new_seg->next->prev = new_seg; new_seg->prev = list_seg; list_seg->next = new_seg; -#ifdef DEBUG - printf("HandleSegmentStartsAfterListSegment: new_seg %p, new_seg->next %p, new_seg->prev %p, list_seg->next %p\n", new_seg, new_seg->next, new_seg->prev, list_seg->next); -#endif + + SCLogDebug("new_seg %p, new_seg->next %p, new_seg->prev %p, list_seg->next %p", new_seg, new_seg->next, new_seg->prev, list_seg->next); StreamTcpSegmentDataReplace(new_seg, seg, new_seg->seq, new_seg->payload_len); } @@ -830,9 +818,7 @@ static int HandleSegmentStartsAfterListSegment(TcpStream *stream, TcpSegment *li StreamTcpSegmentDataReplace(list_seg, seg, seg->seq, overlap); end_after = FALSE; } else { -#ifdef DEBUG - printf("Using Old Data in starts beyond list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "\n", list_seg->seq, os_policy, overlap); -#endif + SCLogDebug("using old data in starts beyond list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "", list_seg->seq, os_policy, overlap); } break; case OS_POLICY_LAST: @@ -849,9 +835,7 @@ static int HandleSegmentStartsAfterListSegment(TcpStream *stream, TcpSegment *li case OS_POLICY_MACOS: case OS_POLICY_FIRST: default: /* DEFAULT POLICY */ -#ifdef DEBUG - printf("Using Old Data in starts beyond list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "\n", list_seg->seq, os_policy, overlap); -#endif + SCLogDebug("using old data in starts beyond list case, list_seg->seq %" PRIu32 " policy %" PRIu32 " overlap %" PRIu32 "", list_seg->seq, os_policy, overlap); break; } if (end_before == TRUE || end_same == TRUE || handle_beyond == FALSE) { @@ -936,13 +920,13 @@ static int StreamTcpReassembleCheckLimit(TcpSession *ssn, TcpStream *stream, Pac if (stream->ra_base_seq == stream->isn) { if (StreamMsgQueueGetMinInitChunkLen(STREAM_TOSERVER) > (stream->last_ack - stream->ra_base_seq)) { - SCDebug("toserver min init chunk len not yet reached: last_ack %"PRIu32", ra_base_seq %"PRIu32", len %"PRIu32"", stream->last_ack, stream->ra_base_seq, StreamMsgQueueGetMinInitChunkLen(STREAM_TOSERVER)); + SCLogDebug("toserver min init chunk len not yet reached: last_ack %"PRIu32", ra_base_seq %"PRIu32", len %"PRIu32"", stream->last_ack, stream->ra_base_seq, StreamMsgQueueGetMinInitChunkLen(STREAM_TOSERVER)); return 0; } } else { if (StreamMsgQueueGetMinChunkLen(STREAM_TOSERVER) > (stream->last_ack - stream->ra_base_seq)) { - SCDebug("toserver min chunk len not yet reached"); + SCLogDebug("toserver min chunk len not yet reached"); return 0; } } @@ -950,13 +934,13 @@ static int StreamTcpReassembleCheckLimit(TcpSession *ssn, TcpStream *stream, Pac if (stream->ra_base_seq == stream->isn) { if (StreamMsgQueueGetMinInitChunkLen(STREAM_TOCLIENT) > (stream->last_ack - stream->ra_base_seq)) { - SCDebug("StreamTcpReassembleCheckLimit: toclient min init chunk len not yet reached"); + SCLogDebug("StreamTcpReassembleCheckLimit: toclient min init chunk len not yet reached"); return 0; } } else { if (StreamMsgQueueGetMinChunkLen(STREAM_TOCLIENT) > (stream->last_ack - stream->ra_base_seq)) { - SCDebug("toclient min chunk len not yet reached"); + SCLogDebug("toclient min chunk len not yet reached"); return 0; } } @@ -969,7 +953,7 @@ int StreamTcpReassembleHandleSegmentUpdateACK (TcpReassemblyThreadCtx *ra_ctx, T if (stream->seg_list == NULL) return 0; - SCDebug("start p %p", p); + SCLogDebug("start p %p", p); StreamMsg *smsg = NULL; uint16_t smsg_offset = 0; @@ -980,22 +964,22 @@ int StreamTcpReassembleHandleSegmentUpdateACK (TcpReassemblyThreadCtx *ra_ctx, T /* check if we have enough data to send to L7 */ if (StreamTcpReassembleCheckLimit(ssn,stream,p) == 0) { - SCDebug("not yet reassembling"); + SCLogDebug("not yet reassembling"); return 0; } /* loop through the segments and fill one or more msgs */ for (; seg != NULL && SEQ_LT(seg->seq, stream->last_ack);) { - SCDebug("seg %p", seg); + SCLogDebug("seg %p", seg); /* If packets are fully before ra_base_seq, skip them. We do this * because we've reassembled up to the ra_base_seq point already, * so we won't do anything with segments before it anyway. */ - SCDebug("checking for pre ra_base_seq %"PRIu32" seg %p seq %"PRIu32" len %"PRIu16", combined %"PRIu32"", stream->ra_base_seq, seg, seg->seq, seg->payload_len, seg->seq+seg->payload_len); + SCLogDebug("checking for pre ra_base_seq %"PRIu32" seg %p seq %"PRIu32" len %"PRIu16", combined %"PRIu32"", stream->ra_base_seq, seg, seg->seq, seg->payload_len, seg->seq+seg->payload_len); /** \todo we should probably not even insert them into the seglist */ if (SEQ_LEQ((seg->seq + seg->payload_len), (stream->ra_base_seq+1))) { - SCDebug("removing pre ra_base_seq %"PRIu32" seg %p seq %"PRIu32" len %"PRIu16"", stream->ra_base_seq, seg, seg->seq, seg->payload_len); + SCLogDebug("removing pre ra_base_seq %"PRIu32" seg %p seq %"PRIu32" len %"PRIu16"", stream->ra_base_seq, seg, seg->seq, seg->payload_len); TcpSegment *next_seg = seg->next; if (seg->prev == NULL) { @@ -1018,7 +1002,7 @@ int StreamTcpReassembleHandleSegmentUpdateACK (TcpReassemblyThreadCtx *ra_ctx, T /* see what the length of the gap is, gap length is seg->seq - (ra_base_seq +1) */ uint32_t gap_len = seg->seq - next_seq; - SCDebug("expected next_seq %" PRIu32 ", got %" PRIu32 " , stream->last_ack %" PRIu32 ". Seq gap %" PRIu32"", next_seq, seg->seq, stream->last_ack, gap_len); + SCLogDebug("expected next_seq %" PRIu32 ", got %" PRIu32 " , stream->last_ack %" PRIu32 ". Seq gap %" PRIu32"", next_seq, seg->seq, stream->last_ack, gap_len); next_seq = seg->seq; @@ -1052,7 +1036,7 @@ int StreamTcpReassembleHandleSegmentUpdateACK (TcpReassemblyThreadCtx *ra_ctx, T /* if the segment ends beyond ra_base_seq we need to consider it */ if (SEQ_GT((seg->seq + seg->payload_len), stream->ra_base_seq)) { - SCDebug("seg->seq %" PRIu32 ", seg->payload_len %" PRIu32 ", stream->ra_base_seq %" PRIu32 "", + SCLogDebug("seg->seq %" PRIu32 ", seg->payload_len %" PRIu32 ", stream->ra_base_seq %" PRIu32 "", seg->seq, seg->payload_len, stream->ra_base_seq); if (smsg == NULL) { smsg = StreamMsgGetFromPool(); @@ -1095,7 +1079,7 @@ int StreamTcpReassembleHandleSegmentUpdateACK (TcpReassemblyThreadCtx *ra_ctx, T memcpy(smsg->data.data + smsg_offset, seg->payload + payload_offset, copy_size); smsg_offset += copy_size; stream->ra_base_seq += copy_size; - SCDebug("stream->ra_base_seq %"PRIu32"", stream->ra_base_seq); + SCLogDebug("stream->ra_base_seq %"PRIu32"", stream->ra_base_seq); smsg->data.data_len += copy_size; /* queue the smsg if it's full */ @@ -1107,7 +1091,7 @@ int StreamTcpReassembleHandleSegmentUpdateACK (TcpReassemblyThreadCtx *ra_ctx, T /* if the payload len is bigger than what we copied, we handle the rest of the payload next... */ if (copy_size < payload_len) { - SCDebug("copy_size %" PRIu32 " < %" PRIu32 "", copy_size, payload_len); + SCLogDebug("copy_size %" PRIu32 " < %" PRIu32 "", copy_size, payload_len); payload_offset += copy_size; payload_len -= copy_size; @@ -1116,7 +1100,7 @@ int StreamTcpReassembleHandleSegmentUpdateACK (TcpReassemblyThreadCtx *ra_ctx, T /* we need a while loop here as the packets theoretically can be 64k */ char segment_done = FALSE; while (segment_done == FALSE) { - SCDebug("new msg at offset %" PRIu32 ", payload_len %" PRIu32 "", payload_offset, payload_len); + SCLogDebug("new msg at offset %" PRIu32 ", payload_len %" PRIu32 "", payload_offset, payload_len); /* get a new message XXX we need a setup function */ @@ -1136,14 +1120,14 @@ int StreamTcpReassembleHandleSegmentUpdateACK (TcpReassemblyThreadCtx *ra_ctx, T } BUG_ON(copy_size > sizeof(smsg->data.data)); - SCDebug("copy payload_offset %" PRIu32 ", smsg_offset %" PRIu32 ", copy_size %" PRIu32 "", + SCLogDebug("copy payload_offset %" PRIu32 ", smsg_offset %" PRIu32 ", copy_size %" PRIu32 "", payload_offset, smsg_offset, copy_size); memcpy(smsg->data.data + smsg_offset, seg->payload + payload_offset, copy_size); smsg_offset += copy_size; stream->ra_base_seq += copy_size; - SCDebug("stream->ra_base_seq %"PRIu32"", stream->ra_base_seq); + SCLogDebug("stream->ra_base_seq %"PRIu32"", stream->ra_base_seq); smsg->data.data_len += copy_size; - SCDebug("copied payload_offset %" PRIu32 ", smsg_offset %" PRIu32 ", copy_size %" PRIu32 "", + SCLogDebug("copied payload_offset %" PRIu32 ", smsg_offset %" PRIu32 ", copy_size %" PRIu32 "", payload_offset, smsg_offset, copy_size); if (smsg->data.data_len == sizeof (smsg->data.data)) { StreamMsgPutInQueue(ra_ctx->stream_q,smsg); @@ -1169,7 +1153,7 @@ int StreamTcpReassembleHandleSegmentUpdateACK (TcpReassemblyThreadCtx *ra_ctx, T /* done with this segment, return it to the pool */ TcpSegment *next_seg = seg->next; next_seq = seg->seq + seg->payload_len; - SCDebug("removing seg %p, seg->next %p", seg, seg->next); + SCLogDebug("removing seg %p, seg->next %p", seg, seg->next); BUG_ON(seg->prev != NULL); /**< BUG if we aren't the top of the list */ stream->seg_list = seg->next; @@ -1215,13 +1199,13 @@ int StreamTcpReassembleHandleSegment(TcpReassemblyThreadCtx *ra_ctx, TcpSession /* handle ack received */ if (StreamTcpReassembleHandleSegmentUpdateACK(ra_ctx, ssn, stream, p) != 0) { - SCDebug("StreamTcpReassembleHandleSegmentUpdateACK error"); + SCLogDebug("StreamTcpReassembleHandleSegmentUpdateACK error"); return -1; } if (p->payload_len > 0) { if (StreamTcpReassembleHandleSegmentHandleData(ssn, stream, p) != 0) { - SCDebug("StreamTcpReassembleHandleSegmentHandleData error"); + SCLogDebug("StreamTcpReassembleHandleSegmentHandleData error"); return -1; } } @@ -1323,17 +1307,17 @@ void StreamTcpSegmentDataCopy(TcpSegment *dst_seg, TcpSegment *src_seg) { TcpSegment* StreamTcpGetSegment(uint16_t len) { uint16_t idx = segment_pool_idx[len]; - SCDebug("%" PRIu32 " for payload_len %" PRIu32 "", idx, len); + SCLogDebug("%" PRIu32 " for payload_len %" PRIu32 "", idx, len); mutex_lock(&segment_pool_mutex[idx]); TcpSegment *seg = (TcpSegment *) PoolGet(segment_pool[idx]); - SCDebug("segment_pool[%u]->empty_list_size %u, segment_pool[%u]->alloc_list_size %u, alloc %u", + SCLogDebug("segment_pool[%u]->empty_list_size %u, segment_pool[%u]->alloc_list_size %u, alloc %u", idx, segment_pool[idx]->empty_list_size, idx, segment_pool[idx]->alloc_list_size, segment_pool[idx]->allocated); //PoolPrintSaturation(segment_pool[idx]); mutex_unlock(&segment_pool_mutex[idx]); - SCDebug("StreamTcpGetSegment: seg we return is %p", seg); + SCLogDebug("StreamTcpGetSegment: seg we return is %p", seg); if (seg == NULL) { - SCDebug("segment_pool[%u]->empty_list_size %u, alloc %u", idx, segment_pool[idx]->empty_list_size, segment_pool[idx]->allocated); + SCLogDebug("segment_pool[%u]->empty_list_size %u, alloc %u", idx, segment_pool[idx]->empty_list_size, segment_pool[idx]->allocated); } else { #ifdef DEBUG mutex_lock(&segment_pool_cnt_mutex); @@ -1357,7 +1341,7 @@ void StreamTcpSegmentReturntoPool(TcpSegment *seg) { uint16_t idx = segment_pool_idx[seg->pool_size]; mutex_lock(&segment_pool_mutex[idx]); PoolReturn(segment_pool[idx], (void *) seg); - SCDebug("segment_pool[%"PRIu16"]->empty_list_size %"PRIu32"", idx,segment_pool[idx]->empty_list_size); + SCLogDebug("segment_pool[%"PRIu16"]->empty_list_size %"PRIu32"", idx,segment_pool[idx]->empty_list_size); mutex_unlock(&segment_pool_mutex[idx]); #ifdef DEBUG diff --git a/src/stream-tcp.c b/src/stream-tcp.c index 80a9045c10..3aa1c2f3ef 100644 --- a/src/stream-tcp.c +++ b/src/stream-tcp.c @@ -289,7 +289,7 @@ static int StreamTcpPacketStateNone(ThreadVars *tv, Packet *p, StreamTcpThread * /* set the state */ StreamTcpPacketSetState(p, ssn, TCP_SYN_SENT); - SCDebug("ssn %p: =~ ssn state is now TCP_SYN_SENT", ssn); + SCLogDebug("ssn %p: =~ ssn state is now TCP_SYN_SENT", ssn); /* set the sequence numbers and window */ ssn->client.isn = TCP_GET_SEQ(p); @@ -299,7 +299,7 @@ static int StreamTcpPacketStateNone(ThreadVars *tv, Packet *p, StreamTcpThread * /*Set the stream timestamp value, if packet has timestamp option enabled.*/ if (p->tcpvars.ts != NULL) { ssn->client.last_ts = TCP_GET_TSVAL(p); - SCDebug("ssn %p: p->tcpvars.ts %p, %02x", ssn, p->tcpvars.ts, ssn->client.last_ts); + SCLogDebug("ssn %p: p->tcpvars.ts %p, %02x", ssn, p->tcpvars.ts, ssn->client.last_ts); if (ssn->client.last_ts == 0) ssn->client.flags |= STREAMTCP_FLAG_ZERO_TIMESTAMP; @@ -314,7 +314,7 @@ static int StreamTcpPacketStateNone(ThreadVars *tv, Packet *p, StreamTcpThread * ssn->server.wscale = TCP_GET_WSCALE(p); } - SCDebug("ssn %p: ssn->client.isn %" PRIu32 ", ssn->client.next_seq %" PRIu32 ", ssn->client.last_ack %"PRIu32"", + SCLogDebug("ssn %p: ssn->client.isn %" PRIu32 ", ssn->client.next_seq %" PRIu32 ", ssn->client.last_ack %"PRIu32"", ssn, ssn->client.isn, ssn->client.next_seq, ssn->client.last_ack); break; } @@ -330,7 +330,7 @@ static int StreamTcpPacketStateNone(ThreadVars *tv, Packet *p, StreamTcpThread * } /* set the state */ StreamTcpPacketSetState(p, ssn, TCP_SYN_RECV); - SCDebug("ssn %p: =~ midstream picked ssn state is now TCP_SYN_RECV", ssn); + SCLogDebug("ssn %p: =~ midstream picked ssn state is now TCP_SYN_RECV", ssn); ssn->flags = STREAMTCP_FLAG_MIDSTREAM; /* sequence number & window */ @@ -338,7 +338,7 @@ static int StreamTcpPacketStateNone(ThreadVars *tv, Packet *p, StreamTcpThread * ssn->server.ra_base_seq = ssn->server.isn; ssn->server.next_seq = ssn->server.isn + 1; ssn->server.window = TCP_GET_WINDOW(p); - SCDebug("ssn %p: server window %u", ssn, ssn->server.window); + SCLogDebug("ssn %p: server window %u", ssn, ssn->server.window); ssn->client.isn = TCP_GET_ACK(p) - 1; ssn->client.ra_base_seq = ssn->client.isn; @@ -353,16 +353,16 @@ static int StreamTcpPacketStateNone(ThreadVars *tv, Packet *p, StreamTcpThread * ssn->server.wscale = TCP_WSCALE_MAX; } - SCDebug("ssn %p: ssn->client.isn %"PRIu32", ssn->client.next_seq %"PRIu32", ssn->client.last_ack %"PRIu32"", + SCLogDebug("ssn %p: ssn->client.isn %"PRIu32", ssn->client.next_seq %"PRIu32", ssn->client.last_ack %"PRIu32"", ssn, ssn->client.isn, ssn->client.next_seq, ssn->client.last_ack); - SCDebug("ssn %p: ssn->server.isn %"PRIu32", ssn->server.next_seq %"PRIu32", ssn->server.last_ack %"PRIu32"", + SCLogDebug("ssn %p: ssn->server.isn %"PRIu32", ssn->server.next_seq %"PRIu32", ssn->server.last_ack %"PRIu32"", ssn, ssn->server.isn, ssn->server.next_seq, ssn->server.last_ack); /*Set the timestamp value for both streams, if packet has timestamp option enabled.*/ if (p->tcpvars.ts != NULL) { ssn->client.last_ts = TCP_GET_TSVAL(p); ssn->server.last_ts = TCP_GET_TSECR(p); - SCDebug("ssn %p: ssn->server.last_ts %" PRIu32" ssn->client.last_ts %" PRIu32"", ssn, ssn->server.last_ts, ssn->client.last_ts); + SCLogDebug("ssn %p: ssn->server.last_ts %" PRIu32" ssn->client.last_ts %" PRIu32"", ssn, ssn->server.last_ts, ssn->client.last_ts); ssn->flags |= STREAMTCP_FLAG_TIMESTAMP; @@ -391,7 +391,7 @@ static int StreamTcpPacketStateNone(ThreadVars *tv, Packet *p, StreamTcpThread * } /* set the state */ StreamTcpPacketSetState(p, ssn, TCP_ESTABLISHED); - SCDebug("ssn %p: =~ midstream picked ssn state is now TCP_ESTABLISHED", ssn); + SCLogDebug("ssn %p: =~ midstream picked ssn state is now TCP_ESTABLISHED", ssn); ssn->flags = STREAMTCP_FLAG_MIDSTREAM; ssn->flags |= STREAMTCP_FLAG_MIDSTREAM_ESTABLISHED; @@ -403,7 +403,7 @@ static int StreamTcpPacketStateNone(ThreadVars *tv, Packet *p, StreamTcpThread * ssn->client.window = TCP_GET_WINDOW(p); ssn->client.last_ack = TCP_GET_SEQ(p); ssn->client.next_win = ssn->client.last_ack + ssn->client.window; - SCDebug("ssn %p: ssn->client.isn %u, ssn->client.next_seq %u", + SCLogDebug("ssn %p: ssn->client.isn %u, ssn->client.next_seq %u", ssn, ssn->client.isn, ssn->client.next_seq); ssn->server.isn = TCP_GET_ACK(p) - 1; @@ -412,9 +412,9 @@ static int StreamTcpPacketStateNone(ThreadVars *tv, Packet *p, StreamTcpThread * ssn->server.last_ack = TCP_GET_ACK(p); ssn->server.next_win = ssn->server.last_ack; - SCDebug("ssn %p: ssn->client.next_win %"PRIu32", ssn->server.next_win %"PRIu32"", + SCLogDebug("ssn %p: ssn->client.next_win %"PRIu32", ssn->server.next_win %"PRIu32"", ssn, ssn->client.next_win, ssn->server.next_win); - SCDebug("ssn %p: ssn->client.last_ack %"PRIu32", ssn->server.last_ack %"PRIu32"", + SCLogDebug("ssn %p: ssn->client.last_ack %"PRIu32", ssn->server.last_ack %"PRIu32"", ssn, ssn->client.last_ack, ssn->server.last_ack); /** window scaling for midstream pickups, we can't do much other @@ -426,7 +426,7 @@ static int StreamTcpPacketStateNone(ThreadVars *tv, Packet *p, StreamTcpThread * if (p->tcpvars.ts != NULL) { ssn->client.last_ts = TCP_GET_TSVAL(p); ssn->server.last_ts = TCP_GET_TSECR(p); - SCDebug("ssn %p: ssn->server.last_ts %" PRIu32" ssn->client.last_ts %" PRIu32"", ssn, ssn->server.last_ts, ssn->client.last_ts); + SCLogDebug("ssn %p: ssn->server.last_ts %" PRIu32" ssn->client.last_ts %" PRIu32"", ssn, ssn->server.last_ts, ssn->client.last_ts); ssn->flags |= STREAMTCP_FLAG_TIMESTAMP; @@ -450,10 +450,10 @@ static int StreamTcpPacketStateNone(ThreadVars *tv, Packet *p, StreamTcpThread * case TH_FIN|TH_ACK: case TH_FIN|TH_ACK|TH_PUSH: BUG_ON(p->flow->protoctx != NULL); - SCDebug("FIN or RST packet received, no session setup"); + SCLogDebug("FIN or RST packet received, no session setup"); break; default: - SCDebug("default case"); + SCLogDebug("default case"); break; } return 0; @@ -475,25 +475,25 @@ static int StreamTcpPacketStateSynSent(ThreadVars *tv, Packet *p, StreamTcpThrea switch (p->tcph->th_flags) { case TH_SYN: - SCDebug("ssn %p: SYN packet on state SYN_SENT... resent", ssn); + SCLogDebug("ssn %p: SYN packet on state SYN_SENT... resent", ssn); break; case TH_SYN|TH_ACK: if (PKT_IS_TOSERVER(p)) { - SCDebug("ssn %p: SYN/ACK received in the wrong direction", ssn); + SCLogDebug("ssn %p: SYN/ACK received in the wrong direction", ssn); return -1; } /* Check if the SYN/ACK packet ack's the earlier * received SYN packet. */ if (!(SEQ_EQ(TCP_GET_ACK(p), ssn->client.isn + 1))) { - SCDebug("ssn %p: ACK mismatch, packet ACK %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: ACK mismatch, packet ACK %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_ACK(p), ssn->client.isn + 1); return -1; } /* update state */ StreamTcpPacketSetState(p, ssn, TCP_SYN_RECV); - SCDebug("ssn %p: =~ ssn state is now TCP_SYN_RECV", ssn); + SCLogDebug("ssn %p: =~ ssn state is now TCP_SYN_RECV", ssn); /* sequence number & window */ ssn->server.isn = TCP_GET_SEQ(p); @@ -501,11 +501,11 @@ static int StreamTcpPacketStateSynSent(ThreadVars *tv, Packet *p, StreamTcpThrea ssn->server.next_seq = ssn->server.isn + 1; ssn->client.window = TCP_GET_WINDOW(p); - SCDebug("ssn %p: window %" PRIu32 "", ssn, ssn->server.window); + SCLogDebug("ssn %p: window %" PRIu32 "", ssn, ssn->server.window); if ((p->tcpvars.ts != NULL) && (ssn->client.flags & STREAMTCP_FLAG_TIMESTAMP)) { ssn->server.last_ts = TCP_GET_TSVAL(p); - SCDebug("ssn %p: ssn->server.last_ts %" PRIu32" ssn->client.last_ts %" PRIu32"", ssn, ssn->server.last_ts, ssn->client.last_ts); + SCLogDebug("ssn %p: ssn->server.last_ts %" PRIu32" ssn->client.last_ts %" PRIu32"", ssn, ssn->server.last_ts, ssn->client.last_ts); ssn->client.flags &= ~STREAMTCP_FLAG_TIMESTAMP; ssn->flags |= STREAMTCP_FLAG_TIMESTAMP; ssn->server.last_pkt_ts = p->ts.tv_sec; @@ -531,9 +531,9 @@ static int StreamTcpPacketStateSynSent(ThreadVars *tv, Packet *p, StreamTcpThrea ssn->server.next_win = ssn->server.last_ack + ssn->server.window; ssn->client.next_win = ssn->client.last_ack + ssn->client.window; - SCDebug("ssn %p: ssn->server.next_win %" PRIu32 "", ssn, ssn->server.next_win); - SCDebug("ssn %p: ssn->client.next_win %" PRIu32 "", ssn, ssn->client.next_win); - SCDebug("ssn %p: ssn->server.isn %" PRIu32 ", ssn->server.next_seq %" PRIu32 ", ssn->server.last_ack %" PRIu32 " (ssn->client.last_ack %" PRIu32 ")", + SCLogDebug("ssn %p: ssn->server.next_win %" PRIu32 "", ssn, ssn->server.next_win); + SCLogDebug("ssn %p: ssn->client.next_win %" PRIu32 "", ssn, ssn->client.next_win); + SCLogDebug("ssn %p: ssn->server.isn %" PRIu32 ", ssn->server.next_seq %" PRIu32 ", ssn->server.last_ack %" PRIu32 " (ssn->client.last_ack %" PRIu32 ")", ssn, ssn->server.isn, ssn->server.next_seq, ssn->server.last_ack, ssn->client.last_ack); break; case TH_RST: @@ -546,7 +546,7 @@ static int StreamTcpPacketStateSynSent(ThreadVars *tv, Packet *p, StreamTcpThrea return -1; break; default: - SCDebug("ssn %p: default case", ssn); + SCLogDebug("ssn %p: default case", ssn); break; } @@ -569,10 +569,10 @@ static int StreamTcpPacketStateSynRecv(ThreadVars *tv, Packet *p, StreamTcpThrea switch (p->tcph->th_flags) { case TH_SYN: - SCDebug("ssn %p: SYN packet on state SYN_RECV... resent", ssn); + SCLogDebug("ssn %p: SYN packet on state SYN_RECV... resent", ssn); break; case TH_SYN|TH_ACK: - SCDebug("ssn %p: SYN/ACK packet on state SYN_RECV... resent", ssn); + SCLogDebug("ssn %p: SYN/ACK packet on state SYN_RECV... resent", ssn); break; case TH_ACK: /* If the timestamp option is enabled for both the streams, then validate the received packet @@ -584,12 +584,12 @@ static int StreamTcpPacketStateSynRecv(ThreadVars *tv, Packet *p, StreamTcpThrea } if (PKT_IS_TOCLIENT(p)) { - SCDebug("ssn %p: ACK received in the wrong direction", ssn); + SCLogDebug("ssn %p: ACK received in the wrong direction", ssn); return -1; } if (!(SEQ_EQ(TCP_GET_SEQ(p), ssn->client.next_seq))) { - SCDebug("ssn %p: wrong seq nr on packet", ssn); + SCLogDebug("ssn %p: wrong seq nr on packet", ssn); return -1; } ssn->server.last_ack = TCP_GET_ACK(p); @@ -602,17 +602,17 @@ static int StreamTcpPacketStateSynRecv(ThreadVars *tv, Packet *p, StreamTcpThrea ssn->server.wscale = TCP_WSCALE_MAX; ssn->client.wscale = TCP_WSCALE_MAX; } - SCDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); StreamTcpPacketSetState(p, ssn, TCP_ESTABLISHED); - SCDebug("ssn %p: =~ ssn state is now TCP_ESTABLISHED", ssn); + SCLogDebug("ssn %p: =~ ssn state is now TCP_ESTABLISHED", ssn); ssn->client.next_seq += p->payload_len; ssn->server.window = TCP_GET_WINDOW(p) << ssn->server.wscale; ssn->server.next_win = ssn->server.last_ack + ssn->server.window; - SCDebug("ssn %p: ssn->server.next_win %" PRIu32 ", ssn->server.last_ack %"PRIu32"", ssn, ssn->server.next_win, ssn->server.last_ack); + SCLogDebug("ssn %p: ssn->server.next_win %" PRIu32 ", ssn->server.last_ack %"PRIu32"", ssn, ssn->server.next_win, ssn->server.last_ack); break; case TH_RST: case TH_RST|TH_ACK: @@ -632,7 +632,7 @@ static int StreamTcpPacketStateSynRecv(ThreadVars *tv, Packet *p, StreamTcpThrea return -1; break; default: - SCDebug("ssn %p: default case", ssn); + SCLogDebug("ssn %p: default case", ssn); break; } @@ -656,10 +656,10 @@ static int StreamTcpPacketStateEstablished(ThreadVars *tv, Packet *p, StreamTcpT switch (p->tcph->th_flags) { case TH_SYN: - SCDebug("ssn %p: SYN packet on state ESTABLISED... resent", ssn); + SCLogDebug("ssn %p: SYN packet on state ESTABLISED... resent", ssn); break; case TH_SYN|TH_ACK: - SCDebug("ssn %p: SYN/ACK packet on state ESTABLISHED... resent", ssn); + SCLogDebug("ssn %p: SYN/ACK packet on state ESTABLISHED... resent", ssn); break; case TH_ACK: case TH_ACK|TH_PUSH: @@ -672,42 +672,42 @@ static int StreamTcpPacketStateEstablished(ThreadVars *tv, Packet *p, StreamTcpT } if (PKT_IS_TOSERVER(p)) { - SCDebug("ssn %p: =+ pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 ", WIN %"PRIu16"", + SCLogDebug("ssn %p: =+ pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 ", WIN %"PRIu16"", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p), TCP_GET_WINDOW(p)); if (SEQ_EQ(ssn->client.next_seq, TCP_GET_SEQ(p))) { ssn->client.next_seq += p->payload_len; - SCDebug("ssn %p: ssn->client.next_seq %" PRIu32 "", ssn, ssn->client.next_seq); + SCLogDebug("ssn %p: ssn->client.next_seq %" PRIu32 "", ssn, ssn->client.next_seq); } if (SEQ_GEQ(TCP_GET_SEQ(p), ssn->client.last_ack)) { if (SEQ_LEQ(TCP_GET_SEQ(p) + p->payload_len, ssn->client.next_win) || ssn->flags & STREAMTCP_FLAG_MIDSTREAM) { - SCDebug("ssn %p: seq %"PRIu32" in window, ssn->client.next_win %" PRIu32 "", ssn, TCP_GET_SEQ(p), ssn->client.next_win); + SCLogDebug("ssn %p: seq %"PRIu32" in window, ssn->client.next_win %" PRIu32 "", ssn, TCP_GET_SEQ(p), ssn->client.next_win); ssn->server.window = TCP_GET_WINDOW(p) << ssn->server.wscale; - SCDebug("ssn %p: ssn->server.window %"PRIu32"", ssn, ssn->server.window); + SCLogDebug("ssn %p: ssn->server.window %"PRIu32"", ssn, ssn->server.window); if (SEQ_GT(TCP_GET_ACK(p),ssn->server.last_ack)) ssn->server.last_ack = TCP_GET_ACK(p); if (SEQ_GT((ssn->server.last_ack + ssn->server.window), ssn->server.next_win)) { ssn->server.next_win = ssn->server.last_ack + ssn->server.window; - SCDebug("ssn %p: seq %"PRIu32", updated ssn->server.next_win %" PRIu32 " (win %"PRIu32")", ssn, TCP_GET_SEQ(p), ssn->server.next_win, ssn->server.window); + SCLogDebug("ssn %p: seq %"PRIu32", updated ssn->server.next_win %" PRIu32 " (win %"PRIu32")", ssn, TCP_GET_SEQ(p), ssn->server.next_win, ssn->server.window); } StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->client, p); } else { - SCDebug("ssn %p: server => SEQ out of window, packet SEQ %" PRIu32 ", payload size %" PRIu32 " (%" PRIu32 "), ssn->client.last_ack %" PRIu32 ", ssn->client.next_win %" PRIu32 "(%"PRIu32") (ssn->client.ra_base_seq %"PRIu32")", ssn, TCP_GET_SEQ(p), p->payload_len, TCP_GET_SEQ(p) + p->payload_len, ssn->client.last_ack, ssn->client.next_win, TCP_GET_SEQ(p) + p->payload_len - ssn->client.next_win, ssn->client.ra_base_seq); + SCLogDebug("ssn %p: server => SEQ out of window, packet SEQ %" PRIu32 ", payload size %" PRIu32 " (%" PRIu32 "), ssn->client.last_ack %" PRIu32 ", ssn->client.next_win %" PRIu32 "(%"PRIu32") (ssn->client.ra_base_seq %"PRIu32")", ssn, TCP_GET_SEQ(p), p->payload_len, TCP_GET_SEQ(p) + p->payload_len, ssn->client.last_ack, ssn->client.next_win, TCP_GET_SEQ(p) + p->payload_len - ssn->client.next_win, ssn->client.ra_base_seq); } } else { - SCDebug("ssn %p: server => SEQ before last_ack, packet SEQ %" PRIu32 ", payload size %" PRIu32 " (%" PRIu32 "), ssn->client.last_ack %" PRIu32 ", ssn->client.next_win %" PRIu32 "(%"PRIu32") (ssn->client.ra_base_seq %"PRIu32")", ssn, TCP_GET_SEQ(p), p->payload_len, TCP_GET_SEQ(p) + p->payload_len, ssn->client.last_ack, ssn->client.next_win, TCP_GET_SEQ(p) + p->payload_len - ssn->client.next_win, ssn->client.ra_base_seq); + SCLogDebug("ssn %p: server => SEQ before last_ack, packet SEQ %" PRIu32 ", payload size %" PRIu32 " (%" PRIu32 "), ssn->client.last_ack %" PRIu32 ", ssn->client.next_win %" PRIu32 "(%"PRIu32") (ssn->client.ra_base_seq %"PRIu32")", ssn, TCP_GET_SEQ(p), p->payload_len, TCP_GET_SEQ(p) + p->payload_len, ssn->client.last_ack, ssn->client.next_win, TCP_GET_SEQ(p) + p->payload_len - ssn->client.next_win, ssn->client.ra_base_seq); } - SCDebug("ssn %p: next SEQ %" PRIu32 ", last ACK %" PRIu32 ", next win %" PRIu32 ", win %" PRIu32 "", + SCLogDebug("ssn %p: next SEQ %" PRIu32 ", last ACK %" PRIu32 ", next win %" PRIu32 ", win %" PRIu32 "", ssn, ssn->client.next_seq, ssn->server.last_ack, ssn->client.next_win, ssn->client.window); } else { /* implied to client */ - SCDebug("ssn %p: =+ pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 ", WIN %"PRIu16"", + SCLogDebug("ssn %p: =+ pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 ", WIN %"PRIu16"", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p), TCP_GET_WINDOW(p)); /* To get the server window value from the servers packet, when connection @@ -716,39 +716,39 @@ static int StreamTcpPacketStateEstablished(ThreadVars *tv, Packet *p, StreamTcpT ssn->server.window = TCP_GET_WINDOW(p); ssn->server.next_win = ssn->server.last_ack + ssn->server.window; ssn->flags &= ~STREAMTCP_FLAG_MIDSTREAM_ESTABLISHED; - SCDebug("ssn %p: adjusted midstream ssn->server.next_win to %" PRIu32 "", ssn, ssn->server.next_win); + SCLogDebug("ssn %p: adjusted midstream ssn->server.next_win to %" PRIu32 "", ssn, ssn->server.next_win); } if (SEQ_EQ(ssn->server.next_seq, TCP_GET_SEQ(p))) { ssn->server.next_seq += p->payload_len; - SCDebug("ssn %p: ssn->server.next_seq %" PRIu32 "", ssn, ssn->server.next_seq); + SCLogDebug("ssn %p: ssn->server.next_seq %" PRIu32 "", ssn, ssn->server.next_seq); } if (SEQ_GEQ(TCP_GET_SEQ(p), ssn->server.last_ack)) { if (SEQ_LEQ(TCP_GET_SEQ(p) + p->payload_len, ssn->server.next_win) || ssn->flags & STREAMTCP_FLAG_MIDSTREAM) { - SCDebug("ssn %p: seq %"PRIu32" in window, ssn->server.next_win %" PRIu32 "", ssn, TCP_GET_SEQ(p), ssn->server.next_win); + SCLogDebug("ssn %p: seq %"PRIu32" in window, ssn->server.next_win %" PRIu32 "", ssn, TCP_GET_SEQ(p), ssn->server.next_win); ssn->client.window = TCP_GET_WINDOW(p) << ssn->client.wscale; - SCDebug("ssn %p: ssn->client.window %"PRIu32"", ssn, ssn->client.window); + SCLogDebug("ssn %p: ssn->client.window %"PRIu32"", ssn, ssn->client.window); if (SEQ_GT(TCP_GET_ACK(p),ssn->client.last_ack)) ssn->client.last_ack = TCP_GET_ACK(p); if (SEQ_GT((ssn->client.last_ack + ssn->client.window), ssn->client.next_win)) { ssn->client.next_win = ssn->client.last_ack + ssn->client.window; - SCDebug("ssn %p: seq %"PRIu32", updated ssn->client.next_win %" PRIu32 " (win %"PRIu32")", ssn, TCP_GET_SEQ(p), ssn->client.next_win, ssn->client.window); + SCLogDebug("ssn %p: seq %"PRIu32", updated ssn->client.next_win %" PRIu32 " (win %"PRIu32")", ssn, TCP_GET_SEQ(p), ssn->client.next_win, ssn->client.window); } else { - SCDebug("ssn %p: seq %"PRIu32", keeping ssn->client.next_win %" PRIu32 " the same (win %"PRIu32")", ssn, TCP_GET_SEQ(p), ssn->client.next_win, ssn->client.window); + SCLogDebug("ssn %p: seq %"PRIu32", keeping ssn->client.next_win %" PRIu32 " the same (win %"PRIu32")", ssn, TCP_GET_SEQ(p), ssn->client.next_win, ssn->client.window); } StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->server, p); } else { - SCDebug("ssn %p: client => SEQ out of window, packet SEQ %" PRIu32 ", payload size %" PRIu32 " (%" PRIu32 "), ssn->server.last_ack %" PRIu32 ", ssn->server.next_win %" PRIu32 "(%"PRIu32") (ssn->server.ra_base_seq %"PRIu32")", ssn, TCP_GET_SEQ(p), p->payload_len, TCP_GET_SEQ(p) + p->payload_len, ssn->server.last_ack, ssn->server.next_win, TCP_GET_SEQ(p) + p->payload_len - ssn->server.next_win, ssn->server.ra_base_seq); + SCLogDebug("ssn %p: client => SEQ out of window, packet SEQ %" PRIu32 ", payload size %" PRIu32 " (%" PRIu32 "), ssn->server.last_ack %" PRIu32 ", ssn->server.next_win %" PRIu32 "(%"PRIu32") (ssn->server.ra_base_seq %"PRIu32")", ssn, TCP_GET_SEQ(p), p->payload_len, TCP_GET_SEQ(p) + p->payload_len, ssn->server.last_ack, ssn->server.next_win, TCP_GET_SEQ(p) + p->payload_len - ssn->server.next_win, ssn->server.ra_base_seq); } } else { - SCDebug("ssn %p: client => SEQ before last ack, packet SEQ %" PRIu32 ", payload size %" PRIu32 " (%" PRIu32 "), ssn->server.last_ack %" PRIu32 ", ssn->server.next_win %" PRIu32 "(%"PRIu32") (ssn->server.ra_base_seq %"PRIu32")", ssn, TCP_GET_SEQ(p), p->payload_len, TCP_GET_SEQ(p) + p->payload_len, ssn->server.last_ack, ssn->server.next_win, TCP_GET_SEQ(p) + p->payload_len - ssn->server.next_win, ssn->server.ra_base_seq); + SCLogDebug("ssn %p: client => SEQ before last ack, packet SEQ %" PRIu32 ", payload size %" PRIu32 " (%" PRIu32 "), ssn->server.last_ack %" PRIu32 ", ssn->server.next_win %" PRIu32 "(%"PRIu32") (ssn->server.ra_base_seq %"PRIu32")", ssn, TCP_GET_SEQ(p), p->payload_len, TCP_GET_SEQ(p) + p->payload_len, ssn->server.last_ack, ssn->server.next_win, TCP_GET_SEQ(p) + p->payload_len - ssn->server.next_win, ssn->server.ra_base_seq); } - SCDebug("ssn %p: next SEQ %" PRIu32 ", last ACK %" PRIu32 ", next win %" PRIu32 ", win %" PRIu32 "", + SCLogDebug("ssn %p: next SEQ %" PRIu32 ", last ACK %" PRIu32 ", next win %" PRIu32 ", win %" PRIu32 "", ssn, ssn->server.next_seq, ssn->client.last_ack, ssn->server.next_win, ssn->server.window); } break; @@ -761,7 +761,7 @@ static int StreamTcpPacketStateEstablished(ThreadVars *tv, Packet *p, StreamTcpT return -1; } - SCDebug("StreamTcpPacketStateEstablished (%p): FIN received SEQ %" PRIu32 ", last ACK %" PRIu32 ", next win %" PRIu32 ", win %" PRIu32 "", + SCLogDebug("StreamTcpPacketStateEstablished (%p): FIN received SEQ %" PRIu32 ", last ACK %" PRIu32 ", next win %" PRIu32 ", win %" PRIu32 "", ssn, ssn->server.next_seq, ssn->client.last_ack, ssn->server.next_win, ssn->server.window); if((StreamTcpHandleFin(stt, ssn, p)) == -1) @@ -772,41 +772,41 @@ static int StreamTcpPacketStateEstablished(ThreadVars *tv, Packet *p, StreamTcpT if(ValidReset(ssn, p)) { if(PKT_IS_TOSERVER(p)) { StreamTcpPacketSetState(p, ssn, TCP_CLOSED); - SCDebug("ssn %p: Reset received and state changed to TCP_CLOSED", ssn); + SCLogDebug("ssn %p: Reset received and state changed to TCP_CLOSED", ssn); ssn->client.next_seq = TCP_GET_ACK(p); ssn->server.next_seq = TCP_GET_SEQ(p) + p->payload_len + 1; - SCDebug("ssn %p: ssn->server.next_seq %" PRIu32 "", ssn, ssn->server.next_seq); + SCLogDebug("ssn %p: ssn->server.next_seq %" PRIu32 "", ssn, ssn->server.next_seq); ssn->client.window = TCP_GET_WINDOW(p) << ssn->client.wscale; if (SEQ_GT(TCP_GET_ACK(p),ssn->server.last_ack)) ssn->server.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->client, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->client.next_seq, ssn->server.last_ack); } else { StreamTcpPacketSetState(p, ssn, TCP_CLOSED); - SCDebug("ssn %p: Reset received and state changed to TCP_CLOSED", ssn); + SCLogDebug("ssn %p: Reset received and state changed to TCP_CLOSED", ssn); ssn->server.next_seq = TCP_GET_SEQ(p) + p->payload_len + 1; ssn->client.next_seq = TCP_GET_ACK(p); - SCDebug("ssn %p: ssn->server.next_seq %" PRIu32 "", ssn, ssn->server.next_seq); + SCLogDebug("ssn %p: ssn->server.next_seq %" PRIu32 "", ssn, ssn->server.next_seq); ssn->server.window = TCP_GET_WINDOW(p) << ssn->server.wscale; if (SEQ_GT(TCP_GET_ACK(p),ssn->client.last_ack)) ssn->client.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->server, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->server.next_seq, ssn->client.last_ack); } } else return -1; break; default: - SCDebug("ssn %p: default case", ssn); + SCLogDebug("ssn %p: default case", ssn); break; } return 0; @@ -824,21 +824,21 @@ static int StreamTcpPacketStateEstablished(ThreadVars *tv, Packet *p, StreamTcpT static int StreamTcpHandleFin(StreamTcpThread *stt, TcpSession *ssn, Packet *p) { if (PKT_IS_TOSERVER(p)) { - SCDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (SEQ_LT(TCP_GET_SEQ(p), ssn->client.next_seq) || SEQ_GT(TCP_GET_SEQ(p), (ssn->client.last_ack + ssn->client.window))) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->client.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_CLOSE_WAIT); - SCDebug("ssn %p: state changed to TCP_CLOSE_WAIT", ssn); + SCLogDebug("ssn %p: state changed to TCP_CLOSE_WAIT", ssn); ssn->client.next_seq = TCP_GET_ACK(p); ssn->server.next_seq = TCP_GET_SEQ(p) + p->payload_len + 1; - SCDebug("ssn %p: ssn->server.next_seq %" PRIu32 "", ssn, ssn->server.next_seq); + SCLogDebug("ssn %p: ssn->server.next_seq %" PRIu32 "", ssn, ssn->server.next_seq); ssn->server.window = TCP_GET_WINDOW(p) << ssn->server.wscale; if (SEQ_GT(TCP_GET_ACK(p),ssn->server.last_ack)) @@ -846,23 +846,23 @@ static int StreamTcpHandleFin(StreamTcpThread *stt, TcpSession *ssn, Packet *p) StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->client, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->client.next_seq, ssn->server.last_ack); } else { /* implied to client */ - SCDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (SEQ_LT(TCP_GET_SEQ(p), ssn->server.next_seq) || SEQ_GT(TCP_GET_SEQ(p), (ssn->server.last_ack + ssn->server.window))) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->server.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_FIN_WAIT1); - SCDebug("ssn %p: state changed to TCP_FIN_WAIT1", ssn); + SCLogDebug("ssn %p: state changed to TCP_FIN_WAIT1", ssn); ssn->server.next_seq = TCP_GET_SEQ(p) + p->payload_len + 1; ssn->client.next_seq = TCP_GET_ACK(p); - SCDebug("ssn %p: ssn->server.next_seq %" PRIu32 "", ssn, ssn->server.next_seq); + SCLogDebug("ssn %p: ssn->server.next_seq %" PRIu32 "", ssn, ssn->server.next_seq); ssn->client.window = TCP_GET_WINDOW(p) << ssn->client.wscale; if (SEQ_GT(TCP_GET_ACK(p),ssn->client.last_ack)) @@ -870,7 +870,7 @@ static int StreamTcpHandleFin(StreamTcpThread *stt, TcpSession *ssn, Packet *p) StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->server, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->server.next_seq, ssn->client.last_ack); } return 0; @@ -899,11 +899,11 @@ static int StreamTcpPacketStateFinWait1(ThreadVars *tv, Packet *p, StreamTcpThre } if (PKT_IS_TOSERVER(p)) { - SCDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); StreamTcpPacketSetState(p, ssn, TCP_FIN_WAIT2); - SCDebug("ssn %p: state changed to TCP_FIN_WAIT2", ssn); + SCLogDebug("ssn %p: state changed to TCP_FIN_WAIT2", ssn); ssn->server.window = TCP_GET_WINDOW(p) << ssn->server.wscale; @@ -911,20 +911,20 @@ static int StreamTcpPacketStateFinWait1(ThreadVars *tv, Packet *p, StreamTcpThre ssn->server.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->client, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->client.next_seq, ssn->server.last_ack); } else { /* implied to client */ - SCDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); StreamTcpPacketSetState(p, ssn, TCP_FIN_WAIT2); - SCDebug("ssn %p: state changed to TCP_FIN_WAIT2", ssn); + SCLogDebug("ssn %p: state changed to TCP_FIN_WAIT2", ssn); ssn->client.window = TCP_GET_WINDOW(p) << ssn->client.wscale; if (SEQ_GT(TCP_GET_ACK(p),ssn->client.last_ack)) ssn->client.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->server, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->server.next_seq, ssn->client.last_ack); } break; @@ -938,17 +938,17 @@ static int StreamTcpPacketStateFinWait1(ThreadVars *tv, Packet *p, StreamTcpThre } if (PKT_IS_TOSERVER(p)) { - SCDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (SEQ_LT(TCP_GET_SEQ(p), ssn->client.next_seq || SEQ_GT(TCP_GET_SEQ(p), (ssn->client.last_ack + ssn->client.window)))) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->client.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_TIME_WAIT); - SCDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); + SCLogDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); ssn->server.window = TCP_GET_WINDOW(p) << ssn->server.wscale; @@ -956,20 +956,20 @@ static int StreamTcpPacketStateFinWait1(ThreadVars *tv, Packet *p, StreamTcpThre ssn->server.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->client, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->client.next_seq, ssn->server.last_ack); } else { /* implied to client */ - SCDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (SEQ_LT(TCP_GET_SEQ(p), ssn->server.next_seq) || SEQ_GT(TCP_GET_SEQ(p), (ssn->server.last_ack + ssn->server.window))) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->server.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_TIME_WAIT); - SCDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); + SCLogDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); ssn->client.window = TCP_GET_WINDOW(p) << ssn->client.wscale; @@ -977,7 +977,7 @@ static int StreamTcpPacketStateFinWait1(ThreadVars *tv, Packet *p, StreamTcpThre ssn->client.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->server, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->server.next_seq, ssn->client.last_ack); } break; @@ -985,13 +985,13 @@ static int StreamTcpPacketStateFinWait1(ThreadVars *tv, Packet *p, StreamTcpThre case TH_RST|TH_ACK: if(ValidReset(ssn, p)) { StreamTcpPacketSetState(p, ssn, TCP_CLOSED); - SCDebug("ssn %p: Reset received state changed to TCP_CLOSED", ssn); + SCLogDebug("ssn %p: Reset received state changed to TCP_CLOSED", ssn); } else return -1; break; default: - SCDebug("ssn (%p): default case", ssn); + SCLogDebug("ssn (%p): default case", ssn); break; } @@ -1021,16 +1021,16 @@ static int StreamTcpPacketStateFinWait2(ThreadVars *tv, Packet *p, StreamTcpThre } if (PKT_IS_TOSERVER(p)) { - SCDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (TCP_GET_SEQ(p) != ssn->client.next_seq) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->client.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_TIME_WAIT); - SCDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); + SCLogDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); ssn->server.window = TCP_GET_WINDOW(p) << ssn->server.wscale; @@ -1038,19 +1038,19 @@ static int StreamTcpPacketStateFinWait2(ThreadVars *tv, Packet *p, StreamTcpThre ssn->server.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->client, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->client.next_seq, ssn->server.last_ack); } else { /* implied to client */ - SCDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (TCP_GET_SEQ(p) != ssn->server.next_seq) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->server.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_TIME_WAIT); - SCDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); + SCLogDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); ssn->client.window = TCP_GET_WINDOW(p) << ssn->client.wscale; @@ -1058,7 +1058,7 @@ static int StreamTcpPacketStateFinWait2(ThreadVars *tv, Packet *p, StreamTcpThre ssn->client.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->server, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->server.next_seq, ssn->client.last_ack); } break; @@ -1066,7 +1066,7 @@ static int StreamTcpPacketStateFinWait2(ThreadVars *tv, Packet *p, StreamTcpThre case TH_RST|TH_ACK: if(ValidReset(ssn, p)) { StreamTcpPacketSetState(p, ssn, TCP_CLOSED); - SCDebug("ssn %p: Reset received state changed to TCP_CLOSED", ssn); + SCLogDebug("ssn %p: Reset received state changed to TCP_CLOSED", ssn); } else return -1; @@ -1079,17 +1079,17 @@ static int StreamTcpPacketStateFinWait2(ThreadVars *tv, Packet *p, StreamTcpThre } if (PKT_IS_TOSERVER(p)) { - SCDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (SEQ_LT(TCP_GET_SEQ(p), ssn->client.next_seq || SEQ_GT(TCP_GET_SEQ(p), (ssn->client.last_ack + ssn->client.window)))) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->client.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_TIME_WAIT); - SCDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); + SCLogDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); ssn->server.window = TCP_GET_WINDOW(p) << ssn->server.wscale; if (SEQ_GT(TCP_GET_ACK(p),ssn->server.last_ack)) @@ -1097,32 +1097,32 @@ static int StreamTcpPacketStateFinWait2(ThreadVars *tv, Packet *p, StreamTcpThre StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->client, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->client.next_seq, ssn->server.last_ack); } else { /* implied to client */ - SCDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (SEQ_LT(TCP_GET_SEQ(p), ssn->server.next_seq) || SEQ_GT(TCP_GET_SEQ(p), (ssn->server.last_ack + ssn->server.window))) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->server.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_TIME_WAIT); - SCDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); + SCLogDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); ssn->client.window = TCP_GET_WINDOW(p) << ssn->client.wscale; if (SEQ_GT(TCP_GET_ACK(p),ssn->client.last_ack)) ssn->client.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->server, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->server.next_seq, ssn->client.last_ack); } break; default: - SCDebug("ssn %p: default case", ssn); + SCLogDebug("ssn %p: default case", ssn); break; } @@ -1152,17 +1152,17 @@ static int StreamTcpPacketStateClosing(ThreadVars *tv, Packet *p, StreamTcpThrea } if (PKT_IS_TOSERVER(p)) { - SCDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (TCP_GET_SEQ(p) != ssn->client.next_seq) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->client.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_TIME_WAIT); - SCDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); + SCLogDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); ssn->client.window = TCP_GET_WINDOW(p) << ssn->client.wscale; @@ -1170,32 +1170,32 @@ static int StreamTcpPacketStateClosing(ThreadVars *tv, Packet *p, StreamTcpThrea ssn->server.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->client, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->client.next_seq, ssn->server.last_ack); } else { /* implied to client */ - SCDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (TCP_GET_SEQ(p) != ssn->server.next_seq) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->server.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_TIME_WAIT); - SCDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); + SCLogDebug("ssn %p: state changed to TCP_TIME_WAIT", ssn); ssn->client.window = TCP_GET_WINDOW(p) << ssn->client.wscale; if (SEQ_GT(TCP_GET_ACK(p),ssn->client.last_ack)) ssn->client.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->server, p); - SCDebug("StreamTcpPacketStateClosing (%p): =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("StreamTcpPacketStateClosing (%p): =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->server.next_seq, ssn->client.last_ack); } break; default: - SCDebug("ssn %p: default case", ssn); + SCLogDebug("ssn %p: default case", ssn); break; } return 0; @@ -1224,29 +1224,29 @@ static int StreamTcpPacketStateCloseWait(ThreadVars *tv, Packet *p, StreamTcpThr } if (PKT_IS_TOCLIENT(p)) { - SCDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (SEQ_LT(TCP_GET_SEQ(p), ssn->server.next_seq) || SEQ_GT(TCP_GET_SEQ(p), (ssn->server.last_ack + ssn->server.window))) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->server.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_LAST_ACK); - SCDebug("ssn %p: state changed to TCP_LAST_ACK", ssn); + SCLogDebug("ssn %p: state changed to TCP_LAST_ACK", ssn); ssn->client.window = TCP_GET_WINDOW(p) << ssn->client.wscale; if (SEQ_GT(TCP_GET_ACK(p),ssn->client.last_ack)) ssn->client.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->server, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->server.next_seq, ssn->client.last_ack); } break; default: - SCDebug("ssn %p: default case", ssn); + SCLogDebug("ssn %p: default case", ssn); break; } return 0; @@ -1275,17 +1275,17 @@ static int StreamTcpPakcetStateLastAck(ThreadVars *tv, Packet *p, StreamTcpThrea } if (PKT_IS_TOSERVER(p)) { - SCDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (TCP_GET_SEQ(p) != ssn->client.next_seq) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->client.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_CLOSED); - SCDebug("ssn %p: state changed to TCP_CLOSED", ssn); + SCLogDebug("ssn %p: state changed to TCP_CLOSED", ssn); ssn->server.window = TCP_GET_WINDOW(p) << ssn->server.wscale; @@ -1293,12 +1293,12 @@ static int StreamTcpPakcetStateLastAck(ThreadVars *tv, Packet *p, StreamTcpThrea ssn->server.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->client, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->client.next_seq, ssn->server.last_ack); } break; default: - SCDebug("ssn %p: default case", ssn); + SCLogDebug("ssn %p: default case", ssn); break; } return 0; @@ -1327,17 +1327,17 @@ static int StreamTcpPacketStateTimeWait(ThreadVars *tv, Packet *p, StreamTcpThre } if (PKT_IS_TOSERVER(p)) { - SCDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to server: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (TCP_GET_SEQ(p) != ssn->client.next_seq) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->client.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_CLOSED); - SCDebug("ssn %p: state changed to TCP_CLOSED", ssn); + SCLogDebug("ssn %p: state changed to TCP_CLOSED", ssn); ssn->server.window = TCP_GET_WINDOW(p) << ssn->server.wscale; @@ -1345,32 +1345,32 @@ static int StreamTcpPacketStateTimeWait(ThreadVars *tv, Packet *p, StreamTcpThre ssn->server.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->client, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->client.next_seq, ssn->server.last_ack); } else { - SCDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", + SCLogDebug("ssn %p: pkt (%" PRIu32 ") is to client: SEQ %" PRIu32 ", ACK %" PRIu32 "", ssn, p->payload_len, TCP_GET_SEQ(p), TCP_GET_ACK(p)); if (TCP_GET_SEQ(p) != ssn->server.next_seq) { - SCDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", + SCLogDebug("ssn %p: -> SEQ mismatch, packet SEQ %" PRIu32 " != %" PRIu32 " from stream", ssn, TCP_GET_SEQ(p), ssn->server.next_seq); return -1; } StreamTcpPacketSetState(p, ssn, TCP_CLOSED); - SCDebug("ssn %p: state changed to TCP_CLOSED", ssn); + SCLogDebug("ssn %p: state changed to TCP_CLOSED", ssn); ssn->client.window = TCP_GET_WINDOW(p) << ssn->client.wscale; if (SEQ_GT(TCP_GET_ACK(p),ssn->client.last_ack)) ssn->client.last_ack = TCP_GET_ACK(p); StreamTcpReassembleHandleSegment(stt->ra_ctx, ssn, &ssn->server, p); - SCDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", + SCLogDebug("ssn %p: =+ next SEQ %" PRIu32 ", last ACK %" PRIu32 "", ssn, ssn->server.next_seq, ssn->client.last_ack); } break; default: - SCDebug("ssn %p: default case", ssn); + SCLogDebug("ssn %p: default case", ssn); break; } @@ -1472,9 +1472,8 @@ int StreamTcpThreadInit(ThreadVars *tv, void *initdata, void **data) stt->ra_ctx = StreamTcpReassembleInitThreadCtx(); if (stt->ra_ctx == NULL) return -1; -#ifdef DEBUG - printf("StreamTcp thread specific ctx online at %p, reassembly ctx %p\n", stt, stt->ra_ctx); -#endif + + SCLogDebug("StreamTcp thread specific ctx online at %p, reassembly ctx %p", stt, stt->ra_ctx); return 0; } @@ -1532,18 +1531,18 @@ static int ValidReset(TcpSession *ssn, Packet *p) { case OS_POLICY_HPUX11: if(PKT_IS_TOSERVER(p)){ if(SEQ_GEQ(TCP_GET_SEQ(p), ssn->client.next_seq)) { - SCDebug("reset is Valid! Packet SEQ: %" PRIu32 "", TCP_GET_SEQ(p)); + SCLogDebug("reset is Valid! Packet SEQ: %" PRIu32 "", TCP_GET_SEQ(p)); return 1; } else { - SCDebug("reset is not Valid! Packet SEQ: %" PRIu32 " and server SEQ: %" PRIu32 "", TCP_GET_SEQ(p), ssn->client.next_seq); + SCLogDebug("reset is not Valid! Packet SEQ: %" PRIu32 " and server SEQ: %" PRIu32 "", TCP_GET_SEQ(p), ssn->client.next_seq); return 0; } } else { /* implied to client */ if(SEQ_GEQ(TCP_GET_SEQ(p), ssn->server.next_seq)) { - SCDebug("reset is valid! Packet SEQ: %" PRIu32 "", TCP_GET_SEQ(p)); + SCLogDebug("reset is valid! Packet SEQ: %" PRIu32 "", TCP_GET_SEQ(p)); return 1; } else { - SCDebug("reset is not valid! Packet SEQ: %" PRIu32 " and client SEQ: %" PRIu32 "", TCP_GET_SEQ(p), ssn->server.next_seq); + SCLogDebug("reset is not valid! Packet SEQ: %" PRIu32 " and client SEQ: %" PRIu32 "", TCP_GET_SEQ(p), ssn->server.next_seq); return 0; } } @@ -1554,21 +1553,21 @@ static int ValidReset(TcpSession *ssn, Packet *p) { if(PKT_IS_TOSERVER(p)){ if(SEQ_GEQ((TCP_GET_SEQ(p)+p->payload_len), ssn->client.last_ack)) { /*window base is needed !!*/ if(SEQ_LT(TCP_GET_SEQ(p), (ssn->client.next_seq + ssn->client.window))) { - SCDebug("reset is Valid! Packet SEQ: %" PRIu32 "", TCP_GET_SEQ(p)); + SCLogDebug("reset is Valid! Packet SEQ: %" PRIu32 "", TCP_GET_SEQ(p)); return 1; } } else { - SCDebug("reset is not valid! Packet SEQ: %" PRIu32 " and server SEQ: %" PRIu32 "", TCP_GET_SEQ(p), ssn->client.next_seq); + SCLogDebug("reset is not valid! Packet SEQ: %" PRIu32 " and server SEQ: %" PRIu32 "", TCP_GET_SEQ(p), ssn->client.next_seq); return 0; } } else { /* implied to client */ if(SEQ_GEQ((TCP_GET_SEQ(p) + p->payload_len), ssn->server.last_ack)) { /*window base is needed !!*/ if(SEQ_LT(TCP_GET_SEQ(p), (ssn->server.next_seq + ssn->server.window))) { - SCDebug("reset is Valid! Packet SEQ: %" PRIu32 "", TCP_GET_SEQ(p)); + SCLogDebug("reset is Valid! Packet SEQ: %" PRIu32 "", TCP_GET_SEQ(p)); return 1; } } else { - SCDebug("reset is not valid! Packet SEQ: %" PRIu32 " and client SEQ: %" PRIu32 "", TCP_GET_SEQ(p), ssn->server.next_seq); + SCLogDebug("reset is not valid! Packet SEQ: %" PRIu32 " and client SEQ: %" PRIu32 "", TCP_GET_SEQ(p), ssn->server.next_seq); return 0; } } @@ -1585,18 +1584,18 @@ static int ValidReset(TcpSession *ssn, Packet *p) { case OS_POLICY_VISTA: if(PKT_IS_TOSERVER(p)) { if(SEQ_EQ(TCP_GET_SEQ(p), ssn->client.next_seq)) { - SCDebug("reset is valid! Packet SEQ: %" PRIu32 "", TCP_GET_SEQ(p)); + SCLogDebug("reset is valid! Packet SEQ: %" PRIu32 "", TCP_GET_SEQ(p)); return 1; } else { - SCDebug("reset is not valid! Packet SEQ: %" PRIu32 " and server SEQ: %" PRIu32 "", TCP_GET_SEQ(p), ssn->client.next_seq); + SCLogDebug("reset is not valid! Packet SEQ: %" PRIu32 " and server SEQ: %" PRIu32 "", TCP_GET_SEQ(p), ssn->client.next_seq); return 0; } } else { /* implied to client */ if(SEQ_EQ(TCP_GET_SEQ(p), ssn->server.next_seq)) { - SCDebug("reset is valid! Packet SEQ: %" PRIu32 "", TCP_GET_SEQ(p)); + SCLogDebug("reset is valid! Packet SEQ: %" PRIu32 "", TCP_GET_SEQ(p)); return 1; } else { - SCDebug("reset is not valid! Packet SEQ: %" PRIu32 " and client SEQ: %" PRIu32 "", TCP_GET_SEQ(p), ssn->server.next_seq); + SCLogDebug("reset is not valid! Packet SEQ: %" PRIu32 " and client SEQ: %" PRIu32 "", TCP_GET_SEQ(p), ssn->server.next_seq); return 0; } } @@ -1725,10 +1724,10 @@ static int ValidTimestamp (TcpSession *ssn, Packet *p) { sender_stream->last_pkt_ts = p->ts.tv_sec; if (result < 0) { - SCDebug("timestamp is not valid sender_stream->last_ts %" PRIu32 " p->tcpvars->ts %" PRIu32 " result %" PRId32 "", sender_stream->last_ts, ts, result); + SCLogDebug("timestamp is not valid sender_stream->last_ts %" PRIu32 " p->tcpvars->ts %" PRIu32 " result %" PRId32 "", sender_stream->last_ts, ts, result); ret = 0; } else if ((sender_stream->last_ts != 0) && (((uint32_t) p->ts.tv_sec) > sender_stream->last_pkt_ts + PAWS_24DAYS)) { - SCDebug("packet is not valid sender_stream->last_pkt_ts %" PRIu32 " p->ts.tv_sec %" PRIu32 "", sender_stream->last_pkt_ts, (uint32_t) p->ts.tv_sec); + SCLogDebug("packet is not valid sender_stream->last_pkt_ts %" PRIu32 " p->ts.tv_sec %" PRIu32 "", sender_stream->last_pkt_ts, (uint32_t) p->ts.tv_sec); ret = 0; } diff --git a/src/stream.c b/src/stream.c index 968f0326ce..bc9cde3cad 100644 --- a/src/stream.c +++ b/src/stream.c @@ -133,7 +133,7 @@ void StreamMsgPutInQueue(StreamMsgQueue *q, StreamMsg *s) { mutex_lock(&q->mutex_q); StreamMsgEnqueue(q, s); - SCDebug("q->len %" PRIu32 "", q->len); + SCLogDebug("q->len %" PRIu32 "", q->len); pthread_cond_signal(&q->cond_q); mutex_unlock(&q->mutex_q); } diff --git a/src/tm-modules.c b/src/tm-modules.c index a97e274829..db09bf7f75 100644 --- a/src/tm-modules.c +++ b/src/tm-modules.c @@ -3,21 +3,20 @@ #include "eidps-common.h" #include "packet-queue.h" #include "tm-modules.h" +#include "util-debug.h" void TmModuleDebugList(void) { TmModule *t; uint16_t i; - printf("TmModuleDebugList: start\n"); for (i = 0; i < TMM_SIZE; i++) { t = &tmm_modules[i]; if (t->name == NULL) continue; - printf("TmModuleDebugList: %s:%p\n", t->name, t->Func); + SCLogDebug("%s:%p\n", t->name, t->Func); } - printf("TmModuleDebugList: end\n"); } /** \brief get a tm module ptr by name @@ -53,8 +52,8 @@ void TmModuleRegisterTests(void) { continue; if (t->RegisterTests == NULL) { - printf("Warning: threading module %s has no unittest " - "registration function.\n", t->name); + SCLogDebug("threading module %s has no unittest " + "registration function.", t->name); } else { t->RegisterTests(); } diff --git a/src/tm-queues.c b/src/tm-queues.c index dbddd1be70..5380894bee 100644 --- a/src/tm-queues.c +++ b/src/tm-queues.c @@ -1,7 +1,7 @@ #include "eidps.h" #include "threads.h" - #include "tm-queues.h" +#include "util-debug.h" #define TMQ_MAX_QUEUES 256 @@ -24,12 +24,11 @@ Tmq* TmqCreateQueue(char *name) { if (tmq_id >= TMQ_MAX_QUEUES) goto error; -#ifdef DEBUG - printf("TmqCreateQueue: created queue \'%s\'...\n", name); -#endif Tmq *q = &tmqs[tmq_id]; q->name = name; q->id = tmq_id++; + + SCLogDebug("created queue \'%s\', %p", name, q); return q; error: diff --git a/src/tm-threads.c b/src/tm-threads.c index add3c57ded..1da535e562 100644 --- a/src/tm-threads.c +++ b/src/tm-threads.c @@ -13,6 +13,7 @@ #include "tm-threads.h" #include "tmqh-packetpool.h" #include "threads.h" +#include "util-debug.h" /* prototypes */ static int SetCPUAffinity(int cpu); @@ -212,7 +213,7 @@ void *TmThreadsSlot1NoInOut(void *td) { if (tv->set_cpu_affinity == 1) SetCPUAffinity(tv->cpu_affinity); - //printf("TmThreadsSlot1NoInOut: %s starting\n", tv->name); + SCLogDebug("%s starting", tv->name); if (s->s.SlotThreadInit != NULL) { r = s->s.SlotThreadInit(tv, s->s.slot_initdata, &s->s.slot_data); @@ -272,7 +273,7 @@ void *TmThreadsSlot1(void *td) { if (tv->set_cpu_affinity == 1) SetCPUAffinity(tv->cpu_affinity); - //printf("TmThreadsSlot1: %s starting\n", tv->name); + SCLogDebug("%s starting", tv->name); if (s->s.SlotThreadInit != NULL) { r = s->s.SlotThreadInit(tv, s->s.slot_initdata, &s->s.slot_data); @@ -336,7 +337,7 @@ void *TmThreadsSlot1(void *td) { } } - //printf("TmThreadsSlot1: %s ending\n", tv->name); + SCLogDebug("%s ending", tv->name); TmThreadsSetFlag(tv, THV_CLOSED); pthread_exit((void *) 0); } @@ -452,7 +453,7 @@ void *TmThreadsSlotVar(void *td) { } } - //printf("TmThreadsSlot1: %s ending\n", tv->name); + SCLogDebug("%s ending", tv->name); TmThreadsSetFlag(tv, THV_CLOSED); pthread_exit((void *) 0); } @@ -597,9 +598,7 @@ ThreadVars *TmThreadCreate(char *name, char *inq_name, char *inqh_name, Tmq *tmq = NULL; Tmqh *tmqh = NULL; -#ifdef DEBUG - printf("TmThreadCreate: creating thread \"%s\"...\n", name); -#endif + SCLogDebug("creating thread \"%s\"...", name); /* XXX create separate function for this: allocate a thread container */ tv = malloc(sizeof(ThreadVars)); @@ -777,9 +776,7 @@ void TmThreadKillThreads(void) { while (tv) { TmThreadsSetFlag(tv, THV_KILL); -#ifdef DEBUG - printf("TmThreadKillThreads: told thread %s to stop\n", tv->name); -#endif + SCLogDebug("told thread %s to stop", tv->name); /* XXX hack */ StreamMsgSignalQueueHack(); @@ -801,9 +798,7 @@ void TmThreadKillThreads(void) { int cnt = 0; while (1) { if (TmThreadsCheckFlag(tv, THV_CLOSED)) { -#ifdef DEBUG - printf("signalled the thread %" PRId32 " times\n", cnt); -#endif + SCLogDebug("signalled the thread %" PRId32 " times", cnt); break; } @@ -815,19 +810,14 @@ void TmThreadKillThreads(void) { usleep(100); } -#ifdef DEBUG - printf("TmThreadKillThreads: signalled tv->inq->id %" PRIu32 "\n", tv->inq->id); -#endif - + SCLogDebug("signalled tv->inq->id %" PRIu32 "", tv->inq->id); } if (tv->cond != NULL ) { int cnt = 0; while (1) { if (TmThreadsCheckFlag(tv, THV_CLOSED)) { -#ifdef DEBUG - printf("signalled the thread %" PRId32 " times\n", cnt); -#endif + SCLogDebug("signalled the thread %" PRId32 " times", cnt); break; } @@ -841,9 +831,7 @@ void TmThreadKillThreads(void) { /* join it */ pthread_join(tv->t, NULL); -#ifdef DEBUG - printf("TmThreadKillThreads: thread %s stopped\n", tv->name); -#endif + SCLogDebug("thread %s stopped", tv->name); tv = tv->next; } @@ -1039,7 +1027,7 @@ static void TmThreadRestartThread(ThreadVars *tv) } tv->restarted++; - printf("Thread \"%s\" restarted\n", tv->name); + SCLogInfo("thread \"%s\" restarted", tv->name); return; } @@ -1114,8 +1102,8 @@ int TmThreadWaitOnThreadInit(void) } } - printf("All %"PRIu16" packet processing threads, %"PRIu16" management " - "threads initialized, engine started.\n", ppt_num, mgt_num); + SCLogInfo("all %"PRIu16" packet processing threads, %"PRIu16" management " + "threads initialized, engine started.", ppt_num, mgt_num); return 0; } diff --git a/src/util-binsearch.c b/src/util-binsearch.c index 4170255eea..cd3a7c6532 100644 --- a/src/util-binsearch.c +++ b/src/util-binsearch.c @@ -1,28 +1,11 @@ #include "eidps-common.h" +#include "eidps.h" /** \todo replace this by a better algo */ -uint8_t nocasetable[256]; -#define _nc(c) nocasetable[(c)] - void BinSearchInit (void) { - /* create table for O(1) case conversion lookup */ - uint8_t c = 0; - for ( ; c < 255; c++) { - if ( c >= 'a' && c <= 'z') - nocasetable[c] = (c - ('a' - 'A')); - else if (c >= 'A' && c <= 'Z') - nocasetable[c] = (c + ('a' - 'A')); - else - nocasetable[c] = c; - } -#ifdef DEBUG - for (c = 0; c < 255; c++) { - if (isprint(nocasetable[c])) - printf("nocasetable[%c]: %c\n", c, nocasetable[c]); - } -#endif /* DEBUG */ + /* nothing no more */ } /* Binary search. @@ -85,12 +68,11 @@ BinSearchNocase(const uint8_t *haystack, size_t haystack_len, return NULL; for (n = needle; haystack != hmax; haystack++) { - if (*haystack != *n && *haystack != _nc(*n)) { + if (*haystack != *n && *haystack != u8_tolower(*n)) { continue; } for (h = haystack+1, n++; h != hmax; h++, n++) { - //printf("h %c n %c\n", isprint(*h) ? *h : 'X', *n); - if (*h != *n && *h != _nc(*n)) { + if (*h != *n && *h != u8_tolower(*n)) { break; } /* if we run out of needle we fully matched */ diff --git a/src/util-debug.c b/src/util-debug.c index d08d239293..243097620d 100644 --- a/src/util-debug.c +++ b/src/util-debug.c @@ -813,7 +813,7 @@ static inline void SCLogSetOPFilter(SCLogInitData *sc_lid, SCLogConfig *sc_lc) } #ifdef DEBUG - printf("filter: %s\n", filter); + printf("SCLogSetOPFilter: filter %s\n", filter ? filter : "no filter"); #endif return; diff --git a/src/util-debug.h b/src/util-debug.h index 6ad74b448f..bf370143d1 100644 --- a/src/util-debug.h +++ b/src/util-debug.h @@ -342,7 +342,7 @@ extern int sc_log_module_cleaned; */ #define SCReturn do { \ if (sc_log_global_log_level >= SC_LOG_DEBUG) { \ - SCDebug("Returning ... <<" ); \ + SCLogDebug("Returning ... <<" ); \ SCLogCheckFDFilterExit(__FUNCTION__); \ } \ return; \ @@ -360,7 +360,7 @@ extern int sc_log_module_cleaned; */ #define SCReturnInt(x) do { \ if (sc_log_global_log_level >= SC_LOG_DEBUG) { \ - SCDebug("Returning: %d ... <<", x); \ + SCLogDebug("Returning: %d ... <<", x); \ SCLogCheckFDFilterExit(__FUNCTION__); \ } \ return x; \ @@ -378,7 +378,7 @@ extern int sc_log_module_cleaned; */ #define SCReturnUInt(x) do { \ if (sc_log_global_log_level >= SC_LOG_DEBUG) { \ - SCDebug("Returning: %u ... <<", x); \ + SCLogDebug("Returning: %u ... <<", x); \ SCLogCheckFDFilterExit(__FUNCTION__); \ } \ return x; \ @@ -396,7 +396,7 @@ extern int sc_log_module_cleaned; */ #define SCReturnDbl(x) do { \ if (sc_log_global_log_level >= SC_LOG_DEBUG) { \ - SCDebug("Returning: %f ... <<", x); \ + SCLogDebug("Returning: %f ... <<", x); \ SCLogCheckFDFilterExit(__FUNCTION__); \ } \ return x; \ @@ -414,7 +414,7 @@ extern int sc_log_module_cleaned; */ #define SCReturnChar(x) do { \ if (sc_log_global_log_level >= SC_LOG_DEBUG) { \ - SCDebug("Returning: %c ... <<", x); \ + SCLogDebug("Returning: %c ... <<", x); \ SCLogCheckFDFilterExit(__FUNCTION__); \ } \ return x; \ @@ -432,7 +432,7 @@ extern int sc_log_module_cleaned; */ #define SCReturnCharPtr(x) do { \ if (sc_log_global_log_level >= SC_LOG_DEBUG) { \ - SCDebug("Returning: %s ... <<", x); \ + SCLogDebug("Returning: %s ... <<", x); \ SCLogCheckFDFilterExit(__FUNCTION__); \ } \ return x; \ @@ -453,7 +453,7 @@ extern int sc_log_module_cleaned; */ #define SCReturnCT(x, type) do { \ if (sc_log_global_log_level >= SC_LOG_DEBUG) { \ - SCDebug("Returning var of " \ + SCLogDebug("Returning var of " \ "type %s ... <<", type); \ SCLogCheckFDFilterExit(__FUNCTION__); \ } \ @@ -475,7 +475,7 @@ extern int sc_log_module_cleaned; */ #define SCReturnPtr(x, type) do { \ if (sc_log_global_log_level >= SC_LOG_DEBUG) { \ - SCDebug("Returning pointer of " \ + SCLogDebug("Returning pointer of " \ "type %s ... <<", type); \ SCLogCheckFDFilterExit(__FUNCTION__); \ } \ diff --git a/src/util-mpm-b2g.c b/src/util-mpm-b2g.c index 2ad0f830cc..ecd96c3866 100644 --- a/src/util-mpm-b2g.c +++ b/src/util-mpm-b2g.c @@ -286,7 +286,7 @@ void B2gFreePattern(MpmCtx *mpm_ctx, B2gPattern *p) { if (p) { free(p); mpm_ctx->memory_cnt--; - mpm_ctx->memory_size -= sizeof(B2gPattern); + mpm_ctx->memory_size -= sizeof(B2gPattern); } } diff --git a/src/util-mpm.c b/src/util-mpm.c index da965bd6c9..5b03a3ffa9 100644 --- a/src/util-mpm.c +++ b/src/util-mpm.c @@ -85,7 +85,7 @@ void PmqFree(PatternMatcherQueue *pmq) { * used at search runtime (or actually once per search) */ void MpmMatchCleanup(MpmThreadCtx *thread_ctx) { - SCDebug("mem %" PRIu32 "", thread_ctx->memory_size); + SCLogDebug("mem %" PRIu32 "", thread_ctx->memory_size); MpmMatch *nxt; MpmMatch *m = thread_ctx->qlist; @@ -213,7 +213,7 @@ MpmMatchAppend(MpmThreadCtx *thread_ctx, PatternMatcherQueue *pmq, MpmEndMatch * } } - SCDebug("len %" PRIu32 " (offset %" PRIu32 ")", mb->len, m->offset); + SCLogDebug("len %" PRIu32 " (offset %" PRIu32 ")", mb->len, m->offset); #if 0 MpmMatch *tmp = thread_ctx->qlist; diff --git a/src/util-pool.c b/src/util-pool.c index 2aaac8125a..4b8758ccd6 100644 --- a/src/util-pool.c +++ b/src/util-pool.c @@ -3,6 +3,7 @@ #include "eidps-common.h" #include "util-pool.h" #include "util-unittest.h" +#include "util-debug.h" Pool *PoolInit(uint32_t size, uint32_t prealloc_size, void *(*Alloc)(void *), void *AllocData, void (*Free)(void *)) { @@ -148,7 +149,7 @@ void PoolReturn(Pool *p, void *data) { } void PoolPrintSaturation(Pool *p) { - printf("PoolPrintSaturation: Pool %p is using %"PRIu32" out of %"PRIu32" items (%02.1f%%), max %"PRIu32" (%02.1f%%): pool struct memory %"PRIu64".\n", p, p->outstanding, p->max_buckets, (float)(p->outstanding/(float)(p->max_buckets))*100, p->max_outstanding, (float)(p->max_outstanding/(float)(p->max_buckets))*100, (uint64_t)(p->max_buckets * sizeof(PoolBucket))); + SCLogDebug("pool %p is using %"PRIu32" out of %"PRIu32" items (%02.1f%%), max %"PRIu32" (%02.1f%%): pool struct memory %"PRIu64".", p, p->outstanding, p->max_buckets, (float)(p->outstanding/(float)(p->max_buckets))*100, p->max_outstanding, (float)(p->max_outstanding/(float)(p->max_buckets))*100, (uint64_t)(p->max_buckets * sizeof(PoolBucket))); } /* diff --git a/src/util-time.c b/src/util-time.c index d55328880d..4e27ba1183 100644 --- a/src/util-time.c +++ b/src/util-time.c @@ -11,12 +11,12 @@ static char live = TRUE; void TimeModeSetLive(void) { live = TRUE; - SCDebug("live time mode enabled"); + SCLogDebug("live time mode enabled"); } void TimeModeSetOffline (void) { live = FALSE; - SCDebug("offline time mode enabled"); + SCLogDebug("offline time mode enabled"); } void TimeSet(struct timeval *tv) { @@ -30,7 +30,7 @@ void TimeSet(struct timeval *tv) { current_time.tv_sec = tv->tv_sec; current_time.tv_usec = tv->tv_usec; - SCDebug("time set to %" PRIuMAX " sec, %" PRIuMAX " usec", + SCLogDebug("time set to %" PRIuMAX " sec, %" PRIuMAX " usec", (uintmax_t)current_time.tv_sec, (uintmax_t)current_time.tv_usec); mutex_unlock(¤t_time_mutex); @@ -49,7 +49,7 @@ void TimeGet(struct timeval *tv) { mutex_unlock(¤t_time_mutex); } - SCDebug("time we got is %" PRIuMAX " sec, %" PRIuMAX " usec", + SCLogDebug("time we got is %" PRIuMAX " sec, %" PRIuMAX " usec", (uintmax_t)tv->tv_sec, (uintmax_t)tv->tv_usec); }