static TmEcode OutputTxLog(ThreadVars *tv, Packet *p, void *thread_data)
{
BUG_ON(thread_data == NULL);
if (list == NULL) {
/* No child loggers registered. */
return TM_ECODE_OK;
}
OutputLoggerThreadData *op_thread_data = (OutputLoggerThreadData *)thread_data;
OutputTxLogger *logger = list;
OutputLoggerThreadStore *store = op_thread_data->store;
BUG_ON(logger == NULL && store != NULL);
BUG_ON(logger != NULL && store == NULL);
BUG_ON(logger == NULL && store == NULL);
if (p->flow == NULL)
return TM_ECODE_OK;
Flow * const f = p->flow;
AppProto alproto = f->alproto;
if (AppLayerParserProtocolIsTxAware(p->proto, alproto) == 0)
goto end;
if (AppLayerParserProtocolHasLogger(p->proto, alproto) == 0)
goto end;
void *alstate = f->alstate;
if (alstate == NULL) {
SCLogDebug("no alstate");
goto end;
}
uint64_t total_txs = AppLayerParserGetTxCnt(p->proto, alproto, alstate);
uint64_t tx_id = AppLayerParserGetTransactionLogId(f->alparser);
for (; tx_id < total_txs; tx_id++)
{
int logger_not_logged = 0;
void *tx = AppLayerParserGetTx(p->proto, alproto, alstate, tx_id);
if (tx == NULL) {
SCLogDebug("tx is NULL not logging");
continue;
}
int tx_progress_ts = AppLayerParserGetStateProgress(p->proto, alproto,
tx, FlowGetDisruptionFlags(f, STREAM_TOSERVER));
int tx_progress_tc = AppLayerParserGetStateProgress(p->proto, alproto,
tx, FlowGetDisruptionFlags(f, STREAM_TOCLIENT));
SCLogDebug("tx_progress_ts %d tx_progress_tc %d",
tx_progress_ts, tx_progress_tc);
// call each logger here (pseudo code)
logger = list;
store = op_thread_data->store;
while (logger && store) {
BUG_ON(logger->LogFunc == NULL);
SCLogDebug("logger %p, LogCondition %p, ts_log_progress %d "
"tc_log_progress %d", logger, logger->LogCondition,
logger->ts_log_progress, logger->tc_log_progress);
if (logger->alproto == alproto) {
SCLogDebug("alproto match, logging tx_id %"PRIu64, tx_id);
if (AppLayerParserGetTxLogged(p->proto, alproto, alstate, tx,
logger->id)) {
SCLogDebug("logger has already logged this transaction");
goto next;
}
if (!(AppLayerParserStateIssetFlag(f->alparser,
APP_LAYER_PARSER_EOF))) {
if (logger->LogCondition) {
int r = logger->LogCondition(tv, p, alstate, tx, tx_id);
if (r == FALSE) {
SCLogDebug("conditions not met, not logging");
logger_not_logged = 1;
goto next;
}
} else {
if (tx_progress_tc < logger->tc_log_progress) {
SCLogDebug("progress not far enough, not logging");
logger_not_logged = 1;
goto next;
}
if (tx_progress_ts < logger->ts_log_progress) {
SCLogDebug("progress not far enough, not logging");
logger_not_logged = 1;
goto next;
}
}
}
PACKET_PROFILING_LOGGER_START(p, logger->logger_id);
logger->LogFunc(tv, store->thread_data, p, f, alstate, tx, tx_id);
PACKET_PROFILING_LOGGER_END(p, logger->logger_id);
AppLayerParserSetTxLogged(p->proto, alproto, alstate, tx,
logger->id);
}
next:
logger = logger->next;
store = store->next;
BUG_ON(logger == NULL && store != NULL);
BUG_ON(logger != NULL && store == NULL);
}
if (!logger_not_logged) {
SCLogDebug("updating log tx_id %"PRIu64, tx_id);
AppLayerParserSetTransactionLogId(f->alparser);
}
}
end:
return TM_ECODE_OK;
}
int AppLayerParserParse(ThreadVars *tv, AppLayerParserThreadCtx *alp_tctx, Flow *f, AppProto alproto,
uint8_t flags, uint8_t *input, uint32_t input_len)
{
SCEnter();
#ifdef DEBUG_VALIDATION
BUG_ON(f->protomap != FlowGetProtoMapping(f->proto));
#endif
AppLayerParserState *pstate = NULL;
AppLayerParserProtoCtx *p = &alp_ctx.ctxs[f->protomap][alproto];
void *alstate = NULL;
uint64_t p_tx_cnt = 0;
/* we don't have the parser registered for this protocol */
if (p->StateAlloc == NULL)
goto end;
/* Do this check before calling AppLayerParse */
if (flags & STREAM_GAP) {
SCLogDebug("stream gap detected (missing packets), "
"this is not yet supported.");
if (f->alstate != NULL)
AppLayerParserStreamTruncated(f->proto, alproto, f->alstate, flags);
goto error;
}
/* Get the parser state (if any) */
pstate = f->alparser;
if (pstate == NULL) {
f->alparser = pstate = AppLayerParserStateAlloc();
if (pstate == NULL)
goto error;
}
pstate->version++;
SCLogDebug("app layer parser state version incremented to %"PRIu8,
pstate->version);
if (flags & STREAM_EOF)
AppLayerParserStateSetFlag(pstate, APP_LAYER_PARSER_EOF);
alstate = f->alstate;
if (alstate == NULL) {
f->alstate = alstate = p->StateAlloc();
if (alstate == NULL)
goto error;
SCLogDebug("alloced new app layer state %p (name %s)",
alstate, AppLayerGetProtoName(f->alproto));
} else {
SCLogDebug("using existing app layer state %p (name %s))",
alstate, AppLayerGetProtoName(f->alproto));
}
if (AppLayerParserProtocolIsTxAware(f->proto, alproto)) {
p_tx_cnt = AppLayerParserGetTxCnt(f->proto, alproto, f->alstate);
}
/* invoke the recursive parser, but only on data. We may get empty msgs on EOF */
if (input_len > 0 || (flags & STREAM_EOF)) {
/* invoke the parser */
if (p->Parser[(flags & STREAM_TOSERVER) ? 0 : 1](f, alstate, pstate,
input, input_len,
alp_tctx->alproto_local_storage[f->protomap][alproto]) < 0)
{
goto error;
}
}
/* set the packets to no inspection and reassembly if required */
if (pstate->flags & APP_LAYER_PARSER_NO_INSPECTION) {
AppLayerParserSetEOF(pstate);
FlowSetNoPayloadInspectionFlag(f);
if (f->proto == IPPROTO_TCP) {
StreamTcpDisableAppLayer(f);
/* Set the no reassembly flag for both the stream in this TcpSession */
if (pstate->flags & APP_LAYER_PARSER_NO_REASSEMBLY) {
/* Used only if it's TCP */
TcpSession *ssn = f->protoctx;
if (ssn != NULL) {
StreamTcpSetSessionNoReassemblyFlag(ssn,
flags & STREAM_TOCLIENT ? 1 : 0);
StreamTcpSetSessionNoReassemblyFlag(ssn,
flags & STREAM_TOSERVER ? 1 : 0);
}
}
}
}
/* In cases like HeartBleed for TLS we need to inspect AppLayer but not Payload */
if (!(f->flags & FLOW_NOPAYLOAD_INSPECTION) && pstate->flags & APP_LAYER_PARSER_NO_INSPECTION_PAYLOAD) {
FlowSetNoPayloadInspectionFlag(f);
/* Set the no reassembly flag for both the stream in this TcpSession */
if (f->proto == IPPROTO_TCP) {
/* Used only if it's TCP */
TcpSession *ssn = f->protoctx;
if (ssn != NULL) {
StreamTcpSetDisableRawReassemblyFlag(ssn, 0);
StreamTcpSetDisableRawReassemblyFlag(ssn, 1);
}
}
}
if (AppLayerParserProtocolIsTxAware(f->proto, alproto)) {
if (likely(tv)) {
uint64_t cur_tx_cnt = AppLayerParserGetTxCnt(f->proto, alproto, f->alstate);
if (cur_tx_cnt > p_tx_cnt) {
AppLayerIncTxCounter(tv, f, cur_tx_cnt - p_tx_cnt);
}
}
}
/* next, see if we can get rid of transactions now */
AppLayerParserTransactionsCleanup(f);
/* stream truncated, inform app layer */
if (flags & STREAM_DEPTH)
AppLayerParserStreamTruncated(f->proto, alproto, alstate, flags);
end:
SCReturnInt(0);
error:
/* Set the no app layer inspection flag for both
* the stream in this Flow */
if (f->proto == IPPROTO_TCP) {
StreamTcpDisableAppLayer(f);
}
AppLayerParserSetEOF(pstate);
SCReturnInt(-1);
}
static TmEcode OutputTxLog(ThreadVars *tv, Packet *p, void *thread_data)
{
BUG_ON(thread_data == NULL);
if (list == NULL) {
/* No child loggers registered. */
return TM_ECODE_OK;
}
OutputLoggerThreadData *op_thread_data = (OutputLoggerThreadData *)thread_data;
if (p->flow == NULL)
return TM_ECODE_OK;
Flow * const f = p->flow;
const uint8_t ipproto = f->proto;
const AppProto alproto = f->alproto;
if (AppLayerParserProtocolIsTxAware(p->proto, alproto) == 0)
goto end;
if (AppLayerParserProtocolHasLogger(p->proto, alproto) == 0)
goto end;
const LoggerId logger_expectation = AppLayerParserProtocolGetLoggerBits(p->proto, alproto);
if (logger_expectation == 0)
goto end;
void *alstate = f->alstate;
if (alstate == NULL) {
SCLogDebug("no alstate");
goto end;
}
const uint8_t ts_disrupt_flags = FlowGetDisruptionFlags(f, STREAM_TOSERVER);
const uint8_t tc_disrupt_flags = FlowGetDisruptionFlags(f, STREAM_TOCLIENT);
const uint64_t total_txs = AppLayerParserGetTxCnt(f, alstate);
uint64_t tx_id = AppLayerParserGetTransactionLogId(f->alparser);
uint64_t max_id = tx_id;
int logged = 0;
int gap = 0;
AppLayerGetTxIteratorFunc IterFunc = AppLayerGetTxIterator(ipproto, alproto);
AppLayerGetTxIterState state;
memset(&state, 0, sizeof(state));
while (1) {
AppLayerGetTxIterTuple ires = IterFunc(ipproto, alproto, alstate, tx_id, total_txs, &state);
if (ires.tx_ptr == NULL)
break;
void * const tx = ires.tx_ptr;
tx_id = ires.tx_id;
LoggerId tx_logged = AppLayerParserGetTxLogged(f, alstate, tx);
const LoggerId tx_logged_old = tx_logged;
SCLogDebug("logger: expect %08x, have %08x", logger_expectation, tx_logged);
if (tx_logged == logger_expectation) {
/* tx already fully logged */
goto next_tx;
}
int tx_progress_ts = AppLayerParserGetStateProgress(p->proto, alproto,
tx, ts_disrupt_flags);
int tx_progress_tc = AppLayerParserGetStateProgress(p->proto, alproto,
tx, tc_disrupt_flags);
SCLogDebug("tx_progress_ts %d tx_progress_tc %d",
tx_progress_ts, tx_progress_tc);
const OutputTxLogger *logger = list;
const OutputLoggerThreadStore *store = op_thread_data->store;
#ifdef DEBUG_VALIDATION
BUG_ON(logger == NULL && store != NULL);
BUG_ON(logger != NULL && store == NULL);
BUG_ON(logger == NULL && store == NULL);
#endif
while (logger && store) {
BUG_ON(logger->LogFunc == NULL);
SCLogDebug("logger %p, LogCondition %p, ts_log_progress %d "
"tc_log_progress %d", logger, logger->LogCondition,
logger->ts_log_progress, logger->tc_log_progress);
if (logger->alproto == alproto &&
(tx_logged_old & (1<<logger->logger_id)) == 0)
{
SCLogDebug("alproto match, logging tx_id %"PRIu64, tx_id);
if (!(AppLayerParserStateIssetFlag(f->alparser,
APP_LAYER_PARSER_EOF))) {
if (logger->LogCondition) {
int r = logger->LogCondition(tv, p, alstate, tx, tx_id);
if (r == FALSE) {
SCLogDebug("conditions not met, not logging");
goto next_logger;
}
} else {
if (tx_progress_tc < logger->tc_log_progress) {
SCLogDebug("progress not far enough, not logging");
goto next_logger;
}
if (tx_progress_ts < logger->ts_log_progress) {
SCLogDebug("progress not far enough, not logging");
goto next_logger;
}
}
}
SCLogDebug("Logging tx_id %"PRIu64" to logger %d", tx_id,
logger->logger_id);
PACKET_PROFILING_LOGGER_START(p, logger->logger_id);
logger->LogFunc(tv, store->thread_data, p, f, alstate, tx, tx_id);
PACKET_PROFILING_LOGGER_END(p, logger->logger_id);
tx_logged |= (1<<logger->logger_id);
}
next_logger:
logger = logger->next;
store = store->next;
#ifdef DEBUG_VALIDATION
BUG_ON(logger == NULL && store != NULL);
BUG_ON(logger != NULL && store == NULL);
#endif
}
if (tx_logged != tx_logged_old) {
SCLogDebug("logger: storing %08x (was %08x)",
tx_logged, tx_logged_old);
AppLayerParserSetTxLogged(p->proto, alproto, alstate, tx,
tx_logged);
}
/* If all loggers logged set a flag and update the last tx_id
* that was logged.
*
* If not all loggers were logged we flag that there was a gap
* so any subsequent transactions in this loop don't increase
* the maximum ID that was logged. */
if (!gap && tx_logged == logger_expectation) {
logged = 1;
max_id = tx_id;
} else {
gap = 1;
}
next_tx:
if (!ires.has_next)
break;
tx_id++;
}
/* Update the the last ID that has been logged with all
* transactions before it. */
if (logged) {
SCLogDebug("updating log tx_id %"PRIu64, max_id);
AppLayerParserSetTransactionLogId(f->alparser, max_id + 1);
}
end:
return TM_ECODE_OK;
}
static TmEcode OutputTxLog(ThreadVars *tv, Packet *p, void *thread_data, PacketQueue *pq, PacketQueue *postpq)
{
BUG_ON(thread_data == NULL);
BUG_ON(list == NULL);
OutputLoggerThreadData *op_thread_data = (OutputLoggerThreadData *)thread_data;
OutputTxLogger *logger = list;
OutputLoggerThreadStore *store = op_thread_data->store;
BUG_ON(logger == NULL && store != NULL);
BUG_ON(logger != NULL && store == NULL);
BUG_ON(logger == NULL && store == NULL);
if (p->flow == NULL)
return TM_ECODE_OK;
Flow * const f = p->flow;
FLOWLOCK_WRLOCK(f); /* WRITE lock before we updated flow logged id */
AppProto alproto = f->alproto;
if (AppLayerParserProtocolIsTxAware(p->proto, alproto) == 0)
goto end;
if (AppLayerParserProtocolHasLogger(p->proto, alproto) == 0)
goto end;
void *alstate = f->alstate;
if (alstate == NULL) {
SCLogDebug("no alstate");
goto end;
}
uint64_t total_txs = AppLayerParserGetTxCnt(p->proto, alproto, alstate);
uint64_t tx_id = AppLayerParserGetTransactionLogId(f->alparser);
int tx_progress_done_value_ts =
AppLayerParserGetStateProgressCompletionStatus(p->proto, alproto,
STREAM_TOSERVER);
int tx_progress_done_value_tc =
AppLayerParserGetStateProgressCompletionStatus(p->proto, alproto,
STREAM_TOCLIENT);
for (; tx_id < total_txs; tx_id++)
{
int proto_logged = 0;
void *tx = AppLayerParserGetTx(p->proto, alproto, alstate, tx_id);
if (tx == NULL) {
SCLogDebug("tx is NULL not logging");
continue;
}
if (!(AppLayerParserStateIssetFlag(f->alparser, APP_LAYER_PARSER_EOF)))
{
int tx_progress = AppLayerParserGetStateProgress(p->proto, alproto,
tx, FlowGetDisruptionFlags(f, STREAM_TOSERVER));
if (tx_progress < tx_progress_done_value_ts) {
SCLogDebug("progress not far enough, not logging");
break;
}
tx_progress = AppLayerParserGetStateProgress(p->proto, alproto,
tx, FlowGetDisruptionFlags(f, STREAM_TOCLIENT));
if (tx_progress < tx_progress_done_value_tc) {
SCLogDebug("progress not far enough, not logging");
break;
}
}
// call each logger here (pseudo code)
logger = list;
store = op_thread_data->store;
while (logger && store) {
BUG_ON(logger->LogFunc == NULL);
SCLogDebug("logger %p", logger);
if (logger->alproto == alproto) {
SCLogDebug("alproto match, logging tx_id %ju", tx_id);
PACKET_PROFILING_TMM_START(p, logger->module_id);
logger->LogFunc(tv, store->thread_data, p, f, alstate, tx, tx_id);
PACKET_PROFILING_TMM_END(p, logger->module_id);
proto_logged = 1;
}
logger = logger->next;
store = store->next;
BUG_ON(logger == NULL && store != NULL);
BUG_ON(logger != NULL && store == NULL);
}
if (proto_logged) {
SCLogDebug("updating log tx_id %ju", tx_id);
AppLayerParserSetTransactionLogId(f->alparser);
}
}
end:
FLOWLOCK_UNLOCK(f);
return TM_ECODE_OK;
}
static TmEcode OutputTxLog(ThreadVars *tv, Packet *p, void *thread_data)
{
BUG_ON(thread_data == NULL);
if (list == NULL) {
/* No child loggers registered. */
return TM_ECODE_OK;
}
OutputLoggerThreadData *op_thread_data = (OutputLoggerThreadData *)thread_data;
if (p->flow == NULL)
return TM_ECODE_OK;
Flow * const f = p->flow;
const AppProto alproto = f->alproto;
if (AppLayerParserProtocolIsTxAware(p->proto, alproto) == 0)
goto end;
if (AppLayerParserProtocolHasLogger(p->proto, alproto) == 0)
goto end;
void *alstate = f->alstate;
if (alstate == NULL) {
SCLogDebug("no alstate");
goto end;
}
const uint8_t ts_disrupt_flags = FlowGetDisruptionFlags(f, STREAM_TOSERVER);
const uint8_t tc_disrupt_flags = FlowGetDisruptionFlags(f, STREAM_TOCLIENT);
const uint64_t total_txs = AppLayerParserGetTxCnt(f, alstate);
uint64_t tx_id = AppLayerParserGetTransactionLogId(f->alparser);
uint64_t max_id = tx_id;
int logged = 0;
int gap = 0;
for (; tx_id < total_txs; tx_id++)
{
/* Track the number of loggers, of the eligible loggers that
* actually logged this transaction. They all must have logged
* before the transaction is considered logged. */
int number_of_loggers = 0;
int loggers_that_logged = 0;
void *tx = AppLayerParserGetTx(p->proto, alproto, alstate, tx_id);
if (tx == NULL) {
SCLogDebug("tx is NULL not logging");
continue;
}
int tx_progress_ts = AppLayerParserGetStateProgress(p->proto, alproto,
tx, ts_disrupt_flags);
int tx_progress_tc = AppLayerParserGetStateProgress(p->proto, alproto,
tx, tc_disrupt_flags);
SCLogDebug("tx_progress_ts %d tx_progress_tc %d",
tx_progress_ts, tx_progress_tc);
const OutputTxLogger *logger = list;
const OutputLoggerThreadStore *store = op_thread_data->store;
#ifdef DEBUG_VALIDATION
BUG_ON(logger == NULL && store != NULL);
BUG_ON(logger != NULL && store == NULL);
BUG_ON(logger == NULL && store == NULL);
#endif
while (logger && store) {
BUG_ON(logger->LogFunc == NULL);
SCLogDebug("logger %p, LogCondition %p, ts_log_progress %d "
"tc_log_progress %d", logger, logger->LogCondition,
logger->ts_log_progress, logger->tc_log_progress);
if (logger->alproto == alproto) {
SCLogDebug("alproto match, logging tx_id %"PRIu64, tx_id);
number_of_loggers++;
if (AppLayerParserGetTxLogged(f, alstate, tx, logger->id)) {
SCLogDebug("logger has already logged this transaction");
loggers_that_logged++;
goto next;
}
if (!(AppLayerParserStateIssetFlag(f->alparser,
APP_LAYER_PARSER_EOF))) {
if (logger->LogCondition) {
int r = logger->LogCondition(tv, p, alstate, tx, tx_id);
if (r == FALSE) {
SCLogDebug("conditions not met, not logging");
goto next;
}
} else {
if (tx_progress_tc < logger->tc_log_progress) {
SCLogDebug("progress not far enough, not logging");
goto next;
}
if (tx_progress_ts < logger->ts_log_progress) {
SCLogDebug("progress not far enough, not logging");
goto next;
}
}
}
SCLogDebug("Logging tx_id %"PRIu64" to logger %d", tx_id,
logger->logger_id);
PACKET_PROFILING_LOGGER_START(p, logger->logger_id);
logger->LogFunc(tv, store->thread_data, p, f, alstate, tx, tx_id);
PACKET_PROFILING_LOGGER_END(p, logger->logger_id);
AppLayerParserSetTxLogged(p->proto, alproto, alstate, tx,
logger->id);
loggers_that_logged++;
}
next:
logger = logger->next;
store = store->next;
#ifdef DEBUG_VALIDATION
BUG_ON(logger == NULL && store != NULL);
BUG_ON(logger != NULL && store == NULL);
#endif
}
/* If all loggers logged set a flag and update the last tx_id
* that was logged.
*
* If not all loggers were logged we flag that there was a gap
* so any subsequent transactions in this loop don't increase
* the maximum ID that was logged. */
if (!gap && loggers_that_logged == number_of_loggers) {
logged = 1;
max_id = tx_id;
} else {
gap = 1;
}
}
/* Update the the last ID that has been logged with all
* transactions before it. */
if (logged) {
SCLogDebug("updating log tx_id %"PRIu64, max_id);
AppLayerParserSetTransactionLogId(f->alparser, max_id + 1);
}
end:
return TM_ECODE_OK;
}
