Couple of observations/questions with out of memory situations

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
3 messages Options
Reply | Threaded
Open this post in threaded view
|

Couple of observations/questions with out of memory situations

GLASS mailing list
Dear all,

Let me share some thoughts after fighting an out of memory situation. I was getting a "VM temporary object memory is full , too many failed pom_gen scavenges"

1) As Richard pointed out, in order to get useful info for debugging this, I had to do `export GS_DEBUG_VMGC_VERBOSE_OUTOFMEM=1`. I think the GemStone default value should be 1. Why would not want such an info in an out of memory situation?  If changing GemStone default value is too risky, then at least, I would make gsDevKit_home `createStone` to add:

export GS_DEBUG_VMGC_VERBOSE_OUTOFMEM=1

In the `stone.env`

Also...note that for GS_DEBUG_VMGC_VERBOSE_OUTOFMEM, you MUST restart netldi and hence the gems. If you can reproduce the out of memory, then great. But it may not be easy to reproduce the situation and hence you have no information. 


2) If you want the default to continue to be 0, then why don't you add something like "You may want to restart the stone with GS_DEBUG_VMGC_VERBOSE_OUTOFMEM enabled and try again"

3) In the printed information when GS_DEBUG_VMGC_VERBOSE_OUTOFMEM is enabled...where we list instances "Instances counts for generation all", "Instances counts for generation pom" ,etc... can those be sorted by "bytes" or "number of instances"?

4) In the printed information when GS_DEBUG_VMGC_VERBOSE_OUTOFMEM is enabled... where you render the stack, can't we display the selectors instead of the OOP of the selector:

1  FaTableAccessorRowDictionary >>  (selector:168096001) (envId 0) @startIP   [GsNMethod 35367683841]
  nCode: 0x7f5f43f6eae8
  gsNmeth: 0x7f5f43f6ea98
              FP: 0x7f5ec4616740=StackLimit[-280] , callerFP: StackLimit[-274]
  rcvr: 0x7f5f06aedc78 oid:57927623937 (cls:164715265 FaTableAccessorRowDictionary size:3)
2  (block, homeMethod:81257841921) @ 0x7f5f43f76a42=@natCode+0x8a  [GsNMethod 81261597185]
  nCode: 0x7f5f43f769b8
  gsNmeth: 0x7f5f43f768c0
              FP: 0x7f5ec4616770=StackLimit[-274] , callerFP: StackLimit[-262]
  temp 3: 0x7f5f06aedc78 oid:57927623937 (cls:164715265 FaTableAccessorRowDictionary size:3)
  temp 2: 0x7f5f1fa4ac18 (cls:52778248449 FaQuandlZacksFundamentalsDataLoader size:1)
  temp 1: 0x7f5ef1556780 (cls:134913 VariableContext size:11)
  arg 1:0x7f5f06aedc78 oid:57927623937 (cls:164715265 FaTableAccessorRowDictionary size:3)
  rcvr: 0x7f5ef1556b48 (cls:128001 ExecBlock1 size:5)
3  SequenceableCollection >>  (selector:2336001) (envId 0) @ 0x7f5f43f1c343=@natCode+0x153  [GsNMethod 26843271937]
  nCode: 0x7f5f43f1c1f0
  gsNmeth: 0x7f5f43f1bff8
              FP: 0x7f5ec46167d0=StackLimit[-262] , callerFP: StackLimit[-253]
  temp 8: 0x7f5ef1556b48 (cls:128001 ExecBlock1 size:5)
  temp 7: 202 (SmallInteger 25)
  temp 6: 0x7f5ef1556b88 (cls:66817 Array size:27)
  temp 5: 202 (SmallInteger 25)
  temp 4: 218 (SmallInteger 27)
  temp 3: 202 (SmallInteger 25)
  temp 2: 218 (SmallInteger 27)
  temp 1: 0x7f5ef1556b88 (cls:66817 Array size:27)
  arg 1:0x7f5ef1556b48 (cls:128001 ExecBlock1 size:5)
  rcvr: 0x7f5ef1556878 (cls:66817 Array size:27)


It's really a pain having to have a workspace opened doing "Object _objectForOop: XXX" for every single piece of the stack you want to know. 

At least, display this for the first...20 items.


Cheers, 



--

_______________________________________________
Glass mailing list
[hidden email]
http://lists.gemtalksystems.com/mailman/listinfo/glass
Reply | Threaded
Open this post in threaded view
|

Re: Couple of observations/questions with out of memory situations

GLASS mailing list
Mariano,

Thanks for the feedback ... I've submitted internal issue 46101 (so you can watch for it in future release notes) as a feature request for internal discussion ..

With regards to your fourth point about having oops instead of selectors, when we print the stack for out of memory we are trying to avoid consuming as little memory as possible and getting the bytes for a symbol does end up consuming additional memory (we do print the bytes for the selector if the symbol has already been faulted in), but your points for this were included in the bug mail and we will take a second look at what we might be able to do in this case ..

Dale

On 03/08/2016 08:55 AM, Mariano Martinez Peck via Glass wrote:
Dear all,

Let me share some thoughts after fighting an out of memory situation. I was getting a "VM temporary object memory is full , too many failed pom_gen scavenges"

1) As Richard pointed out, in order to get useful info for debugging this, I had to do `export GS_DEBUG_VMGC_VERBOSE_OUTOFMEM=1`. I think the GemStone default value should be 1. Why would not want such an info in an out of memory situation?  If changing GemStone default value is too risky, then at least, I would make gsDevKit_home `createStone` to add:

export GS_DEBUG_VMGC_VERBOSE_OUTOFMEM=1

In the `stone.env`

Also...note that for GS_DEBUG_VMGC_VERBOSE_OUTOFMEM, you MUST restart netldi and hence the gems. If you can reproduce the out of memory, then great. But it may not be easy to reproduce the situation and hence you have no information. 


2) If you want the default to continue to be 0, then why don't you add something like "You may want to restart the stone with GS_DEBUG_VMGC_VERBOSE_OUTOFMEM enabled and try again"

3) In the printed information when GS_DEBUG_VMGC_VERBOSE_OUTOFMEM is enabled...where we list instances "Instances counts for generation all", "Instances counts for generation pom" ,etc... can those be sorted by "bytes" or "number of instances"?

4) In the printed information when GS_DEBUG_VMGC_VERBOSE_OUTOFMEM is enabled... where you render the stack, can't we display the selectors instead of the OOP of the selector:

1  FaTableAccessorRowDictionary >>  (selector:168096001) (envId 0) @startIP   [GsNMethod 35367683841]
  nCode: 0x7f5f43f6eae8
  gsNmeth: 0x7f5f43f6ea98
              FP: 0x7f5ec4616740=StackLimit[-280] , callerFP: StackLimit[-274]
  rcvr: 0x7f5f06aedc78 oid:57927623937 (cls:164715265 FaTableAccessorRowDictionary size:3)
2  (block, homeMethod:81257841921) @ 0x7f5f43f76a42=@natCode+0x8a  [GsNMethod 81261597185]
  nCode: 0x7f5f43f769b8
  gsNmeth: 0x7f5f43f768c0
              FP: 0x7f5ec4616770=StackLimit[-274] , callerFP: StackLimit[-262]
  temp 3: 0x7f5f06aedc78 oid:57927623937 (cls:164715265 FaTableAccessorRowDictionary size:3)
  temp 2: 0x7f5f1fa4ac18 (cls:52778248449 FaQuandlZacksFundamentalsDataLoader size:1)
  temp 1: 0x7f5ef1556780 (cls:134913 VariableContext size:11)
  arg 1:0x7f5f06aedc78 oid:57927623937 (cls:164715265 FaTableAccessorRowDictionary size:3)
  rcvr: 0x7f5ef1556b48 (cls:128001 ExecBlock1 size:5)
3  SequenceableCollection >>  (selector:2336001) (envId 0) @ 0x7f5f43f1c343=@natCode+0x153  [GsNMethod 26843271937]
  nCode: 0x7f5f43f1c1f0
  gsNmeth: 0x7f5f43f1bff8
              FP: 0x7f5ec46167d0=StackLimit[-262] , callerFP: StackLimit[-253]
  temp 8: 0x7f5ef1556b48 (cls:128001 ExecBlock1 size:5)
  temp 7: 202 (SmallInteger 25)
  temp 6: 0x7f5ef1556b88 (cls:66817 Array size:27)
  temp 5: 202 (SmallInteger 25)
  temp 4: 218 (SmallInteger 27)
  temp 3: 202 (SmallInteger 25)
  temp 2: 218 (SmallInteger 27)
  temp 1: 0x7f5ef1556b88 (cls:66817 Array size:27)
  arg 1:0x7f5ef1556b48 (cls:128001 ExecBlock1 size:5)
  rcvr: 0x7f5ef1556878 (cls:66817 Array size:27)


It's really a pain having to have a workspace opened doing "Object _objectForOop: XXX" for every single piece of the stack you want to know. 

At least, display this for the first...20 items.


Cheers, 



--


_______________________________________________
Glass mailing list
[hidden email]
http://lists.gemtalksystems.com/mailman/listinfo/glass


_______________________________________________
Glass mailing list
[hidden email]
http://lists.gemtalksystems.com/mailman/listinfo/glass
Reply | Threaded
Open this post in threaded view
|

Re: Couple of observations/questions with out of memory situations

GLASS mailing list


On Tue, Mar 8, 2016 at 3:00 PM, Dale Henrichs via Glass <[hidden email]> wrote:
Mariano,

Thanks for the feedback ... I've submitted internal issue 46101 (so you can watch for it in future release notes) as a feature request for internal discussion ..


Thanks! I will write it down. 
 
With regards to your fourth point about having oops instead of selectors, when we print the stack for out of memory we are trying to avoid consuming as little memory as possible and getting the bytes for a symbol does end up consuming additional memory (we do print the bytes for the selector if the symbol has already been faulted in), but your points for this were included in the bug mail and we will take a second look at what we might be able to do in this case ..


I imagined. That's why I said at least for the first 10 elements of the stack or something.

A final comment... is that... not sure if it is possible or not but maybe a nice solution could be to write the structure info (tables, counters, stack, etc).. I mean...NOT the generated string but the real info used to build that string... if that could be written in the object log, THEN, you might add a convenience method to print a much nicer stack. So...you start up a new gem, read the stuff from the object log and then you kind of print a better stack with:

1) Real selectors instead of OOP
2) Print source of blocks (using _sourceStringForBlock)
 

Not sure if possible...but just an idea..

But again...is likely that you build the string on a "streaming fashion" instead of getting all info and then write it...as you have little memory.

Cheers,




Dale


On 03/08/2016 08:55 AM, Mariano Martinez Peck via Glass wrote:
Dear all,

Let me share some thoughts after fighting an out of memory situation. I was getting a "VM temporary object memory is full , too many failed pom_gen scavenges"

1) As Richard pointed out, in order to get useful info for debugging this, I had to do `export GS_DEBUG_VMGC_VERBOSE_OUTOFMEM=1`. I think the GemStone default value should be 1. Why would not want such an info in an out of memory situation?  If changing GemStone default value is too risky, then at least, I would make gsDevKit_home `createStone` to add:

export GS_DEBUG_VMGC_VERBOSE_OUTOFMEM=1

In the `stone.env`

Also...note that for GS_DEBUG_VMGC_VERBOSE_OUTOFMEM, you MUST restart netldi and hence the gems. If you can reproduce the out of memory, then great. But it may not be easy to reproduce the situation and hence you have no information. 


2) If you want the default to continue to be 0, then why don't you add something like "You may want to restart the stone with GS_DEBUG_VMGC_VERBOSE_OUTOFMEM enabled and try again"

3) In the printed information when GS_DEBUG_VMGC_VERBOSE_OUTOFMEM is enabled...where we list instances "Instances counts for generation all", "Instances counts for generation pom" ,etc... can those be sorted by "bytes" or "number of instances"?

4) In the printed information when GS_DEBUG_VMGC_VERBOSE_OUTOFMEM is enabled... where you render the stack, can't we display the selectors instead of the OOP of the selector:

1  FaTableAccessorRowDictionary >>  (selector:168096001) (envId 0) @startIP   [GsNMethod 35367683841]
  nCode: 0x7f5f43f6eae8
  gsNmeth: 0x7f5f43f6ea98
              FP: 0x7f5ec4616740=StackLimit[-280] , callerFP: StackLimit[-274]
  rcvr: 0x7f5f06aedc78 oid:57927623937 (cls:164715265 FaTableAccessorRowDictionary size:3)
2  (block, homeMethod:81257841921) @ 0x7f5f43f76a42=@natCode+0x8a  [GsNMethod 81261597185]
  nCode: 0x7f5f43f769b8
  gsNmeth: 0x7f5f43f768c0
              FP: 0x7f5ec4616770=StackLimit[-274] , callerFP: StackLimit[-262]
  temp 3: 0x7f5f06aedc78 oid:57927623937 (cls:164715265 FaTableAccessorRowDictionary size:3)
  temp 2: 0x7f5f1fa4ac18 (cls:52778248449 FaQuandlZacksFundamentalsDataLoader size:1)
  temp 1: 0x7f5ef1556780 (cls:134913 VariableContext size:11)
  arg 1:0x7f5f06aedc78 oid:57927623937 (cls:164715265 FaTableAccessorRowDictionary size:3)
  rcvr: 0x7f5ef1556b48 (cls:128001 ExecBlock1 size:5)
3  SequenceableCollection >>  (selector:2336001) (envId 0) @ 0x7f5f43f1c343=@natCode+0x153  [GsNMethod 26843271937]
  nCode: 0x7f5f43f1c1f0
  gsNmeth: 0x7f5f43f1bff8
              FP: 0x7f5ec46167d0=StackLimit[-262] , callerFP: StackLimit[-253]
  temp 8: 0x7f5ef1556b48 (cls:128001 ExecBlock1 size:5)
  temp 7: 202 (SmallInteger 25)
  temp 6: 0x7f5ef1556b88 (cls:66817 Array size:27)
  temp 5: 202 (SmallInteger 25)
  temp 4: 218 (SmallInteger 27)
  temp 3: 202 (SmallInteger 25)
  temp 2: 218 (SmallInteger 27)
  temp 1: 0x7f5ef1556b88 (cls:66817 Array size:27)
  arg 1:0x7f5ef1556b48 (cls:128001 ExecBlock1 size:5)
  rcvr: 0x7f5ef1556878 (cls:66817 Array size:27)


It's really a pain having to have a workspace opened doing "Object _objectForOop: XXX" for every single piece of the stack you want to know. 

At least, display this for the first...20 items.


Cheers, 



--


_______________________________________________
Glass mailing list
[hidden email]
http://lists.gemtalksystems.com/mailman/listinfo/glass


_______________________________________________
Glass mailing list
[hidden email]
http://lists.gemtalksystems.com/mailman/listinfo/glass




--

_______________________________________________
Glass mailing list
[hidden email]
http://lists.gemtalksystems.com/mailman/listinfo/glass