OMNeT++/OMNEST Bug Tracker - OMNeT++
View Issue Details
0000016OMNeT++runtime / Tkenvpublic2008-12-03 14:202008-12-09 15:27
heep 
andras 
normalminoralways
resolvedfixed 
4.0b8 
4.0rc1 
0000016: "fast mode" very slow
The "fast mode" is 0000003:0000010 times slower than in OMNET-3.4b2, TKenv blocks.
No tags attached.
patch disable-filtering.patch (1,567) 2008-12-04 16:32
https://dev.omnetpp.org/bugs/file_download.php?file_id=3&type=bug
Issue History
2008-12-03 14:20heepNew Issue
2008-12-03 14:25heepNote Added: 0000048
2008-12-03 15:46andrasNote Added: 0000051
2008-12-03 16:23stkrauseNote Added: 0000052
2008-12-03 16:42stkrauseNote Edited: 0000052
2008-12-03 22:38andrasNote Added: 0000054
2008-12-04 10:08stkrauseNote Added: 0000055
2008-12-04 12:04stkrauseNote Added: 0000058
2008-12-04 15:06andrasNote Added: 0000061
2008-12-04 16:32andrasFile Added: disable-filtering.patch
2008-12-04 16:33andrasNote Added: 0000062
2008-12-06 09:21andrasNote Added: 0000067
2008-12-06 09:21andrasStatusnew => resolved
2008-12-06 09:21andrasFixed in Version => 4.0rc1
2008-12-06 09:21andrasResolutionopen => fixed
2008-12-06 09:21andrasAssigned To => andras
2008-12-06 22:52andrasNote Added: 0000071
2008-12-09 15:27andrasNote Added: 0000084

Notes
(0000048)
heep   
2008-12-03 14:25   
10 times slower, blocks frequently for several seconds (2200 messages present -> 50 events/s)
(0000051)
andras   
2008-12-03 15:46   
Could you be a little more specific? What kind of simulation? Is it possible that eventlog recording is turned ON in 4.0, or you're recording a lot more data into output vectors than with 3.4b2?

Blocks frequently for several seconds: that's because the output vector manager keeps data buffered, and writes them out in large chunks (that's when the blocking occurs). This is normal behaviour.
(0000052)
stkrause   
2008-12-03 16:23   
(edited on: 2008-12-03 16:42)
We're doing OverSim-Quon simulations. Eventlog recourding is turned off. The simulation is exactly the same, so we are not recording more data. Also, "frequently blocking" means "almost the whole time", i.e. every time I click a button it takes several seconds until omnet reacts. This does not happen in "normal" or "express" mode.

The speed problem seems to connect to the number of lines in the scrollback buffer, as the simulation speed decreses (quickly) after switching from express to fast at any given point in the simulation. Scrollback buffer size is 100k, in omnet4 as well as omnet3.

The blocking problem seems to be that omnet only refreshes when it displays a string in the output window. If you filter the output to only display the output of a module that produces no output, omnet will stay frozen.

(0000054)
andras   
2008-12-03 22:38   
OK I know what frequent blocking means: Tkenv processes UI messages every x simulation events; this x can be changed in the Simulation Options dialog -> General tab -> Update Freq. If you have 50 ev/s, then Update Freq should be <50... (Note: maybe it would be better to make it time based, not event number based.)

How does event/sec change when you turn off UI features one by one, that is:
 - close graphical inspectors,
 - hide object tree in the main window (using toolbar icon),
 - hide timeline,
 - disable logging into the main window (Sim.Options->General->top checkbox) ?
(0000055)
stkrause   
2008-12-04 10:08   
To blocking: Time based updates should be MUCH better, especially when combined with filtering.

To speed:
- close graphical inspectors: no imprivement
- close object tree: no improvement
- close timeline: no improvement
- disable logging: bingo. Speed increases by a factor of 300.
(0000058)
stkrause   
2008-12-04 12:04   
A quick valgrind shows the problem may be related to the use of elide (0000017:0000057) in the main window: Most of the runtime was spend in "TkTextIsElided" and "TkBTreeGetTags" (even when not filtering output at all)
(0000061)
andras   
2008-12-04 15:06   
Yep. Looks like the tagging feature of the Tk text widget (see bug 0000017) doesn't scale to having hundres of tags... (Currently every module ID is used as a tag.) I'll investigate doing the filtering in another way.
(0000062)
andras   
2008-12-04 16:33   
Attached a temporary workaround patch (filtering won't work but simulation will run faster).
(0000067)
andras   
2008-12-06 09:21   
I reimplemented filtering in another way. Now I store the log messages in the memory myself, and on closing the filter dialog I re-fill the text widget with manually filtered contents. This fixes strange scrolling behavior (0000017) as well.

New feature that came as side effect from storing the log: when you open a per-module output window, it comes up containing previous messages (and not empty as it used to).

Current issue: Tk takes its time to clear existing window contents, i.e. ".main.text delete 1.0 end" takes forever. Destroying and re-creating the widget would be instantaneous, but very cumbersome to implement...
(0000071)
andras   
2008-12-06 22:52   
Found workaround for lousy "delete 1.0 end" performance: need to delete tags from the widget first. Makes it very fast (<<1s).
(0000084)
andras   
2008-12-09 15:27   
Changed Tkenv to use time-based display updates during Fast/Express Run (by default every 500ms and 1000ms, respectively; configurable from the Options dialog)