extent0.dbf grows

Ciao,

i have a deployment system based on GemStone version '3.1.0.6'

Now i use Gemtools and todeClient to do some works on the repository:  update code,  save repository .....

When i login with the tools  i note the repository grows significantly,  and also, the relative  full backups grows significantly.

To reset the system i need to clear the Object Log with the relative clear command  ( ol clear in tode ) 

After 1 hour ,  because i have active the #WAGemStoneMaintenanceTask 

A) the system recovers the free space

B) the relative full backups become small

But now i have an extent0.dbf   of   5 991 563 264   with a freeSpace of 5 267 701 760.

It is not a very good situation.

Questions:

1) what should I do with the tools to not increase the size of the relative extent ?

I need to operate with the tools  when the seasideGems30 are down ?

2) to resize the extent i need to do a full backup and restoring into a virgin extent?

3) there is possibility of directly reducing the extent file ?

Thanks for any considerations,

Dario

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

On 07/31/2015 08:58 AM, Trussardi Dario Romano via Glass wrote:

James,

On Jul 31, 2015, at 3:37 AM, Trussardi Dario Romano via Glass <[hidden email]> wrote:

Ciao,

i have a deployment system based on GemStone version '3.1.0.6'

Now i use Gemtools and todeClient to do some works on the repository:  update code,  save repository .....

When i login with the tools  i note the repository grows significantly,  and also, the relative  full backups grows significantly.

To reset the system i need to clear the Object Log with the relative clear command  ( ol clear in tode ) 

Do you think that the Object Log grows significantly during your time logged in with the tools? What is its size at the beginning and end of your session?

I don't have real data about the extent0.dbf change size from beginning and end of a gemtools session.

But the full backup size  before Object Log  clear is :  4 258 529280

after Object Log clear is: 1 376 124 928

The SystemRepository freeSpace size before Object Log clear is :  1 092 419 584

after Object Log clear ( and one hour  of system background works )  is:  5 267 701 760

Okay as James has mentioned, it definitely looks like the Object Log is the source of the "excess data" ... it would be interesting to understand what is in the object log ... My guess would be that you are having recurring errors and the continuations created to record those errors can easily cause a bunch of data to be stored in your extent ... if the errors are providing useful data, than this can be viewed as a "cost of doing business" and you will just need to have a regularly scheduled task for clearing the object log ... you could arrange to regularly clear continuation entries from the object log that are more than a day or week or ? old then at least you would expect to reach a steady state for extent size ... then you would only need to consider shrinking the size of the extent when you had an anomaly where a series of unexpected errors cropped up ....

As Mariano and James point out, there are other possible sources of extent growth that are related to a commit record backlog because you have a GemTools/tODE/topaz session open (and idle) on a production system that is "busy committing" ... commit record backlog data is transient data that is stored in the extent and will cause the extent to grow, but once the session or sessions causing the commit record backlog log out commit or abort, the transient data is no longer needed by the system and will "magically turn into free space" at checkpoint boundaries ....

The key point here is that object log data is persistent "user data" and will not turn into free space until 1) you break the link to the persistent root (object log clear) and 2) you run an MFC. Commit record backlog data "system data" and will turn into free space as soon as the sessions abort/commit/logout and a checkpoint is hit, i.e., no MFC is needed ... The default checkpoint interval is 5 minutes I think ...

Here is my script...

cleanupObjectLog

  | log date1 date2 sortedCopy count |

  log := ObjectLogEntry objectLog.

“keep only one per day of various maintenance tasks (useful to go back years on size!)"

  #('MTCE: Repository Size' 'MTCE: MFC' 'MTCE: expired sessions') do: [:eachLabel | 

  log copy do: [:each | 

  each label = eachLabel ifTrue: [

  each stamp date = date1 ifTrue: [

  log remove: each.

  ] ifFalse: [

  date1 := each stamp date.

  ].

  ].

  ].

  ].

“Keep only one per week of anything more than a month old"

  date1 := Date today subtractDays: 30.

  log copy do: [:each | 

  (each stamp date < date1 and: [each stamp date day \\ 7 ~= 0]) ifTrue: [

  log remove: each.

  ].

  ].

“keep only last three days of session expiration"

  date1 := Date today subtractDays: 3.

  log copy do: [:each | 

  (each stamp date < date1 and: [each label = 'MTCE: expired sessions']) ifTrue: [

  log remove: each.

  ].

  ].

“keep only five per day of lock failures"

date1 := nil.

log copy do: [:each | 

each stamp date = date1 ifTrue: [

each label = 'Lock not acquired - retrying' ifTrue: [

count < 5 ifTrue: [

count := count + 1.

] ifFalse: [

log remove: each.

].

].

] ifFalse: [

date1 := each stamp date.

count := 0.

].

].

“beyond ten days keep only twenty errors per day"

date1 := nil.

  date2 := Date today subtractDays: 10.

log copy do: [:each | 

each stamp date = date1 ifTrue: [

each priority == 2 ifTrue: [

count < 20 ifTrue: [

count := count + 1.

] ifFalse: [

date1 < date2 ifTrue: [

log remove: each.

].

].

].

] ifFalse: [

date1 := each stamp date.

count := 0.

].

].

  sortedCopy := log asSortedCollection: [:a :b | 

  a priority > b priority or: [

  a priority = b priority and: [a stamp < b stamp].

  ].

  ].

  log 

  size: 0;

  addAll: sortedCopy asOrderedCollection;

yourself.

%

On Aug 5, 2015, at 2:33 PM, Mariano Martinez Peck via Glass <[hidden email]> wrote:

On Wed, Aug 5, 2015 at 5:41 PM, Dale Henrichs via Glass <[hidden email]> wrote:

On 07/31/2015 08:58 AM, Trussardi Dario Romano via Glass wrote:

James,

On Jul 31, 2015, at 3:37 AM, Trussardi Dario Romano via Glass <[hidden email]> wrote:

Ciao,

i have a deployment system based on GemStone version '3.1.0.6'

Now i use Gemtools and todeClient to do some works on the repository:  update code,  save repository .....

When i login with the tools  i note the repository grows significantly,  and also, the relative  full backups grows significantly.

To reset the system i need to clear the Object Log with the relative clear command  ( ol clear in tode ) 

Do you think that the Object Log grows significantly during your time logged in with the tools? What is its size at the beginning and end of your session?

I don't have real data about the extent0.dbf change size from beginning and end of a gemtools session.

But the full backup size  before Object Log  clear is :  4 258 529280

after Object Log clear is: 1 376 124 928

The SystemRepository freeSpace size before Object Log clear is :  1 092 419 584

after Object Log clear ( and one hour  of system background works )  is:  5 267 701 760

Okay as James has mentioned, it definitely looks like the Object Log is the source of the "excess data" ... it would be interesting to understand what is in the object log ... My guess would be that you are having recurring errors and the continuations created to record those errors can easily cause a bunch of data to be stored in your extent ... if the errors are providing useful data, than this can be viewed as a "cost of doing business" and you will just need to have a regularly scheduled task for clearing the object log ... you could arrange to regularly clear continuation entries from the object log that are more than a day or week or ? old then at least you would expect to reach a steady state for extent size ... then you would only need to consider shrinking the size of the extent when you had an anomaly where a series of unexpected errors cropped up ....

I do exactly that as part of my daily cleaning:

cleanObjectLogEntriesDaysAgo: aNumberOfDays

| log |

log := self objectLogEntries: true.

(log select: [:ea | (Date today - ea stamp asDate) asDays >= aNumberOfDays ]) do: [:ea | log remove: ea ifAbsent: []].

System commitTransaction.

objectLogEntries: shouldLock

shouldLock 

ifTrue: [

System writeLock: ObjectLogEntry objectQueue

ifDenied: [ 

Transcript show: 'ObjectLogEntry objectQueue lock denied'.

^ nil

]

ifChanged: [ 

System addToCommitOrAbortReleaseLocksSet: ObjectLogEntry objectQueue.

Transcript show: 'ObjectLogEntry objectQueue lock dirty'.

^ nil

].

System addToCommitOrAbortReleaseLocksSet: ObjectLogEntry objectQueue].

^ObjectLogEntry objectLog

Maybe we could add this directly to class side of ObjectLogEntry so that others can benefit from it?

 

 

As Mariano and James point out, there are other possible sources of extent growth that are related to a commit record backlog because you have a GemTools/tODE/topaz session open (and idle) on a production system that is "busy committing" ... commit record backlog data is transient data that is stored in the extent and will cause the extent to grow, but once the session or sessions causing the commit record backlog log out commit or abort, the transient data is no longer needed by the system and will "magically turn into free space" at checkpoint boundaries ....

The key point here is that object log data is persistent "user data" and will not turn into free space until 1) you break the link to the persistent root (object log clear) and 2) you run an MFC. Commit record backlog data "system data" and will turn into free space as soon as the sessions abort/commit/logout and a checkpoint is hit, i.e., no MFC is needed ... The default checkpoint interval is 5 minutes I think ...

Dale, it is not clear to me what the checkpoint interval is. I understood it was at abort/commit/logout..so how is this internal related? Is there a way I can check the stone configuration parameter of this (the 5 minutes)?

So for the "system data" to turn into free space, the other gems need to abort/commit/logout AND only after 5 minutes that turning into free space will happen?   I ask because I am scheduling some batch jobs running at night, and as soon as they all finish, I run GC...and sometimes it seems I do not really GC what I should have...

Thanks!

--

Mariano
http://marianopeck.wordpress.com

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

“Keep only one per week of anything more than a month old"

  date1 := Date today subtractDays: 30.

  log copy do: [:each | 

  (each stamp date < date1 and: [each stamp date day \\ 7 ~= 0]) ifTrue: [

  log remove: each.

  ].

  ].

This is the part I understand the less. Why would make sense to keep one random entry once per week of things older than a month? 
I mean...a random entry will probably tell me anything. In which case do you think this could be useful?

The comment should say “Keep only one DAY per week of anything more than month old”.

This is an attempt to balance keeping everything and keeping nothing (and I don’t claim to have the perfect balance!). Beyond 30 days, for things like MFC reports, four per month seems quite adequate to give an idea of the trend. For things like errors, if you haven’t looked at it in 30 days then some pruning seems appropriate. I figured that picking one random day per week gives an idea if an error is common or rare. 

  sortedCopy := log asSortedCollection: [:a :b | 

  a priority > b priority or: [

  a priority = b priority and: [a stamp < b stamp].

  ].

  ].

  log 

  size: 0;

  addAll: sortedCopy asOrderedCollection;

yourself.

A couple of questions:

1) Don't you need to get the lock (as I did in my script) before trying to write the object log?

Good catch. In the few applications where I’ve used this script the users are active during the day and the maintenance (including this script) run during the night. Thus, I haven’t had a locking problem (that I know of!). But, yes, I should follow your example of getting the lock.

2) I also have some Transcript show (priority 7), some inspect/explore (priority 8) and some trace:  (priority 6).  I guess I should add a similar part for this...not sure how many days though… 

I think that the above will trim your other things to one day per week. From there you could reduce the count as I’ve done with errors.

Thanks in advance,

I appreciate Dale’s suggestion of combining the best of the scripts and adding it to the framework.

James

 

%

On Aug 5, 2015, at 2:33 PM, Mariano Martinez Peck via Glass <[hidden email]> wrote:

On Wed, Aug 5, 2015 at 5:41 PM, Dale Henrichs via Glass <[hidden email]> wrote:

On 07/31/2015 08:58 AM, Trussardi Dario Romano via Glass wrote:

James,

On Jul 31, 2015, at 3:37 AM, Trussardi Dario Romano via Glass <[hidden email]> wrote:

Ciao,

i have a deployment system based on GemStone version '3.1.0.6'

Now i use Gemtools and todeClient to do some works on the repository:  update code,  save repository .....

When i login with the tools  i note the repository grows significantly,  and also, the relative  full backups grows significantly.

To reset the system i need to clear the Object Log with the relative clear command  ( ol clear in tode ) 

Do you think that the Object Log grows significantly during your time logged in with the tools? What is its size at the beginning and end of your session?

I don't have real data about the extent0.dbf change size from beginning and end of a gemtools session.

But the full backup size  before Object Log  clear is :  4 258 529280

after Object Log clear is: 1 376 124 928

The SystemRepository freeSpace size before Object Log clear is :  1 092 419 584

after Object Log clear ( and one hour  of system background works )  is:  5 267 701 760

Okay as James has mentioned, it definitely looks like the Object Log is the source of the "excess data" ... it would be interesting to understand what is in the object log ... My guess would be that you are having recurring errors and the continuations created to record those errors can easily cause a bunch of data to be stored in your extent ... if the errors are providing useful data, than this can be viewed as a "cost of doing business" and you will just need to have a regularly scheduled task for clearing the object log ... you could arrange to regularly clear continuation entries from the object log that are more than a day or week or ? old then at least you would expect to reach a steady state for extent size ... then you would only need to consider shrinking the size of the extent when you had an anomaly where a series of unexpected errors cropped up ....

I do exactly that as part of my daily cleaning:

cleanObjectLogEntriesDaysAgo: aNumberOfDays

| log |

log := self objectLogEntries: true.

(log select: [:ea | (Date today - ea stamp asDate) asDays >= aNumberOfDays ]) do: [:ea | log remove: ea ifAbsent: []].

System commitTransaction.

objectLogEntries: shouldLock

shouldLock 

ifTrue: [

System writeLock: ObjectLogEntry objectQueue

ifDenied: [ 

Transcript show: 'ObjectLogEntry objectQueue lock denied'.

^ nil

]

ifChanged: [ 

System addToCommitOrAbortReleaseLocksSet: ObjectLogEntry objectQueue.

Transcript show: 'ObjectLogEntry objectQueue lock dirty'.

^ nil

].

System addToCommitOrAbortReleaseLocksSet: ObjectLogEntry objectQueue].

^ObjectLogEntry objectLog

Maybe we could add this directly to class side of ObjectLogEntry so that others can benefit from it?

 

 

As Mariano and James point out, there are other possible sources of extent growth that are related to a commit record backlog because you have a GemTools/tODE/topaz session open (and idle) on a production system that is "busy committing" ... commit record backlog data is transient data that is stored in the extent and will cause the extent to grow, but once the session or sessions causing the commit record backlog log out commit or abort, the transient data is no longer needed by the system and will "magically turn into free space" at checkpoint boundaries ....

The key point here is that object log data is persistent "user data" and will not turn into free space until 1) you break the link to the persistent root (object log clear) and 2) you run an MFC. Commit record backlog data "system data" and will turn into free space as soon as the sessions abort/commit/logout and a checkpoint is hit, i.e., no MFC is needed ... The default checkpoint interval is 5 minutes I think ...

Dale, it is not clear to me what the checkpoint interval is. I understood it was at abort/commit/logout..so how is this internal related? Is there a way I can check the stone configuration parameter of this (the 5 minutes)?

So for the "system data" to turn into free space, the other gems need to abort/commit/logout AND only after 5 minutes that turning into free space will happen?   I ask because I am scheduling some batch jobs running at night, and as soon as they all finish, I run GC...and sometimes it seems I do not really GC what I should have...

Thanks!

--

Mariano
http://marianopeck.wordpress.com

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

--

Mariano
http://marianopeck.wordpress.com

On 08/05/2015 02:33 PM, Mariano Martinez Peck wrote:

Dale, it is not clear to me what the checkpoint interval is. I understood it was at abort/commit/logout..so how is this internal related? Is there a way I can check the stone configuration parameter of this (the 5 minutes)?

A checkpoint is a gemstone system operation where all data pages in the SPC that were written before a given commit are flushed to disk. After a checkpoint, gemstone guarantees that all data for a particular commit has been written to the extents ... Until a commit is checkpointed, the systems relies on the records in the tranlog for recovery ... the checkpoint is not necessarily the primary point at which pages are freed up in an extent but it does represent a book keeping boundary that triggers other processing that does lead to freeing up extent pages ....

When you recover from a crash, the system looks at the commit that was last checkpointed and then scans the tranlogs looking for that commit and then reads the tranlogs from that point forwards to complete recovery ....

STN_CHECKPOINT_INTERVAL in the system.conf file is used to customize the checkpoint interval ... Given the above the checkpoint interval controls how much data would have to be recovered from tranlogs in the event of a system crash ... with the default checkpoint interval of 5 minutes, that means that 5 minutes worth of tranlog data will have to be recovered on the other end of the spectrum, with a checkpoint interval of 5 minutes, that means that every 5 minutes the SPC will be scanned for pages that have not been written to disk ... tuning the checkpoint interval involves finding a balance between scan cpu consumption, disk i/o, and recovery time, SPC size and commit rates.

If the checkpoint interval is too short you may consume a lot of cpu time doing checkpoints without actually writing any dirty pages. If the checkpoint interval is too long, it may take a long time to replay tranlogs during crash recovery ... There's a third inflection point where the checkpoint interval is shorter than the time it takes to write all the dirty pages accumulated and you end up in perpetual checkpoint mode - in this case you just have to live with the exposure to longer recovery times (or take steps to improve disk i/o or ....)

At the end of the day, tuning the checkpoint interval only comes into play at higher commit rates ...

So for the "system data" to turn into free space, the other gems need to abort/commit/logout AND only after 5 minutes that turning into free space will happen?   I ask because I am scheduling some batch jobs running at night, and as soon as they all finish, I run GC...and sometimes it seems I do not really GC what I should have...

The actual process for freeing up a page is a pretty complicated process. Dirty pages cannot be reclaimed, so I mentioned the checkpoint interval in relation to free pages because the checkpoint kicks off processing (in a manner of speaking) that leads to the possible creation of free pages ... different types of data are stoned on pages and the rules for reclaiming a page depends upon what type of data is on the page ...

Data pages cannot be reclaimed until there are no active views that could possible reference an object on that page (the object table maps oops to pages) so a single live object on a page can keep an entire data page from being reclaimed ... So in your case when you run the gc, you are not guaranteed that all of the pages housing the objects will be reclaimed. In the worse case, each dead object may be on a separate  page and you end up with no additional free pages ... the reclaim gems do look around for "scavengable pages" and will do a certain amount of automatic data consolidation and you can get information about "data fragmentation" by using Repository>>pagesWithPercentFree: or Repository>>fastPagesWithPercentFree:, but as I think I've mentioned before the system is very dynamic and over time a system that is running at constant rates will achieve an equilibrium in terms of free pages but the actual number of free pages will fluctuate within a  range that is dictated by quite a few different factors.

It's good to keep an eye on things to recognize when unreasonable growth is occurring, but I don't think that it is reasonable to expect that the system always stay within some strict size limits ...

Of course the challenge is to differentiate between unreasonable growth and growth due to real data accumulation, so it's worth diving deep on these different subjects so that you can learn about the normal rhythms of your own system ...

Dale