Skip to content

Instantly share code, notes, and snippets.

@methane
Last active August 29, 2015 14:12
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save methane/1341a204256e5dab52ac to your computer and use it in GitHub Desktop.
Save methane/1341a204256e5dab52ac to your computer and use it in GitHub Desktop.
Faster Stmt.css GC

Benchmarking large concurrent db access.

See here:

Environment

  • c3.8xlarge on same placement group (10Gbit Ethernet).
  • Amazon Linux (SR-IOV enabled)

Result

$ ./wrk -c128 -t8 http://localhost:8080/db
$ ./wrk -c256 -t8 http://localhost:8080/db

Run each command twice and take better result.

c128 req/sec c256 req/sec
default 68334.78 69599.49
multi db 159898.21 57539.94
sprintf 162323.89 70596.93
database/sql patched 140620.06 85945.47
hello: single db
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c128 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 128 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 1.88ms 1.64ms 27.16ms 77.59%
Req/Sec 9.01k 1.05k 12.78k 71.27%
681996 requests in 10.00s, 90.91MB read
Requests/sec: 68206.96
Transfer/sec: 9.09MB
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c128 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 128 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 1.87ms 1.62ms 15.02ms 71.75%
Req/Sec 9.02k 0.98k 13.56k 66.24%
683254 requests in 10.00s, 91.08MB read
Requests/sec: 68334.78
Transfer/sec: 9.11MB
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c256 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 256 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 3.66ms 3.42ms 37.08ms 74.25%
Req/Sec 9.07k 0.98k 14.00k 70.19%
695834 requests in 10.00s, 92.76MB read
Requests/sec: 69599.49
Transfer/sec: 9.28MB
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c256 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 256 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 3.63ms 3.53ms 203.99ms 83.56%
Req/Sec 9.08k 1.30k 15.18k 77.27%
693234 requests in 10.00s, 92.41MB read
Requests/sec: 69334.85
Transfer/sec: 9.24MB
hello: multi db
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c128 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 128 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 0.89ms 1.89ms 48.23ms 96.85%
Req/Sec 20.93k 4.42k 36.22k 70.66%
1582384 requests in 10.00s, 210.94MB read
Requests/sec: 158254.94
Transfer/sec: 21.10MB
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c128 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 128 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 793.94us 771.68us 12.34ms 87.84%
Req/Sec 21.11k 4.34k 36.89k 66.72%
1598890 requests in 10.00s, 213.14MB read
Requests/sec: 159898.21
Transfer/sec: 21.31MB
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c256 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 256 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 4.65ms 5.64ms 51.70ms 85.86%
Req/Sec 7.36k 2.35k 50.20k 90.09%
575303 requests in 10.00s, 76.69MB read
Requests/sec: 57539.94
Transfer/sec: 7.67MB
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c256 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 256 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 4.70ms 5.72ms 56.32ms 85.84%
Req/Sec 7.26k 2.02k 48.44k 87.15%
569666 requests in 10.00s, 75.94MB read
Requests/sec: 56975.60
Transfer/sec: 7.59MB
hello: sprintf
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c128 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 128 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 805.99us 1.08ms 31.85ms 93.71%
Req/Sec 21.31k 3.66k 34.00k 71.70%
1612551 requests in 10.00s, 214.96MB read
Requests/sec: 161269.11
Transfer/sec: 21.50MB
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c128 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 128 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 769.27us 667.82us 9.48ms 86.00%
Req/Sec 21.40k 3.46k 35.11k 69.26%
1623106 requests in 10.00s, 216.37MB read
Requests/sec: 162323.89
Transfer/sec: 21.64MB
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c256 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 256 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 3.90ms 4.73ms 46.34ms 85.55%
Req/Sec 8.65k 1.36k 34.28k 86.30%
673185 requests in 10.00s, 89.74MB read
Requests/sec: 67341.26
Transfer/sec: 8.98MB
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c256 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 256 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 3.80ms 4.64ms 45.44ms 85.72%
Req/Sec 8.97k 1.99k 38.44k 82.48%
705866 requests in 10.00s, 94.09MB read
Requests/sec: 70596.93
Transfer/sec: 9.41MB
hello: database/sql modified.
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c128 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 128 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 0.93ms 1.19ms 34.56ms 93.69%
Req/Sec 18.56k 2.79k 27.89k 72.77%
1404724 requests in 10.00s, 187.25MB read
Requests/sec: 140482.30
Transfer/sec: 18.73MB
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c128 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 128 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 0.89ms 709.55us 10.17ms 86.31%
Req/Sec 18.56k 2.54k 28.56k 68.91%
1406023 requests in 10.00s, 187.43MB read
Requests/sec: 140620.06
Transfer/sec: 18.75MB
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c256 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 256 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 3.46ms 4.44ms 56.11ms 86.51%
Req/Sec 10.71k 4.48k 35.56k 82.19%
829623 requests in 10.00s, 110.59MB read
Requests/sec: 82974.35
Transfer/sec: 11.06MB
[ec2-user@ip-10-0-1-151 wrk]$ ./wrk -c256 -t8 http://localhost:8080/db
Running 10s test @ http://localhost:8080/db
8 threads and 256 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 3.38ms 4.30ms 48.41ms 86.49%
Req/Sec 10.98k 4.47k 32.56k 79.26%
859321 requests in 10.00s, 114.55MB read
Requests/sec: 85945.47
Transfer/sec: 11.46MB
[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
# Disabling symbolic-links is recommended to prevent assorted security risks
symbolic-links=0
# Settings user and group are ignored when systemd is used.
# If you need to run mysqld under a different user or group,
# customize your systemd unit file for mysqld according to the
# instructions in http://fedoraproject.org/wiki/Systemd
max_allowed_packet=16MB
innodb_flush_log_at_trx_commit=0
innodb_doublewrite=0
max_connect_errors=999999999999
thread_cache_size = 128
max_connections = 5000
query_cache_type = 0
back_log = 5000
[mysqld_safe]
log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid
diff --git a/src/database/sql/sql.go b/src/database/sql/sql.go
index 8db9c78..861005f 100644
--- a/src/database/sql/sql.go
+++ b/src/database/sql/sql.go
@@ -217,6 +217,7 @@ type DB struct {
connRequests []chan connRequest
numOpen int
pendingOpens int
+ numClosed int64
// Used to signal the need for new connections
// a goroutine running connectionOpener() reads on this chan and
// maybeOpenNewConnections sends on the chan (one send per needed connection)
@@ -224,10 +225,13 @@ type DB struct {
// goroutine to exit.
openerCh chan struct{}
closed bool
- dep map[finalCloser]depSet
lastPut map[*driverConn]string // stacktrace of last conn's put; debug only
maxIdle int // zero means defaultMaxIdleConns; negative means 0
maxOpen int // <= 0 means unlimited
+
+ // Split from mu to avoid lock contention when using prepared statement in paralle.
+ depmu sync.Mutex
+ dep map[finalCloser]depSet
}
// driverConn wraps a driver.Conn with a mutex, to
@@ -246,7 +250,7 @@ type driverConn struct {
// guarded by db.mu
inUse bool
onPut []func() // code (with db.mu held) run when conn is next returned
- dbmuClosed bool // same as closed, but guarded by db.mu, for connIfFree
+ dbmuClosed bool // same as closed, but guarded by db.mu, for connStmt
}
func (dc *driverConn) releaseConn(err error) {
@@ -291,7 +295,7 @@ func (dc *driverConn) closeDBLocked() func() error {
return func() error { return errors.New("sql: duplicate driverConn close") }
}
dc.closed = true
- return dc.db.removeDepLocked(dc, dc)
+ return dc.db.removeDep(dc, dc)
}
func (dc *driverConn) Close() error {
@@ -306,7 +310,7 @@ func (dc *driverConn) Close() error {
// And now updates that require holding dc.mu.Lock.
dc.db.mu.Lock()
dc.dbmuClosed = true
- fn := dc.db.removeDepLocked(dc, dc)
+ fn := dc.db.removeDep(dc, dc)
dc.db.mu.Unlock()
return fn()
}
@@ -326,6 +330,7 @@ func (dc *driverConn) finalClose() error {
dc.db.mu.Lock()
dc.db.numOpen--
+ dc.db.numClosed++
dc.db.maybeOpenNewConnections()
dc.db.mu.Unlock()
@@ -361,12 +366,7 @@ type finalCloser interface {
// called until all of x's dependencies are removed with removeDep.
func (db *DB) addDep(x finalCloser, dep interface{}) {
//println(fmt.Sprintf("addDep(%T %p, %T %p)", x, x, dep, dep))
- db.mu.Lock()
- defer db.mu.Unlock()
- db.addDepLocked(x, dep)
-}
-
-func (db *DB) addDepLocked(x finalCloser, dep interface{}) {
+ db.depmu.Lock()
if db.dep == nil {
db.dep = make(map[finalCloser]depSet)
}
@@ -376,22 +376,16 @@ func (db *DB) addDepLocked(x finalCloser, dep interface{}) {
db.dep[x] = xdep
}
xdep[dep] = true
+ db.depmu.Unlock()
}
// removeDep notes that x no longer depends on dep.
-// If x still has dependencies, nil is returned.
-// If x no longer has any dependencies, its finalClose method will be
-// called and its error value will be returned.
-func (db *DB) removeDep(x finalCloser, dep interface{}) error {
- db.mu.Lock()
- fn := db.removeDepLocked(x, dep)
- db.mu.Unlock()
- return fn()
-}
-
-func (db *DB) removeDepLocked(x finalCloser, dep interface{}) func() error {
+// If x still has dependencies, empty function is returned.
+// If x no longer has any dependencies, its finalClose method is returned.
+func (db *DB) removeDep(x finalCloser, dep interface{}) func() error {
//println(fmt.Sprintf("removeDep(%T %p, %T %p)", x, x, dep, dep))
-
+ db.depmu.Lock()
+ defer db.depmu.Unlock()
xdep, ok := db.dep[x]
if !ok {
panic(fmt.Sprintf("unpaired removeDep: no deps for %T", x))
@@ -612,7 +606,7 @@ func (db *DB) openNewConnection() {
ci: ci,
}
if db.putConnDBLocked(dc, err) {
- db.addDepLocked(dc, dc)
+ db.addDep(dc, dc)
db.numOpen++
} else {
ci.Close()
@@ -672,7 +666,7 @@ func (db *DB) conn() (*driverConn, error) {
db: db,
ci: ci,
}
- db.addDepLocked(dc, dc)
+ db.addDep(dc, dc)
dc.inUse = true
db.mu.Unlock()
return dc, nil
@@ -683,42 +677,6 @@ var (
errConnBusy = errors.New("database/sql: internal sentinel error: conn is busy")
)
-// connIfFree returns (wanted, nil) if wanted is still a valid conn and
-// isn't in use.
-//
-// The error is errConnClosed if the connection if the requested connection
-// is invalid because it's been closed.
-//
-// The error is errConnBusy if the connection is in use.
-func (db *DB) connIfFree(wanted *driverConn) (*driverConn, error) {
- db.mu.Lock()
- defer db.mu.Unlock()
- if wanted.dbmuClosed {
- return nil, errConnClosed
- }
- if wanted.inUse {
- return nil, errConnBusy
- }
- idx := -1
- for ii, v := range db.freeConn {
- if v == wanted {
- idx = ii
- break
- }
- }
- if idx >= 0 {
- db.freeConn = append(db.freeConn[:idx], db.freeConn[idx+1:]...)
- wanted.inUse = true
- return wanted, nil
- }
- // TODO(bradfitz): shouldn't get here. After Go 1.1, change this to:
- // panic("connIfFree call requested a non-closed, non-busy, non-free conn")
- // Which passes all the tests, but I'm too paranoid to include this
- // late in Go 1.1.
- // Instead, treat it like a busy connection:
- return nil, errConnBusy
-}
-
// putConnHook is a hook for testing.
var putConnHook func(*DB, *driverConn)
@@ -855,10 +813,14 @@ func (db *DB) prepare(query string) (*Stmt, error) {
db.putConn(dc, err)
return nil, err
}
+ db.mu.Lock()
+ numClosed := db.numClosed
+ db.mu.Unlock()
stmt := &Stmt{
- db: db,
- query: query,
- css: []connStmt{{dc, si}},
+ db: db,
+ query: query,
+ css: []connStmt{{dc, si}},
+ lastNumClosed: numClosed,
}
db.addDep(stmt, stmt)
db.putConn(dc, nil)
@@ -1292,7 +1254,8 @@ type Stmt struct {
// that are valid on particular connections. This is only
// used if tx == nil and one is found that has idle
// connections. If tx != nil, txsi is always used.
- css []connStmt
+ css []connStmt
+ lastNumClosed int64
}
// Exec executes a prepared statement with the given arguments and
@@ -1372,27 +1335,24 @@ func (s *Stmt) connStmt() (ci *driverConn, releaseConn func(error), si driver.St
return ci, releaseConn, s.txsi.si, nil
}
- for i := 0; i < len(s.css); i++ {
- v := s.css[i]
- _, err := s.db.connIfFree(v.dc)
- if err == nil {
- s.mu.Unlock()
- return v.dc, v.dc.releaseConn, v.si, nil
- }
- if err == errConnClosed {
- // Lazily remove dead conn from our freelist.
- s.css[i] = s.css[len(s.css)-1]
- s.css = s.css[:len(s.css)-1]
- i--
+ // Lazily remove dead conn from our freelist.
+ s.db.mu.Lock()
+ dbClosed := s.db.numClosed
+ if dbClosed-s.lastNumClosed > int64(s.db.numOpen) {
+ j := 0
+ for i := 0; i < len(s.css); i++ {
+ v := s.css[i]
+ if !v.dc.dbmuClosed {
+ s.css[j] = v
+ j++
+ }
}
-
+ s.css = s.css[:j]
}
+ s.lastNumClosed = dbClosed
+ s.db.mu.Unlock()
s.mu.Unlock()
- // If all connections are busy, either wait for one to become available (if
- // we've already hit the maximum number of open connections) or create a
- // new one.
- //
// TODO(bradfitz): or always wait for one? make configurable later?
dc, err := s.db.conn()
if err != nil {
@@ -1454,7 +1414,7 @@ func (s *Stmt) Query(args ...interface{}) (*Rows, error) {
s.db.addDep(s, rows)
rows.releaseConn = func(err error) {
releaseConn(err)
- s.db.removeDep(s, rows)
+ s.db.removeDep(s, rows)()
}
return rows, nil
}
@@ -1534,7 +1494,7 @@ func (s *Stmt) Close() error {
}
s.mu.Unlock()
- return s.db.removeDep(s, s)
+ return s.db.removeDep(s, s)()
}
func (s *Stmt) finalClose() error {
(pprof) top20 [46/514]
52280ms of 86800ms total (60.23%)
Dropped 294 nodes (cum <= 434ms)
Showing top 20 nodes out of 125 (cum >= 500ms)
flat flat% sum% cum cum%
23060ms 26.57% 26.57% 24400ms 28.11% syscall.Syscall
6450ms 7.43% 34.00% 6450ms 7.43% runtime.epollwait
6050ms 6.97% 40.97% 6050ms 6.97% runtime.futex
2760ms 3.18% 44.15% 3070ms 3.54% runtime.mallocgc
1680ms 1.94% 46.08% 1680ms 1.94% scanblock
1400ms 1.61% 47.70% 1400ms 1.61% runtime.atomicload
1200ms 1.38% 49.08% 2340ms 2.70% database/sql.(*Stmt).connStmt
1110ms 1.28% 50.36% 1110ms 1.28% findrunnable
1000ms 1.15% 51.51% 1000ms 1.15% sync/atomic.CompareAndSwapUint32
970ms 1.12% 52.63% 970ms 1.12% runtime.MSpan_Sweep
970ms 1.12% 53.74% 970ms 1.12% sync/atomic.AddUint32
840ms 0.97% 54.71% 1550ms 1.79% runtime.deferreturn
720ms 0.83% 55.54% 720ms 0.83% runqgrab
670ms 0.77% 56.31% 730ms 0.84% runtime.mapiternext
610ms 0.7% 57.02% 610ms 0.7% ExternalCode
610ms 0.7% 57.72% 610ms 0.7% runtime.cas
610ms 0.7% 58.42% 1260ms 1.45% runtime.mapassign1
560ms 0.65% 59.07% 560ms 0.65% runtime.xchg
510ms 0.59% 59.65% 510ms 0.59% runtime.memmove
500ms 0.58% 60.23% 500ms 0.58% runtime.writebarrierptr
(pprof) list connStmt [21/514]
Total: 1.45mins
ROUTINE ======================== database/sql.(*Stmt).connStmt in /home/ec2-user/local/go/src/database/sql/sql.go
1.20s 2.34s (flat, cum) 2.70% of Total
. . 1312:
. . 1313:// connStmt returns a free driver connection on which to execute the
. . 1314:// statement, a function to call to release the connection, and a
. . 1315:// statement bound to that connection.
. . 1316:func (s *Stmt) connStmt() (ci *driverConn, releaseConn func(error), si driver.Stmt, err error) {
10ms 10ms 1317: if err = s.stickyErr; err != nil {
. . 1318: return
. . 1319: }
20ms 270ms 1320: s.mu.Lock()
. . 1321: if s.closed {
. . 1322: s.mu.Unlock()
. . 1323: err = errors.New("sql: statement is closed")
. . 1324: return
. . 1325: }
. . 1326:
. . 1327: // In a transaction, we always use the connection that the
. . 1328: // transaction was created on.
. . 1329: if s.tx != nil {
. . 1330: s.mu.Unlock()
. . 1331: ci, err = s.tx.grabConn() // blocks, waiting for the connection.
. . 1332: if err != nil {
. . 1333: return
. . 1334: }
. . 1335: releaseConn = func(error) {}
. . 1336: return ci, releaseConn, s.txsi.si, nil
. . 1337: }
. . 1338:
. . 1339: // Lazily remove dead conn from our freelist.
. 140ms 1340: s.db.mu.Lock()
20ms 20ms 1341: dbClosed := s.db.numClosed
. . 1342: if dbClosed-s.lastNumClosed > int64(s.db.numOpen) {
. . 1343: j := 0
. . 1344: for i := 0; i < len(s.css); i++ {
. . 1345: v := s.css[i]
. . 1346: if !v.dc.dbmuClosed {
. . 1347: s.css[j] = v
. . 1348: j++
. . 1349: }
. . 1350: }
. . 1351: s.css = s.css[:j]
. . 1352: }
. . 1353: s.lastNumClosed = dbClosed
. 40ms 1354: s.db.mu.Unlock()
. 80ms 1355: s.mu.Unlock()
. . 1356:
. . 1357: // TODO(bradfitz): or always wait for one? make configurable later?
. 360ms 1358: dc, err := s.db.conn()
. . 1359: if err != nil {
. . 1360: return nil, nil, nil, err
. . 1361: }
. . 1362:
. . 1363: // Do another pass over the list to see whether this statement has
. . 1364: // already been prepared on the connection assigned to us.
10ms 70ms 1365: s.mu.Lock()
930ms 930ms 1366: for _, v := range s.css {
210ms 210ms 1367: if v.dc == dc {
. 130ms 1368: s.mu.Unlock()
. 80ms 1369: return dc, dc.releaseConn, v.si, nil
. . 1370: }
. . 1371: }
. . 1372: s.mu.Unlock()
. . 1373:
. . 1374: // No luck; we need to prepare the statement on this connection
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment