Berserk idleLoop in event handling?John M McIntosh johnmci at smalltalkconsulting.comThu Jan 8 05:21:01 UTC 2004
On Jan 7, 2004, at 7:32 PM, Andreas Raab wrote:
> 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).
See new listing below
>
>> 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).
? Is that doing the display? Well I'm accounting for the 106 ms, must
be a GC
see below
>
>> 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).
Ya, see below
>
>> 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.
That is correct.
Another Try:
Given I've added event type 80, 81, 82
resume: aProcess
| activeProc activePriority newPriority |
self inline: false.
activeProc _ self fetchPointer: ActiveProcessIndex
ofObject: self schedulerPointer.
activePriority _ self quickFetchInteger: PriorityIndex ofObject:
activeProc.
newPriority _ self quickFetchInteger: PriorityIndex ofObject:
aProcess.
newPriority > activePriority ifTrue: [
self putToSleep: activeProc. /* Event type 80 */
self transferTo: aProcess.
] ifFalse: [
self putToSleep: aProcess. /* Event type 81 */
].
transferTo: aProc
"Record a process to be awoken on the next interpreter cycle.
ikp 11/24/1999 06:07 -- added hook for external runtime compiler"
/* Event type 82 */
plus
1 for start of sleep
2 for end of sleep
3 for end sleep pending delay when called
70 for start of Incremental GC
71 for end of Incremental GC
72 for start of FULL GC
73 for end of FULL GC
now I see
type 70 time 5962 Increment GC start
type 71 time 5988 Increment GC end
type 25 time 6013 Morphic end handleEvent: {HandMorph processEvents}
type 7 time 6190 KEY PRESS
{ I do signal the event sensor input semaphore }
{As expected this starts the EventSenor ioProcess to run ASAP}
type 80 time 6191 resume: (newPriority > activePriority)
type 82 time 6191 transferTo:
type 10 time 6191 EventSensor get event start
type 11 time 6192 EventSensor get event end
type 12 time 6192 EventSensor put key down on queue
type 10 time 6192
type 11 time 6192
type 12 time 6192 EventSensor put key char on queue
type 10 time 6193
type 11 time 6193
type 12 time 6193 EventSensor put key up on queue
type 10 time 6193
type 11 time 6193
type 82 time 6193 transferTo:
Events placed on EventSensor event queue, 2ms
Waiting for the HandMorph processEvents to run???
type 70 time 6265 INCREMENTAL GC START
type 71 time 6267 INCREMENTAL GC END
type 81 time 6300 resume: newPriority <= activePriority
type 82 time 6300 transferTo:
type 81 time 6300 resume: newPriority <= activePriority
type 82 time 6301 transferTo:
type 20 time 6301 Morphic start Sensor nextEvent {HandMorph
processEvents}
108 ms before HandMorph processEvents starts Sensor nextEvent
type 21 time 6301 Morphic end Sensor nextEvent {Pehaps an idle, or
mouse here, not keyboard 40ms gets chewed tho}
type 24 time 6301 Morphic start handleEvent: {HandMorph
processEvents}
type 25 time 6340 Morphic end handleEvent: {HandMorph processEvents}
type 70 time 6453 INCREMENTAL GC START
type 71 time 6457 INCREMENTAL GC END
type 81 time 6486 resume: newPriority <= activePriority
type 82 time 6486 transferTo:
type 81 time 6486 resume: newPriority <= activePriority
type 82 time 6486 transferTo:
type 20 time 6487 Morphic start Sensor nextEvent {Key down
processing starts}
type 21 time 6487 Morphic end Sensor nextEvent
type 22 time 6487 Morphic start generateKeyboardEvent: {HandMorph
processEvents}
type 23 time 6487 Morphic end generateKeyboardEvent: {HandMorph
processEvents}
type 24 time 6487 Morphic start handleEvent: {HandMorph
processEvents}
type 25 time 6490 Morphic end handleEvent: {HandMorph processEvents}
type 20 time 6490 Morphic start Sensor nextEvent {Key char
type 21 time 6490
type 22 time 6490
type 23 time 6490
type 24 time 6490
type 25 time 6507
type 20 time 6508 Morphic start Sensor nextEvent {Key up
type 21 time 6508
type 22 time 6508
type 23 time 6508
type 24 time 6508
type 25 time 6509
type 20 time 6510 Morphic start Sensor nextEvent {
type 80 time 6510 resume: (newPriority > activePriority)
type 82 time 6510
type 10 time 6510
type 11 time 6510
316? ms to process one mouse event and keyboard event?
--
========================================================================
===
John M. McIntosh <johnmci at smalltalkconsulting.com> 1-800-477-2659
Corporate Smalltalk Consulting Ltd. http://www.smalltalkconsulting.com
========================================================================
===
More information about the Squeak-dev mailing list |