[Java] snelheid opmerkelijk

[Memorice]

Onderstaande stukken code zijn identiek, behalve dat in de onderste code 1 regel in commentaar is gezet (namelijk het toevoegen aan de TreeSet). Opmerkelijk is dat de eerste code consequent 3 seconden sneller is dan de tweede code. Tijdens het testen had ik beide stukken code in dezelfde functie onder elkaar staan. Tevens gaat het niet om een eenmalige test (dus toeval). De runtimes zijn namelijk keer op keer zeer constant.

Snellere code (avg runtime: 38 s):

Java:

long start_time1 = new Date().getTime();
int nr1 = 0;
TreeSet<Coloring> population1 = new TreeSet<Coloring>();
while (nr1 < 1000) {
  nr1++;
  Coloring coloring = VD(random(colors));
  population1.add(coloring);
}
System.out.println("TIME USED FOR TEST: "+(new Date().getTime()-start_time1));

Tragere code (avg runtime: 41 s):

Java:

long start_time = new Date().getTime();
int nr = 0;
TreeSet<Coloring> population = new TreeSet<Coloring>();
while (nr < 1000) {
  nr++;
  Coloring coloring = VD(random(colors));
  //population.add(coloring);
}
System.out.println("TIME USED FOR TEST: "+(new Date().getTime()-start_time));

Ik ben erg nieuwsgierig hoe dit kan, wellicht dat iemand hier een idee heeft?

[JaWi]

Je TreeSet maakt intern gebruik van twee HashMaps (dacht ik). Nu worden deze standaard met 10 "buckets" aangemaakt, waardoor er in jouw geval een fix aantal keer de hoeveelheid buckets aangevuld moeten worden. En daardoor is het tweede stukje "ietsjes" sneller dan het eerste.

Probeer dezelfde test nog eens met bijv.

Java:

new HashMap<Coloring>(1000);

dan zullen de verschillen waarschijnlijk al een stuk minder zijn. Je bent dan wel je ordering kwijt.

Is het echt nodig om een TreeSet te gebruiken?

edit:
Voor 'n TreeSet kan geen initial capacity opgegeven worden...

[ Voor 17% gewijzigd door JaWi op 07-01-2009 22:21 ]

[Gorion3]

Ik denk dat bij het eerste stukje code de JIT compiler in zijn werking treed. En bij het 2de stukje niet omdat daar niet iets "speciaals" gebeurt.

[TeeDee]

Lees ik het nou volkomen verkeerd of zegt de TS dat het eerste stukje code sneller is (met de .add op de TreeSet) dan het tweede.

Anyway, het is niet zo dat de ~3 sec. verschil door het opstarten komt icm een debugger? Want imo is de vertraging code-technisch gezien niet te verklaren.
Is ook niet logisch, dan zou het eerste stuk alsnog trager moeten zijn (als het door een debugger/JIT) komt.

[ Voor 16% gewijzigd door TeeDee op 07-01-2009 22:40 ]

[Memorice]

@all

Het eerste stukje code met (met de .add op de TreeSet) is sneller dan het tweede stukje. Er is dus geen externe oorzaak (opstarten, debuggen, etc.) die het snelheids verschil kan verklaren.

@Gorion3

Mocht het komen doordat bij het eerste stukje code de JIT compiler in werking treedt omdat het toevoegen aan een TreeSet 'speciaal' is. Is het dan mogelijk om dit te controleren, door bijvoorbeeld te forceren dat de JIT compiler altijd gebruikt moet worden of zo?

[Adion]

Misschien iets met de garbage collection?

Bij het eerste stuk wordt het object opgeslagen voor later gebruik, bij het tweede stuk zou het kunnen dat de garbage collector het object moet verwijderen.

[Memorice]

Het lijkt inderdaad de garbage collector te zijn, als ik ze namelijk onthoud in een simpele array (Coloring[]) dan verschilt dit ~3 seconden.

[.oisyn]

Draai het nu eens om, dus dat je de eerst de code uitvoert die praktisch niets doet en daarna de code die de container daadwerkelijk vult.

[Memorice]

@ .oisyn

Dit maakt geen verschil in runtime.

[.oisyn]

Ah wacht er staat seconde, ik dacht even milliseconde te lezen. Dan willen benchmarks nogal eens een (consistent) vertekend beeld geven namelijk

[ACM]

Zou het niet kunnen dat het snelheidsverschil toch door externe oorzaken wordt veroorzaakt? 1000 objecten in 41 seconde genereren is imho niet bepaald een triviale tijd... In het ene geval gooi je ze direct weer weg en in het andere bewaar je ze, en dus ook alles wat ze intern refereren.

Dus het kan best zijn dat er enorme data-structuren in het laatste geval wel en in het eerste geval niet weggegooid worden. Afhankelijk van hoe je een en ander hebt aangepakt is het niet per se vreemd dat garbage collection in het ene geval daardoor zwaarder wordt.
Hoewel het op zich dan nog steeds vreemd is, aangezien dingen uit de young generation weggooien normaliter erg goedkoop is en ze naar de old generation kopieren wel handelingen kost en dus per definitie zwaarder is.

Met welke Java werk je hier en op wat voor platform? Met recente Sun Java's (zo'n beetje alle Java2's) zou de 2e situatie niet zomaar sneller mogen zijn dan de 1e.

Maar ik zou deze tamelijk zinloze test opzij zetten en als je wil weten waar de tijd in gaat zitten, controleren waarom het genereren van 1000 objecten uberhaupt meer dan 30 seconde duurt. De oorzaak zit in je VD of in je random gok ik zo.

JaWi schreef op woensdag 07 januari 2009 @ 22:17:
Je TreeSet maakt intern gebruik van twee HashMaps (dacht ik). Nu worden deze standaard met 10 "buckets" aangemaakt, waardoor er in jouw geval een fix aantal keer de hoeveelheid buckets aangevuld moeten worden. En daardoor is het tweede stukje "ietsjes" sneller dan het eerste.

Een TreeSet gebruikt intern hooguit een TreeMap, niet een HashMap, want die is niet te ordenen En voor een Red-Black tree (zoals de TreeMap) is het niet zo nuttig dat je vooraf weet hoe groot ie gaat worden, je weet dan alsnog niet hoe ze geordened gaan zijn.
Bovendien zou er, als je gelijk had dat de 2e situatie sneller was dan de 1e, alsnog geen 3 seconde verschil moeten zitten in een tree van slechts 1000 objecten, tenzij de compareTo erg duur is. Ik heb zelf in ieder geval pasgeleden in veel minder tijd, veel meer objecten in TreeSet's verwerkt.

[Memorice]

@ACM

Ik werk met java 6 update 11, gewoon via de command line op een Intel C2D T9300 onder windows xp pro.

Het is inderdaad een tamelijk zinloze test. Eigenlijk was ik bezig met het graph coloring probleem op een tamelijk grote graaf. Ik wilde Multistart Local Search vergelijken (MLS) met Genetic Local Search (GLS), door de GLS even veel tijd te geven als 1000 MLS. Toen viel op dat het maken van een populatie sneller ging dan het doen van een single local search. En aangezien deze twee vrijwel het zelfde zijn, behalve dat bij het aanmaken van de populatie de local search toegevoegd wordt aan de populatie (TreeSet). Intuitief zou je zeggen dat dit een extra operatie is en dus (log n) meer tijd kost, maar hierbij was ik de garbage collector even vergeten.

Verder was het niet echt de bedoeling om de code te optimaliseren, gezien het niet veel sneller kan, simpelweg doordat de graaf enorm groot is en het gebruikte algoritme (Vertex Descent) niet efficienter te implementeren is. Het was dus meer een vraag uit nieuwsgierigheid.

Overigens weet ik niet zeker of je mijn posts wel goed gelezen hebt, het stuk code zonder het toevoegen aan de TreeSet is namelijk trager. En jij suggereert in je post het tegenovergestelde:

Met recente Sun Java's (zo'n beetje alle Java2's) zou de 2e situatie niet zomaar sneller mogen zijn dan de 1e.

Ik weet niet of dit slordigheid in jouw post is of dat je mijn posts verkeerd gelezen hebt, vandaar dat ik het nogmaals vermeld.

[jAnO!]

Wat nog interressant kan zijn is of de resultaten hetzelfde zijn voor -client en -server. Sowieso kan je even runnen met -Xprof, dan zie je waar die mee bezig is geweest, JIT etc..

[ACM]

MEMORICE schreef op donderdag 08 januari 2009 @ 00:26:
@ACM

Ik werk met java 6 update 11, gewoon via de command line op een Intel C2D T9300 onder windows xp pro.

Ah mooi, in de JDK-directory zit een bin, met daar weer in de een hele handige tool genaamd 'jvisualvm', daar kan je - als je dat nog niet gedaan hebt - heel eenvoudig je VM (met die applicatie) bekijken wat betreft garbage collection, geheugen gebruik en zelfs profilen.
Verder kan je met jstat -gc $jepid op de commandline ook een heel eind komen.

Intuitief zou je zeggen dat dit een extra operatie is en dus (log n) meer tijd kost, maar hierbij was ik de garbage collector even vergeten.

Op zich zou als alles gelijk is inderdaad de variant met het toevoegen aan de tree meer tijd kosten (O(n log n) zelfs), maar dan wel ten opzichte van het aantal elementen, dus in dit geval "slechts" 1000. In mijn ervaring wordt (zeker met zo'n recente VM) de treeset erg snel uitgevoerd, en zou dat - tenzij je compareTo of Comparator heel zwaar is - eigenlijk niet terug moeten zien in de executietijd.

Je draait waarschijnlijk een 32bits versie Java? In dat geval heb je kans dat ie er voor kiest om de "client" vm te starten, ipv de "server" vm. Als je hier niet op gelet had: In dit geval zou je flink winst kunnen hebben van de krachtigere JIT en GC in de server-versie (hij start wel wat slomere schijnbaar), dat kan je controleren door domweg bij java -help te zien welke vm ze als default noemen. Bij een 64bits platform, of een 32bits met >= 2GB ram en >= 2 cores staat al onder de vm-keuzes dat server de default is.

Verder was het niet echt de bedoeling om de code te optimaliseren, gezien het niet veel sneller kan, simpelweg doordat de graaf enorm groot is en het gebruikte algoritme (Vertex Descent) niet efficienter te implementeren is. Het was dus meer een vraag uit nieuwsgierigheid.

Ok, het blijft inderdaad een vreemd verschijnsel.

Overigens weet ik niet zeker of je mijn posts wel goed gelezen hebt, het stuk code zonder het toevoegen aan de TreeSet is namelijk trager. En jij suggereert in je post het tegenovergestelde:

Jahoor, ik had het door. Maar ik zeg vooral dat de TreeSet met slechts 1000 elementen imho niet zomaar verantwoordelijk kan zijn voor het leeuwendeel van die tijd. Dus dat het vervangen van de TreeSet door een HashSet je waarschijnlijk nauwelijks een tijdsvoordeel oplevert, zelfs als dat voor je algoritme goed zou kunnen.

jAnO! schreef op donderdag 08 januari 2009 @ 09:02:
Wat nog interressant kan zijn is of de resultaten hetzelfde zijn voor -client en -server. Sowieso kan je even runnen met -Xprof, dan zie je waar die mee bezig is geweest, JIT etc..

Hoe zwaarder een algoritme en hoe langer het duurt, hoe groter de kans dat de server-vm winst biedt. -Xprof biedt nauwelijks granulariteit, maar het geeft inderdaad wel een beeld van wat er zoal gebeurt. de JVisualVM of andere profilers bieden een wat fijnere granulariteit.
Waar je je overigens niet op moet blind staren, want de profilers zorgen er ook voor dat allerlei hotspot-optimalisaties niet of anders uitgevoerd worden

[JKVA]

1000 objecten aanmaken is minder dan millisecondenwerk. Ik verwacht dat je de oorzaak in VD() of in random() moet zoeken. Wat doen die methoden?

Maar dan nog, micro benchmarks in Java zijn zinloos. Er zijn teveel variabelen om rekening mee te houden. Denk aan:

• Java versie,
• JIT compiling (een JIT compiler kan halverwege gaan compileren wat op zichzelf ook tijd kost),
• warmup tijden,
• reordering, inlining, dead code elision,
• garbage collection timing,
• de OS/thread scheduler,
• en nog vanalles...

Vooral het niet doen van een warming up en dead code elision zijn typische problemen die je in een micro benchmark tegenkomt.

De kans is erg groot dat een Java micro benchmark je op het verkeerde been zet. Je moet in je benchmark simpelweg met teveel zaken rekening houden.

[bomberboy]

ACM schreef op donderdag 08 januari 2009 @ 00:01:
Dus het kan best zijn dat er enorme data-structuren in het laatste geval wel en in het eerste geval niet weggegooid worden. Afhankelijk van hoe je een en ander hebt aangepakt is het niet per se vreemd dat garbage collection in het ene geval daardoor zwaarder wordt.
Hoewel het op zich dan nog steeds vreemd is, aangezien dingen uit de young generation weggooien normaliter erg goedkoop is en ze naar de old generation kopieren wel handelingen kost en dus per definitie zwaarder is.

Hangt uiteraard ook samen met de grootte van de objecten en vooral de references naar andere objecten.
Heeft die constructor eigenlijk neveneffecten?
In ieder geval gaat de JVM er hier van uit van wel. Indien die zou kunnen bepalen dat er helemaal geen neveneffecten zijn, dan zou het eerste stukje code onmiddellijk moeten returnen aangezien er niets met het object gedaan wordt en het dus eigenlijk zelfs niet moet gegenereerd worden. Wel blijft die 'nr' nog in scope na de loop, wat bij een for met die nr in de for niet gebeurd en daardoor mss een fractie sneller is (of die detectie van neveneffecten wel kan)

Een mogelijke test om de garbage collection te elimineren is veel geheugen te specificeren bij de uitvoering van je applicatie (-Xmx1024m -Xms1024m -> specificeert minimum en maximum grootte van de heap).
In dat geval zal de gc niet optreden en kan je die elimineren.

Het toevoegen van de objecten aan de TreeSet kan er eventueel ook voor zorgen dat die objecten veel sneller naar de old generation gepromoveerd worden ipv in de young generation een groot aantal keer heen weer gekopieerd te worden. (de young generation bestaat eigenlijk uit 2 delen waartussen de alive objecten x aantal keer gekopieerd worden, de andere wordt dan helemaal gecleared voor ze weer gebruikt wordt)
Indien het object direct in de old generation zit moet dit niet gebeuren enz. De old generation wordt dan bv ook veel minder vaak bezocht door de garbage collector.

In ieder geval is het zeer moeilijk om op basis van de getoonde code daar echte conclusies uit te trekken.

[Memorice]

Hetgeen wat veel tijd kost is uiteraard het VD algoritme (vanwege de grote input graaf). Dit kan ook niet veel sneller, zoals al eerder vermeld.

@jAnO!
De optie -server zorgt er voor dat de runtime van 41s naar 30s gaat. Dit is dus wel fijner werken en kost verder geen enkele moeite :-)

[ACM]

bomberboy schreef op donderdag 08 januari 2009 @ 17:42:
Een mogelijke test om de garbage collection te elimineren is veel geheugen te specificeren bij de uitvoering van je applicatie (-Xmx1024m -Xms1024m -> specificeert minimum en maximum grootte van de heap).
In dat geval zal de gc niet optreden en kan je die elimineren.

Garbage collection kan je vziw helemaal niet (op die manier iig) uitschakelen, het belangrijkste wat je met die twee vlaggen van je bereikt is dat er geen dure geheugenruimte-vergrotingen nodig zijn.

Zelfs met "veel" geheugen loopt een complexe applicatie in je VM vrijwel gegarandeerd wel tegen die grens aan, hoe hoog ie ook ligt, en de VM probeert al vrij vroeg weer wat ruimte vrij te maken (vooral in de young generation).

[bomberboy]

Voor een kleine test/benchmark resulteert dit in praktijk meestal tot geen garbage-collection. Helemaal uitschakelen doe je ze daarmee uiteraard niet.
Vandaar dat ik ook melde dat het belangrijk is om iets meer te weten over de grootte van de gebruikte objecten en hoeveel ruimte die innemen. Garbage collection in de young generation is vrij goedkoop en moet zowiezo gebeuren. Door die grote heap te specificeren voorkom je wel dat de old generation door de garbage collector bezocht wordt.
Tevens telkens de heap vergroot wordt, wordt er ook een garbage collection uitgevoerd. Dus die stap vermijd je dan.

Iets wat de -server vlag trouwens ook doet is een andere default grootte voor de heap en verschillende generaties kiezen, dus een deel van de snelheidswinst zou daar kunnen komen door het minder voorkomen van de garbage collection.

Bij een langdurige test zou je normaal nooit zoń grote tijdsverschillen mogen zien als de OP hier nu meldt met de -server vlag. Dat zou kunnen duiden op de verschillende groottes van die heap en generaties in beide testen.