-
Notifications
You must be signed in to change notification settings - Fork 58
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
lmdb: strange numbers of allocations reported by benchmarks #63
Comments
So, here is how I interpret this:
Now, considering that N is kind of large (a few 100k probably), allocations from makeBenchDBVal do not factor in. The 4 allocations per op are exclusively from Txn.Put. Not very exciting so far. But where are those allocations happening in Txn.Put (this is a different run from the one above, so absolute numbers won't match up)? Total: 906361
ROUTINE ======================== github.com/bmatsuo/lmdb-go/lmdb.(*Txn).Put in /Users/lorenz/go/src/github.com/bmatsuo/lmdb-go/lmdb/txn.go
905940 905940 (flat, cum) 100% of Total
. . 314: vn := len(val)
. . 315: if vn == 0 {
. . 316: val = []byte{0}
. . 317: }
. . 318:
905940 905940 319: ret := C.lmdbgo_mdb_put2(
. . 320: txn._txn, C.MDB_dbi(dbi),
. . 321: unsafe.Pointer(&key[0]), C.size_t(kn),
. . 322: unsafe.Pointer(&val[0]), C.size_t(vn),
. . 323: C.uint(flags),
. . 324: )
The only way I can make the numbers match up is if |
Ah. I was partially misreading the code. Indeed makeBenchDBVal will only allocate a fraction of the time. So it will not have an effect on the benchmark's computed allocs/op. Making those numbers add up is a stretch. Honestly given some of the weird swings in benchmark numbers I have seen before I have wondered if cgo could somehow be allocating or copying things which I don't expect. I never had real evidence for that before this. edit: this was one of my wacky theories about slowdowns experienced trying to fix #56 |
Well this is pretty fascinating. Check out the following example: http://play.golang.org/p/hC-b5VSG58 Now look at this benchmark: http://play.golang.org/p/e37ObBxwJP And the results
Shocking |
Wow. These benchmarks (for the earlier example) tell another interesting story: http://play.golang.org/p/vLQoKQRxPP
I guess the cgo pointer checks are doing a linear scan for pointers despite the fact that it is given a edit: Holy hell! I didn't even notice that alloced space increases at the end! What is going on? |
That is indeed fascinating! Does DEBUG=cgocheck=0 change that? |
Execellent question. The answer...
|
I don't know why the allocated space went down.. It doesn't actually seem correlated with the variable setting. |
In fact, the name was wrong, the environment variable is GODEBUG, not DEBUG. Oops. That makes the linear runtime go away, but the allocations are still there. I'll update my old comment. |
See https://github.com/golang/go/blob/master/src/runtime/cgocall.go#L327 ?
|
I didn't completely realize this was a dumb runtime check which did not benefit at all from type information about the argument (presumably because it has already been converted to unsafe.Pointer). I've also noted that this behavior seems to be
Weirdly enough the very last test says 1 byte is allocated per loop iteration. That is strange indeed. But probably not that important. |
Yes, I think you are right. The check tries to be smart and aborts if it knows that the type can not contain pointers, but that plan is foiled by conversion to unsafe.Pointer. See https://github.com/golang/go/blob/master/src/runtime/cgocall.go#L466 Trying to dig up where the type coercion to unsafe.Pointer is happening, no luck :( |
Tadaaa golang/go#14387 |
Fantastic detective work, @lmb. It makes me quite happy that this should be fixed before go1.7. After noticing that the allocations were tied to The results look good. Though I'm going to look into that Go issue further, and probably try things out on tip/master before doing anything with that commit. Here are the tentative numbers though. I always love seeing "-100%" 😄
|
After testing on tip it seems that the allocations remain present with But the allocs mean I may end up merging that |
It was discovered in #63 that void* arguments cause allocations in cgo and extra time checking arguments as opposed to char* arguments. The issue golang/go#14387 claims that it will fix this problem but I am going to keep this patch around for testing against tip and later merging if necessary.
Nice 👍 Maybe this will make the benchmarks less volatile as well. |
I wouldn't get my hopes too high about that 😄 Even in those numbers I pasted there is some weirdness (e.g. ReaderList +10%?) The interaction with the system is so high. My suspicion is that you need a real clean-room style environment to run the benchmarks if you want truly consistent times. Something like busybox with minimal external processes, running everything in memory, and where any kind of virtualization has been disabled. IDK though. |
I'm tempted to make this part of the next release as well. But it will wait until I can get some more insight about whether those allocations would feasibly be eliminated somehow in the near future. |
Yea. I think those allocations are going to be around for a while. I made an issue about it but it doesn't seem to be a high priority. I'm preparing a pull request. |
@lmb pointed out some anomalous looking numbers reported by
go test -bench=. -benchmem
in #61, Specifically regarding the BenchmarkTxn_Put function.The 4 allocations reported are difficult to track down.
One should be happening in the benchmark function itself(edit: that is false, allocations in the benchmark function get amortized and do not have a significant effect). But the others are not easy to account for. In a normal (non-error) case Txn.Put does not appear to make allocations inside the Go runtime.@lmb ran the pprof tool using
-alloc_objects
and the following information about allocations in the benchmark function was comptued:Nothing seems to be adding up correctly here.
The text was updated successfully, but these errors were encountered: