Flushing output for world.Note

Posted by Graymane on Tue 24 Jun 2014 01:41 PM — 12 posts, 38,970 views.

Graymane USA Tue 24 Jun 2014 01:41 PM #0

I have a lua script where I want to run a long running operation and update the user as it progresses. So I have a loop and each iteration of the loop prints out progress.

...
for k in pairs (blah) do
print ("processing step " .. k)
...
end

The problem is that none of the print statements show up until the loop is done and I can't figure out a way to flush the output. I read that lua print is actually overridden by MushClient to do world.Note or the equivalent.

My question is, how can I write this loop to print out immediately?

Fiendish USA Global Moderator Tue 24 Jun 2014 02:33 PM #1

http://www.gammon.com.au/scripts/function.php?name=Repaint

Graymane USA Tue 24 Jun 2014 02:38 PM #2

Thanks! Worked like a charm.

Fiendish USA Global Moderator Tue 24 Jun 2014 02:42 PM #3

Though if you call Repaint too frequently you'll find that MUSHclient can slow down, because Repaint calls are expensive. I made a plugin that works around this.

https://code.google.com/p/aardwolfclientpackage/wiki/RepaintBuffer

Nick Gammon Australia Forum Administrator Tue 24 Jun 2014 09:48 PM #4

An alternative is to do SetStatus which I usually do for this sort of situation where you are keeping track of a lengthy operation. This should update immediately, although I have noticed that it may stop doing that if you lose focus on the output window.

Nick Gammon Australia Forum Administrator Wed 25 Jun 2014 03:57 AM #5

I measured doing 1000 Repaint calls in 2.73 seconds on my PC, so you could reckon the overhead of doing a single Repaint would be around 3 mS.

Nick Gammon Australia Forum Administrator Wed 25 Jun 2014 04:10 AM #6

Fiendish's plugin (rather cleverly) defers the repainting until OnPluginTick is called which itself is every 40 mS (25 times a second). So the overhead of 3 mS is now only expended every 40 mS.

This gives a 25 FPS frame rate which is pretty acceptable as that is what TV broadcast frame rates are (roughly).

Using his plugin (example code below) the time for the loop has reduced to 0.445 seconds which is therefore an overhead of 0.445 mS per iteration rather than 2.73 mS, which is somewhat of an improvement.


start = utils.timer ()
for i = 1, 1000 do
  print (i)
  BroadcastPlugin (999, "repaint")
end 
finish = utils.timer ()
print (finish - start, "seconds")

Fiendish USA Global Moderator Wed 25 Jun 2014 04:30 AM #7

Well...it will give between 10 and 25 fps, depending on load. OnPluginTick only gets called when the system isn't busy doing other things so the plugin forces a paint sometimes.

Now that I think about it more, I wonder if I don't need to change this to use timers instead. Calls made within 0.1 seconds of the last effective one will still get starved out by activity (blocking OnPluginTick) if no calls occur subsequently.

I think I recall timers being a bit slower though. Dilemma.

Fiendish USA Global Moderator Wed 25 Jun 2014 04:51 AM #8

If Repaint just naturally buffered calls internally, of course, all the overhead of custom timer creation and plugin callbacks would go away. Not to mention the plugintick spam in trace outputs.

Nick Gammon Australia Forum Administrator Wed 25 Jun 2014 08:21 PM #9

I tried that just now and it didn't work. Which didn't totally surprise me, as I was confused about how the Repaint_Buffer plugin worked anyway.

The reason for my confusion was that you are in a tight Lua loop (in this case) and there is no reason for timers to be processed until the Lua code exits back to the C++ main loop.

However then I noticed this:


function OnPluginBroadcast (msg, id, name, text)
   if (msg == 999 and text == "repaint") then
      repaint_on_tick = true
      if (utils.timer() - last_repaint_time > .1) then
         repaint_on_tick = false        
         Repaint()
         last_repaint_time = utils.timer()
      end
   end
end

The check for the timer right there is what makes it work.

Fiendish USA Global Moderator Thu 26 Jun 2014 03:08 AM #10

What did you try?

Quote:
The reason for my confusion was that you are in a tight Lua loop (in this case) and there is no reason for timers to be processed until the Lua code exits back to the C++ main loop.

I'm talking about leaving in this part

 if (utils.timer() - last_repaint_time > .1) then

because it's still necessary but replacing the

repaint_on_tick = true/false

with 0.1 second one-shot temporary timer set/unset calls and then removing the OnPluginTick callback.

Anyway, as you say the timer wouldn't get processed until later, so this wouldn't help. I guess nothing can be done about that edge case.

Nick Gammon Australia Forum Administrator Thu 26 Jun 2014 04:02 AM #11

Fiendish said:

What did you try?

To replicate what your plugin did in code, basically. It set a flag in Repaint and that flag was tested at the time it does the OnPluginTick stuff. However since that depended on a system timer firing and being noticed, it wasn't since the Lua script did not terminate and let Windows feed my code more events. So it did nothing basically.

The only reason your plugin works in a CPU loop (ie a lot of scripting) is your test for elapsed time.

Quote:

I'm talking about leaving in this part

...

because it's still necessary but replacing the

...

with 0.1 second one-shot temporary timer set/unset calls and then removing the OnPluginTick callback.

Unfortunately that wouldn't do much. I would have to basically replicate the entire plugin in code, including that test for time. You may as well just leave the plugin there.