From: Victor Julien Date: Thu, 12 Jan 2023 14:13:43 +0000 (+0100) Subject: stream: add debug statements X-Git-Tag: suricata-7.0.0-rc1~160 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=ef2ed35311a282bb345a340166c3e42e2eac7e04;p=thirdparty%2Fsuricata.git stream: add debug statements --- diff --git a/src/stream-tcp-list.c b/src/stream-tcp-list.c index 1c26ff6cc4..2fae335b34 100644 --- a/src/stream-tcp-list.c +++ b/src/stream-tcp-list.c @@ -1,4 +1,4 @@ -/* Copyright (C) 2007-2022 Open Information Security Foundation +/* Copyright (C) 2007-2023 Open Information Security Foundation * * You can copy, redistribute or modify this Program under the terms of * the GNU General Public License version 2 as published by the Free @@ -772,7 +772,8 @@ static inline uint64_t GetLeftEdge(Flow *f, TcpSession *ssn, TcpStream *stream) const bool use_app = !(ssn->flags & STREAMTCP_FLAG_APP_LAYER_DISABLED); const bool use_raw = !(stream->flags & STREAMTCP_STREAM_FLAG_DISABLE_RAW); const bool use_log = stream_config.streaming_log_api; - SCLogDebug("use_app %d use_raw %d use_log %d", use_app, use_raw, use_log); + SCLogDebug("use_app %d use_raw %d use_log %d tcp win %u", use_app, use_raw, use_log, + stream->window); if (use_raw) { uint64_t raw_progress = STREAM_RAW_PROGRESS(stream); @@ -927,6 +928,7 @@ void StreamTcpPruneSession(Flow *f, uint8_t flags) } const uint64_t left_edge = GetLeftEdge(f, ssn, stream); + SCLogDebug("buffer left_edge %" PRIu64, left_edge); if (left_edge && left_edge > STREAM_BASE_OFFSET(stream)) { uint32_t slide = left_edge - STREAM_BASE_OFFSET(stream); SCLogDebug("buffer sliding %u to offset %"PRIu64, slide, left_edge); diff --git a/src/stream-tcp-reassemble.c b/src/stream-tcp-reassemble.c index e47e479a6c..e50f44eac8 100644 --- a/src/stream-tcp-reassemble.c +++ b/src/stream-tcp-reassemble.c @@ -223,13 +223,16 @@ static void *ReassembleCalloc(size_t n, size_t size) void *StreamTcpReassembleRealloc(void *optr, size_t orig_size, size_t size) { if (size > orig_size) { - if (StreamTcpReassembleCheckMemcap(size - orig_size) == 0) + if (StreamTcpReassembleCheckMemcap(size - orig_size) == 0) { + SCLogDebug("memcap hit at %" PRIu64, SC_ATOMIC_GET(stream_config.reassembly_memcap)); return NULL; + } } void *nptr = SCRealloc(optr, size); - if (nptr == NULL) + if (nptr == NULL) { + SCLogDebug("realloc fail"); return NULL; - + } if (size > orig_size) { StreamTcpReassembleIncrMemuse(size - orig_size); } else { @@ -250,6 +253,7 @@ static void ReassembleFree(void *ptr, size_t size) /** \brief alloc a tcp segment pool entry */ static void *TcpSegmentPoolAlloc(void) { + SCLogDebug("segment alloc"); if (StreamTcpReassembleCheckMemcap((uint32_t)sizeof(TcpSegment)) == 0) { return NULL; } @@ -1048,6 +1052,7 @@ static bool GetAppBuffer(const TcpStream *stream, const uint8_t **data, uint32_t *data = mydata; *data_len = mydata_len; } else { + SCLogDebug("block mode"); StreamingBufferBlock *blk = GetBlock(&stream->sb, offset); if (blk == NULL) { *data = NULL; @@ -1058,6 +1063,7 @@ static bool GetAppBuffer(const TcpStream *stream, const uint8_t **data, uint32_t /* block at expected offset */ if (blk->offset == offset) { + SCLogDebug("blk at offset"); StreamingBufferSBBGetData(&stream->sb, blk, data, data_len); @@ -1184,8 +1190,11 @@ static int ReassembleUpdateAppLayer (ThreadVars *tv, uint64_t app_progress = STREAM_APP_PROGRESS(*stream); SCLogDebug("app progress %"PRIu64, app_progress); - SCLogDebug("last_ack %u, base_seq %u", (*stream)->last_ack, (*stream)->base_seq); - +#ifdef DEBUG + uint64_t last_ack_abs = GetAbsLastAck(*stream); + SCLogDebug("last_ack %u (abs %" PRIu64 "), base_seq %u", (*stream)->last_ack, last_ack_abs, + (*stream)->base_seq); +#endif const uint8_t *mydata; uint32_t mydata_len; bool last_was_gap = false; @@ -1195,6 +1204,7 @@ static int ReassembleUpdateAppLayer (ThreadVars *tv, bool check_for_gap_ahead = ((*stream)->data_required > 0); bool gap_ahead = GetAppBuffer(*stream, &mydata, &mydata_len, app_progress, check_for_gap_ahead); + SCLogDebug("gap_ahead %s mydata_len %u", BOOL2STR(gap_ahead), mydata_len); if (last_was_gap && mydata_len == 0) { break; } @@ -1237,11 +1247,13 @@ static int ReassembleUpdateAppLayer (ThreadVars *tv, continue; } else if (flags & STREAM_DEPTH) { + SCLogDebug("DEPTH"); // we're just called once with this flag, so make sure we pass it on if (mydata == NULL && mydata_len > 0) { mydata_len = 0; } } else if (mydata == NULL || (mydata_len == 0 && ((flags & STREAM_EOF) == 0))) { + SCLogDebug("GAP?1"); /* Possibly a gap, but no new data. */ if ((p->flags & PKT_PSEUDO_STREAM_END) == 0 || ssn->state < TCP_CLOSED) SCReturnInt(0); @@ -1257,7 +1269,9 @@ static int ReassembleUpdateAppLayer (ThreadVars *tv, *stream, &(*stream)->sb, mydata_len, app_progress); if ((p->flags & PKT_PSEUDO_STREAM_END) == 0 || ssn->state < TCP_CLOSED) { + SCLogDebug("GAP?2"); if (mydata_len < (*stream)->data_required) { + SCLogDebug("GAP?3 gap_head %s", BOOL2STR(gap_ahead)); if (gap_ahead) { SCLogDebug("GAP while expecting more data (expect %u, gap size %u)", (*stream)->data_required, mydata_len); @@ -1274,6 +1288,7 @@ static int ReassembleUpdateAppLayer (ThreadVars *tv, } (*stream)->data_required = 0; + SCLogDebug("parser"); /* update the app-layer */ (void)AppLayerHandleTCPData(tv, ra_ctx, p, p->flow, ssn, stream, (uint8_t *)mydata, mydata_len, flags); diff --git a/src/stream-tcp.c b/src/stream-tcp.c index 50aad5390b..b805a0893a 100644 --- a/src/stream-tcp.c +++ b/src/stream-tcp.c @@ -6073,8 +6073,10 @@ void StreamTcpUpdateAppLayerProgress(TcpSession *ssn, char direction, { if (direction) { ssn->server.app_progress_rel += progress; + SCLogDebug("progress now %" PRIu64, STREAM_APP_PROGRESS(&ssn->server)); } else { ssn->client.app_progress_rel += progress; + SCLogDebug("progress now %" PRIu64, STREAM_APP_PROGRESS(&ssn->client)); } }