Subject: bug#25386: This can be closed

From: Linas Vepstas <[email-masked]>
Date: Wed, 11 Jan 2017 00:14:14 -0600

This can be closed as 'fixed'; I tested on today's git

guile (GNU Guile) 2.1.5.19-7e9395

and the worst of it seems to be over.  mem usage growth on the
original test case:

(heap-size . 7921664) (gc-times . 40)
(heap-size . 14344192) (gc-times . 953)
(heap-size . 14344192) (gc-times . 5219)  ; after 4 minutes CPU
(heap-size . 26419200) (gc-times . 64975) ; after 77 minutes CPU
(heap-size . 26419200) (gc-times . 133346) ; after 154 mins CPU
(heap-size . 26419200) (gc-times . 170083) ; after 192 mins CPU
(heap-size . 26419200) (gc-times . 249102) ; after 283 mins cpu
(heap-size . 26419200) (gc-times . 420031) ; after 468 min cpu
(heap-size . 26419200) (gc-times . 557039) ; after 804 mins CPU

i.e. 26MBytes - larger than it needs to be, but acceptable.

The last entry was, in full,
((gc-time-taken . 355210357) (heap-size . 26419200) (heap-free-size .
20336640) (heap-total-allocated . 2522568563312)
(heap-allocated-since-gc . 57648) (protected-objects . 0) (gc-times .
557619))

i.e. of the 26MB, only 6MB is in use, the rest is free.  The 6MB is
close to what it starts with.  2522 GB were chewed through in the
process, so this is OK, I guess.

A variant test case, create 510 threads before calling join:  (change
10 to 510 in above test)

(heap-size . 10604544) (gc-times . 32)
(heap-size . 19505152) (gc-times . 484)
(heap-size . 35926016) (gc-times . 1761)
(heap-size . 48238592) (gc-times . 4217)  ; after 8 minutes cpu time
(heap-size . 48238592) (gc-times . 47902) ; after 76 mins CPU
(heap-size . 48238592) (gc-times . 73063) ; after 114 mins CPU
(heap-size . 65540096) (gc-times . 128094) ; after 209 mins cpu
(heap-size . 65540096) (gc-times . 248321) ; after 399 mins
(heap-size . 65540096) (gc-times . 344197) ; after 546 min

i.e. 65MBytes .. acceptable, I guess.

The last one was:
((gc-time-taken . 218714374) (heap-size . 65540096) (heap-free-size .
54419456) (heap-total-allocated . 2057186203744)
(heap-allocated-since-gc . 4553872) (protected-objects . 0) (gc-times
. 344799))

so of the 65MB, only 11MB is in-use.

My production server is doing this:

(heap-size . 652918784) (gc-times . 233) ; about 8 mins CPU
(heap-size . 737722368) (gc-times . 339) ; 12 mins CPU
(heap-size . 1332973568) (gc-times . 1797) ; 120 mins CPU
(heap-size . 1441443840) (gc-times . 2221) ; 151 min CPU
(heap-size . 1521213440) (gc-times . 2441) ; 168 min cpu
(heap-size . 1595101184) (gc-times . 3061) ; 218 min cpu
(heap-size . 1726119936) (gc-times . 3292) ; 237 min
(heap-size . 1960865792) (gc-times . 6698) ; 510 minn
(heap-size . 1960865792) (gc-times . 10383) ; 805 min
(heap-size . 2931556352) (gc-times . 14211) ; 1199 min

about 3GB --

Last one is, in  full:
(gc-stats)
((gc-time-taken . 19818394581722) (heap-size . 2931556352)
(heap-free-size . 1767579648) (heap-total-allocated . 731393991040)
(heap-allocated-since-gc . 4063680) (protected-objects . 318)
(gc-times . 14211))

so of the 3GB, 1.8GB is free, and 1.2GB in use which is surprisingly
high for my app, but I can live with that.

Thanks!

--linas