Hi,
I'm experiencing the following concern with repository space: In a GLASS app, the repository is slowly growing to a too large size corresponding to the data that is in it (it grows to +- 4Gb). Every hour, I do an MFC which makes some space available but, overall, the repository is growing too fast. When I do a full backup and restore in a new extent, I end of with a repository of about 1/10th large. What can cause this behavior and is there something I can do about it? Can I find out what is consuming this space? I tried some things that are mentioned in the GS manual, but I don't really see anything. I also read that a full backup compacts the object table so less page space is wasted, but can this really be the thing I am seeing? Reclaim gems are running normally and I am using a maintenance gem that is started via cron (and which does MFC and session expiration). Any ideas appreciated! Johan |
Hi Johan,
Perhaps SystemRepository fileSizeReport will give you an idea how much free space is in the repo. We find that after the reclaim did its work, the compressed backup is about 1/4 of the size. We also found that with the default settings, reclaiming was delayed because the SPC was more than 75% dirty, which must be because of all the garbage the sessions create. Look in the reclaim gem log. The objectAudit showed some big HTML strings created, which we could trace with findReferencePaths. HTH Otto On 11 Aug 2011, at 19:29, Johan Brichau <[hidden email]> wrote: > Hi, > > I'm experiencing the following concern with repository space: > > In a GLASS app, the repository is slowly growing to a too large size corresponding to the data that is in it (it grows to +- 4Gb). > Every hour, I do an MFC which makes some space available but, overall, the repository is growing too fast. > > When I do a full backup and restore in a new extent, I end of with a repository of about 1/10th large. > > What can cause this behavior and is there something I can do about it? Can I find out what is consuming this space? I tried some things that are mentioned in the GS manual, but I don't really see anything. > I also read that a full backup compacts the object table so less page space is wasted, but can this really be the thing I am seeing? > > Reclaim gems are running normally and I am using a maintenance gem that is started via cron (and which does MFC and session expiration). > > Any ideas appreciated! > Johan |
In reply to this post by Johan Brichau-2
Hi Johan,
another reason for a slowly growing repository may be that you are running with constantly increasing commit record backlog. This will be the case if you have a productive system which is constantly serving requests (and so doing commits to the repository) AND you have at least one other session which stays in a transaction and does not commit or abort. So the simplest reason would be that your app is constanlty handling it's requests and you still have your "forgotten GemTools" logged in, staying in a transaction. May that be the case? best regards, Ralph Am 11.08.2011 19:29, schrieb Johan Brichau: > Hi, > > I'm experiencing the following concern with repository space: > > In a GLASS app, the repository is slowly growing to a too large size corresponding to the data that is in it (it grows to +- 4Gb). > Every hour, I do an MFC which makes some space available but, overall, the repository is growing too fast. > > When I do a full backup and restore in a new extent, I end of with a repository of about 1/10th large. > > What can cause this behavior and is there something I can do about it? Can I find out what is consuming this space? I tried some things that are mentioned in the GS manual, but I don't really see anything. > I also read that a full backup compacts the object table so less page space is wasted, but can this really be the thing I am seeing? > > Reclaim gems are running normally and I am using a maintenance gem that is started via cron (and which does MFC and session expiration). > > Any ideas appreciated! > Johan > |
In reply to this post by Johan Brichau-2
Johan,
A couple of things... The most recent GLASS key file[1] permits unlimited repository size, so the 4GB limit shouldn't be an issue. The "backup and restore to new extent" operation compacts repository pages, not the object table ... Over time pages may become sparsely populated by objects ... after objects are declared dead by an MFC, the reclaim process copies live objects to new pages in the repository and the old pages are recycled. The old pages are put on the free page list. The size of a repository is the sum of "live" pages and "free pages". "Live" pages may not be completely full. When you do a "backup and restore to new extent" pages are filled up during the restore in effect compacting the "live" pages. Also during the restore a minimal number of "free" pages are created.... James Foster has created a ScanBackup tool[2] that analyzes a backup and reports back the contents of the backup ... but this guy measures only live objects. To get an idea what might be considered garbage, you could make a backup right before you hourly MFC run and then again right afterward and then analyze the backup files .... you could also do a restore of the before and after backups to compare your extent sizes ... Otto gives some good advice ... the object audit has a large object report... Ralph also gives good advice ... you can use the statmonitor to see if you have spikes in your commit record backlog (the stone stat CommitRecordCount?)... The seaside session state can accumulate depending upon the request rate ... in my experiments several years ago[3], it appeared that you could sustain a steady rate of 15 requests/second and still stay within the 4GB limit but those tests didn't take into account the growth of the repository from your business objects ... The point is that session state can account for quite a bit of repository size swing ... Dale [1] http://seaside.gemstone.com/etc/ [2] http://programminggems.wordpress.com/2009/12/15/scanbackup-2/ [3] http://gemstonesoup.wordpress.com/2007/10/19/scaling-seaside-with-gemstones/#conclusions ----- Original Message ----- | From: "Johan Brichau" <[hidden email]> | To: "GemStone Seaside beta discussion" <[hidden email]> | Sent: Thursday, August 11, 2011 10:29:35 AM | Subject: [GS/SS Beta] repository space | | Hi, | | I'm experiencing the following concern with repository space: | | In a GLASS app, the repository is slowly growing to a too large size | corresponding to the data that is in it (it grows to +- 4Gb). | Every hour, I do an MFC which makes some space available but, | overall, the repository is growing too fast. | | When I do a full backup and restore in a new extent, I end of with a | repository of about 1/10th large. | | What can cause this behavior and is there something I can do about | it? Can I find out what is consuming this space? I tried some things | that are mentioned in the GS manual, but I don't really see | anything. | I also read that a full backup compacts the object table so less page | space is wasted, but can this really be the thing I am seeing? | | Reclaim gems are running normally and I am using a maintenance gem | that is started via cron (and which does MFC and session | expiration). | | Any ideas appreciated! | Johan |
In reply to this post by otto
Hi Otto,
> Perhaps SystemRepository fileSizeReport will give you an idea how much > free space is in the repo. Yes, I am referring to the used and free spaces that are reported there. The used space is steadily growing. > We also found > that with the default settings, reclaiming was delayed because the SPC > was more than 75% dirty, which must be because of all the garbage the > sessions create. Look in the reclaim gem log. That is interesting. What do you mean with '75% dirty'? And how did you notice that this was delaying the reclaim process? > The objectAudit showed > some big HTML strings created, which we could trace with > findReferencePaths. The object audit indeed shows me a lot of strings. However, I wonder why they keep lingering around. I include it below: Object audit as of 08/11/11 22:24:28 CEST. Summary of objects whose sizes exceed 100000 Bytes or Oops: ObjectID Class ClassName LogicalSize ---------------------------------------------------------------------------------------------------------- 1416370945 103425 ByteArray 122880 Oops 2665894657 74753 String 212188 Oops 2668065537 74753 String 183387 Oops 358902273 103425 ByteArray 122880 Oops 596413953 101377 Dictionary 126044 Oops 2666372353 74753 String 141151 Oops 693299969 101377 Dictionary 270008 Oops 550854145 74753 String 122916 Oops 2665870593 74753 String 370032 Oops 209127681 74753 String 139853 Oops 176673537 74753 String 141151 Oops 181380097 74753 String 366302 Oops 181381121 74753 String 196779 Oops 181775617 74753 String 183387 Oops 2666151169 74753 String 366302 Oops 2665977089 74753 String 196779 Oops 227244545 74753 String 183387 Oops 209483521 74753 String 183183 Oops 228395777 74753 String 196779 Oops 228397569 74753 String 366302 Oops 219827969 74753 String 196577 Oops 220749057 74753 String 363274 Oops 227653889 74753 String 141151 Oops 2587344897 74753 String 164661 Oops 2588097281 74753 String 212188 Oops 2590823425 74753 String 370032 Oops 2590824449 74753 String 198793 Oops 130566913 103425 ByteArray 122880 Oops 2564694785 74753 String 163312 Oops 2666146561 74753 String 198587 Oops 2665677569 74753 String 366931 Oops 2665869569 74753 String 198793 Oops 2667402753 74753 String 211977 Oops 2667209729 74753 String 164661 Oops 3870573313 74753 String 125935 Oops 3008485377 74753 String 2209300 Oops 3018173441 74753 String 2209365 Oops 2847841793 74753 String 2209300 Oops 2858208513 74753 String 2209365 Oops 3243380993 74753 String 451631 Oops 3245453057 74753 String 451695 Oops 3130990337 74753 String 2209300 Oops 3142624513 74753 String 2209365 Oops 8120544001 74753 String 107540 Oops 4986202369 101377 Dictionary 270008 Oops 4390321409 74753 String 123847 Oops 4390322433 74753 String 103623 Oops 4390322689 74753 String 118565 Oops 4390323457 74753 String 142960 Oops 1286341633 101377 Dictionary 150068 Oops 4922307585 74753 String 102680 Oops 4922309377 74753 String 106937 Oops 5804818433 74753 String 102680 Oops 5804819201 74753 String 106937 Oops 5999437057 74753 String 102029 Oops 5999437825 74753 String 106276 Oops 1159951105 101377 Dictionary 237098 Oops 4649084417 101377 Dictionary 126044 Oops 7878366465 74753 String 103867 Oops 1316451073 74753 String 129710 Oops 1316452097 74753 String 148191 Oops 1316452353 74753 String 124578 Oops 6256428801 74753 String 117241 Oops 8337980673 74753 String 107185 Oops 8489262849 74753 String 104059 Oops 8441193217 74753 String 104855 Oops 7177938433 74753 String 108934 Oops 8575871233 74753 String 107285 Oops 8737196289 74753 String 107149 Oops 9617316865 74753 String 215545 Oops 9617317377 74753 String 163221 Oops 6172942337 101377 Dictionary 165008 Oops 6643096065 79361 KeyValueDictionary 449478 Oops ----------- Object Statistics Summary ----------------- ----- Instances of invisible (private) classes ------ Number of instances: 8088 Total size: 111422 K Bytes Average size: 13.8 Bytes Class: 209153 Instances: 0 Total Size: 0 K Bytes Class: 209409 Instances: 8049 Total Size: 110933 K Bytes Class: 209665 Instances: 0 Total Size: 0 K Bytes Class: 209921 Instances: 0 Total Size: 0 K Bytes Class: 210177 Instances: 0 Total Size: 0 K Bytes Class: 210433 Instances: 0 Total Size: 0 K Bytes Class: 210689 Instances: 0 Total Size: 0 K Bytes Class: 210945 Instances: 0 Total Size: 0 K Bytes Class: 211201 Instances: 0 Total Size: 0 K Bytes Class: 211457 Instances: 0 Total Size: 0 K Bytes Class: 211713 Instances: 0 Total Size: 0 K Bytes Class: 211969 Instances: 0 Total Size: 0 K Bytes Class: 212225 Instances: 0 Total Size: 0 K Bytes Class: 212481 Instances: 0 Total Size: 0 K Bytes Class: 212737 Instances: 39 Total Size: 490 K Bytes Class: 212993 Instances: 0 Total Size: 0 K Bytes Class: 213249 Instances: 0 Total Size: 0 K Bytes Class: 213505 Instances: 0 Total Size: 0 K Bytes Class: 213761 Instances: 0 Total Size: 0 K Bytes ----- Instances of visible classes ----------------- Number of objects : 28875861 Total Size : 1948595 K Bytes size of Object Headers : 676777 K Bytes size of Object Values : 1258718 K Bytes size of Object Tags : 0 K Bytes average of Object Value: 44.6 Bytes |
We saw that in the logs of the reclaim gc gem. In our setup it's in the same location as the stone log. There was a threshold (something like reclaimDeferThreshold) that one can set. Have a look at UserGlobals in the GcUser's profile.
Does this help? |
In reply to this post by Johan Brichau-2
Johan,
What does you ObjectLog look like ... Transcript output is kept around in the ObjectLog ... However, if the Strings are cleaned up by a gc, then the ObjectLog is not a culprit ... Continuations (which are instances of GsProcess) will hang onto method temps (and therefore potentially a lot of junk) until the session state is expired, this would be my guess if the big Strings get collected by an MFC... If the strings are not reaped by an MFC then given the oop of the String, you can look at it 'Object _objectForOop: <oop>` and that might give you a clue as to it's source. You can use `SystemRepository findReferencePathToObject: (Object _objectForOop: <oop>)` to find reference paths that keep the string alive ... Dale ----- Original Message ----- | From: "Johan Brichau" <[hidden email]> | To: "GemStone Seaside beta discussion" <[hidden email]> | Sent: Thursday, August 11, 2011 1:32:01 PM | Subject: Re: [GS/SS Beta] repository space | | Hi Otto, | | > Perhaps SystemRepository fileSizeReport will give you an idea how | > much | > free space is in the repo. | | Yes, I am referring to the used and free spaces that are reported | there. The used space is steadily growing. | | > We also found | > that with the default settings, reclaiming was delayed because the | > SPC | > was more than 75% dirty, which must be because of all the garbage | > the | > sessions create. Look in the reclaim gem log. | | That is interesting. What do you mean with '75% dirty'? And how did | you notice that this was delaying the reclaim process? | | > The objectAudit showed | > some big HTML strings created, which we could trace with | > findReferencePaths. | | The object audit indeed shows me a lot of strings. However, I wonder | why they keep lingering around. | I include it below: | | | Object audit as of 08/11/11 22:24:28 CEST. | Summary of objects whose sizes exceed 100000 Bytes or Oops: | | ObjectID Class ClassName | LogicalSize | ---------------------------------------------------------------------------------------------------------- | 1416370945 103425 ByteArray | 122880 Oops | 2665894657 74753 String | 212188 Oops | 2668065537 74753 String | 183387 Oops | 358902273 103425 ByteArray | 122880 Oops | 596413953 101377 Dictionary | 126044 Oops | 2666372353 74753 String | 141151 Oops | 693299969 101377 Dictionary | 270008 Oops | 550854145 74753 String | 122916 Oops | 2665870593 74753 String | 370032 Oops | 209127681 74753 String | 139853 Oops | 176673537 74753 String | 141151 Oops | 181380097 74753 String | 366302 Oops | 181381121 74753 String | 196779 Oops | 181775617 74753 String | 183387 Oops | 2666151169 74753 String | 366302 Oops | 2665977089 74753 String | 196779 Oops | 227244545 74753 String | 183387 Oops | 209483521 74753 String | 183183 Oops | 228395777 74753 String | 196779 Oops | 228397569 74753 String | 366302 Oops | 219827969 74753 String | 196577 Oops | 220749057 74753 String | 363274 Oops | 227653889 74753 String | 141151 Oops | 2587344897 74753 String | 164661 Oops | 2588097281 74753 String | 212188 Oops | 2590823425 74753 String | 370032 Oops | 2590824449 74753 String | 198793 Oops | 130566913 103425 ByteArray | 122880 Oops | 2564694785 74753 String | 163312 Oops | 2666146561 74753 String | 198587 Oops | 2665677569 74753 String | 366931 Oops | 2665869569 74753 String | 198793 Oops | 2667402753 74753 String | 211977 Oops | 2667209729 74753 String | 164661 Oops | 3870573313 74753 String | 125935 Oops | 3008485377 74753 String | 2209300 Oops | 3018173441 74753 String | 2209365 Oops | 2847841793 74753 String | 2209300 Oops | 2858208513 74753 String | 2209365 Oops | 3243380993 74753 String | 451631 Oops | 3245453057 74753 String | 451695 Oops | 3130990337 74753 String | 2209300 Oops | 3142624513 74753 String | 2209365 Oops | 8120544001 74753 String | 107540 Oops | 4986202369 101377 Dictionary | 270008 Oops | 4390321409 74753 String | 123847 Oops | 4390322433 74753 String | 103623 Oops | 4390322689 74753 String | 118565 Oops | 4390323457 74753 String | 142960 Oops | 1286341633 101377 Dictionary | 150068 Oops | 4922307585 74753 String | 102680 Oops | 4922309377 74753 String | 106937 Oops | 5804818433 74753 String | 102680 Oops | 5804819201 74753 String | 106937 Oops | 5999437057 74753 String | 102029 Oops | 5999437825 74753 String | 106276 Oops | 1159951105 101377 Dictionary | 237098 Oops | 4649084417 101377 Dictionary | 126044 Oops | 7878366465 74753 String | 103867 Oops | 1316451073 74753 String | 129710 Oops | 1316452097 74753 String | 148191 Oops | 1316452353 74753 String | 124578 Oops | 6256428801 74753 String | 117241 Oops | 8337980673 74753 String | 107185 Oops | 8489262849 74753 String | 104059 Oops | 8441193217 74753 String | 104855 Oops | 7177938433 74753 String | 108934 Oops | 8575871233 74753 String | 107285 Oops | 8737196289 74753 String | 107149 Oops | 9617316865 74753 String | 215545 Oops | 9617317377 74753 String | 163221 Oops | 6172942337 101377 Dictionary | 165008 Oops | 6643096065 79361 KeyValueDictionary | 449478 Oops | | ----------- Object Statistics Summary ----------------- | | ----- Instances of invisible (private) classes ------ | Number of instances: 8088 | Total size: 111422 K Bytes | Average size: 13.8 Bytes | | Class: 209153 Instances: 0 Total Size: | 0 K Bytes | Class: 209409 Instances: 8049 Total Size: | 110933 K Bytes | Class: 209665 Instances: 0 Total Size: | 0 K Bytes | Class: 209921 Instances: 0 Total Size: | 0 K Bytes | Class: 210177 Instances: 0 Total Size: | 0 K Bytes | Class: 210433 Instances: 0 Total Size: | 0 K Bytes | Class: 210689 Instances: 0 Total Size: | 0 K Bytes | Class: 210945 Instances: 0 Total Size: | 0 K Bytes | Class: 211201 Instances: 0 Total Size: | 0 K Bytes | Class: 211457 Instances: 0 Total Size: | 0 K Bytes | Class: 211713 Instances: 0 Total Size: | 0 K Bytes | Class: 211969 Instances: 0 Total Size: | 0 K Bytes | Class: 212225 Instances: 0 Total Size: | 0 K Bytes | Class: 212481 Instances: 0 Total Size: | 0 K Bytes | Class: 212737 Instances: 39 Total Size: | 490 K Bytes | Class: 212993 Instances: 0 Total Size: | 0 K Bytes | Class: 213249 Instances: 0 Total Size: | 0 K Bytes | Class: 213505 Instances: 0 Total Size: | 0 K Bytes | Class: 213761 Instances: 0 Total Size: | 0 K Bytes | | | ----- Instances of visible classes ----------------- | Number of objects : 28875861 | Total Size : 1948595 K Bytes | size of Object Headers : 676777 K Bytes | size of Object Values : 1258718 K Bytes | size of Object Tags : 0 K Bytes | average of Object Value: 44.6 Bytes | | |
In reply to this post by Dale Henrichs
Hi Dale, Otto, Ralph,
Thanks a lot for all the suggestions and feedback. I really appreciate it. In general, I find the repository growth OK as long as it would recover overnight when the repository is quiet and only the maintenance and reclaim gems are actively doing work. It *seems* it requires me to do a backup/restore every 2 weeks to get me back at the small size. I especially noticed how an MFC takes considerably longer when the repository is larger, which puts more stress on the system, which I want to avoid. In the meantime, I got my repository used space back to +-700Mb. Although that's still quite large in my eyes, it's possible. The large strings in the object audit were http response strings from sessions lingering in the object log, indeed. However, there were only 18 seaside sessions still in the objectlog. I am a bit surprised that that accounts for 1.8Gb (which is the size I reclaimed after clearing them) since I did clear out the transcript elements from the log. I actually only keep continuations on the object log that I need to investigate further, all the other items are cleared out regularly. However, it might be that the associated seaside sessions are quite long running sessions with a lot of callbacks and continuations associated to them. I will try to investigate that a bit more. Some more below... > James Foster has created a ScanBackup tool[2] that analyzes a backup and reports back the contents of the backup ... but this guy measures only live objects. To get an idea what might be considered garbage, you could make a backup right before you hourly MFC run and then again right afterward and then analyze the backup files .... you could also do a restore of the before and after backups to compare your extent sizes … I have tried running this but it did not work. There is a method not implemented error when I run: ScanBackup64 scanBackupAtServerPath: aPathString -> #determineFileTypeAndVersion is not implemented :-( > Ralph also gives good advice ... you can use the statmonitor to see if you have spikes in your commit record backlog (the stone stat CommitRecordCount?)… I made a statmonitor run of 24 hours a little more than a month ago. It gives the regular output that is still valid today. I do see some spikes in the CR backlog but are they relevant? They spike to 800 maximally. I cannot remember if I was logged into gemtools at those moments, but it's possible. When I was logged into gemtools for a long time, I noticed the CR backlog growing larger and larger, which is not what I am seeing here. If it can give some valuable information, I put the statmonitor file here: files.me.com/johanbrichau/r38mml Johan |
On Aug 11, 2011, at 3:12 PM, Johan Brichau wrote: >> James Foster has created a ScanBackup tool[2] that analyzes a backup and reports back the contents of the backup ... but this guy measures only live objects. To get an idea what might be considered garbage, you could make a backup right before you hourly MFC run and then again right afterward and then analyze the backup files .... you could also do a restore of the before and after backups to compare your extent sizes … > > I have tried running this but it did not work. There is a method not implemented error when I run: > ScanBackup64 scanBackupAtServerPath: aPathString > -> #determineFileTypeAndVersion is not implemented :-( Johan, You are right, later versions of ScanBackup are broken. I was working on reading transaction logs and saved my work without testing it on earlier functionality. If you switch back to version 8 it should work with a 2.4.x backup. James |
Hi James,
> You are right, later versions of ScanBackup are broken. I was working on reading transaction logs and saved my work without testing it on earlier functionality. If you switch back to version 8 it should work with a 2.4.x backup. Aha! Thanks for that information. It works like a charm now. Johan |
Free forum by Nabble | Edit this page |