search

toshsan / caliper

Automatically exported from code.google.com/p/caliper
Apache License 2.0
0 stars 0 forks source link

Caliper seems to have painfully high overhead between trials #208

Open GoogleCodeExporter opened 9 years ago

GoogleCodeExporter commented 9 years ago 
I have some trials which should take only about (1 second + VM startup time), 
yet caliper is inching along at a rate of about 15 seconds per trial.

Can we please try to look into where all that time is going? It's quite 
excruciating and will definitely hamper users' willingness to run lots of 
trials of lots of parameters.

Original issue reported on code.google.com by kevinb@google.com on 29 Jan 2013 at 12:37

GoogleCodeExporter commented 9 years ago 
All I know right now is that it's all inside the stop and start of 
trialStopwatch.

INFO: trial completed in 12.59 s

Original comment by kevinb@google.com on 29 Jan 2013 at 12:39

GoogleCodeExporter commented 9 years ago 
You say that it should take about 1s, but could you elaborate on the settings 
for the microbenchmark instrument?  The "instrument.micro.options" section of 
the output from --print-config would be really helpful.

Original comment by gak@google.com on 29 Jan 2013 at 4:05

GoogleCodeExporter commented 9 years ago 
instrument.micro.options.warmup=200ms
instrument.micro.options.timingInterval=20ms
instrument.micro.options.measurements=20
instrument.micro.options.maxTotalRuntime=2s

Original comment by kevinb@google.com on 29 Jan 2013 at 4:21

GoogleCodeExporter commented 9 years ago 
(Thinking out loud)
Places we spend a fair amount of time:
 - File IO for the results
 - Network IO for the results
 - JVM startup
 - Shelling out to create the pipe for results data

A few of these things seem to be in the scope of the trial stopwatch, but 
really shouldn't be.  I suspect the result processors and some timing and 
logging around those is probably a good idea anyway.

Original comment by gak@google.com on 29 Jan 2013 at 4:30

GoogleCodeExporter commented 9 years ago 
If result processing is a big part of this, note that if there were an option 
that let me defer all result processing until the end when it could batched up 
and done presumably more efficiently, I would totally use that option sometimes.

Original comment by kevinb@google.com on 29 Jan 2013 at 5:01

GoogleCodeExporter commented 9 years ago 
Oh, yeah, that's not a bad idea.  I know that I have actually gotten a lot of 
benefit out of having it done after every trial, but a config option to defer 
seems reasonable.

Original comment by gak@google.com on 29 Jan 2013 at 5:09

GoogleCodeExporter commented 9 years ago 
This is the culprit:

000.000 Starting experiment 1 of 2: ...
014.007 Complete!
014.097 HttpUploader starts
045.387 HttpUploader finishes
045.392 Starting experiment 2 of 2: ...
059.201 Complete!
059.221 HttpUploader starts
093.003 HttpUploader finishes

The HttpUploader gets invoked after each trial and accounts for 65 out of 93 
seconds. Commenting out the line

results.upload.class=com.google.caliper.runner.HttpUploader

makes it more than 3 times faster (and rather useless given the lack of console 
output). Upload all the saved data after the whole benchmark?

Original comment by Maaarti...@gmail.com on 27 Aug 2013 at 8:43