Skip to content

Commit

Permalink
d_msg: is now able to filter for sourcefile with regular expression.
Browse files Browse the repository at this point in the history
d_msg can filter the debug output based on a regex and only print the
messages that are generated by files that match to the regex.

This is implemented with the c++11 <regex> header and we have
gtest unit tests that verify the functionality.

We have to check if this can be compiled on all platforms.

What is still missing is to enable the setdebug command to set this
filter string.
  • Loading branch information
pstorz committed Jul 9, 2018
1 parent 91f4640 commit b95c3a3
Show file tree
Hide file tree
Showing 3 changed files with 149 additions and 52 deletions.
91 changes: 49 additions & 42 deletions core/src/lib/message.cc
Expand Up @@ -3,7 +3,7 @@
Copyright (C) 2000-2012 Free Software Foundation Europe e.V.
Copyright (C) 2011-2012 Planets Communications B.V.
Copyright (C) 2013-2013 Bareos GmbH & Co. KG
Copyright (C) 2013-2018 Bareos GmbH & Co. KG
This program is Free Software; you can redistribute it and/or
modify it under the terms of version three of the GNU Affero General Public
Expand Down Expand Up @@ -34,18 +34,18 @@
#include "include/bareos.h"
#include "include/jcr.h"
#include "lib/util.h"
#include <regex>

db_log_insert_func p_db_log_insert = NULL;

#define FULL_LOCATION 1 /* set for file:line in Debug messages */

/*
* This is where we define "Globals" because all the daemons include this file.
*/
DLL_IMP_EXP const char *working_directory = NULL; /* working directory path stored here */
DLL_IMP_EXP const char *assert_msg = (char *)NULL; /* ASSERT2 error message */
DLL_IMP_EXP int verbose = 0; /* increase User messages */
DLL_IMP_EXP int debug_level = 0; /* debug level */
DLL_IMP_EXP std::string d_msg_srcfile_filter_expression; /* regex to filter the debug output */
DLL_IMP_EXP bool dbg_timestamp = false; /* print timestamp in debug output */
DLL_IMP_EXP bool prt_kaboom = false; /* Print kaboom output */
DLL_IMP_EXP utime_t daemon_start_time = 0; /* Daemon start time */
Expand Down Expand Up @@ -1210,10 +1210,27 @@ static void pt_out(char *buf)
fflush(stdout);
}

/*
* If the Debug Filter Message Regex is not set, we log everything.
* If it is set, we only log messages that are generated in a file whose filename matches the regex.
*/
bool DebugMessageFilterMatches(std::string &filename)
{
if (d_msg_srcfile_filter_expression.empty())
{
return true;
}
std::regex message_filter_regex (d_msg_srcfile_filter_expression);
if (std::regex_match(filename, message_filter_regex))
{
return true;
}
return false;
}

/*
* This subroutine prints a debug message if the level number is less than or
* equal the debug_level. File and line numbers are included for more detail if
* desired, but not currently printed.
* equal the debug_level. File and line numbers are included for more detail
*
* If the level is negative, the details of file and line number are not printed.
*/
Expand All @@ -1234,40 +1251,40 @@ void d_msg(const char *file, int line, int level, const char *fmt,...)
}

if (level <= debug_level) {
if (dbg_timestamp) {
mtime = GetCurrentBtime();
usecs = mtime % 1000000;
Mmsg(buf, "%s.%06d ", bstrftimes(ed1, sizeof(ed1), BtimeToUtime(mtime)), usecs);
pt_out(buf.c_str());
}
std::string basename = get_basename(file);
if (DebugMessageFilterMatches( basename )) {
if (dbg_timestamp) {
mtime = GetCurrentBtime();
usecs = mtime % 1000000;
Mmsg(buf, "%s.%06d ", bstrftimes(ed1, sizeof(ed1), BtimeToUtime(mtime)), usecs);
pt_out(buf.c_str());
}

#ifdef FULL_LOCATION
if (details) {
Mmsg(buf, "%s (%d): %s:%d-%u ", my_name, level, get_basename(file), line, GetJobidFromTsd());
}
#endif
if (details) {
Mmsg(buf, "%s (%d): %s:%d-%u ", my_name, level, basename.c_str(), line,
GetJobidFromTsd());
}

while (1) {
maxlen = more.MaxSize() - 1;
va_start(ap, fmt);
len = Bvsnprintf(more.c_str(), maxlen, fmt, ap);
va_end(ap);
while (1) {
maxlen = more.MaxSize() - 1;
va_start(ap, fmt);
len = Bvsnprintf(more.c_str(), maxlen, fmt, ap);
va_end(ap);

if (len < 0 || len >= (maxlen - 5)) {
more.ReallocPm(maxlen + maxlen / 2);
continue;
if (len < 0 || len >= (maxlen - 5)) {
more.ReallocPm(maxlen + maxlen / 2);
continue;
}

break;
}

break;
}
if (details) {
pt_out(buf.c_str());
}

#ifdef FULL_LOCATION
if (details) {
pt_out(buf.c_str());
pt_out(more.c_str());
}
#endif

pt_out(more.c_str());
}
}

Expand Down Expand Up @@ -1339,11 +1356,9 @@ void p_msg(const char *file, int line, int level, const char *fmt,...)
PoolMem buf(PM_EMSG),
more(PM_EMSG);

#ifdef FULL_LOCATION
if (level >= 0) {
Mmsg(buf, "%s: %s:%d-%u ", my_name, get_basename(file), line, GetJobidFromTsd());
}
#endif

while (1) {
maxlen = more.MaxSize() - 1;
Expand All @@ -1359,11 +1374,9 @@ void p_msg(const char *file, int line, int level, const char *fmt,...)
break;
}

#ifdef FULL_LOCATION
if (level >= 0) {
pt_out(buf.c_str());
}
#endif

pt_out(more.c_str());
}
Expand All @@ -1380,13 +1393,11 @@ void p_msg_fb(const char *file, int line, int level, const char *fmt,...)
int len = 0;
va_list arg_ptr;

#ifdef FULL_LOCATION
if (level >= 0) {
len = Bsnprintf(buf, sizeof(buf), "%s: %s:%d-%u ",
my_name, get_basename(file), line,
GetJobidFromTsd());
}
#endif

va_start(arg_ptr, fmt);
Bvsnprintf(buf + len, sizeof(buf) - len, (char *)fmt, arg_ptr);
Expand Down Expand Up @@ -1423,11 +1434,9 @@ void t_msg(const char *file, int line, int level, const char *fmt,...)
trace_fd = fopen(fn.c_str(), "a+b");
}

#ifdef FULL_LOCATION
if (details) {
Mmsg(buf, "%s: %s:%d-%u ", my_name, get_basename(file), line, GetJobidFromTsd());
}
#endif

while (1) {
maxlen = more.MaxSize() - 1;
Expand All @@ -1444,11 +1453,9 @@ void t_msg(const char *file, int line, int level, const char *fmt,...)
}

if (trace_fd != NULL) {
#ifdef FULL_LOCATION
if (details) {
fputs(buf.c_str(), trace_fd);
}
#endif
fputs(more.c_str(), trace_fd);
fflush(trace_fd);
}
Expand Down
21 changes: 11 additions & 10 deletions core/src/lib/unittests/CMakeLists.txt
Expand Up @@ -25,19 +25,20 @@ ENDIF()
set (TEST_SRC
alist_test.cc
dlist_test.cc
# base64_test.cc
# bsnprintf_test.cc
# devlock_test.cc
# edit_test.cc
htable_test.cc
# junction_test.cc
# passphrase_test.cc
# scan_test.cc
d_msg_test.cc
# base64_test.cc
# bsnprintf_test.cc
# devlock_test.cc
# edit_test.cc
# junction_test.cc
# passphrase_test.cc
# scan_test.cc
# rwlock_test.cc
# sellist_test.cc
#tree_test.cc
#rblist_test.cc
#ini_test.cc
# tree_test.cc
# rblist_test.cc
# ini_test.cc
)


Expand Down
89 changes: 89 additions & 0 deletions core/src/lib/unittests/d_msg_test.cc
@@ -0,0 +1,89 @@
/*
BAREOS® - Backup Archiving REcovery Open Sourced
Copyright (C) 2018-2018 Bareos GmbH & Co. KG
This program is Free Software; you can redistribute it and/or
modify it under the terms of version three of the GNU Affero General Public
License as published by the Free Software Foundation and included
in the file LICENSE.
This program is distributed in the hope that it will be useful, but
WITHOUT ANY WARRANTY; without even the implied warranty of
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
Affero General Public License for more details.
You should have received a copy of the GNU Affero General Public License
along with this program; if not, write to the Free Software
Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
02110-1301, USA.
*/
#include "gtest/gtest.h"
#include <iostream>
#include <fstream>
#include "include/bareos.h"

extern std::string d_msg_srcfile_filter_expression; /* regex to filter the debug output */

std::string myname = "d_msg_unittest";
std::string working_dir = "/tmp";
std::string tracefilename = working_dir + "/" + myname + ".trace";

static void init_for_test() {
std::remove(tracefilename.c_str());
debug_level = 3;
working_directory = working_dir.c_str();
MyNameIs(0, NULL, myname.c_str());
InitMsg(NULL, NULL);

SetTrace(0); // sync file
SetTrace(1);
}

std::string read_one_line() {
std::ifstream file(tracefilename);
std::string logline;
getline(file, logline);
file.close();
return logline;
}

TEST(d_msg, output_below_debug_level) {
init_for_test();
d_msg("dir/file", 12345, 1, "This is a log message\n");
ASSERT_EQ(read_one_line(), "d_msg_unittest (1): dir/file:12345-0 This is a log message");
}

TEST(d_msg, output_equal_to_debug_level) {
init_for_test();
d_msg("dir/file", 12345, 3, "This is a log message\n");
ASSERT_EQ(read_one_line(), "d_msg_unittest (3): dir/file:12345-0 This is a log message");
}

TEST(d_msg, noout_higher_than_debug_level) {
init_for_test();
d_msg("dir/file", 12345, 5, "This is a log message\n");
ASSERT_TRUE(read_one_line().empty());
}

// tests for regex filtering
TEST(d_msg, noout_regex_doesnt_match) {
init_for_test();
d_msg_srcfile_filter_expression = "dir/blub";
d_msg("dir/file", 12345, 1, "This is a log message\n");

ASSERT_TRUE(read_one_line().empty());
d_msg_srcfile_filter_expression = "";
}

TEST(d_msg, output_regex_match) {
init_for_test();
d_msg_srcfile_filter_expression = "dir/.*";
d_msg("dir/file", 12345, 1, "This is a log message\n");
d_msg("filed/file", 12345, 1, "This is a log message\n");
d_msg("stored/file", 12345, 1, "This is a log message\n");
d_msg("console/file", 12345, 1, "This is a log message\n");

ASSERT_EQ(read_one_line(), "d_msg_unittest (1): dir/file:12345-0 This is a log message");
d_msg_srcfile_filter_expression = "";
}

0 comments on commit b95c3a3

Please sign in to comment.