Berserk idleLoop in event handling?

John M McIntosh johnmci at smalltalkconsulting.com
Thu Jan 8 02:58:22 UTC 2004


Right so I was chatting with Tim today about this and after dinner  
couldn't resist hacking something together.

The logging code to stderr collects data either as a call in the VM, or  
via a primitive call from smalltalk.
This comes from a debug VM which isn't optimized and it's rather slow.

Type Code, Time in Milliseconds, Comments
type 	1	time	4059	VM Sleep  - This is when we sleep the VM as a result  
of ioRelinquishProcessorForMicroseconds()
type 	2	time	4079	VM wake  - Waking up, back to doing Smalltalk
type 	20	time	4080	Morphic start Sensor nextEvent  {HandMorph  
processEvents}
type 	10	time	4080	Smalltalk Event Sensor get event prim start  
{EventSensor primGetNextEvent:}
type 	11	time	4080	Smalltalk Event Sensor get event prim end  
{EventSensor primGetNextEvent:}
type 	21	time	4080	Morphic end Sensor nextEvent  {HandMorph  
processEvents}
type 	7	time	4119	Key down in VM  {VM CODE handing the 'a' key being  
pressed}

YES the key is put on the internal VM queue and the input semaphore is  
signaled.

type 	10	time	4120	Smalltalk Event Sensor get event prim start

EventSensor ioProcess wakes and hunts for the VM event, 1 millisecond.

type 	11	time	4120	Smalltalk Event Sensor get event prim end
type 	12	time	4120	(key down) Smalltalk Event Sensor put on Event Queue
type 	10	time	4120	Smalltalk Event Sensor get event prim start
type 	11	time	4121	Smalltalk Event Sensor get event prim end
type 	12	time	4121	(Key code) Smalltalk Event Sensor put on Event Queue
type 	10	time	4121	Smalltalk Event Sensor get event prim start
type 	11	time	4121	Smalltalk Event Sensor get event prim end
type 	12	time	4121	(key up) Smalltalk Event Sensor put on Event Queue
type 	10	time	4121	Smalltalk Event Sensor get event prim start
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

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? }

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

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
Total time taken to handle the 3 keyboard events is 150 milliseconds.

type 	20	time	4269	Morphic start Sensor nextEvent


On Jan 7, 2004, at 1:59 AM, Andreas Raab wrote:

> Hi Tim,
>
>> So, I had a timestamped log of when events came in, when a screen
>> update happened and when the idleloop prim runs. Imagine my shock to
>> see the latter running nearly all the time - even between a key press
>> and the screen update to display the char! I'm not about to delve into
>> the event handling loop without a native guide (you think I'm  
>> _crazy_?)
>> so I'm wondering if anyone has been playing in that particular poo-pit
>> recently and noticed anything likely to let the idleloop go loopy?
>
> Not likely. IdleLoop is run when there is no system activity (e.g., no
> processes running) and given that the main morphic loop looks like
> - handle event(s)
> - redisplay
> - wait
> There shouldn't be an idleLoop inbetween the key press and the display
> update. Unless there's some blocking wait in keyboard processing  
> somewhere
> down the line I would suspect that this problem is caused by some  
> error in
> the logging process.
>
> BTW, one possibility to test this would be to set up a very low-level
> priority background process ("just" above the real background process)  
> and
> have it complain when its being run while Morphic processes events.
>
> Cheers,
>   - Andreas
>
>
>
>
--
======================================================================== 
===
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