logging: move lock into write function

All loggers were wrapping just the write in a lock with some
updating a counter.  This moves the lock into the write function.

The log_ctx alerts counter was also removed as many modules have
stopped using this and the alert count is available elsewhere.

Should satisfy Coverity CID 1400798:

CID 1400798 (#1 of 1): Data race condition (MISSING_LOCK) 2.
missing_lock: Accessing log_ctx->rotation_flag without holding lock
LogFileCtx_.fp_mutex. Elsewhere, "LogFileCtx_.rotation_flag" is accessed
with LogFileCtx_.fp_mutex held 4 out of 5 times.

Which appears to be a false positive as all calls to SCLogFileWrite
were done under lock, but this will make it more explicit.
pull/2606/head
Jason Ish 9 years ago committed by Victor Julien
parent ddf1bf6518
commit 0c3f1e2974

@ -304,11 +304,8 @@ static TmEcode AlertDebugLogger(ThreadVars *tv, const Packet *p, void *thread_da
}
}
SCMutexLock(&aft->file_ctx->fp_mutex);
aft->file_ctx->Write((const char *)MEMBUFFER_BUFFER(aft->buffer),
MEMBUFFER_OFFSET(aft->buffer), aft->file_ctx);
aft->file_ctx->alerts += p->alerts.cnt;
SCMutexUnlock(&aft->file_ctx->fp_mutex);
return TM_ECODE_OK;
}
@ -367,11 +364,8 @@ static TmEcode AlertDebugLogDecoderEvent(ThreadVars *tv, const Packet *p, void *
PrintRawDataToBuffer(aft->buffer->buffer, &aft->buffer->offset, aft->buffer->size,
GET_PKT_DATA(p), GET_PKT_LEN(p));
SCMutexLock(&aft->file_ctx->fp_mutex);
aft->file_ctx->Write((const char *)MEMBUFFER_BUFFER(aft->buffer),
MEMBUFFER_OFFSET(aft->buffer), aft->file_ctx);
aft->file_ctx->alerts += p->alerts.cnt;
SCMutexUnlock(&aft->file_ctx->fp_mutex);
return TM_ECODE_OK;
}
@ -424,8 +418,6 @@ static void AlertDebugLogExitPrintStats(ThreadVars *tv, void *data)
if (aft == NULL) {
return;
}
SCLogInfo("(%s) Alerts %" PRIu64 "", tv->name, aft->file_ctx->alerts);
}
static void AlertDebugLogDeInitCtx(OutputCtx *output_ctx)

@ -98,12 +98,8 @@ int AlertFastLogCondition(ThreadVars *tv, const Packet *p)
static inline void AlertFastLogOutputAlert(AlertFastLogThread *aft, char *buffer,
int alert_size)
{
SCMutex *file_lock = &aft->file_ctx->fp_mutex;
/* Output the alert string and count alerts. Only need to lock here. */
SCMutexLock(file_lock);
aft->file_ctx->alerts++;
aft->file_ctx->Write(buffer, alert_size, aft->file_ctx);
SCMutexUnlock(file_lock);
}
int AlertFastLogger(ThreadVars *tv, void *data, const Packet *p)

@ -205,10 +205,9 @@ static TmEcode AlertSyslogIPv4(ThreadVars *tv, const Packet *p, void *data)
if (p->alerts.cnt == 0)
return TM_ECODE_OK;
/* Not sure if this mutex is needed around calls to syslog. */
SCMutexLock(&ast->file_ctx->fp_mutex);
ast->file_ctx->alerts += p->alerts.cnt;
for (i = 0; i < p->alerts.cnt; i++) {
const PacketAlert *pa = &p->alerts.alerts[i];
if (unlikely(pa->s == NULL)) {
@ -265,8 +264,6 @@ static TmEcode AlertSyslogIPv6(ThreadVars *tv, const Packet *p, void *data)
SCMutexLock(&ast->file_ctx->fp_mutex);
ast->file_ctx->alerts += p->alerts.cnt;
for (i = 0; i < p->alerts.cnt; i++) {
const PacketAlert *pa = &p->alerts.alerts[i];
if (unlikely(pa->s == NULL)) {
@ -328,7 +325,6 @@ static TmEcode AlertSyslogDecoderEvent(ThreadVars *tv, const Packet *p, void *da
SCMutexLock(&ast->file_ctx->fp_mutex);
ast->file_ctx->alerts += p->alerts.cnt;
char temp_buf_hdr[512];
char temp_buf_pkt[65] = "";
char temp_buf_tail[32];
@ -383,8 +379,6 @@ static void AlertSyslogExitPrintStats(ThreadVars *tv, void *data)
if (ast == NULL) {
return;
}
SCLogInfo("(%s) Alerts %" PRIu64 "", tv->name, ast->file_ctx->alerts);
}
static int AlertSyslogCondition(ThreadVars *tv, const Packet *p)

@ -928,7 +928,6 @@ static int Unified2IPv6TypeAlert(ThreadVars *t, const Packet *p, void *data)
? true : false;
if (truncate || file_ctx->rotation_flag) {
if (Unified2AlertRotateFile(aun, truncate) < 0) {
aun->unified2alert_ctx->file_ctx->alerts += i;
SCMutexUnlock(&file_ctx->fp_mutex);
return -1;
}
@ -936,7 +935,6 @@ static int Unified2IPv6TypeAlert(ThreadVars *t, const Packet *p, void *data)
}
if (Unified2Write(aun) != 1) {
file_ctx->alerts += i;
SCMutexUnlock(&file_ctx->fp_mutex);
return -1;
}
@ -951,12 +949,10 @@ static int Unified2IPv6TypeAlert(ThreadVars *t, const Packet *p, void *data)
ret = Unified2PacketTypeAlert(aun, p, phdr->event_id, stream);
if (ret != 1) {
SCLogError(SC_ERR_FWRITE, "Error: fwrite failed: %s", strerror(errno));
aun->unified2alert_ctx->file_ctx->alerts += i;
SCMutexUnlock(&file_ctx->fp_mutex);
return -1;
}
fflush(aun->unified2alert_ctx->file_ctx->fp);
aun->unified2alert_ctx->file_ctx->alerts++;
SCMutexUnlock(&file_ctx->fp_mutex);
}
@ -1108,7 +1104,6 @@ static int Unified2IPv4TypeAlert (ThreadVars *tv, const Packet *p, void *data)
? true : false;
if (truncate || file_ctx->rotation_flag) {
if (Unified2AlertRotateFile(aun, truncate) < 0) {
file_ctx->alerts += i;
SCMutexUnlock(&file_ctx->fp_mutex);
return -1;
}
@ -1116,7 +1111,6 @@ static int Unified2IPv4TypeAlert (ThreadVars *tv, const Packet *p, void *data)
}
if (Unified2Write(aun) != 1) {
file_ctx->alerts += i;
SCMutexUnlock(&file_ctx->fp_mutex);
return -1;
}
@ -1132,13 +1126,11 @@ static int Unified2IPv4TypeAlert (ThreadVars *tv, const Packet *p, void *data)
(pa->flags & (PACKET_ALERT_FLAG_STATE_MATCH|PACKET_ALERT_FLAG_STREAM_MATCH) ? 1 : 0) : 0;
ret = Unified2PacketTypeAlert(aun, p, event_id, stream);
if (ret != 1) {
aun->unified2alert_ctx->file_ctx->alerts += i;
SCMutexUnlock(&file_ctx->fp_mutex);
return -1;
}
fflush(aun->unified2alert_ctx->file_ctx->fp);
aun->unified2alert_ctx->file_ctx->alerts++;
SCMutexUnlock(&file_ctx->fp_mutex);
}

@ -96,10 +96,8 @@ static void LogQuery(LogDnsLogThread *aft, char *timebuf, char *srcip, char *dst
" [**] %s [**] %s:%" PRIu16 " -> %s:%" PRIu16 "\n",
record, srcip, sp, dstip, dp);
SCMutexLock(&hlog->file_ctx->fp_mutex);
hlog->file_ctx->Write((const char *)MEMBUFFER_BUFFER(aft->buffer),
MEMBUFFER_OFFSET(aft->buffer), hlog->file_ctx);
SCMutexUnlock(&hlog->file_ctx->fp_mutex);
}
static void LogAnswer(LogDnsLogThread *aft, char *timebuf, char *srcip, char *dstip, Port sp, Port dp, DNSTransaction *tx, DNSAnswerEntry *entry)
@ -159,10 +157,8 @@ static void LogAnswer(LogDnsLogThread *aft, char *timebuf, char *srcip, char *ds
" [**] %s:%" PRIu16 " -> %s:%" PRIu16 "\n",
srcip, sp, dstip, dp);
SCMutexLock(&hlog->file_ctx->fp_mutex);
hlog->file_ctx->Write((const char *)MEMBUFFER_BUFFER(aft->buffer),
MEMBUFFER_OFFSET(aft->buffer), hlog->file_ctx);
SCMutexUnlock(&hlog->file_ctx->fp_mutex);
}
static int LogDnsLogger(ThreadVars *tv, void *data, const Packet *p,

@ -498,10 +498,8 @@ static TmEcode LogHttpLogIPWrapper(ThreadVars *tv, void *data, const Packet *p,
aft->uri_cnt ++;
SCMutexLock(&hlog->file_ctx->fp_mutex);
hlog->file_ctx->Write((const char *)MEMBUFFER_BUFFER(aft->buffer),
MEMBUFFER_OFFSET(aft->buffer), hlog->file_ctx);
SCMutexUnlock(&hlog->file_ctx->fp_mutex);
end:
SCReturnInt(0);

@ -156,10 +156,8 @@ int LogStatsLogger(ThreadVars *tv, void *thread_data, const StatsTable *st)
}
}
SCMutexLock(&aft->statslog_ctx->file_ctx->fp_mutex);
aft->statslog_ctx->file_ctx->Write((const char *)MEMBUFFER_BUFFER(aft->buffer),
MEMBUFFER_OFFSET(aft->buffer), aft->statslog_ctx->file_ctx);
SCMutexUnlock(&aft->statslog_ctx->file_ctx->fp_mutex);
MemBufferReset(aft->buffer);

@ -161,10 +161,8 @@ static int LogTcpDataLoggerFile(ThreadVars *tv, void *thread_data, const Flow *f
PrintRawDataToBuffer(aft->buffer->buffer, &aft->buffer->offset,
aft->buffer->size, (uint8_t *)data,data_len);
SCMutexLock(&td->file_ctx->fp_mutex);
td->file_ctx->Write((const char *)MEMBUFFER_BUFFER(aft->buffer),
MEMBUFFER_OFFSET(aft->buffer), td->file_ctx);
SCMutexUnlock(&td->file_ctx->fp_mutex);
}
SCReturnInt(TM_ECODE_OK);
}

@ -323,10 +323,8 @@ static int LogTlsLogger(ThreadVars *tv, void *thread_data, const Packet *p,
aft->tls_cnt++;
SCMutexLock(&hlog->file_ctx->fp_mutex);
hlog->file_ctx->Write((const char *)MEMBUFFER_BUFFER(aft->buffer),
MEMBUFFER_OFFSET(aft->buffer), hlog->file_ctx);
SCMutexUnlock(&hlog->file_ctx->fp_mutex);
return 0;
}

@ -127,6 +127,8 @@ static int SCLogUnixSocketReconnect(LogFileCtx *log_ctx)
*/
static int SCLogFileWrite(const char *buffer, int buffer_len, LogFileCtx *log_ctx)
{
SCMutexLock(&log_ctx->fp_mutex);
/* Check for rotation. */
if (log_ctx->rotation_flag) {
log_ctx->rotation_flag = 0;
@ -152,6 +154,8 @@ static int SCLogFileWrite(const char *buffer, int buffer_len, LogFileCtx *log_ct
}
}
SCMutexUnlock(&log_ctx->fp_mutex);
return ret;
}
@ -671,10 +675,8 @@ int LogFileWrite(LogFileCtx *file_ctx, MemBuffer *buffer)
{
/* append \n for files only */
MemBufferWriteString(buffer, "\n");
SCMutexLock(&file_ctx->fp_mutex);
file_ctx->Write((const char *)MEMBUFFER_BUFFER(buffer),
MEMBUFFER_OFFSET(buffer), file_ctx);
SCMutexUnlock(&file_ctx->fp_mutex);
}
#ifdef HAVE_LIBHIREDIS
else if (file_ctx->type == LOGFILE_TYPE_REDIS) {

@ -109,8 +109,6 @@ typedef struct LogFileCtx_ {
uint64_t size_limit; /**< file size limit */
uint64_t size_current; /**< file current size */
/* Alerts on the module (not on the file) */
uint64_t alerts;
/* flag to avoid multiple threads printing the same stats */
uint8_t flags;

Loading…
Cancel
Save