Gemstone 3.1.0 503 - Service Not Available

Hi,
        i load the new Gemstone 3.1.0 on my MAC.

        After i load on it the Seaside30 from ConfigurationOfSeaside30-dhk.375


        I run the environment with:

        source /opt/gemstone/product/seaside/defSeaside
        export GEMSTONE_NAME=development
        $GEMSTONE/seaside/bin/startnet
        $GEMSTONE/seaside/bin/startGemstone
        $GEMSTONE/seaside/bin/runSeasideGems30 start  WAFastCGIAdaptor "2020 2021 2022"



        All work fine, the seaside entry point work right when the Browser call it.


                 Sometime the system answer  the error:  503 - Service Not Available

                and the relative topaz process go in overload. ( 100 % of CPU time )

                At this point i need to  stop and start ( restart )  the Gemstone environment.


        It's my problem ?

        Anyone found something relative to it ?


        Thanks,


                Dario

       

Dario,

Could you do a `kill -USR1 <gem pid>` to get a sample of the stack so we can see what the vm is doing when it goes hot. Do the `kill` command several times in a row to get several samples.

If you mail the log to me, I'll take a look.

Dale

----- Original Message -----
| From: "Dario Trussardi" <[hidden email]>
| To: "beta discussion Gemstone Seaside" <[hidden email]>
| Sent: Tuesday, July 24, 2012 3:30:12 AM
| Subject: [GS/SS Beta] Gemstone 3.1.0  503 - Service Not Available
|
| Hi,
| i load the new Gemstone 3.1.0 on my MAC.
|
| After i load on it the Seaside30 from
| ConfigurationOfSeaside30-dhk.375
|
|
| I run the environment with:
|
| source /opt/gemstone/product/seaside/defSeaside
| export GEMSTONE_NAME=development
| $GEMSTONE/seaside/bin/startnet
| $GEMSTONE/seaside/bin/startGemstone
| $GEMSTONE/seaside/bin/runSeasideGems30 start  WAFastCGIAdaptor "2020
| 2021 2022"
|
|
|
| All work fine, the seaside entry point work right when the Browser
| call it.
|
|
| Sometime the system answer  the error:  503 - Service Not
| Available
|
| and the relative topaz process go in overload. ( 100 % of CPU time
| )
|
| At this point i need to  stop and start ( restart )  the Gemstone
| environment.
|
|
| It's my problem ?
|
| Anyone found something relative to it ?
|
|
| Thanks,
|
|
| Dario
|
|

Dale,

        excuse for my ignorance,

        but when i do the command kill -USR1 8157   ( my pid for example ) what the system generate ?

        I don't find any files.

        I missing something ?

        Thanks,

                Dario

Dario,

Sorry about that I should have mentioned that I was interested in the gem log ... which you did find ...

It is interesting though that the gem start log (capturing stdout) has the c-stack information ... which may turn out to be useful.

>From looking at the stack samples it looks like FSRecordStruct >> readFromStream: is in an infinite loop:

------------------------------------------------------------------------------------------------
  SAMPLE 1
-----------


1  Magnitude >> min: (envId 0) @IP 56  [GsNMethod 3509249]
              FP: 0x110e18c28=StackLimit[-123] , callerFP: StackLimit[-111]
  arg 1:10 (SmallInteger 1)
  rcvr: 16002 (SmallInteger 2000)
2  FSGsSocket >> next: (envId 0) @IP 440  [GsNMethod 110132481]
              FP: 0x110e18c88=StackLimit[-111] , callerFP: StackLimit[-106]
  arg 1:10 (SmallInteger 1)
  rcvr: 0x10afbaa50 (cls:37233921 FSGsSocket size:2)
3  FSGsSocket >> next (envId 0) @IP 80  [GsNMethod 110132993]
              FP: 0x110e18cb0=StackLimit[-106] , callerFP: StackLimit[-101]
  rcvr: 0x10afbaa50 (cls:37233921 FSGsSocket size:2)
4  FSRecordStruct >> readFromStream: (envId 0) @IP 72  [GsNMethod 104444161]
              FP: 0x110e18cd8=StackLimit[-101] , callerFP: StackLimit[-96]
  arg 1:0x10afbaa50 (cls:37233921 FSGsSocket size:2)
  rcvr: 0x10afbae88 (cls:99787265 FSRecordStruct size:5)

  SAMPLE 2
-----------

1  SequenceableCollection >> copyFrom:to:into:startingAt: (envId 0) @IP 56  [GsNMethod 3790593]
              FP: 0x110e18c18=StackLimit[-125] , callerFP: StackLimit[-111]
  arg 4:10 (SmallInteger 1)
  arg 3:0x10afbaec8 (cls:103425 ByteArray size:1)
  arg 2:2 (SmallInteger 0)
  arg 1:10 (SmallInteger 1)
  rcvr: 0x10afbaee8 (cls:103425 ByteArray size:2000)
2  FSGsSocket >> next: (envId 0) @IP 544  [GsNMethod 110132481]
              FP: 0x110e18c88=StackLimit[-111] , callerFP: StackLimit[-106]
  arg 1:10 (SmallInteger 1)
  rcvr: 0x10afbaa50 (cls:37233921 FSGsSocket size:2)
3  FSGsSocket >> next (envId 0) @IP 80  [GsNMethod 110132993]
              FP: 0x110e18cb0=StackLimit[-106] , callerFP: StackLimit[-101]
  rcvr: 0x10afbaa50 (cls:37233921 FSGsSocket size:2)
4  FSRecordStruct >> readFromStream: (envId 0) @IP 72  [GsNMethod 104444161]
              FP: 0x110e18cd8=StackLimit[-101] , callerFP: StackLimit[-96]
  arg 1:0x10afbaa50 (cls:37233921 FSGsSocket size:2)
  rcvr: 0x10afbae88 (cls:99787265 FSRecordStruct size:5)

  SAMPLE 3
-----------

1  SequenceableCollection >> copyFrom:to:into:startingAt: (envId 0) @IP 56  [GsNMethod 3790593]
              FP: 0x110e18c18=StackLimit[-125] , callerFP: StackLimit[-111]
  arg 4:10 (SmallInteger 1)
  arg 3:0x10afbaec8 (cls:103425 ByteArray size:1)
  arg 2:2 (SmallInteger 0)
  arg 1:10 (SmallInteger 1)
  rcvr: 0x10afbaee8 (cls:103425 ByteArray size:2000)
2  FSGsSocket >> next: (envId 0) @IP 544  [GsNMethod 110132481]
              FP: 0x110e18c88=StackLimit[-111] , callerFP: StackLimit[-106]
  arg 1:10 (SmallInteger 1)
  rcvr: 0x10afbaa50 (cls:37233921 FSGsSocket size:2)
3  FSGsSocket >> next (envId 0) @IP 80  [GsNMethod 110132993]
              FP: 0x110e18cb0=StackLimit[-106] , callerFP: StackLimit[-101]
  rcvr: 0x10afbaa50 (cls:37233921 FSGsSocket size:2)
4  FSRecordStruct >> readFromStream: (envId 0) @IP 72  [GsNMethod 104444161]
              FP: 0x110e18cd8=StackLimit[-101] , callerFP: StackLimit[-96]
  arg 1:0x10afbaa50 (cls:37233921 FSGsSocket size:2)
  rcvr: 0x10afbae88 (cls:99787265 FSRecordStruct size:5)
------------------------------------------------------------------------------------------------

In each case the FSRecordStruct is oop 0x10afbae88 so we're looking at the same object in each sample...

It's suspicious that SequenceableCollection >> copyFrom:to:into:startingAt: is called with the args

  1
  0
  ByteArray
  1

Offhand, I would have expected an error from #copyFrom:to:into:startingAt: if one were copyy from 1 to 0 ...

In FSGsSocket >> next: there's a block of code that will clearly go into an infinite loop if <result> is 0:

        [ remaining > 0 ] whileTrue: [
                result := socket
                        read: (bufSize min: remaining)
                        into: buffer.
                result == nil ifTrue: [ self error: socket lastErrorString ].
                buffer copyFrom: 1 to: result into: bytes startingAt: pos.
                pos := pos + result.
                remaining := remaining - result.
        ].

In 2.4.4.1 #copyFrom:to:into:startingAt: has an explicit test to throw an error when <from> is less than <to>, but in 3.1, the implementation was changed and #copyFrom:to:into:startingAt: stopped throwing an error, which is a bug ...

Here's a patch for SequenceableCollection>>copyFrom:to:into:startingAt: that throws errors correctly:

copyFrom: index1 to: index2 into: aSeqCollection startingAt: destIndex

"Deprecated, non-ANSI.
 Copies the elements of the receiver between index1 and index2, inclusive,
 into aSeqCollection starting at destIndex, overwriting the previous
 contents.  If aSeqCollection is the same object as the receiver, the
 source and destination blocks may overlap. Returns the receiver."

 self deprecated: 'copyFrom:to:into:startingAt:' .
 (index1 > index2)
  ifTrue: [ ^ self _errorIndexOutOfRange: index2].

(index1 < 1)
  ifTrue: [ ^ self _errorIndexOutOfRange: index1].

(index2 > self size)
  ifTrue: [ ^ self _errorIndexOutOfRange: index2].

((destIndex < 1) _or: [(destIndex > (aSeqCollection size + 1))])
   ifTrue: [ ^ aSeqCollection _errorIndexOutOfRange: destIndex].

aSeqCollection replaceFrom: destIndex to: destIndex + (index2 - index1)
        with: self startingAt: index1 .
 ^ self

I'll submit bugs, etc. later ...

Thanks for the report,

Dale

----- Original Message -----
| From: "Dario Trussardi" <[hidden email]>
| To: "GemStone Seaside beta discussion" <[hidden email]>
| Sent: Tuesday, July 24, 2012 5:22:00 AM
| Subject: Re: [GS/SS Beta] Gemstone 3.1.0  503 - Service Not Available
|
|
| Dale,
|
| excuse for my ignorance,
|
| but when i do the command kill -USR1 8157   ( my pid for example )
| what the system generate ?
|
| I don't find any files.
|
| I missing something ?
|
| Thanks,
|
| Dario
|
| > Dario,
| >
| > Could you do a `kill -USR1 <gem pid>` to get a sample of the stack
| > so we can see what the vm is doing when it goes hot. Do the `kill`
| > command several times in a row to get several samples.
| >
| > If you mail the log to me, I'll take a look.
| >
| > Dale
| >
| > ----- Original Message -----
| > | From: "Dario Trussardi" <[hidden email]>
| > | To: "beta discussion Gemstone Seaside"
| > | <[hidden email]>
| > | Sent: Tuesday, July 24, 2012 3:30:12 AM
| > | Subject: [GS/SS Beta] Gemstone 3.1.0  503 - Service Not Available
| > |
| > | Hi,
| > | i load the new Gemstone 3.1.0 on my MAC.
| > |
| > | After i load on it the Seaside30 from
| > | ConfigurationOfSeaside30-dhk.375
| > |
| > |
| > | I run the environment with:
| > |
| > | source /opt/gemstone/product/seaside/defSeaside
| > | export GEMSTONE_NAME=development
| > | $GEMSTONE/seaside/bin/startnet
| > | $GEMSTONE/seaside/bin/startGemstone
| > | $GEMSTONE/seaside/bin/runSeasideGems30 start  WAFastCGIAdaptor
| > | "2020
| > | 2021 2022"
| > |
| > |
| > |
| > | All work fine, the seaside entry point work right when the
| > | Browser
| > | call it.
| > |
| > |
| > | Sometime the system answer  the error:  503 - Service Not
| > | Available
| > |
| > | and the relative topaz process go in overload. ( 100 % of CPU
| > | time
| > | )
| > |
| > | At this point i need to  stop and start ( restart )  the
| > | Gemstone
| > | environment.
| > |
| > |
| > | It's my problem ?
| > |
| > | Anyone found something relative to it ?
| > |
| > |
| > | Thanks,
| > |
| > |
| > | Dario
| > |
| > |
|
|

Ciao,

        i update my Gemstone with:



        and the system don't go in overload.

        But sometime the system  answer in any case the:

                503 - Service Not Available

        I don't understund when, and because.

        After the error i reload the page and all work fine for more time.


        I have two impressions:

                A) after  the all web page open on the same Gemstone environment
       
                        aren't update for ( 30 seconds ) the  probability of error greatly increase.
               
                B) when the memory of the system is all busy  the  probability of error increase.

                        I have do some test with 0,5 GB of memory free and all work fine.
                       
                        Is possible this behavior ?
                       

        My system is based on MAC  Lion 10.7.4 with 4GB

                where i run Gemstone 3.1.0

                 and Lighttpd server with minimal configuration  for manage fastcgi request.



P.S. for Dale :   i do some test with original SequenceableCollection>>

                        copyFrom: index1 to: index2 into: aSeqCollection startingAt: destIndex

                         "Deprecated, non-ANSI. Copies the elements of the receiver ...................


                        and with 0,3GB  system memory free the system work fine.
       
                        No 503 error erase and no topaz process go in overload.

                        When the free memory  decreases the system begin with 503 error

                                and now the copyFrom: index1 to: index2 into: aSeqCollection startingAt: destIndex

                                it's important for manage the overload.

                        I think it's important the free memory for the  Gemstone environment.

                       

        I hope this consideration help to understand the question.


                Thanks,

                Dario