Scheduled tasks not preserving order with Dynamic?

Question

In studying the last Basic Example in the documentation for StartScheduledTask, namely

fun := With[{t = RandomInteger[{1, 3}]}, 
  Print["Waiting ", t, " seconds."]; Pause[t]]

RunScheduledTask[fun; StartScheduledTask[$ScheduledTask], {1}];

RemoveScheduledTask[ScheduledTasks[]];

I first noted that nothing Prints. That doesn't scare me too much; I would just guess that since the task is on another thread, it would have difficulty printing to the Notebook thread, and this might be a regression overlooked in recent versions (it doesn't print when evaluating directly in the documentation, either; MMA 9.0.1.0 on Mac OS X 10.9).

I decided to peek inside the task by making it assign something to a Dynamic that's on display in the Notebook, so I wrote

$foo = 1;

Dynamic[$foo]


RemoveScheduledTask@ScheduledTasks[];
$foo = -1;
    $fun[] :=
  With[{t = RandomReal[]},
   $foo = ("Waiting " <> ToString@N[t, 2] <> " seconds.");
       Pause[t]];
    RunScheduledTask[$fun[];
 StartScheduledTask[$ScheduledTask], {1}];

When I run this, the value of $foo is updated with the random number t, but it seems to be after doing the Pause. In other words, let's say t has the following sequence of values

0.10000
0.90000
0.20000

Now, I can feel the difference between 0.1 seconds and 0.9 seconds and 0.2 seconds, and it feels like 0.1 is Displayed for 0.9 seconds, and the number 0.9 is displayed for 0.2 seconds, and so on. In other words, the display looks like

Waiting 0.10000 seconds   (* this displays for 0.9 seconds *)
Waiting 0.90000 seconds   (* this displays for 0.2 seconds *)
etc.

What's going on here?

Answer 1

I think there are two things that go wrong: first by restarting $ScheduledTask you are also reusing the delay of one second that you gave with RunScheduledTask. Second your Pause might start before the Dynamic fires (or is finished). This seems to work as expected (I am using a slightly more complicated Dynamic which lets me better see what happen as I don't feel I can judge time differences below 1 second reliable...):

$foo = 1; lastTime = AbsoluteTime[];
    Dynamic[Function[lastTime = #2; 
       Row[{DateString[{"Minute", ":", "Second"}], ":    ", 
         Round[(#2 - #1)] -> $foo}]
       ][lastTime, AbsoluteTime[]], TrackedSymbols :> {$foo}]

$fun[] := With[{t = RandomChoice[Range[4]] + 0.1*RandomReal[]},
       $foo = ("Waiting " <> ToString@N[t, 2] <> " seconds.");
   FinishDynamic[];
   Pause[t]
   ];

$foo = -1;
    RemoveScheduledTask@ScheduledTasks[];
    RunScheduledTask[
      $fun[];
  StartScheduledTask[$ScheduledTask],
  {0.05}
  ];

The trick is to use FinishDynamic to let the Dynamic do its work before starting the Pause and also using only a very short delay in RunScheduledTask. When playing with this I found that there seems to be a problem with the general idea: it seems that the Pause within the scheduled task does block the kernel also for shift-return evaluations which might or might not be a problem for what you try to achieve. It certainly makes the FrontEnd feel very slow when used in the usual interactive way...