Coverage Report

Created: 2026-08-14 07:34

next uncovered line (L), next uncovered region (R), next uncovered branch (B)
/src/suricata7/src/output-tx.c
Line
Count
Source
1
/* Copyright (C) 2007-2022 Open Information Security Foundation
2
 *
3
 * You can copy, redistribute or modify this Program under the terms of
4
 * the GNU General Public License version 2 as published by the Free
5
 * Software Foundation.
6
 *
7
 * This program is distributed in the hope that it will be useful,
8
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
9
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
10
 * GNU General Public License for more details.
11
 *
12
 * You should have received a copy of the GNU General Public License
13
 * version 2 along with this program; if not, write to the Free Software
14
 * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
15
 * 02110-1301, USA.
16
 */
17
18
/**
19
 * \file
20
 *
21
 * \author Victor Julien <victor@inliniac.net>
22
 *
23
 * AppLayer TX Logger Output registration functions
24
 */
25
26
#include "suricata-common.h"
27
#include "output.h"
28
#include "output-tx.h"
29
#include "stream.h"
30
#include "app-layer.h"
31
#include "app-layer-parser.h"
32
#include "util-profiling.h"
33
#include "util-validate.h"
34
35
/** per thread data for this module, contains a list of per thread
36
 *  data for the packet loggers. */
37
typedef struct OutputTxLoggerThreadData_ {
38
    OutputLoggerThreadStore *store[ALPROTO_MAX];
39
40
    /* thread local data from file api */
41
    OutputFileLoggerThreadData *file;
42
    /* thread local data from filedata api */
43
    OutputFiledataLoggerThreadData *filedata;
44
} OutputTxLoggerThreadData;
45
46
/* logger instance, a module + a output ctx,
47
 * it's perfectly valid that have multiple instances of the same
48
 * log module (e.g. http.log) with different output ctx'. */
49
typedef struct OutputTxLogger_ {
50
    AppProto alproto;
51
    TxLogger LogFunc;
52
    TxLoggerCondition LogCondition;
53
    OutputCtx *output_ctx;
54
    struct OutputTxLogger_ *next;
55
    const char *name;
56
    LoggerId logger_id;
57
    uint32_t id;
58
    int tc_log_progress;
59
    int ts_log_progress;
60
    TmEcode (*ThreadInit)(ThreadVars *, const void *, void **);
61
    TmEcode (*ThreadDeinit)(ThreadVars *, void *);
62
    void (*ThreadExitPrintStats)(ThreadVars *, void *);
63
} OutputTxLogger;
64
65
static OutputTxLogger *list[ALPROTO_MAX] = { NULL };
66
67
int OutputRegisterTxLogger(LoggerId id, const char *name, AppProto alproto,
68
                           TxLogger LogFunc,
69
                           OutputCtx *output_ctx, int tc_log_progress,
70
                           int ts_log_progress, TxLoggerCondition LogCondition,
71
                           ThreadInitFunc ThreadInit,
72
                           ThreadDeinitFunc ThreadDeinit,
73
                           void (*ThreadExitPrintStats)(ThreadVars *, void *))
74
46
{
75
46
    if (alproto != ALPROTO_UNKNOWN && !(AppLayerParserIsEnabled(alproto))) {
76
0
        SCLogDebug(
77
0
                "%s logger not enabled: protocol %s is disabled", name, AppProtoToString(alproto));
78
0
        return -1;
79
0
    }
80
46
    OutputTxLogger *op = SCMalloc(sizeof(*op));
81
46
    if (op == NULL)
82
0
        return -1;
83
46
    memset(op, 0x00, sizeof(*op));
84
85
46
    op->alproto = alproto;
86
46
    op->LogFunc = LogFunc;
87
46
    op->LogCondition = LogCondition;
88
46
    op->output_ctx = output_ctx;
89
46
    op->name = name;
90
46
    op->logger_id = id;
91
46
    op->ThreadInit = ThreadInit;
92
46
    op->ThreadDeinit = ThreadDeinit;
93
46
    op->ThreadExitPrintStats = ThreadExitPrintStats;
94
95
46
    if (alproto == ALPROTO_UNKNOWN) {
96
2
        op->tc_log_progress = 0;
97
44
    } else if (tc_log_progress < 0) {
98
40
        op->tc_log_progress =
99
40
            AppLayerParserGetStateProgressCompletionStatus(alproto,
100
40
                                                           STREAM_TOCLIENT);
101
40
    } else {
102
4
        op->tc_log_progress = tc_log_progress;
103
4
    }
104
105
46
    if (alproto == ALPROTO_UNKNOWN) {
106
2
        op->ts_log_progress = 0;
107
44
    } else if (ts_log_progress < 0) {
108
40
        op->ts_log_progress =
109
40
            AppLayerParserGetStateProgressCompletionStatus(alproto,
110
40
                                                           STREAM_TOSERVER);
111
40
    } else {
112
4
        op->ts_log_progress = ts_log_progress;
113
4
    }
114
115
46
    if (list[alproto] == NULL) {
116
40
        op->id = 1;
117
40
        list[alproto] = op;
118
40
    } else {
119
6
        OutputTxLogger *t = list[alproto];
120
8
        while (t->next)
121
2
            t = t->next;
122
6
        if (t->id * 2ULL > UINT32_MAX) {
123
0
            FatalError("Too many loggers registered.");
124
0
        }
125
6
        op->id = t->id * 2;
126
6
        t->next = op;
127
6
    }
128
129
46
    SCLogDebug("OutputRegisterTxLogger happy");
130
46
    return 0;
131
46
}
132
133
extern bool g_file_logger_enabled;
134
extern bool g_filedata_logger_enabled;
135
136
/** \brief run the per tx file logging
137
 *  \todo clean up various end of tx/stream etc indicators
138
 */
139
static inline void OutputTxLogFiles(ThreadVars *tv, OutputFileLoggerThreadData *file_td,
140
        OutputFiledataLoggerThreadData *filedata_td, Packet *p, Flow *f, void *tx,
141
        const uint64_t tx_id, AppLayerTxData *txd, const bool tx_complete, const bool ts_ready,
142
        const bool tc_ready, const bool ts_eof, const bool tc_eof, const bool eof)
143
24.9M
{
144
24.9M
    uint8_t packet_dir;
145
24.9M
    uint8_t opposing_dir;
146
24.9M
    bool packet_dir_ready;
147
24.9M
    const bool opposing_dir_ready = eof;
148
24.9M
    bool opposing_tx_ready;
149
24.9M
    if (p->flowflags & FLOW_PKT_TOSERVER) {
150
12.4M
        packet_dir = STREAM_TOSERVER;
151
12.4M
        opposing_dir = STREAM_TOCLIENT;
152
12.4M
        packet_dir_ready = eof | ts_ready | ts_eof;
153
12.4M
        opposing_tx_ready = tc_ready;
154
12.5M
    } else if (p->flowflags & FLOW_PKT_TOCLIENT) {
155
12.5M
        packet_dir = STREAM_TOCLIENT;
156
12.5M
        opposing_dir = STREAM_TOSERVER;
157
12.5M
        packet_dir_ready = eof | tc_ready | tc_eof;
158
12.5M
        opposing_tx_ready = ts_ready;
159
12.5M
    } else {
160
0
        abort();
161
0
    }
162
163
24.9M
    SCLogDebug("eof %d ts_ready %d ts_eof %d", eof, ts_ready, ts_eof);
164
24.9M
    SCLogDebug("eof %d tc_ready %d tc_eof %d", eof, tc_ready, tc_eof);
165
166
24.9M
    SCLogDebug("packet dir %s opposing %s packet_dir_ready %d opposing_dir_ready %d",
167
24.9M
            packet_dir == STREAM_TOSERVER ? "TOSERVER" : "TOCLIENT",
168
24.9M
            opposing_dir == STREAM_TOSERVER ? "TOSERVER" : "TOCLIENT", packet_dir_ready,
169
24.9M
            opposing_dir_ready);
170
171
24.9M
    AppLayerGetFileState app_files =
172
24.9M
            AppLayerParserGetTxFiles(f, FlowGetAppState(f), tx, packet_dir);
173
24.9M
    FileContainer *ffc = app_files.fc;
174
24.9M
    AppLayerGetFileState app_files_opposing =
175
24.9M
            AppLayerParserGetTxFiles(f, FlowGetAppState(f), tx, opposing_dir);
176
24.9M
    FileContainer *ffc_opposing = app_files_opposing.fc;
177
178
    /* see if opposing side is finished: if no file support in this direction, of is not
179
     * files and tx is done for opposing dir. */
180
24.9M
    bool opposing_finished =
181
24.9M
            ffc_opposing == NULL || (ffc_opposing->head == NULL && opposing_tx_ready);
182
24.9M
    SCLogDebug("opposing_finished %d ffc_opposing %p ffc_opposing->head %p opposing_tx_ready %d",
183
24.9M
            opposing_finished, ffc_opposing, ffc_opposing ? ffc_opposing->head : NULL,
184
24.9M
            opposing_tx_ready);
185
186
24.9M
    if (ffc || ffc_opposing)
187
24.9M
        SCLogDebug("pcap_cnt %" PRIu64 " flow %p tx %p tx_id %" PRIu64
188
24.9M
                   " ffc %p ffc_opposing %p tx_complete %d",
189
24.9M
                p->pcap_cnt, f, tx, tx_id, ffc, ffc_opposing, tx_complete);
190
191
24.9M
    if (ffc) {
192
24.9M
        const bool file_close = ((p->flags & PKT_PSEUDO_STREAM_END)) | eof;
193
24.9M
        const bool file_trunc = StreamTcpReassembleDepthReached(p) | eof;
194
24.9M
        SCLogDebug("tx: calling files: ffc %p head %p file_close %d file_trunc %d", ffc, ffc->head,
195
24.9M
                file_close, file_trunc);
196
24.9M
        if (filedata_td && txd->files_opened > txd->files_stored)
197
466k
            OutputFiledataLogFfc(tv, filedata_td, p, app_files, tx, tx_id, txd, packet_dir,
198
466k
                    file_close, file_trunc, packet_dir);
199
24.9M
        if (file_td && txd->files_opened > txd->files_logged)
200
466k
            OutputFileLogFfc(
201
466k
                    tv, file_td, p, ffc, tx, tx_id, txd, file_close, file_trunc, packet_dir);
202
24.9M
    }
203
    /* if EOF and we support files, do a final write out */
204
24.9M
    if (opposing_dir_ready && ffc_opposing != NULL) {
205
33.1k
        const bool file_close = ((p->flags & PKT_PSEUDO_STREAM_END)) | tx_complete | eof;
206
33.1k
        const bool file_trunc = StreamTcpReassembleDepthReached(p) | eof;
207
33.1k
        opposing_finished = true;
208
33.1k
        SCLogDebug("tx: calling for opposing direction files: file_close:%s file_trunc:%s",
209
33.1k
                file_close ? "true" : "false", file_trunc ? "true" : "false");
210
33.1k
        if (filedata_td && txd->files_opened > txd->files_stored)
211
843
            OutputFiledataLogFfc(tv, filedata_td, p, app_files_opposing, tx, tx_id, txd,
212
843
                    opposing_dir, file_close, file_trunc, opposing_dir);
213
33.1k
        if (file_td && txd->files_opened > txd->files_logged)
214
843
            OutputFileLogFfc(tv, file_td, p, ffc_opposing, tx, tx_id, txd, file_close, file_trunc,
215
843
                    opposing_dir);
216
33.1k
    }
217
218
24.9M
    const bool tx_done = packet_dir_ready && opposing_finished;
219
24.9M
    SCLogDebug("tx_done %d packet_dir_ready %d opposing_finished %d", tx_done, packet_dir_ready,
220
24.9M
            opposing_finished);
221
222
    /* if not a file tx or if tx is done, set logger flags so tx can move on */
223
24.9M
    const bool is_file_tx = (ffc != NULL || ffc_opposing != NULL);
224
24.9M
    if (!is_file_tx || tx_done) {
225
201k
        SCLogDebug("is_file_tx %d tx_done %d", is_file_tx, tx_done);
226
201k
        if (file_td) {
227
201k
            txd->logged.flags |= BIT_U32(LOGGER_FILE);
228
201k
            SCLogDebug("setting LOGGER_FILE => %08x", txd->logged.flags);
229
201k
        }
230
201k
        if (filedata_td) {
231
201k
            txd->logged.flags |= BIT_U32(LOGGER_FILEDATA);
232
201k
            SCLogDebug("setting LOGGER_FILEDATA => %08x", txd->logged.flags);
233
201k
        }
234
24.7M
    } else {
235
24.7M
        SCLogDebug("pcap_cnt %" PRIu64 " flow %p tx %p tx_id %" PRIu64
236
24.7M
                   " NOT SETTING FILE FLAGS ffc %p ffc_opposing %p tx_complete %d",
237
24.7M
                p->pcap_cnt, f, tx, tx_id, ffc, ffc_opposing, tx_complete);
238
24.7M
    }
239
24.9M
}
240
241
static void OutputTxLogList0(ThreadVars *tv, OutputTxLoggerThreadData *op_thread_data, Packet *p,
242
        Flow *f, void *tx, const uint64_t tx_id)
243
59.1M
{
244
59.1M
    const OutputTxLogger *logger = list[ALPROTO_UNKNOWN];
245
59.1M
    const OutputLoggerThreadStore *store = op_thread_data->store[ALPROTO_UNKNOWN];
246
247
59.1M
    DEBUG_VALIDATE_BUG_ON(logger == NULL && store != NULL);
248
59.1M
    DEBUG_VALIDATE_BUG_ON(logger != NULL && store == NULL);
249
59.1M
    DEBUG_VALIDATE_BUG_ON(logger == NULL && store == NULL);
250
251
118M
    while (logger && store) {
252
59.1M
        DEBUG_VALIDATE_BUG_ON(logger->LogFunc == NULL);
253
254
59.1M
        SCLogDebug("logger %p", logger);
255
256
        /* always invoke "wild card" tx loggers */
257
59.1M
        SCLogDebug("Logging tx_id %"PRIu64" to logger %d", tx_id, logger->logger_id);
258
59.1M
        PACKET_PROFILING_LOGGER_START(p, logger->logger_id);
259
59.1M
        logger->LogFunc(tv, store->thread_data, p, f, f->alstate, tx, tx_id);
260
59.1M
        PACKET_PROFILING_LOGGER_END(p, logger->logger_id);
261
262
59.1M
        logger = logger->next;
263
59.1M
        store = store->next;
264
265
59.1M
        DEBUG_VALIDATE_BUG_ON(logger == NULL && store != NULL);
266
59.1M
        DEBUG_VALIDATE_BUG_ON(logger != NULL && store == NULL);
267
59.1M
    }
268
59.1M
}
269
270
struct Ctx {
271
    uint32_t tx_logged_old;
272
    uint32_t tx_logged;
273
};
274
275
static void OutputTxLogCallLoggers(ThreadVars *tv, OutputTxLoggerThreadData *op_thread_data,
276
        const OutputTxLogger *logger, const OutputLoggerThreadStore *store, Packet *p, Flow *f,
277
        void *alstate, void *tx, const uint64_t tx_id, const AppProto alproto, const bool eof,
278
        const int tx_progress_ts, const int tx_progress_tc, struct Ctx *ctx)
279
28.5M
{
280
28.5M
    DEBUG_VALIDATE_BUG_ON(logger == NULL && store != NULL);
281
28.5M
    DEBUG_VALIDATE_BUG_ON(logger != NULL && store == NULL);
282
    // DEBUG_VALIDATE_BUG_ON(logger == NULL && store == NULL);
283
284
83.0M
    while (logger && store) {
285
54.4M
        DEBUG_VALIDATE_BUG_ON(logger->LogFunc == NULL);
286
54.4M
        DEBUG_VALIDATE_BUG_ON(logger->alproto != alproto);
287
288
54.4M
        SCLogDebug("logger %p, Alproto %d LogCondition %p, ts_log_progress %d "
289
54.4M
                   "tc_log_progress %d",
290
54.4M
                logger, logger->alproto, logger->LogCondition, logger->ts_log_progress,
291
54.4M
                logger->tc_log_progress);
292
54.4M
        if ((ctx->tx_logged_old & BIT_U32(logger->logger_id)) == 0) {
293
54.3M
            SCLogDebug("alproto match %d, logging tx_id %" PRIu64, logger->alproto, tx_id);
294
295
54.3M
            SCLogDebug("pcap_cnt %" PRIu64 ", tx_id %" PRIu64 " logger %d. EOF %s", p->pcap_cnt,
296
54.3M
                    tx_id, logger->logger_id, eof ? "true" : "false");
297
298
54.3M
            if (eof) {
299
122k
                SCLogDebug("EOF, so log now");
300
54.2M
            } else {
301
54.2M
                if (logger->LogCondition) {
302
832k
                    int r = logger->LogCondition(tv, p, alstate, tx, tx_id);
303
832k
                    if (r == FALSE) {
304
832k
                        SCLogDebug("conditions not met, not logging");
305
832k
                        goto next_logger;
306
832k
                    }
307
53.3M
                } else {
308
53.3M
                    if (tx_progress_tc < logger->tc_log_progress) {
309
46.1M
                        SCLogDebug("progress not far enough, not logging");
310
46.1M
                        goto next_logger;
311
46.1M
                    }
312
313
7.27M
                    if (tx_progress_ts < logger->ts_log_progress) {
314
6.73M
                        SCLogDebug("progress not far enough, not logging");
315
6.73M
                        goto next_logger;
316
6.73M
                    }
317
7.27M
                }
318
54.2M
            }
319
320
666k
            SCLogDebug("Logging tx_id %" PRIu64 " to logger %d", tx_id, logger->logger_id);
321
666k
            PACKET_PROFILING_LOGGER_START(p, logger->logger_id);
322
666k
            logger->LogFunc(tv, store->thread_data, p, f, alstate, tx, tx_id);
323
666k
            PACKET_PROFILING_LOGGER_END(p, logger->logger_id);
324
325
666k
            ctx->tx_logged |= BIT_U32(logger->logger_id);
326
666k
        }
327
328
54.4M
    next_logger:
329
54.4M
        logger = logger->next;
330
54.4M
        store = store->next;
331
332
54.4M
        DEBUG_VALIDATE_BUG_ON(logger == NULL && store != NULL);
333
54.4M
        DEBUG_VALIDATE_BUG_ON(logger != NULL && store == NULL);
334
54.4M
    }
335
28.5M
}
336
337
static TmEcode OutputTxLog(ThreadVars *tv, Packet *p, void *thread_data)
338
12.0M
{
339
12.0M
    DEBUG_VALIDATE_BUG_ON(thread_data == NULL);
340
12.0M
    if (p->flow == NULL)
341
2.20M
        return TM_ECODE_OK;
342
9.79M
    if (!PKT_IS_PSEUDOPKT(p) && p->app_update_direction == 0 &&
343
7.07M
            ((PKT_IS_TOSERVER(p) && (p->flow->flags & FLOW_TS_APP_UPDATED) == 0) ||
344
6.39M
                    (PKT_IS_TOCLIENT(p) && (p->flow->flags & FLOW_TC_APP_UPDATED) == 0))) {
345
6.39M
        SCLogDebug("not pseudo, no app update: skip");
346
6.39M
        return TM_ECODE_OK;
347
6.39M
    }
348
3.40M
    SCLogDebug("pseudo, or app update: run output");
349
350
3.40M
    OutputTxLoggerThreadData *op_thread_data = (OutputTxLoggerThreadData *)thread_data;
351
352
3.40M
    Flow * const f = p->flow;
353
3.40M
    const uint8_t ipproto = f->proto;
354
3.40M
    const AppProto alproto = f->alproto;
355
3.40M
    SCLogDebug("pcap_cnt %u tx logging %u/%s", (uint32_t)p->pcap_cnt, alproto,
356
3.40M
            AppProtoToString(alproto));
357
358
3.40M
    const bool file_logging_active = (op_thread_data->file || op_thread_data->filedata);
359
3.40M
    if (!file_logging_active) {
360
0
        if (list[alproto] == NULL && list[ALPROTO_UNKNOWN] == NULL) {
361
0
            SCLogDebug("bail");
362
            /* No child loggers registered. */
363
0
            return TM_ECODE_OK;
364
0
        }
365
0
        if (AppLayerParserProtocolHasLogger(ipproto, alproto) == 0)
366
0
            goto end;
367
0
    }
368
3.40M
    void *alstate = f->alstate;
369
3.40M
    if (alstate == NULL) {
370
181k
        SCLogDebug("no alstate");
371
181k
        goto end;
372
181k
    }
373
3.21M
    const LoggerId logger_expectation = AppLayerParserProtocolGetLoggerBits(ipproto, alproto);
374
3.21M
    if (logger_expectation == 0) {
375
296k
        SCLogDebug("bail: logger_expectation %u. LOGGER_FILE %u LOGGER_FILEDATA %u",
376
296k
                logger_expectation, LOGGER_FILE, LOGGER_FILEDATA);
377
296k
        goto end;
378
296k
    }
379
2.92M
    SCLogDebug("pcap_cnt %" PRIu64, p->pcap_cnt);
380
381
2.92M
    const bool last_pseudo = (p->flowflags & FLOW_PKT_LAST_PSEUDO) != 0;
382
2.92M
    const bool ts_eof = AppLayerParserStateIssetFlag(f->alparser,
383
2.92M
                                (APP_LAYER_PARSER_EOF_TS | APP_LAYER_PARSER_TRUNC_TS)) != 0;
384
2.92M
    const bool tc_eof = AppLayerParserStateIssetFlag(f->alparser,
385
2.92M
                                (APP_LAYER_PARSER_EOF_TC | APP_LAYER_PARSER_TRUNC_TC)) != 0;
386
387
2.92M
    const bool eof = last_pseudo || (ts_eof && tc_eof);
388
2.92M
    SCLogDebug("eof %d last_pseudo %d ts_eof %d tc_eof %d", eof, last_pseudo, ts_eof, tc_eof);
389
390
2.92M
    const uint8_t ts_disrupt_flags = FlowGetDisruptionFlags(f, STREAM_TOSERVER);
391
2.92M
    const uint8_t tc_disrupt_flags = FlowGetDisruptionFlags(f, STREAM_TOCLIENT);
392
2.92M
    SCLogDebug("ts_disrupt_flags %02x tc_disrupt_flags %02x", ts_disrupt_flags, tc_disrupt_flags);
393
2.92M
    const uint64_t total_txs = AppLayerParserGetTxCnt(f, alstate);
394
2.92M
    uint64_t tx_id = AppLayerParserGetTransactionLogId(f->alparser);
395
2.92M
    uint64_t max_id = tx_id;
396
2.92M
    int logged = 0;
397
2.92M
    bool gap = false;
398
2.92M
    const bool support_files = AppLayerParserSupportsFiles(ipproto, alproto);
399
2.92M
    const uint8_t pkt_dir = STREAM_FLAGS_FOR_PACKET(p);
400
401
2.92M
    SCLogDebug("pcap_cnt %" PRIu64 ": tx_id %" PRIu64 " total_txs %" PRIu64, p->pcap_cnt, tx_id,
402
2.92M
            total_txs);
403
404
2.92M
    AppLayerGetTxIteratorFunc IterFunc = AppLayerGetTxIterator(ipproto, alproto);
405
2.92M
    AppLayerGetTxIterState state;
406
2.92M
    memset(&state, 0, sizeof(state));
407
408
2.92M
    const int complete_ts =
409
2.92M
            AppLayerParserGetStateProgressCompletionStatus(alproto, STREAM_TOSERVER);
410
2.92M
    const int complete_tc =
411
2.92M
            AppLayerParserGetStateProgressCompletionStatus(alproto, STREAM_TOCLIENT);
412
30.0M
    while (1) {
413
30.0M
        AppLayerGetTxIterTuple ires = IterFunc(ipproto, alproto, alstate, tx_id, total_txs, &state);
414
30.0M
        if (ires.tx_ptr == NULL)
415
335k
            break;
416
29.7M
        void * const tx = ires.tx_ptr;
417
29.7M
        tx_id = ires.tx_id;
418
29.7M
        SCLogDebug("STARTING tx_id %" PRIu64 ", tx %p", tx_id, tx);
419
420
29.7M
        AppLayerTxData *txd = AppLayerParserGetTxData(ipproto, alproto, tx);
421
29.7M
        if (unlikely(txd == NULL)) {
422
0
            SCLogDebug("NO TXD");
423
            /* make sure this tx, which can't be properly logged is skipped */
424
0
            logged = 1;
425
0
            max_id = tx_id;
426
0
            goto next_tx;
427
0
        }
428
429
29.7M
        const int tx_progress_ts =
430
29.7M
                AppLayerParserGetStateProgress(ipproto, alproto, tx, ts_disrupt_flags);
431
29.7M
        const int tx_progress_tc =
432
29.7M
                AppLayerParserGetStateProgress(ipproto, alproto, tx, tc_disrupt_flags);
433
29.7M
        const bool tx_complete = (tx_progress_ts == complete_ts && tx_progress_tc == complete_tc);
434
435
29.7M
        SCLogDebug("file_thread_data %p filedata_thread_data %p", op_thread_data->file,
436
29.7M
                op_thread_data->filedata);
437
438
29.7M
        if (file_logging_active) {
439
29.7M
            if (AppLayerParserIsFileTx(txd)) { // need to process each tx that might be a file tx,
440
                                               // even if there are not files (yet)
441
25.1M
                const bool ts_ready = (tx_progress_ts == complete_ts);
442
25.1M
                const bool tc_ready = (tx_progress_tc == complete_tc);
443
25.1M
                SCLogDebug("ts_ready %d tc_ready %d", ts_ready, tc_ready);
444
445
25.1M
                const bool eval_files = ts_ready | tc_ready | tx_complete | ts_eof | tc_eof | eof;
446
447
25.1M
                SCLogDebug("eval_files: %u, ts_ready %u, tc_ready %u, tx_complete %u, ts_eof %u, "
448
25.1M
                           "tc_eof %u, eof %u",
449
25.1M
                        eval_files, ts_ready, tc_ready, tx_complete, ts_eof, tc_eof, eof);
450
25.1M
                SCLogDebug("txd->file_tx & pkt_dir: %02x & %02x -> %02x", txd->file_tx, pkt_dir,
451
25.1M
                        (txd->file_tx & pkt_dir));
452
453
                /* call only for the correct direction, except when it looks anything like a end of
454
                 * transaction or end of stream. Since OutputTxLogFiles has complicated logic around
455
                 * that, we just leave it to that function to sort things out for now. */
456
25.1M
                if (eval_files || AppLayerParserIsFileTxInDir(txd, pkt_dir)) {
457
24.9M
                    OutputTxLogFiles(tv, op_thread_data->file, op_thread_data->filedata, p, f, tx,
458
24.9M
                            tx_id, txd, tx_complete, ts_ready, tc_ready, ts_eof, tc_eof, eof);
459
24.9M
                }
460
25.1M
            } else if (support_files) {
461
3.18M
                if (op_thread_data->file) {
462
3.18M
                    txd->logged.flags |= BIT_U32(LOGGER_FILE);
463
3.18M
                    SCLogDebug("not a file_tx: setting LOGGER_FILE => %08x", txd->logged.flags);
464
3.18M
                }
465
3.18M
                if (op_thread_data->filedata) {
466
3.18M
                    txd->logged.flags |= BIT_U32(LOGGER_FILEDATA);
467
3.18M
                    SCLogDebug("not a file_tx: setting LOGGER_FILEDATA => %08x", txd->logged.flags);
468
3.18M
                }
469
3.18M
            }
470
29.7M
        }
471
29.7M
        SCLogDebug("logger: expect %08x, have %08x", logger_expectation, txd->logged.flags);
472
29.7M
        if (!txd->updated_tc && !txd->updated_ts && !(tx_progress_ts == complete_ts) &&
473
3.99M
                !(tx_progress_tc == complete_tc) && !ts_eof && !tc_eof) {
474
679k
            gap = true;
475
679k
            goto next_tx;
476
679k
        }
477
478
29.0M
        if (list[ALPROTO_UNKNOWN] != 0) {
479
29.0M
            OutputTxLogList0(tv, op_thread_data, p, f, tx, tx_id);
480
29.0M
            if (list[alproto] == NULL)
481
74.3k
                goto next_tx;
482
29.0M
        }
483
484
28.9M
        SCLogDebug("tx %p/%" PRIu64 " txd %p: log_flags %x logger_expectation %x", tx, tx_id, txd,
485
28.9M
                txd->config.log_flags, logger_expectation);
486
28.9M
        if (txd->config.log_flags & BIT_U8(CONFIG_TYPE_TX)) {
487
614
            SCLogDebug("SKIP tx %p/%"PRIu64, tx, tx_id);
488
            // so that AppLayerParserTransactionsCleanup can clean this tx
489
614
            txd->logged.flags |= logger_expectation;
490
614
            goto next_tx;
491
614
        }
492
493
28.9M
        if (txd->logged.flags == logger_expectation) {
494
417k
            SCLogDebug("fully logged");
495
            /* tx already fully logged */
496
417k
            goto next_tx;
497
417k
        }
498
499
28.5M
        SCLogDebug("logger: expect %08x, have %08x", logger_expectation, txd->logged.flags);
500
28.5M
        const OutputTxLogger *logger = list[alproto];
501
28.5M
        const OutputLoggerThreadStore *store = op_thread_data->store[alproto];
502
28.5M
        struct Ctx ctx = { .tx_logged = txd->logged.flags, .tx_logged_old = txd->logged.flags };
503
28.5M
        SCLogDebug("logger: expect %08x, have %08x", logger_expectation, ctx.tx_logged);
504
505
28.5M
        OutputTxLogCallLoggers(tv, op_thread_data, logger, store, p, f, alstate, tx, tx_id, alproto,
506
28.5M
                eof, tx_progress_ts, tx_progress_tc, &ctx);
507
508
28.5M
        SCLogDebug("logger: expect %08x, have %08x", logger_expectation, ctx.tx_logged);
509
28.5M
        if (ctx.tx_logged != ctx.tx_logged_old) {
510
549k
            SCLogDebug("logger: storing %08x (was %08x)", ctx.tx_logged, ctx.tx_logged_old);
511
549k
            DEBUG_VALIDATE_BUG_ON(txd == NULL);
512
549k
            txd->logged.flags |= ctx.tx_logged;
513
549k
        }
514
515
        /* If all loggers logged set a flag and update the last tx_id
516
         * that was logged.
517
         *
518
         * If not all loggers were logged we flag that there was a gap
519
         * so any subsequent transactions in this loop don't increase
520
         * the maximum ID that was logged. */
521
28.5M
        if (!gap && ctx.tx_logged == logger_expectation) {
522
427k
            SCLogDebug("no gap %d, %08x == %08x", gap, ctx.tx_logged, logger_expectation);
523
427k
            logged = 1;
524
427k
            max_id = tx_id;
525
427k
            SCLogDebug("max_id %" PRIu64, max_id);
526
28.1M
        } else {
527
28.1M
            gap = true;
528
28.1M
        }
529
29.7M
next_tx:
530
29.7M
        if (!ires.has_next)
531
2.58M
            break;
532
27.1M
        tx_id++;
533
27.1M
    }
534
535
    /* Update the last ID that has been logged with all
536
     * transactions before it. */
537
2.92M
    if (logged) {
538
376k
        SCLogDebug("updating log tx_id %"PRIu64, max_id);
539
376k
        AppLayerParserSetTransactionLogId(f->alparser, max_id + 1);
540
376k
    }
541
542
3.40M
end:
543
3.40M
    return TM_ECODE_OK;
544
2.92M
}
545
546
/** \brief thread init for the tx logger
547
 *  This will run the thread init functions for the individual registered
548
 *  loggers */
549
static TmEcode OutputTxLogThreadInit(ThreadVars *tv, const void *_initdata, void **data)
550
4
{
551
4
    OutputTxLoggerThreadData *td = SCMalloc(sizeof(*td));
552
4
    if (td == NULL)
553
0
        return TM_ECODE_FAILED;
554
4
    memset(td, 0x00, sizeof(*td));
555
556
4
    *data = (void *)td;
557
4
    SCLogDebug("OutputTxLogThreadInit happy (*data %p)", *data);
558
559
156
    for (AppProto alproto = 0; alproto < ALPROTO_MAX; alproto++) {
560
152
        OutputTxLogger *logger = list[alproto];
561
240
        while (logger) {
562
88
            if (logger->ThreadInit) {
563
88
                void *retptr = NULL;
564
88
                if (logger->ThreadInit(tv, (void *)logger->output_ctx, &retptr) == TM_ECODE_OK) {
565
88
                    OutputLoggerThreadStore *ts = SCMalloc(sizeof(*ts));
566
88
    /* todo */      BUG_ON(ts == NULL);
567
88
                    memset(ts, 0x00, sizeof(*ts));
568
569
                    /* store thread handle */
570
88
                    ts->thread_data = retptr;
571
572
88
                    if (td->store[alproto] == NULL) {
573
80
                        td->store[alproto] = ts;
574
80
                    } else {
575
8
                        OutputLoggerThreadStore *tmp = td->store[alproto];
576
10
                        while (tmp->next != NULL)
577
2
                            tmp = tmp->next;
578
8
                        tmp->next = ts;
579
8
                    }
580
581
88
                    SCLogDebug("%s is now set up", logger->name);
582
88
                }
583
88
            }
584
585
88
            logger = logger->next;
586
88
        }
587
152
    }
588
589
4
    if (g_file_logger_enabled) {
590
4
        if (OutputFileLogThreadInit(tv, &td->file) != TM_ECODE_OK) {
591
0
            FatalError("failed to set up file thread data");
592
0
        }
593
4
    }
594
4
    if (g_filedata_logger_enabled) {
595
4
        if (OutputFiledataLogThreadInit(tv, &td->filedata) != TM_ECODE_OK) {
596
0
            FatalError("failed to set up filedata thread data");
597
0
        }
598
4
    }
599
600
4
    SCLogDebug("file_thread_data %p filedata_thread_data %p", td->file, td->filedata);
601
602
4
    return TM_ECODE_OK;
603
4
}
604
605
static TmEcode OutputTxLogThreadDeinit(ThreadVars *tv, void *thread_data)
606
0
{
607
0
    OutputTxLoggerThreadData *op_thread_data = (OutputTxLoggerThreadData *)thread_data;
608
609
0
    for (AppProto alproto = 0; alproto < ALPROTO_MAX; alproto++) {
610
0
        OutputLoggerThreadStore *store = op_thread_data->store[alproto];
611
0
        OutputTxLogger *logger = list[alproto];
612
613
0
        while (logger && store) {
614
0
            if (logger->ThreadDeinit) {
615
0
                logger->ThreadDeinit(tv, store->thread_data);
616
0
            }
617
618
0
            OutputLoggerThreadStore *next_store = store->next;
619
0
            SCFree(store);
620
0
            store = next_store;
621
0
            logger = logger->next;
622
0
        }
623
0
    }
624
625
0
    if (op_thread_data->file) {
626
0
        OutputFileLogThreadDeinit(tv, op_thread_data->file);
627
0
    }
628
0
    if (op_thread_data->filedata) {
629
0
        OutputFiledataLogThreadDeinit(tv, op_thread_data->filedata);
630
0
    }
631
632
0
    SCFree(op_thread_data);
633
0
    return TM_ECODE_OK;
634
0
}
635
636
static void OutputTxLogExitPrintStats(ThreadVars *tv, void *thread_data)
637
0
{
638
0
    OutputTxLoggerThreadData *op_thread_data = (OutputTxLoggerThreadData *)thread_data;
639
640
0
    for (AppProto alproto = 0; alproto < ALPROTO_MAX; alproto++) {
641
0
        OutputLoggerThreadStore *store = op_thread_data->store[alproto];
642
0
        OutputTxLogger *logger = list[alproto];
643
644
0
        while (logger && store) {
645
0
            if (logger->ThreadExitPrintStats) {
646
0
                logger->ThreadExitPrintStats(tv, store->thread_data);
647
0
            }
648
649
0
            logger = logger->next;
650
0
            store = store->next;
651
0
        }
652
0
    }
653
0
}
654
655
static uint32_t OutputTxLoggerGetActiveCount(void)
656
2
{
657
2
    uint32_t cnt = 0;
658
72
    for (AppProto alproto = 0; alproto < ALPROTO_MAX; alproto++) {
659
116
        for (OutputTxLogger *p = list[alproto]; p != NULL; p = p->next) {
660
46
            cnt++;
661
46
        }
662
70
    }
663
664
2
    if (g_file_logger_enabled) {
665
2
        cnt++;
666
2
        SCLogDebug("g_file_logger_enabled");
667
2
    }
668
2
    if (g_filedata_logger_enabled) {
669
2
        cnt++;
670
2
        SCLogDebug("g_filedata_logger_enabled");
671
2
    }
672
673
2
    return cnt;
674
2
}
675
676
677
void OutputTxLoggerRegister (void)
678
33
{
679
33
    OutputRegisterRootLogger(OutputTxLogThreadInit, OutputTxLogThreadDeinit,
680
33
        OutputTxLogExitPrintStats, OutputTxLog, OutputTxLoggerGetActiveCount);
681
33
}
682
683
void OutputTxShutdown(void)
684
0
{
685
0
    for (AppProto alproto = 0; alproto < ALPROTO_MAX; alproto++) {
686
0
        OutputTxLogger *logger = list[alproto];
687
0
        while (logger) {
688
0
            OutputTxLogger *next_logger = logger->next;
689
0
            SCFree(logger);
690
0
            logger = next_logger;
691
0
        }
692
        list[alproto] = NULL;
693
0
    }
694
0
}