0000363: EventlogFileManager incorrectly assumes that sputn always takes a whole line terminated with '\n' as argument

View Issue Details [ Jump to Notes ]

[ Issue History ] [ Print ]

Project

Category

View Status

Date Submitted

Last Update

0000363

OMNeT++

simulation kernel

public

2011-06-24 13:33

Reporter

levy

Assigned To

levy

Priority

normal

Severity

minor

Reproducibility

always

Status

new

Resolution

open

Platform

OS Version

Product Version

4.2b2

Target Version

Fixed in Version

Summary

0000363: EventlogFileManager incorrectly assumes that sputn always takes a whole line terminated with '\n' as argument

Description

From: Jan Vogelgesang

i discovered a possible bug in the way the omnet++ event log is written.
I did some investigation and came up with a working patch. But i'am
afraid i didn't solve the root cause, only hide some of the bad effects.
For this reason i'have included my 'findings' in an extra section of
this mail, if anyone wants to continue investigation.
Caution: in-depth iostream-knowledge required ;-)

Version: OMNeT++ 4.2b2, compiled using gcc 4.4.3 on Ubuntu 10.04
Libraries used: Boost 1.45.0

+++ Description: +++

I'am using boost::iostreams::tee_device together with cEnvir's ostream
(ev.getOStream()). I include the actual code snippet this as [1], but
don't want to go in detail here, because i think the real problem is
unrelated to the boost classes, but related to the way the
EventLogWriter works.
The event log (.elog) written from the simulation contains extraneous
'-' characters at each line following an output send to ev.getOStream().
See following .elog snippet:

E # 8 t 1.1 m 6 ce 1 msg 10
- debug output from my application
- BS id 24 tid 23 eid 24 etid 23 c someMessage n someMessage
SH sm 6 sg 1572865 pd 0.1

This .elog file is clearly defective.

+++ Findings +++

I did some investigation, but i'am not an expert in iostream-stuff, so
please read the following with care:
The std::ostream and the boost::iostreams::stream seems to differs in
the way they communicate with the underlaying streambuf when
encountering std::endl.

The boost::iostreams::stream class is issuing the whole string
(including the trailing '\n') at once through
std::basic_streambuf<>::sputn(), which is calling evbuf::xsputn() (see
cenvir.cc:43). This function calls sync(), which eventually results in a
call to EventLogWriter::recordLogLine(...) (see eventlogwriter.cc:25).

Then boost::iostream is calling std::basic_streambuf<>::pubsync() - to
me this seems reasonable beheavior when handling a endl. pubsync() calls
evbuf::sync() and finally EventLogWriter::recordLogLine(...) is called
again, with parameter n==0.
EventLogWriter::recordLogLine(...) then outputs a leading '-' to the
next line, even if it is called with an empty buffer (n==0).

The std::ostream seems to use sputc(...) to output the trailing '\n' -
thus evbuf::xsputn() isn't called and don't issue an extra sync().

Suggestion: place a breakpoint at eventlogwriter.cc:27 when you start to
investigate this!

I assume a sync() on an empty buffer is supposed to do nothing. And
recordLogLine should not be called on each sync().

+++ Solution +++

For me the following simple patch works:

--- omnetpp-4.1-org/src/envir/eventlogwriter.pl 2010-06-11
18:57:36.000000000 +0200
+++ omnetpp-4.1/src/envir/eventlogwriter.pl 2011-06-23
15:51:46.232429428 +0200
@@ -188,6 +188,9 @@
void EventLogWriter::recordLogLine(FILE *f, const char *s, int n)
{
- CHECK(fprintf(f, \"- \"));
- CHECK(fwrite(s, 1, n, f));
+ if(n > 0)
+ {
+ CHECK(fprintf(f, \"- \"));
+ CHECK(fwrite(s, 1, n, f));
+ }
}

However, i'am afraid this patch doesn't solve the root cause.
In my opinion one should rethink the way recordLogLine is called - at
the moment it is called on each sync(). Thus additional calls to sync()
will do harm. It seems better to call it only on a complete line.

Hope this helps !

jan

[1]:
the following are just a condensed code snippet, part
of a complete omnet++ simulation. I think it should work in almost any
oment++ simulation application.

#include <boost/iostreams/tee.hpp>
#include <boost/iostreams/stream.hpp>
#include <iostream>

typedef boost::iostreams::tee_device<std::ostream,std::ostream>
TeeDevice;
typedef boost::iostreams::stream<TeeDevice> TeeStream;

//instantiate global output stream to cout and omnet ev
TeeDevice tee_debug_out_devices(ev.getOStream(),cout);
TeeStream debs(tee_debug_out_devices);

//...snip....
//somewhere in a function

debs << "debug output from my application" << endl;

Issue History
Date Modified	Username	Field	Change
2011-06-24 13:33	levy	New Issue
2011-06-24 13:33	levy	Assigned To	=> levy

Relationships

Notes
There are no notes attached to this issue.