【发布时间】:2015-08-16 01:58:19
【问题描述】:
上下文
我为用户编写了一个记录器打印消息。级别为“debug”、“info”或“warning”的消息打印在std::cout 中,级别为“error”或“system_error”的消息打印在std::cerr 中。我的程序不是多线程的。我在 Linux openSUSE 12.3 下使用 gcc 4.7.2 和 CMake 3.1.0 工作。
我的问题
我发现有时,当一条长信息消息(以std::cout 打印)之后出现错误消息(以std::cerr 打印)并且当输出被CTest 重定向到文件LastTest.log 时,会出现错误消息在信息消息中(请看下面的示例)。我不太了解这种行为,但我想为std::cout 启动了一个写入线程,然后代码继续,并且为std::cerr 启动另一个写入线程,而无需等待第一个线程终止。
不使用std::cout 是否可以避免这种情况?
我在终端中没有问题。仅当 CTest 将输出重定向到 LastTest.log 文件时才会发生这种情况。
请注意,我的缓冲区已刷新。这不是std::endl 呼叫std::cerr 之后的问题!
示例
预期行为:
[ 12:06:51.497 TRACE ] Start test
[ 12:06:52.837 WARNING ] This
is
a
very
long
warning
message...
[ 12:06:52.837 ERROR ] AT LINE 49 : 7
[ 12:06:52.841 ERROR ] AT LINE 71 : 506
[ 12:06:52.841 TRACE ] End of test
会发生什么:
[ 12:06:51.497 TRACE ] Start test
[ 12:06:52.837 WARNING ] This
is
a
very
long
[ 12:06:52.837 ERROR ] AT LINE 49 : 7
warning
message...
[ 12:06:52.841 ERROR ] AT LINE 71 : 506
[ 12:06:52.841 TRACE ] End of test
我如何称呼我的记录器
这是我如何使用记录器调用std::cout 或std::cerr 的示例。
我用这样的宏调用记录器:
#define LOG_DEBUG(X) {if(Log::debug_is_active()){std::ostringstream o;o<<X;Log::debug(o.str());}}
#define LOG_ERROR(X) {if(Log::error_is_active()){std::ostringstream o;o<<X;Log::error(o.str());}}
//...
LOG_DEBUG("This" << std::endl << "is" << std::endl << "a message");
LOG_ERROR("at line " << __LINE__ << " : " << err_id);
与
void Log::debug(const std::string& msg)
{
Log::write_if_active(Log::DEBUG, msg);
}
void Log::error(const std::string& msg)
{
Log::write_if_active(Log::ERROR, msg);
}
//...
void Log::write_if_active(unsigned short int state, const std::string& msg)
{
Instant now;
now.setCurrentTime();
std::vector<std::string> lines;
for(std::size_t k = 0; k < msg.size();)
{
std::size_t next_endl = msg.find('\n', k);
if(next_endl == std::string::npos)
next_endl = msg.size();
lines.push_back(msg.substr(k, next_endl - k));
k = next_endl + 1;
}
boost::mutex::scoped_lock lock(Log::mutex);
for(unsigned long int i = 0; i < Log::chanels.size(); ++i)
if(Log::chanels[i])
if(Log::chanels[i]->flags & state)
Log::chanels[i]->write(state, now, lines);
}
这里,log chanel是专门用于终端输出的对象,写函数是:
void Log::StdOut::write(unsigned short int state, const Instant& t, const std::vector<std::string>& lines)
{
assert(lines.size() > 0 && "PRE: empty lines");
std::string prefix = "[ ";
if(this->withDate || this->withTime)
{
std::string pattern = "";
if(this->withDate)
pattern += "%Y-%m-%d ";
if(this->withTime)
pattern += "%H:%M:%S.%Z ";
prefix += t.toString(pattern);
}
std::ostream* out = 0;
if(state == Log::TRACE)
{
prefix += " TRACE";
out = &std::cout;
}
else if(state == Log::DEBUG)
{
prefix += " DEBUG";
out = &std::cout;
}
else if(state == Log::INFO)
{
prefix += " INFO";
out = &std::cout;
}
else if(state == Log::WARNING)
{
prefix += "WARNING";
out = &std::cout;
}
else if(state == Log::ERROR)
{
prefix += " ERROR";
out = &std::cerr;
}
else if(state == Log::SYS_ERROR)
{
prefix += "SYERROR";
out = &std::cerr;
}
else
assert(false && "PRE: Invalid Log state");
prefix += " ] ";
(*out) << prefix << lines[0] << "\n";
prefix = std::string(prefix.size(), ' ');
for(unsigned long int i = 1; i < lines.size(); ++i)
(*out) << prefix << lines[i] << "\n";
out->flush();
}
你可以看到我的缓冲区在执行日志指令的时候被刷新了。
【问题讨论】:
-
是的,但是在
std::cerr中打印错误消息的 C++ 指令位于在std::cout中打印最后一个std::endl的指令之后。 -
如果您在程序开始时发出
std::ios_base::sync_with_stdio(false);,有什么变化吗? -
@Hurkyl:
sync_with_stdio完全不同。 -
@Nawaz:可能。但是很难找到的错误通常发生在您确信自己不可能找到错误的地方,这是一件容易测试的事情。 (此外,它使语句“
cout被缓冲”实际上是正确的;在我看到的实现中,cout通常在同步开启时根本不被缓冲;缓冲被委托给stdio库) -
@Nawaz:实际上,我目前的赌注是在 Linux 中的重定向做一些令人惊讶的事情,我评论的重点是消除 Linux 之间的交互以及如何设置
stdio库。 (还有……有时库中确实存在错误)
标签: c++ output io-redirection ctest