fatal error: malloc/free - deadlock under high concurrency using same DB handle

[GoogleCodeExporter]

What steps will reproduce the problem?
1. Create a single sql.DB handle (db) with sql.Open("odbc", connectionString) 
using the odbc driver
2. Call db.SetMaxIdleConns(0) on the DB handle to disable pooling idle 
connections
3. Spawn a bunch of goroutines querying the DB (with db.Query(someSelectQuery)) 
using the DB handle
4. Observe that eventually the following error is thrown and program is exited
fatal error: malloc/free - deadlock
[signal 0xc0000005 code=0x1 addr=0x2f0 pc=0x41c298]

What is the expected output? What do you see instead?
No deadlocks should happen under high load.

What version of the product are you using? On what operating system?
Go1.1.1 x86 on Windows XP (32-bit)
Remote SQL Server 2000 on Windows Server 2003

Please provide any additional information below.
If I increase the idle pooling size using db.SetMaxIdleConns() to a higher 
number, the program can handle higher number of concurrent users without 
crashing.

Pooling Size, Concurrent User, Crash Time
0, ~18 reqs/s, within 1 minute
50, ~18 reqs/s, can not observe the issue with 10+ hours of runtime

Stack traces attached, all the instance of errors are happening on the call 
stack of code.google.com/p/odbc.(*Stmt).Close() inside 
database/sql.(*DB).queryConn()

Original issue reported on code.google.com by Benny.T...@gmail.com on 18 Jul 2013 at 4:23

Attachments:

• st1.txt
• st2.txt
• st3.txt

[GoogleCodeExporter]

Benny,

Thank you for report. I will investigate it, but I am quite busy right now. If 
you could provide a SMALL program that I can run here to reproduce your issue, 
it would be very helpfull. Something that uses as little of other code as 
possible (no network, no net/http).

Thank you.

Alex

Original comment by alex.bra...@gmail.com on 19 Jul 2013 at 1:48

[GoogleCodeExporter]

The sample program attached mimics the repro steps, but I can't seem to 
reproduce this issue on go1.1.1 64-bit on Windows 7.

I will try the same program when I get back to work to see if I can repro the 
same issue on the 32-bit machine with this issue.

Original comment by Benny.T...@gmail.com on 19 Jul 2013 at 1:21

Attachments:

• repro.go

[GoogleCodeExporter]

Turn out the issue has nothing to do with concurrency but with the reusing of 
the same DB handle under error condition.

precondition:
the query has a chance to / will return error from rowsiFromStatement(ds, 
args...) inside queryConn() in database/sql/sql.go (Line 759: si.Close() is 
executed)

error thrown when SetMaxIdleConns(0) is called:
fatal error: malloc/free - deadlock
[signal 0xc0000005 code=0x1 addr=0x2f0 pc=0x4193b8]

goroutine 1 [syscall]:
[fp=0x30e914c4] return()
        C:/Users/ADMINI~1/AppData/Local/Temp/2/bindist934530519/go/src/pkg/runtime/asm_386.s:472
[fp=0x30e914ec] runtime.cgocall(0x41d890, 0x30e914f4)
        C:/Users/ADMINI~1/AppData/Local/Temp/2/bindist934530519/go/src/pkg/runtime/cgocall.c:162 +0x10a
[fp=0x30e91510] syscall.Syscall(0x73563800, 0x2, 0x3, 0x31041dd0, 0x0, ...)
        C:/Users/ADMINI~1/AppData/Local/Temp/2/bindist934530519/go/src/pkg/runtime/zsyscall_windows_windows_386.c:74 +0x49
[fp=0x30e91534] code.google.com/p/odbc/api.SQLFreeHandle(0x480003, 0x31041dd0, 
0x31041dd0)
        C:/Documents and Settings/bennyng/go/src/code.google.com/p/odbc/api/zapi_windows.go:101 +0x57
[fp=0x30e9157c] code.google.com/p/odbc.releaseHandle(0x48b520, 0x31041dd0, 
0x420e7f, 0x0)
        C:/Documents and Settings/bennyng/go/src/code.google.com/p/odbc/handle.go:35 +0x4f
[fp=0x30e91590] code.google.com/p/odbc.(*ODBCStmt).releaseHandle(0x10e8a450, 
0x10e97ca0, 0x0)
        C:/Documents and Settings/bennyng/go/src/code.google.com/p/odbc/odbcstmt.go:90 +0x39
[fp=0x30e915a8] code.google.com/p/odbc.(*ODBCStmt).closeByStmt(0x10e8a450, 0x0, 
0x0)
        C:/Documents and Settings/bennyng/go/src/code.google.com/p/odbc/odbcstmt.go:63 +0xae
[fp=0x30e915c8] code.google.com/p/odbc.(*Stmt).Close(0x10e97bc0, 0x10e97c20, 
0x10e8a480)
        C:/Documents and Settings/bennyng/go/src/code.google.com/p/odbc/stmt.go:40 +0xa6
[fp=0x30e91644] database/sql.(*DB).queryConn(0x10e873c0, 0x10e8a420, 
0x10e8b250, 0x4c99e8, 0x3f, ...)
        C:/Users/ADMINI~1/AppData/Local/Temp/2/bindist934530519/go/src/pkg/database/sql/sql.go:759 +0x333
[fp=0x30e9167c] database/sql.(*DB).query(0x10e873c0, 0x4c99e8, 0x3f, 0x0, 0x0, 
...)
        C:/Users/ADMINI~1/AppData/Local/Temp/2/bindist934530519/go/src/pkg/database/sql/sql.go:715 +0xe3
[fp=0x30e916b4] database/sql.(*DB).Query(0x10e873c0, 0x4c99e8, 0x3f, 0x0, 0x0, 
...)
        C:/Users/ADMINI~1/AppData/Local/Temp/2/bindist934530519/go/src/pkg/database/sql/sql.go:699 +0x6b
[fp=0x30e91748] main.request()
        C:/Documents and Settings/bennyng/go/src/repro/repro.go:21 +0x44
[fp=0x30e917c4] main.main()
        C:/Documents and Settings/bennyng/go/src/repro/repro.go:47 +0x1b7
[fp=0x30e917dc] runtime.main()
        C:/Users/ADMINI~1/AppData/Local/Temp/2/bindist934530519/go/src/pkg/runtime/proc.c:182 +0x8e
[fp=0x30e917e0] runtime.goexit()
        C:/Users/ADMINI~1/AppData/Local/Temp/2/bindist934530519/go/src/pkg/runtime/proc.c:1223

error thrown when SetMaxIdleConns(0) is NOT called:
2013/07/22 11:44:04 SQLExecute: {42S02} [Microsoft][ODBC SQL Server Driver][SQL 
Server]Invalid object name 'table_not_exist'.
{42000} [Microsoft][ODBC SQL Server Driver][SQL Server]Statement(s) could not 
be prepared.
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xc0000005 code=0x0 addr=0x10 pc=0x42a770]

goroutine 1 [running]:
database/sql.(*Rows).Next(0x0, 0x10e601e8)
        C:/Users/ADMINI~1/AppData/Local/Temp/2/bindist934530519/go/src/pkg/database/sql/sql.go:1301 +0x20
main.request()
        C:/Documents and Settings/bennyng/go/src/repro/repro.go:27 +0xd6
main.main()
        C:/Documents and Settings/bennyng/go/src/repro/repro.go:47 +0x1b7

Under both cases (whether SetMaxIdleConns(0) is called or not) the program is 
halted.

A new repro is attached to reflect the issue.

Original comment by Benny.T...@gmail.com on 22 Jul 2013 at 3:44

Attachments:

• repro2.go

[GoogleCodeExporter]

There is an error in repro2.go that I have not return when db.Query() returns 
an err.

repro3.go fixed the error and the program no longer halt when 
SetMaxIdleConns(0) is NOT called. (Instead the program just log the error and 
carry on)

When SetMaxIdleConns(0) is called, the program still halt with the malloc/free 
- deadlock error.

Original comment by Benny.T...@gmail.com on 22 Jul 2013 at 3:58

Attachments:

• repro3.go

[GoogleCodeExporter]

I can reproduce it now. Thank you.

Alex

Original comment by alex.bra...@gmail.com on 22 Jul 2013 at 4:29

[GoogleCodeExporter]

Benny,

I think the problem is in database/sql. I submitted an issue 
https://code.google.com/p/go/issues/detail?id=5936 and a fix 
https://codereview.appspot.com/11620046. Hopefully I am correct, and it will 
get submitted. Please, test my proposed fix against your program and report 
here. Thank you.

Alex

Original comment by alex.bra...@gmail.com on 23 Jul 2013 at 1:33

• Changed state: Started

[GoogleCodeExporter]

Alex,

The patch fixed the problem, the program now log the error instead of throwing 
the fatal error even when SetMaxIdleConns(0) is called. Thanks!

Original comment by Benny.T...@gmail.com on 23 Jul 2013 at 2:34

[GoogleCodeExporter]

Cool. We will wait for the change to get submitted then.

Alex

Original comment by alex.bra...@gmail.com on 23 Jul 2013 at 2:38

[GoogleCodeExporter]

We are done https://code.google.com/p/go/source/detail?r=a86c5dc7e7e9

Thanks for your help.

Alex

Original comment by alex.bra...@gmail.com on 23 Jul 2013 at 4:11

• Changed state: Fixed