Berserk idleLoop in event handling?

Andreas Raab andreas.raab at gmx.de
Thu Jan 8 03:32:18 UTC 2004


Hi John,

> type 11 time 4121 Smalltalk Event Sensor get event prim end
>
> Time taken to get 3 events onto the Smalltalk EventSensor event queue
> is 2 milliseconds from initial keyboard press.
>
> type 20 time 4193 Morphic start Sensor nextEvent  {HandMorph
> processEvents}
>
> Time taken to get Morphic to wake and invoke Sensor nextEvent  74
> milliseconds

This smells either like GC or host processor scheduling. Process switching
in Squeak is Really Fast (tm) and should be nowhere near an msec (even on
slow machines - last time I measured a process switch in Squeak was at the
speed of roughly 4 message sends).

> type 21 time 4194 Morphic end Sensor nextEvent
> type 22 time 4194 Morphic start generateKeyboardEvent:  {HandMorph
> processEvents}
> type 23 time 4194 Morphic end generateKeyboardEvent:  {HandMorph
> processEvents}
> type 24 time 4194 Morphic start handleEvent:  {HandMorph processEvents}
> type 25 time 4225 Morphic end handleEvent:  {HandMorph processEvents}
>
> Time taken to get key down event thru Morphic Handler is  106
> milliseconds { Is that doing the display? }

Nope - processEvents doesn't do display, so unless your annotations are
wrong and these measures weren't really taken from processEvents there is no
display taking place (note that keyDown is never handled in a stock Squeak
so even implicit redraws such as from displayWorld in response to the event
aren't possible).

> type 20 time 4225 Morphic start Sensor nextEvent
> type 21 time 4225 Morphic end Sensor nextEvent
> type 22 time 4226 Morphic start generateKeyboardEvent:
> type 23 time 4226 Morphic end generateKeyboardEvent:
> type 24 time 4226 Morphic start handleEvent:
> type 25 time 4263 Morphic end handleEvent:
>
> Time taken to get key char code event thru Morphic Handler is  38
> milliseconds

Given that keyDown is never handled by a stock Squeak but keyStroke quite
heavily, I would suspect that the above 106 vs. 36 ms are really (again?) a
GC issue. If not, they can hardly be explained (unless again, the host
machine doing some processor scheduling).

> type 20 time 4266 Morphic start Sensor nextEvent
> type 21 time 4266 Morphic end Sensor nextEvent
> type 22 time 4266 Morphic start generateKeyboardEvent:
> type 23 time 4267 Morphic end generateKeyboardEvent:
> type 24 time 4267 Morphic start handleEvent:
> type 25 time 4268 Morphic end handleEvent:
>
> Time taken to get key char code event thru Morphic Handler is  5
> milliseconds

This should be keyUp with 2ms if I'm not mistaken. So the difference between
keyUp and keyDown (both aren't handled in a stock Squeak) is about 100ms.
Given that you have an initial delay of roughly 76ms all of the above might
indeed be explained by two very slow IGCs (76 vs. 100 ms respectively) or
host OS processor scheduling. In any case we would need at least the GC
stats with the log to make some sense.

Cheers,
  - Andreas




More information about the Squeak-dev mailing list