MySQL support?

[robfig]

Hi, just curious if this is supposed to work with MySQL?

I tried to use it like this:

Jet, err = jet.Open("mysql", spec)
rowNum := 500 
var w World 
Jet.Query(worldSelect, rowNum).Value(&w)

For the query, I tried these:

const worldSelect = "SELECT id,randomNumber FROM World where id = ?"
const worldSelect = "SELECT id,randomNumber FROM World where id = $1"
const worldSelect = "SELECT id,randomNumber FROM World where id = "

but all failed, with these various error messages:

SQL: 2013/05/08 00:12:46 SELECT id,randomNumber FROM World where id = $1 ["8082"]
Error scanning world row: Error 1054: Unknown column '$1' in 'where clause'

SQL: 2013/05/08 00:13:04 SELECT id,randomNumber FROM World where id = ? ["8082"]
Error scanning world row: Error 1064: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '?$1' at line 1

SQL: 2013/05/08 00:13:20 SELECT id,randomNumber FROM World where id =  ["8082"]
Error scanning world row: Error 1054: Unknown column '$1' in 'where clause'

[eaigner]

These errors do not come from jet, but the driver you use. What driver is loaded?

[robfig]

Sorry for crossing issues. We should continue discussion here, since it's Jet-related. (From https://github.com/eaigner/hood/issues/61)

You can select a driver in the conf/app.conf file. Right now it uses github.com/go-sql-driver/mysql, which I use for all the other benchmarks.

Also, give me a sec to merge the master branch into it (I recently pushed a large change to Revel, so this will not compile as-is).

[eaigner]

Alright, closed the other issue. Let's continue here.

[robfig]

Merge complete.
https://github.com/robfig/FrameworkBenchmarks/commit/b42a27c26fc985f1b1087fb40726445e1b4c6159

[eaigner]

I'm not quite sure on how to run these benchmarks yet. The README says I need Ubuntu 12.04 machines and run the tests for several hours?

[robfig]

Yeah, you can follow that README to set up two EC2 m1.large instances to run the tests on (which is how they do it for real). But benchmarking locally is much easier and more convenient (those were the instructions I left on the other issue). Ideally you would be able to run the client (wrk) on one machine and the server on another, connected by gigabit ethernet, but I seemed to be getting reasonable, repeatable results running both on the same workstation.

[eaigner]

Ah I see. Overlooked those.

[eaigner]

I guess there was a mixup in the instructions. The GOPATH should be exported after changing to the /revel subdir. And the package needs to be installed

1. git clone git@github.com:robfig/FrameworkBenchmarks.git
2. cd FrameworkBenchmarks
3. git checkout jet
4. cd revel
5. export GOPATH=pwd
6. go get github.com/robfig/revel/revel
7. go install github.com/robfig/revel/revel
8. bin/revel run benchmark prod 8080
9. (In another terminal) wrk -d 30 -c 256 -t 2 http://localhost:8080/db?queries=20

[eaigner]

First error I noticed is that you're using Value instead of Rows. Value returns only the first column's value (simplification for aggregation queries).

[eaigner]

Can't seem to be able to run it. As soon as I start the wrk benchmark (or issue a request to http://localhost:8080/db?queries=20), revel quits. I assume that's caused by a revel.ERROR.Fatalf call, but I see no error logged.

[robfig]

Yea, I've seen that. Try with db?queries=1. The default prod configuration logs to file (benchmark.log in your shell's directory), but you can change it to log to console (app.conf)

[eaigner]

Already fixed it. Had to do some major modifications to Jet, but almost done (I hope).

[robfig]

I've been meaning to implement a connection pool to limit the outstanding connections to MySQL. If you look in FrameworkBenchmarks/config/my.cnf, you can see the configuration they use for testing -- it allows 5k open connections. I suspect that the errors come back when that limit is exceeded (or maybe the practical limit is even lower -- I would play with the max allowed connections to see what value is most performant).

You can see my progress towards making that here (see acquire and release): https://github.com/robfig/FrameworkBenchmarks/blob/connectionlimit/revel/src/benchmark/app/controllers/app.go

It's not too big of a performance killer. If you patch it in, it may prevent your guy from dying.

[eaigner]

Now I get 2013/06/05 02:42:31 invoker.go:26: Binding: queries as int logged for each request. Is that related to the pool?

If I raise the connections to 256 I get panics.

With 100 it at least manages to print Error 1040: Too many connections.

[eaigner]

I patched SetMaxIdleConns into Jet.

[robfig]

That is logged at the TRACE level -- TRACE and INFO should definitely be off.

[robfig]

What if you lower the MaxConnectionCount to 256 ? (in the connectionlimit branch, it was still set to 5000)

[eaigner]

It already was set to 256 in the jet branch

[robfig]

If you:

• are using the connectionlimit patch to limit your outstanding DB connections to 256
• have configured your mysql according to their my.cnf

but you still get panics / errors about Too many connections, then I'm a bit stumped. One other lead is that this patch was recommended to me, due to some extra raising of system limits on open files and stuff it does: https://github.com/TechEmpower/FrameworkBenchmarks/pull/308

(Edit: looking over that patch, I'm not sure it's really that useful for you)

Secondly, the benchmarker.py script raises some limits that may be helpful:

  sudo sysctl -w net.core.somaxconn=5000
  sudo -s ulimit -n 8192
  sudo sysctl net.ipv4.tcp_tw_reuse=1
  sudo sysctl net.ipv4.tcp_tw_recycle=1
  sudo sysctl -w kernel.shmmax=2147483648
  sudo sysctl -w kernel.shmall=2097152

And lastly, you could try running the benchmark on EC2. I managed to follow the instruction to set it up successfully, and running the real benchmarker could be a better test if your local workstation is having trouble.

[eaigner]

Well, I'll call it a day. Wan't to try it on your machine? (will send you a pull request)

[robfig]

Looks like a bug -- presumably it treats all ints as int64, even though that's not allowed. (I just turned on infinite scrollback and went back to the initial goroutine stack)

panic: reflect.Set: value of type int64 is not assignable to type uint16

goroutine 227 [running]:
reflect.Value.assignTo(0x6acc60, 0x1c23, 0x60, 0x7eb2d0, 0xb, ...)
    /home/robfig/go/src/pkg/reflect/value.go:2131 +0x310
reflect.Value.Set(0x6ad320, 0xc200177290, 0x96, 0x6acc60, 0x1c23, ...)
    /home/robfig/go/src/pkg/reflect/value.go:1379 +0x99
github.com/eaigner/jet.setValue(0x6acc60, 0x1c23, 0x6ad320, 0xc200177290, 0x96, ...)
    /home/robfig/FrameworkBenchmarks/revel/src/github.com/eaigner/jet/mapper.go:81 +0x35f
github.com/eaigner/jet.mapper.unpackStruct(0xc20060e680, 0x0, 0x0, 0x74c460, 0xc200177290, ...)
    /home/robfig/FrameworkBenchmarks/revel/src/github.com/eaigner/jet/mapper.go:53 +0x1f8
github.com/eaigner/jet.mapper.unpackValue(0xc20060e680, 0x0, 0x0, 0x74c460, 0xc200177290, ...)
    /home/robfig/FrameworkBenchmarks/revel/src/github.com/eaigner/jet/mapper.go:27 +0x4d0
github.com/eaigner/jet.mapper.unpackValue(0xc20060e680, 0x0, 0x0, 0x6957a0, 0xc200177290, ...)
    /home/robfig/FrameworkBenchmarks/revel/src/github.com/eaigner/jet/mapper.go:25 +0x116
github.com/eaigner/jet.mapper.unpack(0xc20060e680, 0x0, 0x0, 0x6957a0, 0xc200177290, ...)
    /home/robfig/FrameworkBenchmarks/revel/src/github.com/eaigner/jet/mapper.go:19 +0x1a6
github.com/eaigner/jet.(*runner).Rows(0xc200180f80, 0x6957a0, 0xc200177290, 0x0, 0x0, ...)
    /home/robfig/FrameworkBenchmarks/revel/src/github.com/eaigner/jet/runner.go:74 +0x597
benchmark/app/controllers.func·002(0x4)
    /home/robfig/FrameworkBenchmarks/revel/src/benchmark/app/controllers/app.go:71 +0x131
created by benchmark/app/controllers.App.Db
    /home/robfig/FrameworkBenchmarks/revel/src/benchmark/app/controllers/app.go:76 +0x36b

[eaigner]

Ah infinite scrollback... should have thought of that :)

Spotted some other issues as well (e.g. &ww[i] should read &(ww[i])), but enough for today (it's already 3:26 AM).

[eaigner]

"presumably it treats all ints as int64, even though that's not allowed"

Jet uses the values as they come from the driver without cast. So actually it's the drivers fault, but I'll add the casting.

[robfig]

Ah. Unfortunately, I don't believe that MySQL returns such detailed type information. Although you may be directly selecting a value from a int64 column, that exact type is lost in the result set and all you get is "int", which has to be treated as int64 (I'm not sure if that implies a problem with uint64 columns that exceed int64's max value). I suppose one reason for that is because you can select an arithmetic expression, and expressions are not so exactly typed. So, I think that work really is necessary to work with MySQL, regardless of the driver. :~(

Also, &ww[i] is equivalent to &(ww[i])

Have a good night!

[eaigner]

I could swear that &ww[i] dereferences the slice itself and &(ww[i]) the element (I had issues with this sometime ago where the compiler complained about the return type when I just did &ww[i]). At least it was this way before Go 1.1.

[eaigner]

Well, I'll give up with trying to configure OSX for the tests (currently don't have the time to invest hours in this). I am running in limits everywhere (open files/conns).

What I will do is fix the int64 problem in Jet.

[eaigner]

Fixed the int64 conversion issue: https://github.com/eaigner/jet/commit/8d665fae536750cfbcf0171cb12520f73c759bfe

[robfig]

Nice, thanks. I also just pushed connection limiting: https://github.com/robfig/FrameworkBenchmarks/commit/2655f813f612d0b960c55da3e55ea06c257a90bf

and now I can successfully run the concurrency-256 query tests:

queries=1 - 6353 requests/sec queries=20 - 545 requests/sec

Those are from my linux workstation, but my Macbook Pro can run the benchmarks successfully as well (all of the client, server, MySQL). I guess the errors you are getting must be related to differences in MySQL configuration (I used theirs verbatim). (Note that I'm just talking about ad-hoc benchmarking with "wrk", not doing their real benchmarking script, which does not work on OSX)

For me, the update test deadlocks when making a single queries=1 request to it with curl, so I think there's a bug hiding out there.

Thanks for your hard work so far, and sorry that you're having a miserable time trying to run the benchmark!

[eaigner]

Yep. The update request also hung when I tried to send the request via the browser. Haven't investigated it though (but I don't think/hope it's Jet related).

[eaigner]

PS: That test results look strange. That's quite a performance loss.

Could you please run the QBS and Jet tests one after another (under similar system workload) for comparison? If it is really that bad, I need to optimize Jet.

I currently allow serializing columns to a map and using it as an intermediate type. I guess if I remove the map step, I could gain quite some performance.

[robfig]

I assume it must be, since there is nothing else going on than the Jet operations.

Also, this may help your ability to run tests; I found that the server-side fan-out was not actually helpful for performance, so I got rid of that (and the connection limiter).
https://github.com/robfig/FrameworkBenchmarks/tree/fanout

[robfig]

Yep, afraid Jet is pretty far behind QBS. Here are the detailed results, after merging the no-fanout change in to both. (These tests reflect what is at HEAD for each branch right now)

## QBS

Running 30s test @ http://localhost:8080/db?queries=1
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    25.13ms   26.17ms 145.91ms   83.17%
    Req/Sec     4.91k   290.32     5.00k    91.58%
  303142 requests in 30.00s, 40.12MB read
Requests/sec:  10104.70
Transfer/sec:      1.34MB

Running 30s test @ http://localhost:8080/db?queries=20
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   261.72ms   54.91ms 431.13ms   73.72%
    Req/Sec     0.00      0.00     0.00    100.00%
  29109 requests in 30.01s, 20.70MB read
Requests/sec:    970.14
Transfer/sec:    706.30KB

## JET

Running 30s test @ http://localhost:8080/db?queries=1
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    40.80ms   13.13ms  90.16ms   70.10%
    Req/Sec     2.98k   140.52     3.00k    97.99%
  186749 requests in 30.00s, 24.72MB read
Requests/sec:   6224.28
Transfer/sec:    843.53KB

Running 30s test @ http://localhost:8080/db?queries=20
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   464.50ms  140.91ms 964.39ms   78.13%
    Req/Sec     0.00      0.00     0.00    100.00%
  16108 requests in 30.00s, 11.45MB read
Requests/sec:    536.92
Transfer/sec:    390.90KB

[eaigner]

Have already identified several performance bottlenecks. Will push it to QBS speeds. Up until now this wasn't my main concern. It's on! :)

[eaigner]

Could you run the QBS/Jet benches again please? Did some tuning.

[robfig]

(On a more powerful workstation than the last round, OSX)

## QBS

Making 250000 requests to http://localhost:8080/db?queries=1
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    17.60ms    5.09ms  37.76ms   84.65%
    Req/Sec     6.10k   318.90     7.00k    88.80%
  250004 requests in 18.35s, 33.09MB read
  Socket errors: connect 7, read 80, write 0, timeout 63
Requests/sec:  13624.76
Transfer/sec:      1.80MB

Making 25000 requests to http://localhost:8080/db?queries=20
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   235.59ms   56.79ms 340.23ms   86.69%
    Req/Sec     0.00      0.00     0.00    100.00%
  25000 requests in 24.59s, 17.77MB read
  Socket errors: connect 7, read 121, write 0, timeout 84
Requests/sec:   1016.74
Transfer/sec:    740.22KB

## JET

Making 250000 requests to http://localhost:8080/db?queries=1
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    25.94ms    5.71ms  58.53ms   92.55%
    Req/Sec     3.98k   150.64     4.00k    98.57%
  250000 requests in 26.65s, 33.09MB read
  Socket errors: connect 7, read 109, write 0, timeout 91
Requests/sec:   9379.91
Transfer/sec:      1.24MB

Making 25000 requests to http://localhost:8080/db?queries=20
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   330.58ms   82.61ms 424.45ms   91.58%
    Req/Sec     0.00      0.00     0.00    100.00%
  25000 requests in 35.02s, 17.77MB read
  Socket errors: connect 7, read 74, write 0, timeout 119
Requests/sec:    713.88
Transfer/sec:    519.74KB

[eaigner]

Will optimize further. Where QBS has the advantage, is that it only expects the input to be of a struct pointer slice type []*Type, while Jet tries to map to anything passed in.

[eaigner]

PS: Pushed another change that affects the performance of Run() calls. https://github.com/eaigner/jet/commit/722d823e4bd5194286e827a33af68133eb983e4f

[eaigner]

I also narrowed down the mysql hang. It's on this line in runner.go

rows, err := r.qo.Query(query, args...)

qo is the core lib sql.Db type. The same line on postgres works just fine.

[eaigner]

Seems like the mysql driver explicitly requires an Exec(query, args...) if no rows are returned. That fixes the hang.

[eaigner]

Alright. I think that's it. Fixed and tested MySql.

The only caveat with the mysql driver is, that calling Rows() on an insert or query that doesn't return rows, causes it to hang. So call Run() (or Rows(nil)) instead.

Further I benched mysql with 20 threads/connections, and 10.000.000 loops each. Here's the pprof output

  (pprof) top100
  Total: 1102 samples
  853  77.4%  77.4%      853  77.4% runtime.kevent
  64   5.8%  83.2%       83   7.5% sweepspan
  21   1.9%  85.1%       21   1.9% runtime.nanotime
  11   1.0%  86.1%      986  89.5% runtime.mallocgc
  9   0.8%  86.9%        9   0.8% runtime.casp
  8   0.7%  87.7%       23   2.1% runtime.makeslice
  7   0.6%  88.3%        7   0.6% runtime.memmove
  5   0.5%  88.7%        8   0.7% github.com/go-sql-driver/mysql.(*mysqlConn).readColumns
  4   0.4%  89.1%        4   0.4% itab
  4   0.4%  89.5%        8   0.7% reflect.(*structType).FieldByName
  4   0.4%  89.8%        4   0.4% runtime.markallocated
  4   0.4%  90.2%       10   0.9% scanblock
  3   0.3%  90.5%       10   0.9% github.com/go-sql-driver/mysql.(*mysqlConn).readPacket
  3   0.3%  90.7%        7   0.6% net.(*netFD).Write
  3   0.3%  91.0%        3   0.3% newdefer
  3   0.3%  91.3%        3   0.3% reflect.flag.mustBeAssignable
  3   0.3%  91.6%        3   0.3% runtime.markspan
  3   0.3%  91.8%        3   0.3% runtime.settype_flush
  2   0.2%  92.0%       23   2.1% MHeap_FreeLocked
  2   0.2%  92.2%        8   0.7% _/Users/eaigner/Go/src/github.com/eaigner/jet.(*db).Query
  2   0.2%  92.4%       54   4.9% _/Users/eaigner/Go/src/github.com/eaigner/jet.(*mapper).unpackValue
  2   0.2%  92.6%        8   0.7% database/sql.(*Rows).Close
  2   0.2%  92.7%       20   1.8% database/sql.(*Rows).Scan
  2   0.2%  92.9%        2   0.2% flushobjbuf
  2   0.2%  93.1%        8   0.7% gostringsize
  2   0.2%  93.3%        2   0.2% reflect.Value.Field
  2   0.2%  93.5%        4   0.4% reflect.valueInterface
  2   0.2%  93.6%       22   2.0% runtime.MCache_Alloc
  2   0.2%  93.8%        2   0.2% runtime.MHeap_LookupMaybe
  2   0.2%  94.0%       26   2.4% runtime.convT2E
  2   0.2%  94.2%        2   0.2% runtime.mach_semaphore_signal
  2   0.2%  94.4%        2   0.2% runtime.unmarkspan
  2   0.2%  94.6%        4   0.4% strconv.ParseInt
  2   0.2%  94.7%        2   0.2% strconv.ParseUint
  2   0.2%  94.9%        2   0.2% sync.(*Mutex).Unlock
  2   0.2%  95.1%        2   0.2% sync/atomic.AddUint32
  2   0.2%  95.3%        2   0.2% sync/atomic.CompareAndSwapUint32
  1   0.1%  95.4%       18   1.6% MCentral_Grow
  1   0.1%  95.5%       14   1.3% MHeap_AllocLocked

Either I'm doing it wrong, can't read the pprof output right, or there just isn't a method left to optimize.

What's also weird is, that the mysql driver returns string values for int rows, so I have to convert them using strconv. Not happy about that either.

[julienschmidt]

@eaigner I'm assuming you are scanning to interface{} and having a query without args? See https://github.com/go-sql-driver/mysql/issues/86 Use either prepared statements (explicitly or implicitly by having a query with at least 1 arg) which causes the driver to use the binary protocol in which case it returns an int64. Or just scan to an int var instead of interface{}

And what exactly caused the hang?

[robfig]

I find it challenging to pinpoint exactly what can be optimized by using pprof, myself. One possibility is that you're producing more garbage, and that's why the second-highest one is garbage collection. Also, I find the profiling on OSX shows me very different things than profiling on Linux -- maybe I'm doing it wrong, or there's something weird about it.

I do think QBS uses some tricks like caching prepared statements rather than preparing them every time. That doesn't appear to show up in your profile though.

Here's the results I got running Jet again -- no significant difference from last round.

Making 250000 requests to http://localhost:8080/db
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    25.87ms    5.37ms  53.91ms   91.40%
    Req/Sec     3.98k   168.64     4.00k    98.85%
  250000 requests in 26.63s, 33.09MB read
  Socket errors: connect 7, read 80, write 0, timeout 91
Requests/sec:   9388.58
Transfer/sec:      1.24MB

Making 25000 requests to http://localhost:8080/db?queries=20
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   338.93ms   75.60ms 439.36ms   89.83%
    Req/Sec     0.00      0.00     0.00    100.00%
  25000 requests in 35.34s, 17.77MB read
  Socket errors: connect 7, read 78, write 0, timeout 119
Requests/sec:    707.38
Transfer/sec:    515.01KB

[julienschmidt]

@robfig That might be caused by the new integrated net poller in Linux

If you want to avoid garbage using sql.RawBytes might be an option.

I think the driver is already very efficient in terms of produced garbage (compared to other drivers) but we try to push this even further in the next release (before Round 6). https://github.com/go-sql-driver/mysql/pull/71

[julienschmidt]

And yes, prepared statements should be cached somehow, LRU cache, something like a leaky buffer or at least a hashmap.

[eaigner]

As far I know QBS doesn't use statement caching (looked at the code). Basically it's just copy of hood with another name tag. That I am accumulating more garbage is quite possible. As I said, Jets unpacking is more flexible and doesn't assume a special type to be passed for writing columns, therefore the unpacking is a little more complex, whereas QBS unpacking code is about 1/3rd of Jet's I think.

[eaigner]

@JulienSchmidt thanks for the suggestions. I guess I'll give it another shot tomorrow and try some of those optimizations.

[eaigner]

Wanted to include a LRU first, but then optimized just for the most common case, which is running identical queries in a row with different arguments. Here's the patch https://github.com/eaigner/jet/commit/4486f24acc3e170de32d8527a62ae94147045e9f

It should provide at least a 2x speedup.

[eaigner]

Yet another improvement. I went ahead and implemented a simple map based LRU query statement cache. https://github.com/eaigner/jet/commit/52ed7d116996b0d36ff9fa415741f38dbfce5995

[eaigner]

Any noticeable gains in the benchmark times?

[robfig]

Huge!!

## QBS

Making 250000 requests to http://localhost:8080/db
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    18.83ms    5.25ms  45.69ms   81.96%
    Req/Sec     6.02k   176.77     7.00k    96.86%
  250008 requests in 19.38s, 33.09MB read
  Socket errors: connect 7, read 76, write 0, timeout 63
Requests/sec:  12900.55
Transfer/sec:      1.71MB

Making 25000 requests to http://localhost:8080/db?queries=20
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   252.02ms   66.36ms 488.84ms   87.43%
    Req/Sec     0.00      0.00     0.00    100.00%
  25000 requests in 26.18s, 17.77MB read
  Socket errors: connect 7, read 84, write 0, timeout 91
Requests/sec:    955.02
Transfer/sec:    695.31KB

## JET

Making 250000 requests to http://localhost:8080/db
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    17.12ms    3.92ms  28.94ms   87.29%
    Req/Sec     6.61k   554.04     7.00k    63.56%
  250000 requests in 17.83s, 33.09MB read
  Socket errors: connect 7, read 91, write 0, timeout 56
Requests/sec:  14024.99
Transfer/sec:      1.86MB

Making 25000 requests to http://localhost:8080/db?queries=20
  2 threads and 256 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   209.38ms   56.32ms 375.61ms   85.71%
    Req/Sec     0.00      0.00     0.00    100.00%
  25000 requests in 21.93s, 17.78MB read
  Socket errors: connect 7, read 89, write 0, timeout 70
Requests/sec:   1140.14
Transfer/sec:    830.09KB