[Vm-dev] start up performance regression on Mac OS X
Eliot Miranda
eliot.miranda at gmail.com
Sat Oct 13 02:58:59 UTC 2018
On Fri, Oct 12, 2018 at 7:38 PM Eliot Miranda <eliot.miranda at gmail.com>
wrote:
> Hi John,
>
> On Fri, Oct 12, 2018 at 1:46 PM John McIntosh <
> johnmci at smalltalkconsulting.com> wrote:
>
>> Ok, well this code comes from the original implementation in 2010.
>>
>> What it is doing is priming the sound system, by starting up the sound
>> api, feeding it silence, then stopping it.
>> It was written so that the sound plugin was ready to go when someone used
>> the soundPlugin.
>> A 500 ms pause on just the first use of sound drove certain musically
>> inclined folks crazy. As you saw "appalling startup performance"
>>
>
> Actually I think this is Apple's regression and Apple's bug. I see a
> similar performance regression in Safari. Open a new tab. Do a search in
> the URL fields. First, one sees the meatball cursor. Subsequently one
> cannot click any of the links for several seconds. This is on
> Safari Version 12.0 (13606.2.11), macOS High Sierra Version 10.13.6. Does
> anyone else see this or is my system in some strange state?
>
Indeed, fixed by a reboot. This is some weird state the sound system gets
into when switching between an Apple cinema display, some bluetooth
headphones/microphones and AirPlay. Sorry about the noice.
So John, if I understand correctly the code in the VM does actually cause a
0.5 second startup delay. That's, um, undesirable, to say the least. I
agree that we should fix this but is the complexity you outline below
necessary? Isn't there some kind of sound reset call in the API?
>
>
> What could be change by someone with the will to write a bit of code,
>> (then test) is to fork off the sound setup message by sending then "
>> setupSoundLogic" (or maybe separate out the logic after the creation of
>> the soundInterfaceLogic) on a worker thread, then have a guard mutex on
>> the accessor soundInterfaceLogic (just add a explicit
>> soundInterfaceLogic accessor to sqSqueakOSXApplication) so that a call
>> to the OSX soundPlugin like soundInit can not complete until we have
>> fully created the sqSqueakSoundCoreAudio instance. Perhaps the use of
>> @synchronized(soundInterfaceLogic) {}
>>
>> This all assumes use of any platform API can be done on a worker thread
>> versus the main thread.
>>
>>
>> On Thu, Oct 11, 2018 at 9:41 PM, Eliot Miranda <eliot.miranda at gmail.com>
>> wrote:
>>
>>>
>>> Hi All,
>>>
>>> it seems due to this code:
>>>
>>> frame #29: 0x0015358c Squeak`-[sqSqueakOSXApplication
>>> setupSoundLogic](self=0x02408810, _cmd="setupSoundLogic") + 412 at
>>> sqSqueakOSXApplication.m:152
>>> 149 snd_Start(2644, 22050, 1, 0);
>>> 150 char silence[10576];
>>> 151 bzero(&silence, sizeof(silence));
>>> -> 152 snd_PlaySamplesFromAtLength(2644,(usqInt * ) &silence,0);
>>> 153 [self.soundInterfaceLogic snd_Stop_Force];
>>> 154 }
>>> 155
>>>
>>> who wrote it? Surely there's a better way of ensuring the sound system
>>> is in a silent way...
>>>
>>> On Thu, Oct 11, 2018 at 9:36 PM Eliot Miranda <eliot.miranda at gmail.com>
>>> wrote:
>>>
>>>> Hi All,
>>>>
>>>> in building new VMs today I see appalling startup performance on
>>>> Mac OS X. It seems to be related to event setup and/or sound
>>>> initialization. I ran under a debugger and interrupted while the system
>>>> was (slowly) launching and both times I saw a similar stack; see below. So
>>>> the system looks to be caught in some kind of initialization loop:
>>>>
>>>> frame #7: 0x9331ff16
>>>> CoreAudio`HALC_ShellSimpleProxyList::Reconcile(bool, bool) + 646
>>>> frame #8: 0x9331f569 CoreAudio`HALC_ShellPlugIn::ConnectToServer()
>>>> + 153
>>>> frame #9: 0x9338904e
>>>> CoreAudio`HAL_HardwarePlugIn_InitializeWithObjectID(AudioHardwarePlugInInterface**,
>>>> unsigned long) + 78
>>>> frame #10: 0x9331d818 CoreAudio`HALPlugIn::Initialize() + 48
>>>> frame #11: 0x9331c3a0
>>>> CoreAudio`HALPlugInManagement::CreateHALPlugIn(HALCFPlugIn const*) + 2048
>>>> frame #12: 0x9331ac08 CoreAudio`HALPlugInManagement::Initialize() +
>>>> 552
>>>> frame #13: 0x93317070 CoreAudio`HALSystem::CheckOutInstance() + 190
>>>> frame #14: 0x9331e4bb CoreAudio`AudioObjectGetPropertyData + 81
>>>> frame #15: 0x92643947 AudioToolbox`AQMEIO_HAL::Init() + 201
>>>> frame #16: 0x92643132
>>>> AudioToolbox`AQMEIOManager::_FindIOUnit(__CFString const*) + 110
>>>> frame #17: 0x92642f23
>>>> AudioToolbox`AQMEDevice::InitPhase2(__CFString const*) + 239
>>>> frame #18: 0x92642e2e AudioToolbox`AQMixEngine_Single::InitPhase2()
>>>> + 24
>>>> frame #19: 0x92642a34
>>>> AudioToolbox`AQIONodeManager::_FindAQIONode(bool, __CFString const*) + 154
>>>> frame #20: 0x926426a9
>>>> AudioToolbox`AudioQueueObject::DoIONodeConnect(bool) + 963
>>>> frame #21: 0x92715bfe
>>>> AudioToolbox`AudioQueueObject::GetIONodeConnection_Init(long&) + 40
>>>> frame #22: 0x9270b7c6
>>>> AudioToolbox`AudioQueueObject::GetConverterConnection_Init(long&) + 20
>>>> frame #23: 0x9265a77b
>>>> AudioToolbox`AudioQueueObject::AcquirePlayResources() + 215
>>>> frame #24: 0x92709095 AudioToolbox`AudioQueueObject::Prime(unsigned
>>>> long, unsigned long&) + 345
>>>> frame #25: 0x9265a571 AudioToolbox`AQServer_Prime + 95
>>>> frame #26: 0x9265a43d AudioToolbox`AudioQueuePrime + 364
>>>> frame #27: 0x0021c841 Squeak`-[sqSqueakSoundCoreAudio
>>>> snd_PlaySamplesFromAtLength:arrayIndex:startIndex:](self=0x0262e990,
>>>> _cmd="snd_PlaySamplesFromAtLength:arrayIndex:startIndex:", frameCount=2644,
>>>> arrayIndex="", startIndex=0) + 481 at sqSqueakSoundCoreAudio.m:319
>>>> frame #28: 0x0021ed8d
>>>> Squeak`snd_PlaySamplesFromAtLength(frameCount=2644, arrayIndex=0xbfffb588,
>>>> startIndex=0) + 125 at sqSqueakSoundCoreAudioAPI.m:62
>>>> frame #29: 0x0015358c Squeak`-[sqSqueakOSXApplication
>>>> setupSoundLogic](self=0x02408810, _cmd="setupSoundLogic") + 412 at
>>>> sqSqueakOSXApplication.m:152
>>>> frame #30: 0x0016b5c9 Squeak`-[sqSqueakMainApplication
>>>> runSqueak](self=0x02408810, _cmd="runSqueak") + 617 at
>>>> sqSqueakMainApplication.m:198
>>>> frame #31: 0x95216299 Foundation`__NSFirePerformWithOrder + 432
>>>> frame #32: 0x9379a496
>>>> CoreFoundation`__CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__
>>>> + 22
>>>> frame #33: 0x9379a3b2 CoreFoundation`__CFRunLoopDoObservers + 498
>>>> frame #34: 0x9377d7fd CoreFoundation`__CFRunLoopRun + 1661
>>>> frame #35: 0x9377ce51 CoreFoundation`CFRunLoopRunSpecific + 641
>>>> frame #36: 0x9377cbba CoreFoundation`CFRunLoopRunInMode + 122
>>>> frame #37: 0x92d7a37b HIToolbox`RunCurrentEventLoopInMode + 321
>>>> frame #38: 0x92d79f5f HIToolbox`ReceiveNextEventCommon + 454
>>>> frame #39: 0x92d79d7b
>>>> HIToolbox`_BlockUntilNextEventMatchingListInModeWithFilter + 71
>>>> frame #40: 0x9137ab2d AppKit`_DPSNextEvent + 2101
>>>> frame #41: 0x91aece90 AppKit`-[NSApplication(NSEvent)
>>>> _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 2859
>>>> frame #42: 0x91aec35d AppKit`-[NSApplication(NSEvent)
>>>> nextEventMatchingMask:untilDate:inMode:dequeue:] + 134
>>>> frame #43: 0x9136fa7d AppKit`-[NSApplication run] + 763
>>>> frame #44: 0x91341b3a AppKit`NSApplicationMain + 1228
>>>> frame #45: 0x0016558b Squeak`main(argc=2, argv=0xbffff624,
>>>> envp=0xbffff630) + 91 at main.m:52
>>>> frame #46: 0xa728f611 libdyld.dylib`start + 1
>>>>
>>>>
>>>> I changed sqSqueakOSXApplication.m in August, but only to add some
>>>> option processing. Anyone have any ideas?
>>>>
>>>> --
>>>> _,,,^..^,,,_
>>>> best, Eliot
>>>>
>>>
>>>
>>> --
>>> _,,,^..^,,,_
>>> best, Eliot
>>>
>>>
>>
>>
>> --
>>
>> ===========================================================================
>> John M. McIntosh. Corporate Smalltalk Consulting Ltd
>> https://www.linkedin.com/in/smalltalk
>>
>> ===========================================================================
>>
>
>
> --
> _,,,^..^,,,_
> best, Eliot
>
--
_,,,^..^,,,_
best, Eliot
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.squeakfoundation.org/pipermail/vm-dev/attachments/20181012/5165ea04/attachment-0001.html>
More information about the Vm-dev
mailing list