Coverage Report

Created: 2026-02-14 06:42

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
21.3M
{
144
21.3M
    uint8_t packet_dir;
145
21.3M
    uint8_t opposing_dir;
146
21.3M
    bool packet_dir_ready;
147
21.3M
    const bool opposing_dir_ready = eof;
148
21.3M
    bool opposing_tx_ready;
149
21.3M
    if (p->flowflags & FLOW_PKT_TOSERVER) {
150
10.6M
        packet_dir = STREAM_TOSERVER;
151
10.6M
        opposing_dir = STREAM_TOCLIENT;
152
10.6M
        packet_dir_ready = eof | ts_ready | ts_eof;
153
10.6M
        opposing_tx_ready = tc_ready;
154
10.7M
    } else if (p->flowflags & FLOW_PKT_TOCLIENT) {
155
10.7M
        packet_dir = STREAM_TOCLIENT;
156
10.7M
        opposing_dir = STREAM_TOSERVER;
157
10.7M
        packet_dir_ready = eof | tc_ready | tc_eof;
158
10.7M
        opposing_tx_ready = ts_ready;
159
10.7M
    } else {
160
0
        abort();
161
0
    }
162
163
21.3M
    SCLogDebug("eof %d ts_ready %d ts_eof %d", eof, ts_ready, ts_eof);
164
21.3M
    SCLogDebug("eof %d tc_ready %d tc_eof %d", eof, tc_ready, tc_eof);
165
166
21.3M
    SCLogDebug("packet dir %s opposing %s packet_dir_ready %d opposing_dir_ready %d",
167
21.3M
            packet_dir == STREAM_TOSERVER ? "TOSERVER" : "TOCLIENT",
168
21.3M
            opposing_dir == STREAM_TOSERVER ? "TOSERVER" : "TOCLIENT", packet_dir_ready,
169
21.3M
            opposing_dir_ready);
170
171
21.3M
    AppLayerGetFileState app_files =
172
21.3M
            AppLayerParserGetTxFiles(f, FlowGetAppState(f), tx, packet_dir);
173
21.3M
    FileContainer *ffc = app_files.fc;
174
21.3M
    AppLayerGetFileState app_files_opposing =
175
21.3M
            AppLayerParserGetTxFiles(f, FlowGetAppState(f), tx, opposing_dir);
176
21.3M
    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
21.3M
    bool opposing_finished =
181
21.3M
            ffc_opposing == NULL || (ffc_opposing->head == NULL && opposing_tx_ready);
182
21.3M
    SCLogDebug("opposing_finished %d ffc_opposing %p ffc_opposing->head %p opposing_tx_ready %d",
183
21.3M
            opposing_finished, ffc_opposing, ffc_opposing ? ffc_opposing->head : NULL,
184
21.3M
            opposing_tx_ready);
185
186
21.3M
    if (ffc || ffc_opposing)
187
21.3M
        SCLogDebug("pcap_cnt %" PRIu64 " flow %p tx %p tx_id %" PRIu64
188
21.3M
                   " ffc %p ffc_opposing %p tx_complete %d",
189
21.3M
                p->pcap_cnt, f, tx, tx_id, ffc, ffc_opposing, tx_complete);
190
191
21.3M
    if (ffc) {
192
21.3M
        const bool file_close = ((p->flags & PKT_PSEUDO_STREAM_END)) | eof;
193
21.3M
        const bool file_trunc = StreamTcpReassembleDepthReached(p) | eof;
194
21.3M
        SCLogDebug("tx: calling files: ffc %p head %p file_close %d file_trunc %d", ffc, ffc->head,
195
21.3M
                file_close, file_trunc);
196
21.3M
        if (filedata_td && txd->files_opened > txd->files_stored)
197
788k
            OutputFiledataLogFfc(tv, filedata_td, p, app_files, tx, tx_id, txd, packet_dir,
198
788k
                    file_close, file_trunc, packet_dir);
199
21.3M
        if (file_td && txd->files_opened > txd->files_logged)
200
788k
            OutputFileLogFfc(
201
788k
                    tv, file_td, p, ffc, tx, tx_id, txd, file_close, file_trunc, packet_dir);
202
21.3M
    }
203
    /* if EOF and we support files, do a final write out */
204
21.3M
    if (opposing_dir_ready && ffc_opposing != NULL) {
205
28.5k
        const bool file_close = ((p->flags & PKT_PSEUDO_STREAM_END)) | tx_complete | eof;
206
28.5k
        const bool file_trunc = StreamTcpReassembleDepthReached(p) | eof;
207
28.5k
        opposing_finished = true;
208
28.5k
        SCLogDebug("tx: calling for opposing direction files: file_close:%s file_trunc:%s",
209
28.5k
                file_close ? "true" : "false", file_trunc ? "true" : "false");
210
28.5k
        if (filedata_td && txd->files_opened > txd->files_stored)
211
1.01k
            OutputFiledataLogFfc(tv, filedata_td, p, app_files_opposing, tx, tx_id, txd,
212
1.01k
                    opposing_dir, file_close, file_trunc, opposing_dir);
213
28.5k
        if (file_td && txd->files_opened > txd->files_logged)
214
1.01k
            OutputFileLogFfc(tv, file_td, p, ffc_opposing, tx, tx_id, txd, file_close, file_trunc,
215
1.01k
                    opposing_dir);
216
28.5k
    }
217
218
21.3M
    const bool tx_done = packet_dir_ready && opposing_finished;
219
21.3M
    SCLogDebug("tx_done %d packet_dir_ready %d opposing_finished %d", tx_done, packet_dir_ready,
220
21.3M
            opposing_finished);
221
222
    /* if not a file tx or if tx is done, set logger flags so tx can move on */
223
21.3M
    const bool is_file_tx = (ffc != NULL || ffc_opposing != NULL);
224
21.3M
    if (!is_file_tx || tx_done) {
225
100k
        SCLogDebug("is_file_tx %d tx_done %d", is_file_tx, tx_done);
226
100k
        if (file_td) {
227
100k
            txd->logged.flags |= BIT_U32(LOGGER_FILE);
228
100k
            SCLogDebug("setting LOGGER_FILE => %08x", txd->logged.flags);
229
100k
        }
230
100k
        if (filedata_td) {
231
100k
            txd->logged.flags |= BIT_U32(LOGGER_FILEDATA);
232
100k
            SCLogDebug("setting LOGGER_FILEDATA => %08x", txd->logged.flags);
233
100k
        }
234
21.2M
    } else {
235
21.2M
        SCLogDebug("pcap_cnt %" PRIu64 " flow %p tx %p tx_id %" PRIu64
236
21.2M
                   " NOT SETTING FILE FLAGS ffc %p ffc_opposing %p tx_complete %d",
237
21.2M
                p->pcap_cnt, f, tx, tx_id, ffc, ffc_opposing, tx_complete);
238
21.2M
    }
239
21.3M
}
240
241
static void OutputTxLogList0(ThreadVars *tv, OutputTxLoggerThreadData *op_thread_data, Packet *p,
242
        Flow *f, void *tx, const uint64_t tx_id)
243
56.3M
{
244
56.3M
    const OutputTxLogger *logger = list[ALPROTO_UNKNOWN];
245
56.3M
    const OutputLoggerThreadStore *store = op_thread_data->store[ALPROTO_UNKNOWN];
246
247
56.3M
    DEBUG_VALIDATE_BUG_ON(logger == NULL && store != NULL);
248
56.3M
    DEBUG_VALIDATE_BUG_ON(logger != NULL && store == NULL);
249
56.3M
    DEBUG_VALIDATE_BUG_ON(logger == NULL && store == NULL);
250
251
112M
    while (logger && store) {
252
56.3M
        DEBUG_VALIDATE_BUG_ON(logger->LogFunc == NULL);
253
254
56.3M
        SCLogDebug("logger %p", logger);
255
256
        /* always invoke "wild card" tx loggers */
257
56.3M
        SCLogDebug("Logging tx_id %"PRIu64" to logger %d", tx_id, logger->logger_id);
258
56.3M
        PACKET_PROFILING_LOGGER_START(p, logger->logger_id);
259
56.3M
        logger->LogFunc(tv, store->thread_data, p, f, f->alstate, tx, tx_id);
260
56.3M
        PACKET_PROFILING_LOGGER_END(p, logger->logger_id);
261
262
56.3M
        logger = logger->next;
263
56.3M
        store = store->next;
264
265
56.3M
        DEBUG_VALIDATE_BUG_ON(logger == NULL && store != NULL);
266
56.3M
        DEBUG_VALIDATE_BUG_ON(logger != NULL && store == NULL);
267
56.3M
    }
268
56.3M
}
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
22.7M
{
280
22.7M
    DEBUG_VALIDATE_BUG_ON(logger == NULL && store != NULL);
281
22.7M
    DEBUG_VALIDATE_BUG_ON(logger != NULL && store == NULL);
282
    // DEBUG_VALIDATE_BUG_ON(logger == NULL && store == NULL);
283
284
65.8M
    while (logger && store) {
285
43.1M
        DEBUG_VALIDATE_BUG_ON(logger->LogFunc == NULL);
286
43.1M
        DEBUG_VALIDATE_BUG_ON(logger->alproto != alproto);
287
288
43.1M
        SCLogDebug("logger %p, Alproto %d LogCondition %p, ts_log_progress %d "
289
43.1M
                   "tc_log_progress %d",
290
43.1M
                logger, logger->alproto, logger->LogCondition, logger->ts_log_progress,
291
43.1M
                logger->tc_log_progress);
292
43.1M
        if ((ctx->tx_logged_old & BIT_U32(logger->logger_id)) == 0) {
293
43.0M
            SCLogDebug("alproto match %d, logging tx_id %" PRIu64, logger->alproto, tx_id);
294
295
43.0M
            SCLogDebug("pcap_cnt %" PRIu64 ", tx_id %" PRIu64 " logger %d. EOF %s", p->pcap_cnt,
296
43.0M
                    tx_id, logger->logger_id, eof ? "true" : "false");
297
298
43.0M
            if (eof) {
299
105k
                SCLogDebug("EOF, so log now");
300
42.9M
            } else {
301
42.9M
                if (logger->LogCondition) {
302
570k
                    int r = logger->LogCondition(tv, p, alstate, tx, tx_id);
303
570k
                    if (r == FALSE) {
304
570k
                        SCLogDebug("conditions not met, not logging");
305
570k
                        goto next_logger;
306
570k
                    }
307
42.3M
                } else {
308
42.3M
                    if (tx_progress_tc < logger->tc_log_progress) {
309
35.7M
                        SCLogDebug("progress not far enough, not logging");
310
35.7M
                        goto next_logger;
311
35.7M
                    }
312
313
6.60M
                    if (tx_progress_ts < logger->ts_log_progress) {
314
6.28M
                        SCLogDebug("progress not far enough, not logging");
315
6.28M
                        goto next_logger;
316
6.28M
                    }
317
6.60M
                }
318
42.9M
            }
319
320
420k
            SCLogDebug("Logging tx_id %" PRIu64 " to logger %d", tx_id, logger->logger_id);
321
420k
            PACKET_PROFILING_LOGGER_START(p, logger->logger_id);
322
420k
            logger->LogFunc(tv, store->thread_data, p, f, alstate, tx, tx_id);
323
420k
            PACKET_PROFILING_LOGGER_END(p, logger->logger_id);
324
325
420k
            ctx->tx_logged |= BIT_U32(logger->logger_id);
326
420k
        }
327
328
43.1M
    next_logger:
329
43.1M
        logger = logger->next;
330
43.1M
        store = store->next;
331
332
43.1M
        DEBUG_VALIDATE_BUG_ON(logger == NULL && store != NULL);
333
43.1M
        DEBUG_VALIDATE_BUG_ON(logger != NULL && store == NULL);
334
43.1M
    }
335
22.7M
}
336
337
static TmEcode OutputTxLog(ThreadVars *tv, Packet *p, void *thread_data)
338
9.54M
{
339
9.54M
    DEBUG_VALIDATE_BUG_ON(thread_data == NULL);
340
9.54M
    if (p->flow == NULL)
341
1.83M
        return TM_ECODE_OK;
342
7.70M
    if (!PKT_IS_PSEUDOPKT(p) && p->app_update_direction == 0 &&
343
5.82M
            ((PKT_IS_TOSERVER(p) && (p->flow->flags & FLOW_TS_APP_UPDATED) == 0) ||
344
5.29M
                    (PKT_IS_TOCLIENT(p) && (p->flow->flags & FLOW_TC_APP_UPDATED) == 0))) {
345
5.29M
        SCLogDebug("not pseudo, no app update: skip");
346
5.29M
        return TM_ECODE_OK;
347
5.29M
    }
348
2.40M
    SCLogDebug("pseudo, or app update: run output");
349
350
2.40M
    OutputTxLoggerThreadData *op_thread_data = (OutputTxLoggerThreadData *)thread_data;
351
352
2.40M
    Flow * const f = p->flow;
353
2.40M
    const uint8_t ipproto = f->proto;
354
2.40M
    const AppProto alproto = f->alproto;
355
2.40M
    SCLogDebug("pcap_cnt %u tx logging %u/%s", (uint32_t)p->pcap_cnt, alproto,
356
2.40M
            AppProtoToString(alproto));
357
358
2.40M
    const bool file_logging_active = (op_thread_data->file || op_thread_data->filedata);
359
2.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
2.40M
    void *alstate = f->alstate;
369
2.40M
    if (alstate == NULL) {
370
108k
        SCLogDebug("no alstate");
371
108k
        goto end;
372
108k
    }
373
2.30M
    const LoggerId logger_expectation = AppLayerParserProtocolGetLoggerBits(ipproto, alproto);
374
2.30M
    if (logger_expectation == 0) {
375
266k
        SCLogDebug("bail: logger_expectation %u. LOGGER_FILE %u LOGGER_FILEDATA %u",
376
266k
                logger_expectation, LOGGER_FILE, LOGGER_FILEDATA);
377
266k
        goto end;
378
266k
    }
379
2.03M
    SCLogDebug("pcap_cnt %" PRIu64, p->pcap_cnt);
380
381
2.03M
    const bool last_pseudo = (p->flowflags & FLOW_PKT_LAST_PSEUDO) != 0;
382
2.03M
    const bool ts_eof = AppLayerParserStateIssetFlag(f->alparser,
383
2.03M
                                (APP_LAYER_PARSER_EOF_TS | APP_LAYER_PARSER_TRUNC_TS)) != 0;
384
2.03M
    const bool tc_eof = AppLayerParserStateIssetFlag(f->alparser,
385
2.03M
                                (APP_LAYER_PARSER_EOF_TC | APP_LAYER_PARSER_TRUNC_TC)) != 0;
386
387
2.03M
    const bool eof = last_pseudo || (ts_eof && tc_eof);
388
2.03M
    SCLogDebug("eof %d last_pseudo %d ts_eof %d tc_eof %d", eof, last_pseudo, ts_eof, tc_eof);
389
390
2.03M
    const uint8_t ts_disrupt_flags = FlowGetDisruptionFlags(f, STREAM_TOSERVER);
391
2.03M
    const uint8_t tc_disrupt_flags = FlowGetDisruptionFlags(f, STREAM_TOCLIENT);
392
2.03M
    SCLogDebug("ts_disrupt_flags %02x tc_disrupt_flags %02x", ts_disrupt_flags, tc_disrupt_flags);
393
2.03M
    const uint64_t total_txs = AppLayerParserGetTxCnt(f, alstate);
394
2.03M
    uint64_t tx_id = AppLayerParserGetTransactionLogId(f->alparser);
395
2.03M
    uint64_t max_id = tx_id;
396
2.03M
    int logged = 0;
397
2.03M
    bool gap = false;
398
2.03M
    const bool support_files = AppLayerParserSupportsFiles(ipproto, alproto);
399
2.03M
    const uint8_t pkt_dir = STREAM_FLAGS_FOR_PACKET(p);
400
401
2.03M
    SCLogDebug("pcap_cnt %" PRIu64 ": tx_id %" PRIu64 " total_txs %" PRIu64, p->pcap_cnt, tx_id,
402
2.03M
            total_txs);
403
404
2.03M
    AppLayerGetTxIteratorFunc IterFunc = AppLayerGetTxIterator(ipproto, alproto);
405
2.03M
    AppLayerGetTxIterState state;
406
2.03M
    memset(&state, 0, sizeof(state));
407
408
2.03M
    const int complete_ts =
409
2.03M
            AppLayerParserGetStateProgressCompletionStatus(alproto, STREAM_TOSERVER);
410
2.03M
    const int complete_tc =
411
2.03M
            AppLayerParserGetStateProgressCompletionStatus(alproto, STREAM_TOCLIENT);
412
25.3M
    while (1) {
413
25.3M
        AppLayerGetTxIterTuple ires = IterFunc(ipproto, alproto, alstate, tx_id, total_txs, &state);
414
25.3M
        if (ires.tx_ptr == NULL)
415
270k
            break;
416
25.0M
        void * const tx = ires.tx_ptr;
417
25.0M
        tx_id = ires.tx_id;
418
25.0M
        SCLogDebug("STARTING tx_id %" PRIu64 ", tx %p", tx_id, tx);
419
420
25.0M
        AppLayerTxData *txd = AppLayerParserGetTxData(ipproto, alproto, tx);
421
25.0M
        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
25.0M
        const int tx_progress_ts =
430
25.0M
                AppLayerParserGetStateProgress(ipproto, alproto, tx, ts_disrupt_flags);
431
25.0M
        const int tx_progress_tc =
432
25.0M
                AppLayerParserGetStateProgress(ipproto, alproto, tx, tc_disrupt_flags);
433
25.0M
        const bool tx_complete = (tx_progress_ts == complete_ts && tx_progress_tc == complete_tc);
434
435
25.0M
        SCLogDebug("file_thread_data %p filedata_thread_data %p", op_thread_data->file,
436
25.0M
                op_thread_data->filedata);
437
438
25.0M
        if (file_logging_active) {
439
25.0M
            if (AppLayerParserIsFileTx(txd)) { // need to process each tx that might be a file tx,
440
                                               // even if there are not files (yet)
441
21.4M
                const bool ts_ready = (tx_progress_ts == complete_ts);
442
21.4M
                const bool tc_ready = (tx_progress_tc == complete_tc);
443
21.4M
                SCLogDebug("ts_ready %d tc_ready %d", ts_ready, tc_ready);
444
445
21.4M
                const bool eval_files = ts_ready | tc_ready | tx_complete | ts_eof | tc_eof | eof;
446
447
21.4M
                SCLogDebug("eval_files: %u, ts_ready %u, tc_ready %u, tx_complete %u, ts_eof %u, "
448
21.4M
                           "tc_eof %u, eof %u",
449
21.4M
                        eval_files, ts_ready, tc_ready, tx_complete, ts_eof, tc_eof, eof);
450
21.4M
                SCLogDebug("txd->file_tx & pkt_dir: %02x & %02x -> %02x", txd->file_tx, pkt_dir,
451
21.4M
                        (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
21.4M
                if (eval_files || AppLayerParserIsFileTxInDir(txd, pkt_dir)) {
457
21.3M
                    OutputTxLogFiles(tv, op_thread_data->file, op_thread_data->filedata, p, f, tx,
458
21.3M
                            tx_id, txd, tx_complete, ts_ready, tc_ready, ts_eof, tc_eof, eof);
459
21.3M
                }
460
21.4M
            } else if (support_files) {
461
2.78M
                if (op_thread_data->file) {
462
2.78M
                    txd->logged.flags |= BIT_U32(LOGGER_FILE);
463
2.78M
                    SCLogDebug("not a file_tx: setting LOGGER_FILE => %08x", txd->logged.flags);
464
2.78M
                }
465
2.78M
                if (op_thread_data->filedata) {
466
2.78M
                    txd->logged.flags |= BIT_U32(LOGGER_FILEDATA);
467
2.78M
                    SCLogDebug("not a file_tx: setting LOGGER_FILEDATA => %08x", txd->logged.flags);
468
2.78M
                }
469
2.78M
            }
470
25.0M
        }
471
25.0M
        SCLogDebug("logger: expect %08x, have %08x", logger_expectation, txd->logged.flags);
472
25.0M
        if (!txd->updated_tc && !txd->updated_ts && !(tx_progress_ts == complete_ts) &&
473
5.14M
                !(tx_progress_tc == complete_tc) && !ts_eof && !tc_eof) {
474
2.04M
            gap = true;
475
2.04M
            goto next_tx;
476
2.04M
        }
477
478
23.0M
        if (list[ALPROTO_UNKNOWN] != 0) {
479
23.0M
            OutputTxLogList0(tv, op_thread_data, p, f, tx, tx_id);
480
23.0M
            if (list[alproto] == NULL)
481
167k
                goto next_tx;
482
23.0M
        }
483
484
22.8M
        SCLogDebug("tx %p/%" PRIu64 " txd %p: log_flags %x logger_expectation %x", tx, tx_id, txd,
485
22.8M
                txd->config.log_flags, logger_expectation);
486
22.8M
        if (txd->config.log_flags & BIT_U8(CONFIG_TYPE_TX)) {
487
50
            SCLogDebug("SKIP tx %p/%"PRIu64, tx, tx_id);
488
            // so that AppLayerParserTransactionsCleanup can clean this tx
489
50
            txd->logged.flags |= logger_expectation;
490
50
            goto next_tx;
491
50
        }
492
493
22.8M
        if (txd->logged.flags == logger_expectation) {
494
106k
            SCLogDebug("fully logged");
495
            /* tx already fully logged */
496
106k
            goto next_tx;
497
106k
        }
498
499
22.7M
        SCLogDebug("logger: expect %08x, have %08x", logger_expectation, txd->logged.flags);
500
22.7M
        const OutputTxLogger *logger = list[alproto];
501
22.7M
        const OutputLoggerThreadStore *store = op_thread_data->store[alproto];
502
22.7M
        struct Ctx ctx = { .tx_logged = txd->logged.flags, .tx_logged_old = txd->logged.flags };
503
22.7M
        SCLogDebug("logger: expect %08x, have %08x", logger_expectation, ctx.tx_logged);
504
505
22.7M
        OutputTxLogCallLoggers(tv, op_thread_data, logger, store, p, f, alstate, tx, tx_id, alproto,
506
22.7M
                eof, tx_progress_ts, tx_progress_tc, &ctx);
507
508
22.7M
        SCLogDebug("logger: expect %08x, have %08x", logger_expectation, ctx.tx_logged);
509
22.7M
        if (ctx.tx_logged != ctx.tx_logged_old) {
510
333k
            SCLogDebug("logger: storing %08x (was %08x)", ctx.tx_logged, ctx.tx_logged_old);
511
333k
            DEBUG_VALIDATE_BUG_ON(txd == NULL);
512
333k
            txd->logged.flags |= ctx.tx_logged;
513
333k
        }
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
22.7M
        if (!gap && ctx.tx_logged == logger_expectation) {
522
246k
            SCLogDebug("no gap %d, %08x == %08x", gap, ctx.tx_logged, logger_expectation);
523
246k
            logged = 1;
524
246k
            max_id = tx_id;
525
246k
            SCLogDebug("max_id %" PRIu64, max_id);
526
22.5M
        } else {
527
22.5M
            gap = true;
528
22.5M
        }
529
25.0M
next_tx:
530
25.0M
        if (!ires.has_next)
531
1.76M
            break;
532
23.3M
        tx_id++;
533
23.3M
    }
534
535
    /* Update the last ID that has been logged with all
536
     * transactions before it. */
537
2.03M
    if (logged) {
538
202k
        SCLogDebug("updating log tx_id %"PRIu64, max_id);
539
202k
        AppLayerParserSetTransactionLogId(f->alparser, max_id + 1);
540
202k
    }
541
542
2.40M
end:
543
2.40M
    return TM_ECODE_OK;
544
2.03M
}
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
154
    for (AppProto alproto = 0; alproto < ALPROTO_MAX; alproto++) {
560
150
        OutputTxLogger *logger = list[alproto];
561
240
        while (logger) {
562
90
            if (logger->ThreadInit) {
563
90
                void *retptr = NULL;
564
90
                if (logger->ThreadInit(tv, (void *)logger->output_ctx, &retptr) == TM_ECODE_OK) {
565
90
                    OutputLoggerThreadStore *ts = SCMalloc(sizeof(*ts));
566
90
    /* todo */      BUG_ON(ts == NULL);
567
90
                    memset(ts, 0x00, sizeof(*ts));
568
569
                    /* store thread handle */
570
90
                    ts->thread_data = retptr;
571
572
90
                    if (td->store[alproto] == NULL) {
573
80
                        td->store[alproto] = ts;
574
80
                    } else {
575
10
                        OutputLoggerThreadStore *tmp = td->store[alproto];
576
12
                        while (tmp->next != NULL)
577
2
                            tmp = tmp->next;
578
10
                        tmp->next = ts;
579
10
                    }
580
581
90
                    SCLogDebug("%s is now set up", logger->name);
582
90
                }
583
90
            }
584
585
90
            logger = logger->next;
586
90
        }
587
150
    }
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
}