[Glass] GemTools-1.0-beta.8.7.1-32x can't log in to GS 3.2.4
Locked
123
123
Re: [Glass] [GLASS] Seaside - growing extent - normal?
 
|
Larry ...
Ah, I had missed the method that James mentioned ... Repository>>#'findReferencePathToObject:'... That just might get us the answer we are looking for ... Do an allInstances on WASession and get the oop of an old instance ... then logout and to the following (using your oop): System abortTransaction. SystemRepository findReferencePathToObject: (Object _objectForOop: 119868673) This will take a bit, but you will get back an array that looks something like this: (class)@ -> Array (oop)@ -> 365061121 (size)@ -> 11 1@ -> aWASession 2@ -> true 3@ -> WADispatcher 4@ -> aWADispatcher 5@ -> aDictionary( 'browse'->aWAApplication, 'javascript'->aWADispatcher, 'seaside'->aWALegacyRedirectionHandler, 'examples'->aWADispatcher, 'stat... 6@ -> 'browse'->aWAApplication 7@ -> aWAApplication 8@ -> aWACache 9@ -> aRcKeyValueDictionary( '_pIYr5fSpwCZ3W4b'->aWASession, '8t5reroNR8Typqki'->aWASession, 'eXX4KnQGvkUOFEN7'->aWASession, '1hV8xpORJw_5YSey'->a... 10@ -> aRcCollisionBucket 11@ -> aWASession The last slot in the array is the target object and the 3rd slot in the array is the root object ... the case I've got here is the expected reference path for an unexpired session ... but if you run this in your data base, you should find an unexpected reference path and we'll be able to clean this up ... This method only returns _a reference path_ (there could be others) but this should give us a useful path to start identifying the object leak... Sorry about missing Repository>>#'findReferencePathToObject:' ... Dale On 04/03/2015 12:33 PM, James Foster
wrote:
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
Ok, I did what you said but I’m at a bit of a loss as to what to do next. Here are my results: 1 - aWASession 2 - true 3 - WADispatcher 4 - aWADispatcher 5 - aDictionary( 'CreateMusicalPieceRepertoireItemInterface'->aWAApplication, 'LessonTaskRecordingUpdatePrivacySettings'->aWAApplication, 'RetrieveRepertoireItemRequestHandler'->aRetrieveRepertoireItemRequestHandler, 'PracticeSessionUpdateTimePracticedInterface'->aWAApplication, 'CreateMethodBookInterface'->aWAApplication, 'CreatePracticeSessionRequestHandler'->aCreatePracticeSessionRequestHandler, 'LessonTaskRecordingsRequestHandler'->aLessonTaskRecordingsRequestHandler, 'UserActivityRequestHandler'->anUserActivityRequestHandler, 'EmailOptOutInterface'->aWAApplication, 'LessonTaskInformationServer'->aWAApplication, 'UserRegistrationRequestHandler'->anUserRegistrationRequestHandler, 'GetMethodBooks'->aWAApplication, …) 6 - 'UserInformationInterface'->aWAApplication 7 - aWAApplication 8 - aWACache 9 - aRcKeyValueDictionary( '5jTYOuLPzkOYLv4d'->aWASession, 'ePxPIpWmyhtOHA0U'->aWASession, 'zRyovUbd2YaYCEuC'->aWADocumentHandler, 'Qwhb4dokS54vxz03'->aWASession, 'bsXyv4UGt5-gbrEo'->aWASession, 'qTDuZk9Mfu9cllpR'->aWADocumentHandler, 'bSnQRSCCU6tLSuHy'->aWADocumentHandler, 'Dv8_EljXp4UeBCYm'->aWADocumentHandler, 'JRp685a4lHUKhDiT'->aWASession, 'JG6o8KnnCuSOtNjx'->aWASession, 'VqMHwuCbBLRFo40Y'->aWASession, '1pRW-D5PPlAhW37g'->aWASession, 'VyzeJ-GNB8GF-aMJ'->aWASession, 'YOVib-WowYRZNJaN'->aWADocumentHandler, 'I9PoXhB7gBlGMNgY'->aWADocumentHandler, '-lyxYEftM3kUE_Wg'->aWASession, 'ZVnusqwGHRr1Hb7_'->aWADocumentHandler, '9Vch6_hBThnx_eln'->aWASession, 'wNwBarOaES_2Uigs'->aWADocumentHandler, 'oSCks-wA3lHOqbPu'->aWADocumentHandler, ...) 10 - aRcCollisionBucket 11 - aWASession What do I do now? Larry
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
Larry,
Well, this looks like the session expiration code didn't expire the session state as expected: | expired | Transcript cr; show: 'Unregistering...' , DateAndTime now printString. expired := WABasicDevelopment reapSeasideCache. expired > 0 ifTrue: [ (ObjectLogEntry trace: 'MTCE: expired sessions' object: expired) addToLog ]. Transcript cr; show: '...Expired: ' , expired printString , ' sessions.'. System commitTransaction So we'll need to understand why ... and the first thing I want to know is the result of this: | app cache objectsByKey assoc | app := WADispatcher default handlers at: 'UserInformationInterface'. cache := app cache. objectsByKey := cache instVarAt: #'objectsByKey'. assoc := objectsByKey associationAt: '5jTYOuLPzkOYLv4d'. cache expiryPolicy isExpired: assoc value key: assoc key This is basically the expression that gets evaluated when we are trying to remove the expired sessions. If it returns true, then something is wrong with the reaping code and we'll want to step through that logic.. If it returns false, then we need to understand why this presumably ancient session is not expired ... Dale On 04/06/2015 02:56 PM, Lawrence
Kellogg wrote:
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
Ok, I had to rewrite a few things in your code because it crashed, so, I did this, | app cache objectsByKey assoc | app := WADispatcher default handlers at: 'UserInformationInterface'. cache := app cache. objectsByKey := cache instVarAt: 3. assoc := objectsByKey at:'5jTYOuLPzkOYLv4d'. cache expiryPolicy isExpired: assoc value key: assoc key and it returns false. So, I guess we have to figure out why this old session is not expired. Larry
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
Larry,
I've been reading code a bit, looking for some sort of path that would foil the gemstoneReap code and the most likely scenario I can find has to do with this code in WARcLastAccessExpiryPolicy>>isExpired:key: isExpired: anObject key: aString | entry | entry := lastAccessTable at: aString ifAbsent: [ WARcLastAccessEntry new ]. ^ entry isExpired: self timeout and WARcLastAccessExpiryPolicy>>isExpiredUpdating:key: isExpiredUpdating: anObject key: aString | entry | entry := lastAccessTable at: aString ifAbsent: [ WARcLastAccessEntry new ]. ^ entry isExpiredUpdating: self timeout So if somehow the lastAccessTable has lost a key for a session, then the session will survive forever ... We can test this by the following code: | app cache lastAccessTable | app := WADispatcher default handlers at: 'UserInformationInterface'. cache := app cache. lastAccessTable := cache expiryPolicy instVarNamed: #'lastAccessTable'. lastAccessTable at: '5jTYOuLPzkOYLv4d' ifAbsent: [ 'missing' ] I expect the result to be 'missing' ... Based on this expectation, I'll start writing some repair code ... Dale On 04/06/2015 03:30 PM, Lawrence
Kellogg wrote:
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
Okay, I think we'll try taking this route with
WACacheExpiryPolicy>>isExpiredUpdating:key:
isExpiredUpdating: anObject key: aString | entry | entry := lastAccessTable at: aString ifAbsent: [ ^true ]. ^ entry isExpiredUpdating: self timeout This code should force any sessions with a missing `lastAccessTable` to be expired ... Looking at the WACache>>gemstoneReap code, I think I can tell how we load the entries in the `lastAccessTable`. If you notice, in the first loop in WACache>>gemstoneReap, that WACache>>notifyRemoved:key: is called for each of the expired sessions and then when we are looping through `expired` sessions we start committing every 100 sessions ... now after we have processed the first 100 sessions, we commit the removal of ALL of the sessions from the `lastAccessTable` but we only commit the removal of the first 100 sessions from from the `objectsByKey` and `keysByObect` tables and if we crash before finishing the whole operation, we will have corrupted the `lastAccessTable` ... and I seem to recall that we did have such a crash ... This one will take a while to run, but we should be able to get most of the repository cleaned up ... I will submit a bug on the `lastAccessTable` problem ... Dale On 04/06/2015 03:47 PM, Dale Henrichs
wrote:
Larry, _______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
Here is the bug report[1] ... I know that this is a bit premature,
because I haven't quite gotten confirmation from Larry, but I think
the logic is "just plain wrong" based on code reading:)
Dale [1] https://github.com/GsDevKit/Seaside31/issues/68 On 04/06/2015 03:57 PM, Dale Henrichs
wrote:
Okay, I think we'll try taking this route with WACacheExpiryPolicy>>isExpiredUpdating:key: _______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
In reply to this post by GLASS mailing list
On 04/06/2015 04:29 PM, Lawrence
Kellogg wrote:
the value of lastCount is suspicious ... what is the result of `counter value` Dale _______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
For Seaside Gemstone Core: MODIFIED Ancestors: Seaside-GemStone-Core-dkh.63 =========================== Name: Seaside-GemStone-Core-dkh.63 Author: dkh Time: 09/27/2011, 14:59:38 UUID: 81e7cc84-552b-4806-bf52-2d93f25be69c Ancestors: Seaside-GemStone-Core-dkh.62 3.0.6.1 (dkh.334): - remove the GemStone method seasideNextLine and add a test for Issue 289 —————————————
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
Okay,
It looks like I assumed that you were using Seaside 3.1 and you must be using Seaside3.0 ... I don't think that things have actually changed in this area since Seaside 3.0, but it _is_ something to be aware of ... now... Given that the code (in Seaside-GemStone-Core-dkh.70) in WARcLastAccessEntry>>isExpired:updating: (could you verify that your version is the same?): isExpired: timeout updating: updating | value | ^ (value := self counter value) > lastCount ifTrue: [ "accessed since last scan" updating ifTrue: [ lastCount := value. time := Time totalSeconds ]. false ] ifFalse: [ Time totalSeconds - time > timeout ] it appears that we have only done a expiration scan (updating = true) only once and I have been under the impression that we've done at least two full scans (the scan before the backup and the scan after we discovered that we had not recovered any data) ... oh well ... I think that the `time` in this entry corresponds to the date: `2014-11-11T22:42:08+00:00` (Time totalSeconds returns seconds since January 1, 1901) and that implies that the last scan was done a year ago? Unless the code is very different or ... What does `date` return from the linux shell? The next step is to see if the code is working like I expect it to. The code below simulates and expiration scan, and then see how the entry has changed along with couple of other things: | app cache objectsByKey assoc expired1 expired2 timeout lastAccessTable entry | app := WADispatcher default handlers at: 'UserInformationInterface'. cache := app cache. objectsByKey := cache instVarAt: 3. assoc := objectsByKey associationAt: '5jTYOuLPzkOYLv4d'. lastAccessTable := cache expiryPolicy instVarNamed: #'lastAccessTable'. entry := lastAccessTable at: '5jTYOuLPzkOYLv4d'. timeout := cache expiryPolicy. expired1 := entry isExpiredUpdating: timeout. expired2 := entry isExpiredUpdating: -1. ^ {timeout. Time totalSeconds. expired1. entry. entry time. entry lastCount. (entry counter value). expired2} I've got to head home, but I'll check in again this evening when I get the chance ... Dale On 04/06/2015 04:57 PM, Lawrence
Kellogg wrote:
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
Thanks, the above code returns: anArray( aWARcLastAccessExpiryPolicy, 3605819381, false, aWARcLastAccessEntry, 3605819381, 1, 1, true)
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
On 4/6/15 5:30 PM, Lawrence Kellogg
wrote:
The time, corresponds to 2015-04-07T00:29:41+00:00...so the date on your server is probably correct... Oh shoot, the first slot should have been `cache expiryPolicy timeout`, so let's try again, with an edited workspace: | app cache objectsByKey assoc expired1 expired2 timeout lastAccessTable entry | app := WADispatcher default handlers at: 'UserInformationInterface'. cache := app cache. objectsByKey := cache instVarAt: 3. assoc := objectsByKey associationAt: '5jTYOuLPzkOYLv4d'. lastAccessTable := cache expiryPolicy instVarNamed: #'lastAccessTable'. entry := lastAccessTable at: '5jTYOuLPzkOYLv4d'. timeout := cache expiryPolicy timeout. expired1 := entry isExpiredUpdating: timeout. expired2 := entry isExpiredUpdating: -1. ^ {timeout. Time totalSeconds. expired1. entry. entry time. entry lastCount. (entry counter value). expired2} From this little experiment it seems that we've only run one expiration run against this particular session ... so after you get me the results from this array and the timeout (first slot) seems to be a reasonable number (less than 12,620,853), then we will try running the expiration run again... BUT before we run anther expiration run, I want to see the code that you are using in WACache>>gemstoneReap, WABasicDevelopment class>>reapHandlerCache:dispatchers: and WABasicDevelopment class>>reapSeasideCache, just to see if I can spot a transaction error before running a second (and third) expiration. Yes twice more ... for some unknown reason, the session we are looking has apparently not been scanned before (which is why I want to read the code that is in your image) the `lastCount` should have been equal to the `counter value` and I'm not quite sure why the lastCount hasn't been bumped ... unless the first time we touched the session is when we just ran the above workspace ... I will have to drop offline for awhile, but I will try bringing up a stone that has an older version of Seaside installed to see if there are indeed differences in the expiration logic ... I assume that you've been running these tests in the stone that we restored from backup ..... or have you been running these tests in a stone in which you've never run the expiration code? Dale _______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
Answers below….
Ok, here is the result from the above code, substituting at: for associationAt: anArray( 600, 3605869347, true, aWARcLastAccessEntry, 3605819381, 1, 1, true)
gemstoneReap "Iterate through the cache and remove objects that have expired." "In GemStone, this method is performed by a separate maintenance VM, so we are already in transaction (assumed to be running in #autoBegin transactionMode) and do not have to worry about acquiring the TransactionMutex. Since we are using reducedConflict dictionaries in the first place, we will remove the keys and values from the existing dictionaries without using the mutex." | expired count platform | expired := UserGlobals at: #'ExpiryCleanup' put: OrderedCollection new. platform := GRPlatform current. platform doCommitTransaction. count := 0. objectsByKey associationsDo: [ :assoc | (self expiryPolicy isExpiredUpdating: assoc value key: assoc key) ifTrue: [ self notifyRemoved: assoc value key: assoc key. count := count + 1. Transcript cr; show: 'Scan progress: ' , count printString. expired add: assoc. count \\ 100 == 0 ifTrue: [platform doCommitTransaction ]. count \\ 1000 == 0 ifTrue: [Transcript cr; show: 'Scan progress: ' , count printString.] ] ]. Transcript cr; show: 'finished scan: ' , count printString. platform doCommitTransaction. count := 0. (UserGlobals at: #'ExpiryCleanup' ) do: [ :assoc | count := count + 1. Transcript cr; show: 'Expire progress: ' , count printString. objectsByKey removeKey: assoc key ifAbsent: []. keysByObject removeKey: assoc value ifAbsent: [ ]. count \\ 100 == 0 ifTrue: [ platform doCommitTransaction ]. count \\ 1000 == 0 ifTrue: [ Transcript cr; show: 'Expire progress: ' , count printString.]]. platform doCommitTransaction. UserGlobals removeKey: #'ExpiryCleanup'. platform doCommitTransaction. Transcript show: 'Leaving gemstoneReap: ',expired size printString. ^ expired size
reapHandlerCache: aHandler dispatchers: dispatchers | expired | expired := 0. (aHandler isApplication or: [ aHandler isSession ]) ifTrue: [ expired := aHandler cache gemstoneReap. aHandler sessionsDo: [:session | expired := expired + session continuations gemstoneReap ]] ifFalse: [ aHandler isDispatcher ifTrue: [ dispatchers add: aHandler ]]. ^expired
reapSeasideCache | dps expired | expired := 0. dps := OrderedCollection with: WADispatcher default. [ dps isEmpty ] whileFalse: [ | dp | dp := dps removeFirst. dp isApplication ifTrue: [ expired := expired + (self reapHandlerCache: dp dispatchers: dps) ] ifFalse: [ dp handlers valuesDo: [:ep | expired := expired + (self reapHandlerCache: ep dispatchers: dps) ]]]. ^expired
Yes, all of the test have been run from the stone that I restored from backup, and the reap code has been run multiple times, as I recall. Best, Larry
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
Larry,
Okay, I cannot think of a reason that the earlier scans could not work, so I'm thinking that I'd like to pick a smaller subset of the whole system that runs faster and then try to understand why the scan isn't working ... So I'll start by finding out if UserInformationInterface will make a likely candidate, so let's find out how big the cache is: | app cache objectsByKey assoc expired1 expired2 timeout lastAccessTable entry | app := WADispatcher default handlers at: 'UserInformationInterface'. cache := app cache. objectsByKey := cache instVarAt: 3. objectsByKey size I'll put together another workspace for doing a scan on a per application basis in th emean time ... Dale On 04/07/2015 07:28 AM, Lawrence
Kellogg wrote:
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] [GLASS] Seaside - growing extent - normal?
|
|
Larry,
Here's the workspace to use if the size of the cache seems to be reasonable: | app cache objectsByKey | app := WADispatcher default handlers at: 'UserInformationInterface'. cache := app cache. objectsByKey := cache instVarAt: 3. {(objectsByKey size). (cache gemstoneReap)} If 'UserInformationInterface' appears to be too big, poke around in the WAApplication instances that show up in `WADispatcher default handlers` and see if you can find the smallest cache, and then run the above workspace against that app ... also I'd like to see the result array which gives us the number of entries in the cache and the number of entries expired ... If they turn out to be significantly different, then try a second run ... I'm also tempted to ask you to edit the gemstoneReap method to reduce the amount of logging (but this would be optional): WACache>>gemstoneReap, gemstoneReap
"Iterate through the cache and remove objects that have
expired."
"In GemStone, this method is performed by a separate
maintenance VM,
so we are already in transaction (assumed to be running
in #autoBegin
transactionMode) and do not have to worry about
acquiring the TransactionMutex.
Since we are using reducedConflict dictionaries in the
first place, we will remove the keys
and values from the existing dictionaries without using
the mutex."
| expired count platform |
expired := UserGlobals at: #'ExpiryCleanup' put:
OrderedCollection new.
platform := GRPlatform current.
platform doCommitTransaction.
count := 0.
objectsByKey
associationsDo: [ :assoc |
(self expiryPolicy isExpiredUpdating: assoc value key:
assoc key)
ifTrue: [
self notifyRemoved: assoc value key: assoc key.
count := count + 1.
expired add: assoc.
count \\ 100 == 0
ifTrue: [platform doCommitTransaction ].
count \\ 1000 == 0
ifTrue: [Transcript cr; show: 'Scan progress: ' ,
count printString.] ] ].
Transcript cr; show: 'finished scan: ' , count printString.
platform doCommitTransaction.
count := 0.
(UserGlobals at: #'ExpiryCleanup' )
do: [ :assoc |
count := count + 1.
objectsByKey removeKey: assoc key ifAbsent: [].
keysByObject removeKey: assoc value ifAbsent: [ ].
count \\ 100 == 0
ifTrue: [ platform doCommitTransaction ].
count \\ 1000 == 0
ifTrue: [ Transcript cr; show: 'Expire progress: ' ,
count printString.]].
platform doCommitTransaction.
UserGlobals removeKey: #'ExpiryCleanup'.
platform doCommitTransaction.
Transcript show: 'Leaving gemstoneReap: ',expired size
printString.
^ expired size
If you do make these edits then I'd like you to capture the transcript after each run completes ... Dale On 04/07/2015 03:20 PM, Dale Henrichs
wrote:
Larry, _______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [GLASS] Seaside - growing extent - normal?
|
|
In reply to this post by GLASS mailing list
Hello,
So, perhaps I will be forced to finally get a handle on my problem with a growing extent. Something funny happened a couple of weeks ago that I thought I would share. I needed a little backend service to do some testing with an iPhone app so I wrote it in Gemstone. I wrote a simple queue mechanism that uses a few RcQueues that are accessible from a call to a WAComponent. That’s it. Well, my iPhone app polls the back-end very fifteen seconds or so, calling this WAComponent. I found that my extent ballooned from 36 gig to over 60 gig and filled up the whole file system! Can we deduce anything as a result of my experience? Is the Seaside session stuff taking up all the space in the extent? I’ll dig up those steps to try to shrink the extent but I don’t remember having much luck. Best, Larry
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [GLASS] Seaside - growing extent - normal?
|
|
Larry,
Did you have the maintenance vm running while you did this experiment? The maintenace vm should be expiring sessions every minute ... If you are running the maintenance vm, then sharing your code with me would allow me to run local experiments and I should be able to figure out what's going on ... Dale On 08/07/2015 01:46 PM, Lawrence
Kellogg wrote:
Hello, _______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
«
Return to GLASS
|
1 view|%1 views
| Free forum by Nabble | Edit this page |