Mac VM hanging
Locked
 
|
Hi,
I've been using the all-in-one 4.2 Squeak and can't figure out why the VM is hanging. I have some code that runs fine for about six minutes, but if I wrap it in a MessageTally spyOn: [], then the VM will hang after a while (typically 30 to 90 seconds). CMD-period does not wake it up. According to the activity monitor, cpu remains right around 100% and real memory at around 180 meg. Activity Monitor sampling output attached below. Any suggestions? Cheers, Bob Sampling process 71029 for 1 seconds with 1 millisecond of run time between samples Sampling completed, processing symbols... Analysis of sampling Squeak VM Opt (pid 71029) every 1 millisecond Call graph: 880 Thread_2507 543 markAndTrace 543 markAndTrace 247 updatePointersInRangeFromto 247 updatePointersInRangeFromto 63 sweepPhase 63 sweepPhase 8 interpret 8 interpret 6 updatePointersInRootObjectsFromto 6 updatePointersInRootObjectsFromto 5 aioPoll 3 select$DARWIN_EXTSN$NOCANCEL 3 select$DARWIN_EXTSN$NOCANCEL 2 __memcpy 2 __memcpy 3 ioProcessEvents 3 ReceiveNextEvent 3 ReceiveNextEventCommon 3 RunCurrentEventLoopInMode 3 CFRunLoopRunInMode 3 CFRunLoopRunSpecific 3 __CFRunLoopDoObservers 2 FlushAllBuffers(__CFRunLoopObserver*, unsigned long, void*) 1 FlushWindowObject(WindowData*, void**, unsigned char) 1 GetWindowPropertyCore(WindowData*, unsigned long, unsigned long, unsigned long, unsigned long*, void*) 1 HIGetCollectionItem 1 GetCollectionItem 1 FindItem(OpaqueCollection*, unsigned long, long, unsigned long*) 1 CollectionItemRec::getTag() 1 CollectionItemRec::getTag() 1 IsSafeToCallApplication 1 GetTaskStorageKeyForSafeToCall 1 GetTaskStorageKeyForSafeToCall 1 bsd_qsort 1 __CFRunLoopObserverQSortComparator 1 __CFRunLoopObserverQSortComparator 2 mapPointersInObjectsFromto 2 mapPointersInObjectsFromto 1 instantiateSmallClasssizeInBytes 1 instantiateSmallClasssizeInBytes 1 ioMicroMSecs 1 gettimeofday 1 __gettimeofday 1 __nanotime 1 __nanotime 1 markAndTraceInterpreterOops 1 markAndTraceInterpreterOops 880 Thread_2603 880 thread_start 880 _pthread_start 880 TimerThread 880 TSWaitOnSemaphoreCommon 880 TSWaitOnConditionTimedRelative 880 pthread_cond_timedwait_relative_np 880 _pthread_cond_wait 879 semaphore_timedwait_signal_trap 879 semaphore_timedwait_signal_trap 1 pthread_mutex_lock 1 semaphore_wait_trap 1 semaphore_wait_trap Total number in stack (recursive counted multiple, when >=5): Sort by top of stack, same collapsed (when >= 5): semaphore_timedwait_signal_trap 879 markAndTrace 543 updatePointersInRangeFromto 247 sweepPhase 63 interpret 8 updatePointersInRootObjectsFromto 6 Sample analysis of process 71029 written to file /dev/stdout |
|
|
Bob,
Are you saying that your code runs fine for six or more minutes, or are you saying that it runs fine for 6 minutes and then hangs? In other words, does it happen only when you wrap your code in MessageTally, or does MessageTally just seem to make it happen sooner? I don't know the Mac environment, but on the face of it this sounds like a system that is trying to grow object memory beyond available memory and just getting bogged down and unresponsive. Is there a code snippet you can share to reproduce? Dave On Sun, Jun 26, 2011 at 01:48:52PM -0400, Bob Arning wrote: > Hi, > > I've been using the all-in-one 4.2 Squeak and can't figure out why the > VM is hanging. I have some code that runs fine for about six minutes, > but if I wrap it in a > MessageTally spyOn: [], then the VM will hang after a while (typically > 30 to 90 seconds). CMD-period does not wake it up. According to the > activity monitor, cpu remains right around 100% and real memory at > around 180 meg. Activity Monitor sampling output attached below. Any > suggestions? > > Cheers, > Bob > > Sampling process 71029 for 1 seconds with 1 millisecond of run time > between samples > Sampling completed, processing symbols... > Analysis of sampling Squeak VM Opt (pid 71029) every 1 millisecond > Call graph: > 880 Thread_2507 > 543 markAndTrace > 543 markAndTrace > 247 updatePointersInRangeFromto > 247 updatePointersInRangeFromto > 63 sweepPhase > 63 sweepPhase > 8 interpret > 8 interpret > 6 updatePointersInRootObjectsFromto > 6 updatePointersInRootObjectsFromto > 5 aioPoll > 3 select$DARWIN_EXTSN$NOCANCEL > 3 select$DARWIN_EXTSN$NOCANCEL > 2 __memcpy > 2 __memcpy > 3 ioProcessEvents > 3 ReceiveNextEvent > 3 ReceiveNextEventCommon > 3 RunCurrentEventLoopInMode > 3 CFRunLoopRunInMode > 3 CFRunLoopRunSpecific > 3 __CFRunLoopDoObservers > 2 FlushAllBuffers(__CFRunLoopObserver*, unsigned > long, void*) > 1 FlushWindowObject(WindowData*, void**, unsigned > char) > 1 GetWindowPropertyCore(WindowData*, unsigned > long, unsigned long, unsigned long, unsigned long*, void*) > 1 HIGetCollectionItem > 1 GetCollectionItem > 1 FindItem(OpaqueCollection*, unsigned > long, long, unsigned long*) > 1 CollectionItemRec::getTag() > 1 CollectionItemRec::getTag() > 1 IsSafeToCallApplication > 1 GetTaskStorageKeyForSafeToCall > 1 GetTaskStorageKeyForSafeToCall > 1 bsd_qsort > 1 __CFRunLoopObserverQSortComparator > 1 __CFRunLoopObserverQSortComparator > 2 mapPointersInObjectsFromto > 2 mapPointersInObjectsFromto > 1 instantiateSmallClasssizeInBytes > 1 instantiateSmallClasssizeInBytes > 1 ioMicroMSecs > 1 gettimeofday > 1 __gettimeofday > 1 __nanotime > 1 __nanotime > 1 markAndTraceInterpreterOops > 1 markAndTraceInterpreterOops > 880 Thread_2603 > 880 thread_start > 880 _pthread_start > 880 TimerThread > 880 TSWaitOnSemaphoreCommon > 880 TSWaitOnConditionTimedRelative > 880 pthread_cond_timedwait_relative_np > 880 _pthread_cond_wait > 879 semaphore_timedwait_signal_trap > 879 semaphore_timedwait_signal_trap > 1 pthread_mutex_lock > 1 semaphore_wait_trap > 1 semaphore_wait_trap > > Total number in stack (recursive counted multiple, when >=5): > > Sort by top of stack, same collapsed (when >= 5): > semaphore_timedwait_signal_trap 879 > markAndTrace 543 > updatePointersInRangeFromto 247 > sweepPhase 63 > interpret 8 > updatePointersInRootObjectsFromto 6 > Sample analysis of process 71029 written to file /dev/stdout > > |
|
|
David,
The code runs to completion in six minutes in this case, but when I put it in a MessageTally it hangs the VM after a while. Doesn't appear to be a simple case of not enough memory, although, from the Activity Monitor samples, it does appear to be concerned with memory in some fashion. I'm working on pruning down a snippet. Cheers, Bob
|
|
|
Thanks. If you have the opportunity to run your image on another VM, that
might also help narrow the problem down, i.e. try running the image on another computer or try using a different Mac VM, or possibly the unix VM for Mac <http://squeakvm.org/unix/release/Squeak-4.4.7.2357-darwin10.5.0_i386.tar.gz>. If the problem seems to be related to a specific VM, we can move the question to the vm-dev list and hopefully get a better answer for you. Dave On Mon, Jun 27, 2011 at 03:19:59AM -0700, Bob Arning wrote: > David, > > The code runs to completion in six minutes in this case, but when I put it > in a MessageTally it hangs the VM after a while. Doesn't appear to be a > simple case of not enough memory, although, from the Activity Monitor > samples, it does appear to be concerned with memory in some fashion. I'm > working on pruning down a snippet. > > Cheers, > Bob > > > David T. Lewis wrote: > > > > Bob, > > > > Are you saying that your code runs fine for six or more minutes, or > > are you saying that it runs fine for 6 minutes and then hangs? In other > > words, does it happen only when you wrap your code in MessageTally, > > or does MessageTally just seem to make it happen sooner? > > > > I don't know the Mac environment, but on the face of it this sounds > > like a system that is trying to grow object memory beyond available > > memory and just getting bogged down and unresponsive. Is there a code > > snippet you can share to reproduce? > > > > Dave > > > > On Sun, Jun 26, 2011 at 01:48:52PM -0400, Bob Arning wrote: > >> Hi, > >> > >> I've been using the all-in-one 4.2 Squeak and can't figure out why the > >> VM is hanging. I have some code that runs fine for about six minutes, > >> but if I wrap it in a > >> MessageTally spyOn: [], then the VM will hang after a while (typically > >> 30 to 90 seconds). CMD-period does not wake it up. According to the > >> activity monitor, cpu remains right around 100% and real memory at > >> around 180 meg. Activity Monitor sampling output attached below. Any > >> suggestions? > >> |
|
|
Well, VMs seem to be another subject that has passed me by. I'm not clear what to do with the link you sent me. I have downloaded some other VMs: Squeak 5.7.4.1 and Squeak 5.8b12. Both of these open up a blank white window when I drop the image on them, so I can't tell if they would have the same problem or not.
I also have Squeak 4.2.5beta1U which locks up like the VM in the all-in-one. I'm making progress to isolating an example. More later. Cheers, Bob |
|
|
In reply to this post by David T. Lewis
David,
I have narrowed it down further. The problem is an interaction between: - my code - MessageTally - some GC tweaks I was using (see below) If I don't use MessageTally, everything runs fine. If I don't use the GC tweaks, everything runs fine. If I use them in combination, then Squeak grinds to a halt somewhere short of the end of my code (which would normally take a few minutes). I guess this give me a workaround, but if any of the numbers in the code below are known to be a problem, I'll mention it on the seaside list. Cheers, Bob initializeMemorySettingsProfileSeaside "Initialize the memory and GC settings to be more in line with Seaside requirements" "The following settings affect the rate incremental GCs and tenuring" "Limit incremental GC activity to run every 40k allocations" self vmParameterAt: 5 put: 100000. "allocations between GCs (default: 4000)" "Limit tenuring threshold to only tenure w/ > 35k survivors" self vmParameterAt: 6 put: 35000. "tenuring threshold (default: 2000)" "These settings affect overall memory usage" "Only give memory back to the OS when we have more than 16MB free" self vmParameterAt: 24 put: 16*1024*1024. "default 8MB" "Try to keep 8MB headroom at all times" self vmParameterAt: 25 put: 8*1024*1024. "default 4MB" "These settings describe what to do when we're close to running out of free space" "Tell the VM that we'd rather grow than spinning in tight GC loops" self setGCBiasToGrow: 1. "default: false" "Tell the VM to do a fullGC for good measure if the above growth exceeded 16MB" self setGCBiasToGrowGCLimit: 16*1024*1024. "default: 0" |
|
|
On 28.06.2011, at 16:58, Bob Arning wrote: > David, > > I have narrowed it down further. The problem is an interaction between: > - my code > - MessageTally > - some GC tweaks I was using (see below) > > If I don't use MessageTally, everything runs fine. If I don't use the GC > tweaks, everything runs fine. If I use them in combination, then Squeak > grinds to a halt somewhere short of the end of my code (which would normally > take a few minutes). I guess this give me a workaround, but if any of the > numbers in the code below are known to be a problem, I'll mention it on the > seaside list. I've been using this for a specific application: vmParameterAt: 5 put: 16000; "do an incremental GC after this many allocations" vmParameterAt: 6 put: 32000; "tenure when more than this many objects survive the GC" vmParameterAt: 24 put: 16*1024*1024; "when growing object memory, allocate this much extra space" vmParameterAt: 25 put: 8*1024*1024. "when more than this much is free, shrink object memory" There are two main differences: the incremental GC runs more often, and I did not enable the bias-to-grow. - Bert - > Cheers, > Bob > > initializeMemorySettingsProfileSeaside > "Initialize the memory and GC settings to be more in line with > Seaside requirements" > > "The following settings affect the rate incremental GCs and > tenuring" > > "Limit incremental GC activity to run every 40k allocations" > self vmParameterAt: 5 put: 100000. "allocations between GCs > (default: 4000)" > "Limit tenuring threshold to only tenure w/ > 35k survivors" > self vmParameterAt: 6 put: 35000. "tenuring threshold (default: > 2000)" > > "These settings affect overall memory usage" > > "Only give memory back to the OS when we have more than 16MB free" > self vmParameterAt: 24 put: 16*1024*1024. "default 8MB" > "Try to keep 8MB headroom at all times" > self vmParameterAt: 25 put: 8*1024*1024. "default 4MB" > > "These settings describe what to do when we're close to running out > of free space" > > "Tell the VM that we'd rather grow than spinning in tight GC loops" > self setGCBiasToGrow: 1. "default: false" > "Tell the VM to do a fullGC for good measure if the above growth > exceeded 16MB" > self setGCBiasToGrowGCLimit: 16*1024*1024. "default: 0" > > -- > View this message in context: http://forum.world.st/Mac-VM-hanging-tp3626282p3630574.html > Sent from the Squeak - Dev mailing list archive at Nabble.com. > |
|
|
Bert,
I tried just these and it sill hangs the VM when running my stuff inside MessageTally. It's interesting that sometimes Activity Monitor shows squeak as "Not Responding" and sometimes it doesn't, although squeak has stopped doing useful work in either case. Cheers, Bob
|
|
|
In reply to this post by David T. Lewis
Here is a small (but not quite minimal) changeset that demonstrates the issue in a clean 4.2 all-in-one. Cheers, Bob http://dl.dropbox.com/u/28914094/SE001.1.cs.gz |
|
|
On Wed, 29 Jun 2011, Bob Arning wrote:
> > David T. Lewis wrote: >> >> Is there a code snippet you can share to reproduce? >> > > Here is a small (but not quite minimal) changeset that demonstrates the > issue in a clean 4.2 all-in-one. It works on windows using CogVM (r2382). How much memory does your image use? Levente > > Cheers, > Bob > > http://dl.dropbox.com/u/28914094/SE001.1.cs.gz > http://dl.dropbox.com/u/28914094/SE001.1.cs.gz > > -- > View this message in context: http://forum.world.st/Mac-VM-hanging-tp3626282p3633041.html > Sent from the Squeak - Dev mailing list archive at Nabble.com. > > |
|
|
Levente,
Activity Monitor shows it using about 49meg at the point it hangs. If I start it and then interrupt it before it hangs, then I get something like: uptime 0h4m27s memory 35,522,568 bytes old 30,941,924 bytes (87.1%) young 798,984 bytes (2.2%) used 31,740,908 bytes (89.4%) free 3,781,660 bytes (10.6%) GCs 24,668 (11ms between GCs) full 67 totalling 4,084,862ms (1529.0% uptime), avg 60968.0ms incr 24601 totalling 11,282,861ms (4223.0% uptime), avg 459.0ms tenures 5,180 (avg 4 GCs/tenure) Since last view 595 (53ms between GCs) uptime 31.4s full 1 totalling 69,032ms (220.0% uptime), avg 69032.0ms incr 594 totalling 1,366,410ms (4355.0% uptime), avg 2300.0ms tenures 14 (avg 42 GCs/tenure) So, not a great deal of memory. And, while we are looking at this, any ideas why the wild numbers for duration of full and incremental gc's? Cheers, Bob On 7/4/11 8:36 PM, Levente Uzonyi-2 [via Smalltalk] wrote: On Wed, 29 Jun 2011, Bob Arning wrote: |
«
Return to Squeak - Dev
|
1 view|%1 views
| Free forum by Nabble | Edit this page |