VM temporary object memory is full (again)

 Hi,

I have a REST services and Web App being served by the same gem.
After adding a #halt to the web app i can not start Zinc server again.
Even if i shutdown GemStone and restart it again i always get TOM full immediately after evaluating:
[WAGsZincAdaptor startOn: 8888]
  on: AlmostOutOfMemory enable
  do: [:ex | ex error: ex description].

Last time i have this error if i restarted GS --> everything was ok.
Still try to solve this :) any help is appreciated...

From gemnetobject4780.log:

DUMP_OPTIONS = TRUE;
GEM_GCI_LOG_ENABLED = FALSE;
GEM_ABORT_MAX_CRS = 0;
GEM_FREE_FRAME_CACHE_SIZE = -1;
GEM_FREE_FRAME_LIMIT = -1;
GEM_FREE_PAGEIDS_CACHE = 200;
GEM_HALT_ON_ERROR = 0;
GEM_KEEP_MIN_SOFTREFS = 0;
GEM_MAX_SMALLTALK_STACK_DEPTH = 1000;
GEM_NATIVE_CODE_ENABLED = 2;
GEM_PRIVATE_PAGE_CACHE_KB = 960KB;
GEM_PGSVR_COMPRESS_PAGE_TRANSFERS = FALSE;
GEM_PGSVR_FREE_FRAME_CACHE_SIZE = -1;
GEM_PGSVR_FREE_FRAME_LIMIT = -1;
GEM_PGSVR_UPDATE_CACHE_ON_READ = FALSE;
GEM_REPOSITORY_IN_MEMORY = FALSE;
GEM_RPC_KEEPALIVE_INTERVAL = 0;
GEM_RPCGCI_TIMEOUT = 0;
GEM_RPC_USE_SSL = TRUE;
GEM_SOFTREF_CLEANUP_PERCENT_MEM = 50;
GEM_TEMPOBJ_AGGRESSIVE_STUBBING = TRUE;
GEM_TEMPOBJ_CACHE_SIZE = 500000KB;
GEM_TEMPOBJ_MESPACE_SIZE = 0KB;
GEM_TEMPOBJ_OOPMAP_SIZE = 0;
GEM_TEMPOBJ_SCOPES_SIZE = 2000;
GEM_TEMPOBJ_POMGEN_SIZE = 0KB;
GEM_TEMPOBJ_POMGEN_PRUNE_ON_VOTE = 90;
GEM_TEMPOBJ_POMGEN_SCAVENGE_INTERVAL = 1800;
GEM_TEMPOBJ_START_ADDR not used on this platform
LOG_WARNINGS = TRUE;
SHR_NUM_FREE_FRAME_SERVERS = -1;
SHR_PAGE_CACHE_LARGE_MEMORY_PAGE_POLICY = 0;
SHR_PAGE_CACHE_LOCKED = FALSE;
SHR_PAGE_CACHE_NUM_PROCS = 4089;
SHR_PAGE_CACHE_NUM_SHARED_COUNTERS = 1900;
SHR_PAGE_CACHE_PERMISSIONS = 660;
SHR_PAGE_CACHE_SIZE_KB = 1900000KB;
SHR_TARGET_FREE_FRAME_COUNT = -1;
SHR_WELL_KNOWN_PORT_NUMBER = 0;
(vmGc spaceSizes: eden init 2048K max 93696K , survivor init 448K max 15680K,
 vmGc    old max 374912K, code max 100032K, perm max 50048K, pom 10 * 41728K = 417280K,
 vmGc    remSet 9796K, meSpace max 478224K oopMapSize 4194304  max footprint 1571M)

cmdLine= CONNECT AGENT
[Info]: RPC client/gem/minimum GCI levels = 860/860/860
[Info]: Client PID: 4872
[Info]: libssl-3.2.1-64.so: loaded
[Info]: User ID: DataCurator
[Info]: Repository: devKit
[Info]: Session ID: 5
[Info]: GCI Client Host: ::ffff:192.168.29.1
[Info]: Page server PID: -1
[Info]: Login Time: 09/25/2015 13:12:45.346 PDT
Gave this VM preference for OOM killer, Wrote to /proc/4780/oom_score_adj value 250
-----------------------------------------------------
GemStone: Error         Fatal
VM temporary object memory is full
, old space overflow
Error Category: 231169 [GemStone] Number: 4067  Arg Count: 1 Context : 20 exception : 20
Arg 1:   20

[Info]: Logging out at 09/25/2015 13:13:07 PDT (1443211987)


*****************************************************
****** GemStone Abnormal Shutdown at 09/25/2015 13:13:08 PDT
*****************************************************
-----------------------------------------------------
GemStone: Error         Fatal
VM temporary object memory is full
, old space overflow
Error Category: 231169 [GemStone] Number: 4067  Arg Count: 1 Context : 20 exception : 20
Arg 1:   20

Hi,

Just to add more info to this.

I started Zinc and Swazoo on a different port and i did NOT get TOM full.

Now working on port 8989.

No idea why this is happening...

Regards,
Bruno

On 9/25/15 1:14 PM, BrunoBB via Glass wrote:
WAGsZincAdaptor>>startOn: forks a thread to listen on the port and when a connection is accepted, another thread is forked. The AlmostOutOfMemory exception would not likely be raised from the code called by WAGsZincAdaptor>>startOn:
,

The last time this happened, I suggested that you install a static AlmostOutOfMemory handler that is capable of handling an AlmostOutOfMemory no matter which thread signals the exception ... I suggested that you look at MCPlatformSupport class>>installAlmostOutOfMemoryStaticHandler: for inspiration ... this time I'll take it a step farther:)  Here's a static exception handler that will do a halt when 65% of memory is consumed:

   | handler commitThreshold |
   commitThreshold := 65.
   handler := AlmostOutOfMemory addDefaultHandler: [ :ex | self halt ].
   SessionTemps current at: #'AlmostOutOfMemoryStaticException' put: handler.
   System signalAlmostOutOfMemoryThreshold: commitThreshold

If you do this interactively, you should be able to get an idea from the stack in the debugger what is going on ... if you want to do this in a topaz session, you can put in a call to GsProcess class>>stackReportToLevel: and dump the stack to the gem log ....
 
Dale

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

On 9/25/15 1:25 PM, BrunoBB via Glass wrote: With this information I'm going to guess that you've got a process
listening on the old port ... if you do there is a bug in Zinc (on
GemStone) that will cause the the gem to go into an infinite loop ...
I'm pretty sure that I've fixed the bug in the last 6 months or so (or
there's a new failure mechanism) ...

If you are doing this in an interactive session, then it is possible the
the interactive gem is the culprit ... login/logout from the interactive
gem would solve that ... if it is not an interactive session then
looking for a "rogue" topaz process or gem process is called for:

    ps -efw | grep topaz                       # find topaz sessions
    ps -efw | grep TCP | grep sys/gem # find interactive gems

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

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

On Sat, Sep 26, 2015 at 3:08 PM, Dale Henrichs via Glass <[hidden email]> wrote:

If you are doing this in an interactive session, then it is possible the the interactive gem is the culprit ... login/logout from the interactive gem would solve that ... if it is not an interactive session then looking for a "rogue" topaz process or gem process is called for:

   ps -efw | grep topaz                       # find topaz sessions
   ps -efw | grep TCP | grep sys/gem # find interactive gems

Hi Dale, 

This is a little comment to say that I do NOT get that output in my Linux. I think that if gems are opened in the linked way they may look different at `ps` level.

How do you run your gems "linked"? And what does the ps output look like?

Dale

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

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

On Sat, Sep 26, 2015 at 5:11 PM, Dale Henrichs <[hidden email]> wrote:

On 9/26/15 11:59 AM, Mariano Martinez Peck wrote:

On Sat, Sep 26, 2015 at 3:08 PM, Dale Henrichs via Glass <[hidden email]> wrote:

If you are doing this in an interactive session, then it is possible the the interactive gem is the culprit ... login/logout from the interactive gem would solve that ... if it is not an interactive session then looking for a "rogue" topaz process or gem process is called for:

   ps -efw | grep topaz                       # find topaz sessions
   ps -efw | grep TCP | grep sys/gem # find interactive gems

Hi Dale, 

This is a little comment to say that I do NOT get that output in my Linux. I think that if gems are opened in the linked way they may look different at `ps` level.

How do you run your gems "linked"? And what does the ps output look like?

The way I run seaside gems:

cat << EOF | nohup $GEMSTONE/bin/topaz -u "Seaside-$1-$2" -l -q -e $4 -I $APPLICATION_DIR/.topazini 2>&1 >> $APPLICATION_LOG_DIR/${1}_server-${2}.log &

And this is the ps output:

 debrist+  6163     1  0 04:06 ?        00:00:00 /opt/gemstone/product/bin/topaz -u Seaside-FastCGI-40110 -l -q -e /opt/gemstone/product/seaside/etc/seaside30.conf -I /quuve/sites/debrisTesting/gemstone/.topazini

This is the way I open an interactive topaz:

su -m $GEMSTONE_USER -c "$GEMSTONE/bin/topaz -l -e $GEMSTONE_EXE_CONF -I $APPLICATION_DIR/.topazini"

And this is the ps output:

debrist+  7225  7224  0 14:55 ?        00:00:00 /opt/gemstone/product/bin/topaz -l -e /quuve/sites/debrisTesting/gemstone/etc/gem.conf -I /quuve/sites/debrisTesting/gemstone/.topazini

This is on GemStone 3.1.0.6 and CentOS 7.

Okay, but all of those guys will show up in the first case - scanning for topaz processes ... a gem process is launched when you use a non-linked topaz (in which case you get both a gem and topaz process) or when you launch a client from tODE, gemtools, jade, or gbs ... technically you can create a c program with the gci libraries running as a linked session (similar to topaz -l) but then you'd know about those processes as well ...

Dale

Dale

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

Hi,

Is in a interactive session with Jade client. After installing the AlmostOutOfMemory handler i was able to catch the stack, which is the following:
It seems a closed socket is causing the problem (SocketStreamSocket underlyingSocket is nil)

UserDefinedError (AbstractException) >> _signalWith: @5 line 25
UserDefinedError (AbstractException) >> signal @2 line 47
AlmostOutOfMemory (Object) >> error: @6 line 7
[] in  Executed Code  @3 line 10
AlmostOutOfMemory (AbstractException) >> _executeHandler: @3 line 8
AlmostOutOfMemory (AbstractException) >> _signalWith: @1 line 1
[] in  ExecBlock0 (AbstractException) >> _signalAsync @2 line 19
ExecBlock0 (ExecBlock) >> ensure: @2 line 12
AlmostOutOfMemory (AbstractException) >> _signalAsync @6 line 21
GsNMethod >> isMethodForBlock @1 line 1
GsNMethod >> _descrForStackPadTo:rcvr: @4 line 5
GsProcess class >> stackReportToLevel: @32 line 26
[] in  ExecBlock1 (ZnManagingMultiThreadedServer) >> closeConnections @4 line 14
MessageNotUnderstood (AbstractException) >> _executeHandler: @3 line 8
MessageNotUnderstood (AbstractException) >> _signalWith: @1 line 1
MessageNotUnderstood (AbstractException) >> signal @2 line 47
UndefinedObject (Object) >> doesNotUnderstand: @9 line 10
UndefinedObject (Object) >> _doesNotUnderstand:args:envId:reason: @7 line 12
SocketStreamSocket (SpSocket) >> close @3 line 5
SocketStream >> close @3 line 6
[] in  ExecBlock0 (ZnManagingMultiThreadedServer) >> closeConnections @2 line 9
ExecBlock0 (ExecBlock) >> on:do: @3 line 42
[] in  ExecBlock1 (ZnManagingMultiThreadedServer) >> closeConnections @4 line 10
OrderedCollection (Collection) >> do: @5 line 10
[] in  ExecBlock0 (ZnManagingMultiThreadedServer) >> closeConnections @3 line 7
ExecBlock0 (ExecBlock) >> ensure: @2 line 12
TransientMutex (TransientSemaphore) >> critical: @4 line 7
ZnManagingMultiThreadedServer >> closeConnections @7 line 5
ZnManagingMultiThreadedServer >> stop: @3 line 3
ZnManagingMultiThreadedServer (ZnServer) >> stop @2 line 5
ZnManagingMultiThreadedServer (ZnSingleThreadedServer) >> start @2 line 5
WAGsZincAdaptor (ZnZincServerAdaptor) >> basicStart @3 line 2
[] in  ExecBlock0 (WAServerManager) >> start: @2 line 3
[] in  ExecBlock0 (ExecBlock) >> ifCurtailed: @2 line 6
ExecBlock0 (ExecBlock) >> ensure: @2 line 12
ExecBlock0 (ExecBlock) >> ifCurtailed: @3 line 8
WAServerManager >> start: @4 line 4
WAGsZincAdaptor (WAServerAdaptor) >> start @3 line 2
WAGsZincAdaptor >> start @2 line 3
WAGsZincAdaptor class (WAServerAdaptor class) >> startOn: @10 line 10
[] in  Executed Code  @2 line 8
ExecBlock0 (ExecBlock) >> on:do: @3 line 42
Executed Code  @9 line 9
UndefinedObject (GsNMethod class) >> _gsReturnToC @1 line 1

Bruno,

Richard and I looked at this stack quite a bit and we weren't able to
figure out how the system got into this state ... granted were looking
at source code for a pretty  recent version of Zinc from about 4 months ago:

    |ZincHTTPComponents|  f8a268c [gs_master]
filetree:///opt/git/zinc/repository

   commit f8a268ce34ff15b90b28e83ce2225abf717dff41
   Merge: dfe52b3 c2e3bf8
   Author: Dale Henrichs <[hidden email]>
   Date:   Mon Jun 8 15:50:03 2015 -0700

       Merge branch 'dev' into gs_master

The following chunk of stack is odd, because we can't tell how the
instance of ZnManagingMultiThreadedServer had any state to cause an
error from#stop:

   ZnManagingMultiThreadedServer (ZnServer) >> stop @2 line 5
   ZnManagingMultiThreadedServer (ZnSingleThreadedServer) >> start @2 line 5
   WAGsZincAdaptor (ZnZincServerAdaptor) >> basicStart @3 line 2

Also, we don't know what code was being executed to launch this frame:

   WAGsZincAdaptor class (WAServerAdaptor class) >> startOn: @10 line 10

.. but as I said earlier we don't know the exact code that is being
executed in any of the methods other than you are probably using a
version of Zinc from between 10 months and 1.5 years ago:)

Fortunately, we did find the patch for the bug that I suspect to be the
root cause of your troubles, where the server will go into an infinite
loop when attempting to listen on a port that is in use by another
process. The fact that using a different port avoids the problem is
diagnostic...

So before going further, let's see if this patch for
ZnNetworkingUtils>>serverSocketOn: fixes your problem:

   serverSocketOn: port
     | socket |
     socket := SocketStreamSocket newTCPSocket.
     self setServerSocketOptions: socket.
     (socket listenOn: port backlogSize: self listenBacklogSize)
       ifNil: [ self error: 'Error listening on socket: ' , socket
lastErrorString ].
     socket isValid
       ifFalse: [ self error: 'Cannot create socket on port ' , port
printString ].
     ^ socket

The problem was that in the older version, the #listenOn:backlogSize:
could silently fail because of a missing nil test:

   serverSocketOn: port
     | socket |
     socket := SocketStreamSocket newTCPSocket.
     self setServerSocketOptions: socket.
+   (socket listenOn: port backlogSize: self listenBacklogSize)
+     ifNil: [ self error: 'Error listening on socket: ' , socket
lastErrorString ].
-   socket listenOn: port backlogSize: self listenBacklogSize.
     socket isValid
       ifFalse: [ self error: 'Cannot create socket on port ' , port
printString ].
     ^ socket

An error being signalled will still cause your topaz session to exit,
but at least you should have a decent error message....

Dale


On 10/01/2015 12:53 PM, BrunoBB via Glass wrote:
_______________________________________________
Glass mailing list
[hidden email]
http://lists.gemtalksystems.com/mailman/listinfo/glass