Garbage collection problem??

tcarmeli has asked for the wisdom of the Perl Monks concerning the following question:

Replies are listed 'Best First'.
Re: Garbage collection problem?? by chromatic (Archbishop) on Dec 26, 2006 at 17:43 UTC
Every time I ran it on my machine, the second time through was faster. That's what I expected; Perl had to do less work allocating memory for the lexical variables thanks to the same optimization that makes `my $lexical if 0;` so dangerous.	[reply] [d/l]
Re^2: Garbage collection problem?? by sgt (Deacon) on Dec 27, 2006 at 18:37 UTC
Hi Chromatic. If I understand you correctly, you are saying that an optimization like `my $i if 0` occurs in this code. I suppose you mean that some construct will infer a runtime penalty (as opposed to compile-time penalty). Just a bit puzzled, would you care to explain a bit more? Personally I don't like `my $i if 0;` (I would even call it "dangerous" in the sense of not {truly} maintainable) as I prefer the idiom of true shared variables `{ my $shared; sub f1 { ... # use $shared } sub f2 {...} }` In any case I fail to see some optimization kicking in on cygwin. How much faster is the second run on your system? aren't my-allocations very fast with respect to a foreach loop anyway? again seems that all "my slots" will be reserved at compile-time, no? The only thing I see is that could be flagged as non-pbp is the construct `my $region; for $region {...}` that can be transformed into `for my ...` for recent enough perl (I wonder what is the best way to handle all versions of perl though...). cheers --stephan	[reply] [d/l] [select]
Re^3: Garbage collection problem?? by chromatic (Archbishop) on Dec 27, 2006 at 19:36 UTC
I actually meant that Perl won't free all of the memory used by lexicals when it leaves the scope because of an optimization. The idea is that the next time control enters the scope, the memory requirements will be similar. Avoiding `malloc()` calls can improve performance.	[reply] [d/l]
Re^4: Garbage collection problem?? by sgt (Deacon) on Dec 27, 2006 at 22:50 UTC
Re: Garbage collection problem?? by wjw (Priest) on Dec 27, 2006 at 03:16 UTC
Was curious about this. So ran it as follows... winxp 2002 Svc Pack 2 on Toshiba Satellite 1.8Ghz/504MB Ram ActiveState Perl 5.8.8 Section A took 0.7340 CPU seconds Section B took 2.5000 CPU seconds section A took 0.7500 CPU seconds Section B took 16.4530 CPU seconds Section A took 0.7660 CPU seconds Section B took 2.6400 CPU seconds Section A took 0.7650 CPU seconds Section B took 15.3440 CPU seconds Section A took 0.7340 CPU seconds Section B took 2.5630 CPU seconds Section A took 0.7340 CPU seconds Section B took 16.2030 CPU seconds Section A took 0.7340 CPU seconds Section B took 2.5630 CPU seconds Section A took 0.7340 CPU seconds Section B took 16.2030 CPU seconds #################################################### On Suse 10.1 Same Toshiba as mentioned above Perl 5.8.8 Section A took 1.1700 CPU seconds Section B took 2.3800 CPU seconds Section A took 0.9700 CPU seconds Section B took 2.3700 CPU seconds Section A took 1.2800 CPU seconds Section B took 2.4200 CPU seconds Section A took 1.0300 CPU seconds Section B took 2.4100 CPU seconds Section A took 1.2600 CPU seconds Section B took 2.4400 CPU seconds Section A took 0.9800 CPU seconds Section B took 2.4500 CPU seconds Section A took 1.2200 CPU seconds Section B took 2.4300 CPU seconds Section A took 1.0100 CPU seconds Section B took 2.4500 CPU seconds Leaves me to wonder: Is this the OS? The way perl is compiled for the OS? Both OS's use ~ the same amount of memory (90Meg) during the run based on TaskManager readings on XP and top readings on linux, each set to .5 second update. The B second run on XP is about 6.6 times slower than on linux. The A first run is about 1.6 times faster on XP than on linux. This is very rough data, but interesting none-the-less. ...the majority is always wrong, and always the last to know about it...	[reply]
Re: Garbage collection problem?? by BrowserUk (Patriarch) on Dec 26, 2006 at 22:15 UTC
Can't say why (yet), but I can confirm your findings on 5.8.6 under XP. c:\test>junk6 Section A took 1.0150 CPU seconds Section B took 3.3750 CPU seconds Section A took 1.0150 CPU seconds Section B took 5.1410 CPU seconds c:\test>junk6 Section A took 1.0310 CPU seconds Section B took 3.4540 CPU seconds Section A took 1.0000 CPU seconds Section B took 5.0780 CPU seconds :\test>junk6 Section A took 1.0470 CPU seconds Section B took 3.5470 CPU seconds Section A took 0.9690 CPU seconds Section B took 4.8910 CPU seconds c:\test>junk6 Section A took 1.0310 CPU seconds Section B took 3.4690 CPU seconds Section A took 1.0160 CPU seconds Section B took 5.1560 CPU seconds [download] Examine what is said, not who speaks -- Silence betokens consent -- Love the truth but pardon error. "Science is about questioning the status quo. Questioning authority". In the absence of evidence, opinion is indistinguishable from prejudice. "Too many [] have been sedated by an oppressive environment of political correctness and risk aversion."	[reply] [d/l]
Re^2: Garbage collection problem?? by abachus (Monk) on Dec 27, 2006 at 18:00 UTC
On a 360MHz/1024MB ultrasparc running homegrown linux with Perl 5.8.0 : Section A took 10.5400 CPU seconds Section B took 22.2800 CPU seconds Section A took 12.8400 CPU seconds Section B took 22.3900 CPU seconds ciao.	[reply]
Re: Garbage collection problem?? by creamygoodness (Curate) on Dec 27, 2006 at 14:25 UTC
I can't confirm this with the stock Perl 5.8.6 on OS X 10.4 -- the second run seems to be consistently as fast as the first. However, I have experienced similar phenomena on this system before which I figured were a result of memory pool fragmentation. I have an indexing benchmarker script which inverts around 20000 Reuters news stories. In the initial version, once the script had been run a time or two (warming up the OS hard disk read cache) the first run was consistently faster than all subsequent runs by a few percentage points. I wound up launching a child process for each run to defeat the effect. -- Marvin Humphrey Rectangular Research ― http://www.rectangular.com	[reply]
Re: Garbage collection problem?? by Herkum (Parson) on Dec 27, 2006 at 14:26 UTC
I justed to had to run it after everyone else. This is Ubuntu 6.10 with Dell Optiplex GX620. sgkirkup@72sp691lin:~$ ./performance-test.pl Section A took 0.8600 CPU seconds Section B took 2.1800 CPU seconds Section A took 0.8800 CPU seconds Section B took 2.2200 CPU seconds sgkirkup@72sp691lin:~$ ./performance-test.pl Section A took 0.8200 CPU seconds Section B took 2.1300 CPU seconds Section A took 0.8500 CPU seconds Section B took 2.1800 CPU seconds sgkirkup@72sp691lin:~$ ./performance-test.pl Section A took 0.8300 CPU seconds Section B took 2.2100 CPU seconds Section A took 0.8600 CPU seconds Section B took 2.1900 CPU seconds sgkirkup@72sp691lin:~$ perl -v This is perl, v5.8.8 built for i486-linux-gnu-thread-multi Copyright 1987-2006, Larry Wall Perl may be copied only under the terms of either the Artistic License + or the GNU General Public License, which may be found in the Perl 5 source ki +t. Complete documentation for Perl, including FAQ lists, should be found +on this system using "man perl" or "perldoc perl". If you have access to + the Internet, point your browser at http://www.perl.org/, the Perl Home Pa +ge. [download]	[reply] [d/l]
Re: Garbage collection problem?? by EvanK (Chaplain) on Dec 27, 2006 at 17:10 UTC
sweet criminy...dont you just love ~~windows~~ activeperl for windows? windows xp home sp2 amd 64 x2 3800+ 2gb ram activestate 5.8.8 build 819 C:\Documents and Settings\Evan>perl c:\benchtest.pl Section A took 1.0470 CPU seconds Section B took 2.8910 CPU seconds Section A took 1.0470 CPU seconds Section B took 10.9220 CPU seconds C:\Documents and Settings\Evan>perl c:\benchtest.pl Section A took 1.0310 CPU seconds Section B took 2.8440 CPU seconds Section A took 1.0310 CPU seconds Section B took 11.2190 CPU seconds C:\Documents and Settings\Evan>perl c:\benchtest.pl Section A took 1.0470 CPU seconds Section B took 2.7340 CPU seconds Section A took 1.0310 CPU seconds Section B took 10.6410 CPU seconds [download] edit: forgot my perl version :o __________ The trouble with having an open mind, of course, is that people will insist on coming along and trying to put things in it. - Terry Pratchett	[reply] [d/l]
Re^2: Garbage collection problem?? by roboticus (Chancellor) on Dec 27, 2006 at 17:16 UTC
EvanK: It doesn't appear to be windows. My results show the expected behaviour under Windows. I'm suspecting it may be ActiveState related: Are you running that, or the cygwin perl? --roboticus	[reply]
Re: Garbage collection problem?? by sgt (Deacon) on Dec 27, 2006 at 16:20 UTC
I see the same speed for both runs on cygwin 1.5.21-2 with perl 5.8.7 % stephan@labaule (/home/stephan) % % cygcheck -s \| grep ^cygwin' ' cygwin 1.5.22-1 % stephan@labaule (/home/stephan) % % perl -v \| head -n 3; perl -W perf_test.px This is perl, v5.8.7 built for cygwin-thread-multi-64int (with 1 registered patch, see perl -V for more detail) Section A took 1.5920 CPU seconds Section B took 3.3950 CPU seconds Section A took 1.6030 CPU seconds Section B took 3.4550 CPU seconds % stephan@labaule (/home/stephan) % % perl -W perf_test.px Section A took 1.5920 CPU seconds Section B took 3.3650 CPU seconds Section A took 1.6030 CPU seconds Section B took 3.4350 CPU seconds % stephan@labaule (/home/stephan) % % perl -W perf_test.px Section A took 1.6020 CPU seconds Section B took 3.5250 CPU seconds Section A took 1.6120 CPU seconds Section B took 3.3850 CPU seconds [download] hth --stephan	[reply] [d/l]
Re: Garbage collection problem?? by sgt (Deacon) on Dec 27, 2006 at 19:58 UTC
I have put systematically my in the foreach (or in the smallest possible scope), and guess what 'for my' is actually consistently slower in case B. Somehow it surprised me :( % stephan@labaule (/home/stephan) % % for _i in {1..5} > do > echo ===$_i==== > perl -W perf_test_allmy.px > echo --- > perl -W perf_test.px > done ===1==== Section A took 1.7020 CPU seconds Section B took 3.9560 CPU seconds Section A took 1.7330 CPU seconds Section B took 3.9660 CPU seconds --- Section A took 1.7020 CPU seconds Section B took 3.6850 CPU seconds Section A took 1.7420 CPU seconds Section B took 3.7760 CPU seconds ===2==== Section A took 1.7220 CPU seconds Section B took 4.0160 CPU seconds Section A took 1.7030 CPU seconds Section B took 4.0860 CPU seconds --- Section A took 1.7220 CPU seconds Section B took 3.7850 CPU seconds Section A took 1.7230 CPU seconds Section B took 3.6750 CPU seconds ===3==== Section A took 1.7120 CPU seconds Section B took 4.0960 CPU seconds Section A took 1.7220 CPU seconds Section B took 4.0460 CPU seconds --- Section A took 1.7320 CPU seconds Section B took 3.5250 CPU seconds Section A took 1.7220 CPU seconds Section B took 3.6450 CPU seconds ===4==== Section A took 1.7020 CPU seconds Section B took 4.1260 CPU seconds Section A took 1.7120 CPU seconds Section B took 3.9360 CPU seconds --- Section A took 1.7020 CPU seconds Section B took 3.8560 CPU seconds Section A took 1.7430 CPU seconds Section B took 3.6350 CPU seconds ===5==== Section A took 1.7020 CPU seconds Section B took 4.1560 CPU seconds Section A took 1.7120 CPU seconds Section B took 3.9760 CPU seconds --- Section A took 1.7220 CPU seconds Section B took 3.7350 CPU seconds Section A took 1.7330 CPU seconds Section B took 3.5850 CPU seconds [download] hth --stephan	[reply] [d/l]
Re: Garbage collection problem?? by alpha (Scribe) on Dec 27, 2006 at 14:32 UTC
W2k sp4, celeron ~750 MHZ 256 RAM: `C:\pl>stuff.pl Section A took 3.5450 CPU seconds Section B took 12.5380 CPU seconds Section A took 3.5350 CPU seconds Section B took 44.2540 CPU seconds C:\pl>` [download]	[reply] [d/l]
Re^2: Garbage collection problem?? by alandev (Scribe) on Dec 27, 2006 at 15:04 UTC
on HP-Unix bash-2.00$ monk.pl Section A took 5.4500 CPU seconds Section B took 9.7100 CPU seconds Section A took 5.4700 CPU seconds Section B took 9.9800 CPU seconds	[reply]
Re^2: Garbage collection problem?? by tcarmeli (Beadle) on Dec 27, 2006 at 15:13 UTC
See you got over the initial sickness ;-)	[reply]
Re: Garbage collection problem?? by roboticus (Chancellor) on Dec 27, 2006 at 15:21 UTC
Results for Win2K SP4 using cygwin v1.5.18 and perl v5.8.7 on an AMD Sempron 2500+ with 512K RAM: `root@swill ~/PerlMonks $ ./591724.pl Section A took 1.7040 CPU seconds Section B took 3.7960 CPU seconds Section A took 1.7030 CPU seconds Section B took 3.7500 CPU seconds root@swill ~/PerlMonks $ ./591724.pl Section A took 1.6880 CPU seconds Section B took 3.7970 CPU seconds Section A took 1.6870 CPU seconds Section B took 3.6090 CPU seconds` [download] --roboticus Update: If anyone's interested, here's Read more... my configuration: (3 kB)	[reply] [d/l] [select]
Re: Garbage collection problem?? by monarch (Priest) on Dec 27, 2006 at 17:00 UTC
On a dual duo-core Intel Xeon with perl v5.8.8 on x86_64-linux-gnu-thread-multi on Ubuntu 6.10 I got: `Section A took 0.3200 CPU seconds Section B took 1.1300 CPU seconds Section A took 0.3400 CPU seconds Section B took 1.1800 CPU seconds` [download]	[reply] [d/l]
Re: Garbage collection problem?? by tcarmeli (Beadle) on Dec 28, 2006 at 09:31 UTC
Something that does not solve the issue, but makes it less painfull, it to replace the "push" with "unshift". It causes the high values of $time to be used first, so there's one first large memory allocation rather than many extensions on the existing amount.	[reply]
Re: Garbage collection problem?? by alpha (Scribe) on Dec 28, 2006 at 12:10 UTC
I've added third CheckAllPairs(); into script and results are strange imo ;/ `C:\pl>stuff.pl Section A took 2.9140 CPU seconds Section B took 13.4890 CPU seconds Section A took 3.6350 CPU seconds Section B took 44.2330 CPU seconds Section A took 3.6450 CPU seconds Section B took 46.9980 CPU seconds` [download] oh, and I run perl v5.8.8 built for MSWin32-x86-multi-thread with 25 registered patches.	[reply] [d/l]
Re: Garbage collection problem?? by alpha (Scribe) on Dec 27, 2006 at 14:14 UTC
So much foreach loops make me sick =:[]	[reply]
Re: Garbage collection problem?? by Anonymous Monk on Dec 27, 2006 at 18:07 UTC
pretty clear from the results that this phenomenon only occurs in ActivePerl...	[reply]
Re^2: Garbage collection problem?? (Win32 CRTL malloc) by tye (Sage) on Dec 27, 2006 at 18:24 UTC
No, I don't think the problem has anything to do with ActiveState nor their version of Perl. Though I don't see any reports using ActivePerl other than on Win32 (yes, they make such), I doubt that the problem would appear there. My guess based on the results is that the blame can likely be placed on the malloc() of Win32's CRTL and that cygwin-built Perls doesn't use that version of malloc(). In any case, testing with my non-ActiveState Perl on Win32 gives: `C:\> perl checkpairs.pl Section A took 0.7500 CPU seconds Section B took 2.5470 CPU seconds Section A took 0.7340 CPU seconds Section B took 13.8280 CPU seconds` [download] Which certainly disproves that it "only occurs in ActivePerl". (: And I've certainly seen Win32's malloc() cause performance problems. I haven't read the code for it recently but I'm quite familiar with some of the memory use patterns that it produces and those clearly show a very naive algorithm. Anyone got a Win32 (non-cygwin) Perl built with profiling? - tye	[reply] [d/l]
Re^3: Garbage collection problem?? (Win32 CRTL malloc) by BrowserUk (Patriarch) on Dec 27, 2006 at 20:27 UTC
Actually, it appears to be more to do with realloc and/or free rather than malloc per se, but also there seem to be some pretty strange things going on with respect to error handling. I get the impression, but haven't got proof yet, that it may be something to do with the way Perl is using the CRT, possibly to do with how it handles errors. Has anyone tried the OP code on a non-threaded 5.8.x Win32 build? There are lots ( literally millions) of repetitions of the call sequence: `... [T1868] GetLastError(2845dc, 18f5ca4, 77c35292, 2803000e, ...) = 3 [T1868] TlsGetValue(0, 2845dc, 18f5ca4, 77c35292, ...) = 281ea0 [T1868] SetLastError(3, 2845dc, 18f5ca4, 77c35292, ...) = 7ffde000 [T1868] GetLastError(2845dc, 18f5ca4, 77c35292, 2803000e, ...) = 3 [T1868] TlsGetValue(0, 2845dc, 18f5ca4, 77c35292, ...) = 281ea0 [T1868] SetLastError(3, 2845dc, 18f5ca4, 77c35292, ...) = 7ffde000 ...` [download] Examine what is said, not who speaks -- Silence betokens consent -- Love the truth but pardon error. "Science is about questioning the status quo. Questioning authority". In the absence of evidence, opinion is indistinguishable from prejudice. "Too many [] have been sedated by an oppressive environment of political correctness and risk aversion."	[reply] [d/l]
Re^3: Garbage collection problem?? (Win32 CRTL malloc) by roboticus (Chancellor) on Dec 27, 2006 at 18:52 UTC
Which version of cygwin are you using? My results are using cygwin (v1.5.18) and Perl 5.8.7, and don't show the slowdown on the second run.... --roboticus	[reply]
Re^4: Garbage collection problem?? (Win32 CRTL malloc) by tye (Sage) on Dec 27, 2006 at 19:23 UTC
Re^5: Garbage collection problem?? (Win32 CRTL malloc) by roboticus (Chancellor) on Dec 27, 2006 at 19:31 UTC
Some notes below your chosen depth have not been shown here
Re^3: Garbage collection problem?? (Win32 CRTL malloc) by Herkum (Parson) on Dec 27, 2006 at 19:26 UTC
If you look at my tests, they are not using Windows at all nor is it using ActivePerl. Some people have said that it is not an issue on their system but have not posted what type of system they are running (except for OS X). Update: You are correct, I misread your post, sorry about that...	[reply]
Re^4: Garbage collection problem?? ("second") by tye (Sage) on Dec 27, 2006 at 19:31 UTC
Re: Garbage collection problem?? by alpha (Scribe) on Dec 27, 2006 at 16:58 UTC
Then it's probably the OS..	[reply]