Skip to content
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

Don't spawn interrupt goroutine if we know that context cannot be canceled #530

Merged
merged 1 commit into from
Feb 18, 2018

Conversation

navytux
Copy link
Contributor

@navytux navytux commented Feb 16, 2018

For a Go-only project the following code pattern

go func() {
	select {
	case <-ctx.Done():
		// call some cancel

	case <-done:
		// work finished ok
	}
}()

// do some work
close(done)

works good and fast - without high scheduling overhead because scheduler
usually puts spawned goroutine into run queue on the same OS thread and so
after done is closed control is passed to spawned goroutine without OS context
switch.

However in the presence of Cgo calls in "do some work" the situation can
become different - Cgo calls are treated by go runtime similarly to
system calls with the effect that goroutines spawned on original OS
thread tend to be migrated by scheduler to be executed on another OS
thread.

This in turn can bring high overhead for communicating on "done", which
ultimately can result in full context switch: if the spawned goroutine
had chance to run, already checked done and ctx to be not ready, and went
into sleep via wait on futex - showing as something like below in strace for
one read query (note futex calls):

27867 00:38:39.782146 stat(".../neo.sqlite-journal", 0x7f83809c4a20) = -1 ENOENT (No such file or directory)
27867 00:38:39.782165 pread64(3, "\0\0\0\33\0\0\10\235\0\0\10]\0\0\0\27", 16, 24) = 16
27871 00:38:39.782179 <... pselect6 resumed> ) = 0 (Timeout)
27868 00:38:39.782187 <... pselect6 resumed> ) = 0 (Timeout)
27871 00:38:39.782193 futex(0xc4200f8538, FUTEX_WAIT, 0, NULL <unfinished ...>
27868 00:38:39.782199 futex(0xc420013138, FUTEX_WAIT, 0, NULL <unfinished ...>
27867 00:38:39.782205 stat(".../neo.sqlite-wal", 0x7f83809c4a20) = -1 ENOENT (No such file or directory)
27867 00:38:39.782224 fstat(3, {st_mode=S_IFREG|0644, st_size=9031680, ...}) = 0
27867 00:38:39.782247 futex(0xc420013138, FUTEX_WAKE, 1 <unfinished ...>
27868 00:38:39.782259 <... futex resumed> ) = 0
27867 00:38:39.782265 <... futex resumed> ) = 1
27868 00:38:39.782270 pselect6(0, NULL, NULL, NULL, {tv_sec=0, tv_nsec=3000}, NULL <unfinished ...>
27867 00:38:39.782279 fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
27867 00:38:39.782315 fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
27868 00:38:39.782336 <... pselect6 resumed> ) = 0 (Timeout)
27867 00:38:39.782342 fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510} <unfinished ...>
27868 00:38:39.782348 futex(0xc4200f8538, FUTEX_WAKE, 1 <unfinished ...>
27867 00:38:39.782355 <... fcntl resumed> ) = 0
27871 00:38:39.782360 <... futex resumed> ) = 0
27868 00:38:39.782367 <... futex resumed> ) = 1
27871 00:38:39.782372 futex(0xc4200f8138, FUTEX_WAKE, 1 <unfinished ...>
27868 00:38:39.782377 pselect6(0, NULL, NULL, NULL, {tv_sec=0, tv_nsec=3000}, NULL <unfinished ...>
27871 00:38:39.782384 <... futex resumed> ) = 1
27870 00:38:39.782389 <... futex resumed> ) = 0
27867 00:38:39.782394 fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1} <unfinished ...>
27870 00:38:39.782400 pselect6(0, NULL, NULL, NULL, {tv_sec=0, tv_nsec=3000}, NULL <unfinished ...>
27867 00:38:39.782408 <... fcntl resumed> ) = 0

Below link shows that go scheduler itself might be significantly improved for
cases when there are several Cgo calls made for a request in a server:

golang/go#21827 (comment)

in particular CGo-4 case should be closely related to this sqlite3 go package,
because for one query many CGo calls are made to SQLite.

However until there are proper scheduler fixes, let's make what could
be made to improve time to do queries:

If we know that the context under which a query is executed will never
be canceled - we know we can safely skip spawning the interrupt
goroutine and this was avoid ping-pong on done in between different OS
threads.

This brings the following speedup on my notebook with go1.10:

    name               old req/s    new req/s    delta
    Exec                 254k ± 1%    379k ± 1%  +48.89%  (p=0.000 n=10+10)
    Query               90.6k ± 2%   96.4k ± 1%   +6.37%  (p=0.000 n=10+10)
    Params              81.5k ± 1%   87.0k ± 1%   +6.83%  (p=0.000 n=10+10)
    Stmt                 122k ± 2%    129k ± 1%   +6.07%  (p=0.000 n=10+9)
    Rows                2.98k ± 1%   3.06k ± 1%   +2.77%  (p=0.000 n=9+10)
    StmtRows            3.10k ± 1%   3.13k ± 1%   +1.12%  (p=0.000 n=9+10)

    name               old time/op  new time/op  delta
    CustomFunctions-4  10.6µs ± 1%  10.1µs ± 1%   -5.01%  (p=0.000 n=10+10)

@navytux navytux changed the title Don't spawn interrupt goroutine if we know that context cannot be can… Don't spawn interrupt goroutine if we know that context cannot be canceled Feb 16, 2018
@coveralls
Copy link

coveralls commented Feb 16, 2018

Coverage Status

Coverage decreased (-0.2%) to 68.447% when pulling 00a23ba on navytux:y/no-go-if-notneeded into 788c147 on mattn:master.

@navytux
Copy link
Contributor Author

navytux commented Feb 16, 2018

( travis check fail is only because go1.7 build failed due to network timeout: https://travis-ci.org/mattn/go-sqlite3/jobs/342456198 )

sqlite3.go Outdated
go func(db *C.sqlite3) {
select {
case <-ctx.Done():
if ctx.Done() != context.Background().Done() {
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@navytux (I just came across this from the golang/go issue you linked it from). Looking at the stdlib, the correct check is simply ctx.Done() != nil. (See context.go).

Copy link
Owner

@mattn mattn Feb 17, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if ctxdone := ctx.Done(); ctxdone != nil {

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@tmthrgd, @mattn, thanks for feedback. Indeed it is even specified in Context documentation that

Done may return nil if this context can never be canceled.

(https://golang.org/pkg/context/#Context; I was probably under impression of ctx.Done() == context.Background().Done() checks I saw in stdlib earlier that were later fixed - e.g. in golang/go@b9dca1b1).

Code fixed to what mattn says.

sqlite3.go Outdated
select {
case <-ctx.Done():
Copy link
Owner

@mattn mattn Feb 17, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

case <-ctxdone:

defined in above.

sqlite3.go Outdated
select {
case <-done:
case <-ctx.Done():
if ctx.Done() != context.Background().Done() {
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ditto

sqlite3.go Outdated
select {
case <-done:
default:
C.sqlite3_interrupt(db)
case <-ctx.Done():
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

case <-ctxdone:

…celed

For a Go-only project the following code pattern

	go func() {
		select {
		case <-ctx.Done():
			// call some cancel

		case <-done:
			// work finished ok
		}
	}()

	// do some work
	close(done)

works good and fast - without high scheduling overhead because scheduler
usually puts spawned goroutine into run queue on the same OS thread and so
after done is closed control is passed to spawned goroutine without OS context
switch.

However in the presence of Cgo calls in "do some work" the situation can
become different - Cgo calls are treated by go runtime similarly to
system calls with the effect that goroutines spawned on original OS
thread tend to be migrated by scheduler to be executed on another OS
thread.

This in turn can bring high overhead for communicating on "done", which
ultimately can result in full context switch: if the spawned goroutine
had chance to run, already checked done and ctx to be not ready, and went
into sleep via wait on futex - showing as something like below in strace for
one read query (note futex calls):

	27867 00:38:39.782146 stat(".../neo.sqlite-journal", 0x7f83809c4a20) = -1 ENOENT (No such file or directory)
	27867 00:38:39.782165 pread64(3, "\0\0\0\33\0\0\10\235\0\0\10]\0\0\0\27", 16, 24) = 16
	27871 00:38:39.782179 <... pselect6 resumed> ) = 0 (Timeout)
	27868 00:38:39.782187 <... pselect6 resumed> ) = 0 (Timeout)
	27871 00:38:39.782193 futex(0xc4200f8538, FUTEX_WAIT, 0, NULL <unfinished ...>
	27868 00:38:39.782199 futex(0xc420013138, FUTEX_WAIT, 0, NULL <unfinished ...>
	27867 00:38:39.782205 stat(".../neo.sqlite-wal", 0x7f83809c4a20) = -1 ENOENT (No such file or directory)
	27867 00:38:39.782224 fstat(3, {st_mode=S_IFREG|0644, st_size=9031680, ...}) = 0
	27867 00:38:39.782247 futex(0xc420013138, FUTEX_WAKE, 1 <unfinished ...>
	27868 00:38:39.782259 <... futex resumed> ) = 0
	27867 00:38:39.782265 <... futex resumed> ) = 1
	27868 00:38:39.782270 pselect6(0, NULL, NULL, NULL, {tv_sec=0, tv_nsec=3000}, NULL <unfinished ...>
	27867 00:38:39.782279 fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
	27867 00:38:39.782315 fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
	27868 00:38:39.782336 <... pselect6 resumed> ) = 0 (Timeout)
	27867 00:38:39.782342 fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510} <unfinished ...>
	27868 00:38:39.782348 futex(0xc4200f8538, FUTEX_WAKE, 1 <unfinished ...>
	27867 00:38:39.782355 <... fcntl resumed> ) = 0
	27871 00:38:39.782360 <... futex resumed> ) = 0
	27868 00:38:39.782367 <... futex resumed> ) = 1
	27871 00:38:39.782372 futex(0xc4200f8138, FUTEX_WAKE, 1 <unfinished ...>
	27868 00:38:39.782377 pselect6(0, NULL, NULL, NULL, {tv_sec=0, tv_nsec=3000}, NULL <unfinished ...>
	27871 00:38:39.782384 <... futex resumed> ) = 1
	27870 00:38:39.782389 <... futex resumed> ) = 0
	27867 00:38:39.782394 fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1} <unfinished ...>
	27870 00:38:39.782400 pselect6(0, NULL, NULL, NULL, {tv_sec=0, tv_nsec=3000}, NULL <unfinished ...>
	27867 00:38:39.782408 <... fcntl resumed> ) = 0

Below link shows that go scheduler itself might be significantly improved for
cases when there are several Cgo calls made for a request in a server:

golang/go#21827 (comment)

in particular CGo-4 case should be closely related to this sqlite3 go package,
because for one query many CGo calls are made to SQLite.

However until there are proper scheduler fixes, let's make what could
be made to improve time to do queries:

If we know that the context under which a query is executed will never
be canceled - we know we can safely skip spawning the interrupt
goroutine and this was avoid ping-pong on done in between different OS
threads.

This brings the following speedup on my notebook with go1.10:

name               old req/s    new req/s    delta
Exec                 254k ± 1%    379k ± 1%  +48.89%  (p=0.000 n=10+10)
Query               90.6k ± 2%   96.4k ± 1%   +6.37%  (p=0.000 n=10+10)
Params              81.5k ± 1%   87.0k ± 1%   +6.83%  (p=0.000 n=10+10)
Stmt                 122k ± 2%    129k ± 1%   +6.07%  (p=0.000 n=10+9)
Rows                2.98k ± 1%   3.06k ± 1%   +2.77%  (p=0.000 n=9+10)
StmtRows            3.10k ± 1%   3.13k ± 1%   +1.12%  (p=0.000 n=9+10)

name               old time/op  new time/op  delta
CustomFunctions-4  10.6µs ± 1%  10.1µs ± 1%   -5.01%  (p=0.000 n=10+10)
@navytux navytux force-pushed the y/no-go-if-notneeded branch from f3a4cd4 to 00a23ba Compare February 17, 2018 18:10
@navytux
Copy link
Contributor Author

navytux commented Feb 17, 2018

Patch updated with the following interdiff:

--- a/sqlite3.go
+++ b/sqlite3.go
@@ -1123,10 +1123,10 @@ func (s *SQLiteStmt) query(ctx context.Context, args []namedValue) (driver.Rows,
                done:     make(chan struct{}),
        }
 
-       if ctx.Done() != context.Background().Done() {
+       if ctxdone := ctx.Done(); ctxdone != nil {
                go func(db *C.sqlite3) {
                        select {
-                       case <-ctx.Done():
+                       case <-ctxdone:
                                select {
                                case <-rows.done:
                                default:
@@ -1170,13 +1170,13 @@ func (s *SQLiteStmt) exec(ctx context.Context, args []namedValue) (driver.Result
                return nil, err
        }
 
-       if ctx.Done() != context.Background().Done() {
+       if ctxdone := ctx.Done(); ctxdone != nil {
                done := make(chan struct{})
                defer close(done)
                go func(db *C.sqlite3) {
                        select {
                        case <-done:
-                       case <-ctx.Done():
+                       case <-ctxdone:
                                select {
                                case <-done:
                                default:

@mattn
Copy link
Owner

mattn commented Feb 18, 2018

Thank you

@navytux
Copy link
Contributor Author

navytux commented Feb 18, 2018

Thanks for merging.

@navytux navytux deleted the y/no-go-if-notneeded branch February 18, 2018 13:23
navytux added a commit to navytux/gosqlite that referenced this pull request Feb 18, 2018
…andler if context cannot be canceled

Please see mattn/go-sqlite3#530 for similar
change. Here it is not additional goroutine but a callback setup which
will be called ever 100 ops. We can avoid that if we know that ctx
cannot be canceled.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants