Re: +RTS -S heap reporting oddity

2012-08-20 Thread Simon Marlow

On 17/08/2012 17:08, Wolfram Kahl wrote:

During one of my long Agda runs (with GHC-7.4.2), I observed the following
output, with run-time options

+RTS -S -H11G -M11G -K256M

:

7694558208  30623864 3833166176  0.11  0.11  234.75  234.7900  (Gen:  0)
7678904688  29295168 3847737784  0.11  0.11  242.04  242.0900  (Gen:  0)
7662481840  29195736 3861451856  0.11  0.11  249.31  249.3500  (Gen:  0)
7647989280  26482704 3872463688  0.12  0.12  256.64  256.6800  (Gen:  0)
4609865360  25764016 3886000448  0.09  0.09  261.04  261.0900  (Gen:  0)
4581294920  19435032 3891512272  0.07  0.07  265.37  265.4200  (Gen:  0)
4568757088  21095864 3902286000  0.08  0.08  269.70  269.7400  (Gen:  0)
4546421608  21618856 3913923976  0.09  0.09  274.04  274.0900  (Gen:  0)
452151 2894668056 3484748224  7.63  7.63  285.94  285.9800  (Gen:  
1)
8085358392  23776128 3499185336  0.11  0.11  293.49  293.5300  (Gen:  0)
8064630856  32055112 3515876576  0.13  0.13  300.91  300.9500  (Gen:  0)
8040500112  31477608 3528105088  0.12  0.12  308.37  308.4100  (Gen:  0)
8031456296  29641328 3540632456  0.11  0.11  315.83  315.8700  (Gen:  0)
8018447264  30187208 3554339600  0.12  0.12  323.26  323.3100  (Gen:  0)

To my untrained eye, this seems to be saying the following:
In the first 4 lines, the heap runs (almost) full before (minor) collections.
In lines 5 to 9 it apparently leaves 3G empty before collection,
but ``those 3G'' then appear on line 9 in the ``amount of data copied during 
(major) collection''
column, and after that it runs up to fill all 11G again before the next few 
minor collections.

What is really going on here?
(Previously I had never seen such big numbers in the second column on major 
collections.)


It looks like on line 5, the GC thought it was going to do a major 
collection the next time, so it left 3G free to copy the contents of the 
old generation.  But then it didn't do a major GC until line 9.  I've 
just checked the code, and I think this might be due to a slight 
inaccuracy in the way that we estimate whether the next GC will be a 
major one, and at these huge sizes the discrepancy becomes significant. 
 Thanks for pointing it out, I'll fix it to use the same calculation in 
both places.


Cheers,
Simon





Wolfram


P.S.: Same effect again, but more dramatic, later during the same Agda run:

448829488   4864536 5710435424  0.02  0.02 1422.80 1422.9000  (Gen:  0)
445544064   3251712 5710248752  0.01  0.01 1423.23 1423.3200  (Gen:  0)
450236784   4148864 5712696848  0.02  0.02 1423.68 1423.7700  (Gen:  0)
445240152   3828120 5713606328  0.02  0.02 1424.10 1424.1900  (Gen:  0)
443285616   5906448 5717731864  0.02  0.02 1424.52 1424.6100  (Gen:  0)
430698248 4773500032 5363214440  9.30  9.30 1434.21 1434.3000  (Gen:  1)
6148455592  13490304 5374609848  0.07  0.07 1439.83 1439.9200  (Gen:  0)
6185350848  27419744 5389326896  0.11  0.11 1445.50 1445.5900  (Gen:  0)
6168805736  23069072 5398725784  0.11  0.11 1451.22 1451.3200  (Gen:  0)
6157744328  23451872 5408370152  0.09  0.09 1456.93 1457.0300  (Gen:  0)
6151715272  25739584 5421044592  0.11  0.11 1462.62 1462.7200  (Gen:  0)
6132589488  24541688 5428809632  0.10  0.10 1468.26 1468.3700  (Gen:  0)

___
Glasgow-haskell-users mailing list
Glasgow-haskell-users@haskell.org
http://www.haskell.org/mailman/listinfo/glasgow-haskell-users




___
Glasgow-haskell-users mailing list
Glasgow-haskell-users@haskell.org
http://www.haskell.org/mailman/listinfo/glasgow-haskell-users


+RTS -S heap reporting oddity

2012-08-17 Thread Wolfram Kahl
During one of my long Agda runs (with GHC-7.4.2), I observed the following
output, with run-time options

   +RTS -S -H11G -M11G -K256M

:

7694558208  30623864 3833166176  0.11  0.11  234.75  234.7900  (Gen:  0)
7678904688  29295168 3847737784  0.11  0.11  242.04  242.0900  (Gen:  0)
7662481840  29195736 3861451856  0.11  0.11  249.31  249.3500  (Gen:  0)
7647989280  26482704 3872463688  0.12  0.12  256.64  256.6800  (Gen:  0)
4609865360  25764016 3886000448  0.09  0.09  261.04  261.0900  (Gen:  0)
4581294920  19435032 3891512272  0.07  0.07  265.37  265.4200  (Gen:  0)
4568757088  21095864 3902286000  0.08  0.08  269.70  269.7400  (Gen:  0)
4546421608  21618856 3913923976  0.09  0.09  274.04  274.0900  (Gen:  0)
452151 2894668056 3484748224  7.63  7.63  285.94  285.9800  (Gen:  
1)
8085358392  23776128 3499185336  0.11  0.11  293.49  293.5300  (Gen:  0)
8064630856  32055112 3515876576  0.13  0.13  300.91  300.9500  (Gen:  0)
8040500112  31477608 3528105088  0.12  0.12  308.37  308.4100  (Gen:  0)
8031456296  29641328 3540632456  0.11  0.11  315.83  315.8700  (Gen:  0)
8018447264  30187208 3554339600  0.12  0.12  323.26  323.3100  (Gen:  0)

To my untrained eye, this seems to be saying the following:
In the first 4 lines, the heap runs (almost) full before (minor) collections.
In lines 5 to 9 it apparently leaves 3G empty before collection,
but ``those 3G'' then appear on line 9 in the ``amount of data copied during 
(major) collection''
column, and after that it runs up to fill all 11G again before the next few 
minor collections.

What is really going on here?
(Previously I had never seen such big numbers in the second column on major 
collections.)


Wolfram


P.S.: Same effect again, but more dramatic, later during the same Agda run:

448829488   4864536 5710435424  0.02  0.02 1422.80 1422.9000  (Gen:  0)
445544064   3251712 5710248752  0.01  0.01 1423.23 1423.3200  (Gen:  0)
450236784   4148864 5712696848  0.02  0.02 1423.68 1423.7700  (Gen:  0)
445240152   3828120 5713606328  0.02  0.02 1424.10 1424.1900  (Gen:  0)
443285616   5906448 5717731864  0.02  0.02 1424.52 1424.6100  (Gen:  0)
430698248 4773500032 5363214440  9.30  9.30 1434.21 1434.3000  (Gen:  1)
6148455592  13490304 5374609848  0.07  0.07 1439.83 1439.9200  (Gen:  0)
6185350848  27419744 5389326896  0.11  0.11 1445.50 1445.5900  (Gen:  0)
6168805736  23069072 5398725784  0.11  0.11 1451.22 1451.3200  (Gen:  0)
6157744328  23451872 5408370152  0.09  0.09 1456.93 1457.0300  (Gen:  0)
6151715272  25739584 5421044592  0.11  0.11 1462.62 1462.7200  (Gen:  0)
6132589488  24541688 5428809632  0.10  0.10 1468.26 1468.3700  (Gen:  0)

___
Glasgow-haskell-users mailing list
Glasgow-haskell-users@haskell.org
http://www.haskell.org/mailman/listinfo/glasgow-haskell-users