[Trac-tickets] Re: [The Trac Project] #2170: Crash while doing a login/logout in the Timeline

[The Trac Project]

#2170: Crash while doing a login/logout in the Timeline
----------------------+-----------------------------------------------------
 Reporter:  cboos     |        Owner:  cboos   
     Type:  defect    |       Status:  assigned
 Priority:  high      |    Milestone:  0.9     
Component:  general   |      Version:  devel   
 Severity:  critical  |   Resolution:          
 Keywords:            |  
----------------------+-----------------------------------------------------
Changes (by cboos):

  * status:  new => assigned
  * owner:  jonas => cboos

Old description:

> This is somehow reproductible, though I got slightly different stack
> traces
> each time.
> But it always bombs in `connection_commit`, though.
>
> Configuration:
>  * tracd on Linux
>  * python 2.3.4
>  * pysqlite 2.0.4 with sqlite 3.2.7.
>
> With older versions of pysqlite, I got simply dead-locks, but this was
> not a good thing either...
>
> Here's the stack trace:
> {{{
> dserver.bct.de - - [04/Oct/2005 15:59:05] "GET /stable-bct-trac/login
> HTTP/1.1" 401 -
> [New Thread 557091 (LWP 12565)]
> Trac[session] DEBUG: Promoting anonymous session 90d7a758b262bd4e88eced41
> to authenticated session for user cboos
>
> Program received signal SIGSEGV, Segmentation fault.
> [Switching to Thread 557091 (LWP 12565)]
> 0x40582056 in pysqlite_sleep (seconds=-21474836.48) at src/util.c:37
> 37          Py_DECREF(ret);
> (gdb)
> (gdb)
> (gdb) bt
> #0  0x40582056 in pysqlite_sleep (seconds=-21474836.48) at src/util.c:37
> #1  0x4058222d in _sqlite_step_with_busyhandler (statement=0x8550dc8,
> _connection=0x4084e988) at src/util.c:86
> #2  0x4057d940 in connection_commit (self=0x4084e988, args=0x0) at
> src/connection.c:230
> #3  0x080c0c42 in call_function (pp_stack=0x45363450, oparg=0) at
> Python/ceval.c:3425
> #4  0x080bd5d4 in eval_frame (f=0x844ee8c) at Python/ceval.c:2116
> #5  0x080c102c in fast_function (func=0x40839e44, pp_stack=0x453635d0,
> n=2, na=2, nk=0) at Python/ceval.c:3518
> #6  0x080c0e46 in call_function (pp_stack=0x453635d0, oparg=1) at
> Python/ceval.c:3458
> #7  0x080bd5d4 in eval_frame (f=0x84b675c) at Python/ceval.c:2116
> ...
> }}}
>
> pyframe points to `_do_login`, in source:trunk/trac/web/auth.py at 2326#L119

New description:

 This is somehow reproductible, though I got slightly different stack
 traces

 each time.
 But it always bombs in `connection_commit`, though.

 Configuration:
  * tracd on Linux
  * python 2.3.4
  * pysqlite 2.0.4 with sqlite 3.2.7.

 With older versions of pysqlite, I got simply dead-locks, but this was
 not a good thing either...

 Here's the stack trace:
 {{{
 dserver.bct.de - - [04/Oct/2005 15:59:05] "GET /stable-bct-trac/login
 HTTP/1.1" 401 -
 [New Thread 557091 (LWP 12565)]
 Trac[session] DEBUG: Promoting anonymous session 90d7a758b262bd4e88eced41
 to authenticated session for user cboos

 Program received signal SIGSEGV, Segmentation fault.
 [Switching to Thread 557091 (LWP 12565)]
 0x40582056 in pysqlite_sleep (seconds=-21474836.48) at src/util.c:37
 37          Py_DECREF(ret);
 (gdb)
 (gdb)
 (gdb) bt
 #0  0x40582056 in pysqlite_sleep (seconds=-21474836.48) at src/util.c:37
 #1  0x4058222d in _sqlite_step_with_busyhandler (statement=0x8550dc8,
 _connection=0x4084e988) at src/util.c:86
 #2  0x4057d940 in connection_commit (self=0x4084e988, args=0x0) at
 src/connection.c:230
 #3  0x080c0c42 in call_function (pp_stack=0x45363450, oparg=0) at
 Python/ceval.c:3425
 #4  0x080bd5d4 in eval_frame (f=0x844ee8c) at Python/ceval.c:2116
 #5  0x080c102c in fast_function (func=0x40839e44, pp_stack=0x453635d0,
 n=2, na=2, nk=0) at Python/ceval.c:3518
 #6  0x080c0e46 in call_function (pp_stack=0x453635d0, oparg=1) at
 Python/ceval.c:3458
 #7  0x080bd5d4 in eval_frame (f=0x84b675c) at Python/ceval.c:2116
 ...
 }}}

 pyframe points to `_do_login`, in source:trunk/trac/web/auth.py at 2326#L119

Comment:

 I just filled [http://initd.org/tracker/pysqlite/ticket/124
 pysqlite:ticket:124],
 which contains some additional explanations about the issue: in short, we
 have to use 10 and not 10000 for the timeout value when using pysqlite2:
 {{{
 #!diff
 Index: db.py
 ===================================================================
 --- db.py       (revision 2326)
 +++ db.py       (working copy)
 @@ -254,8 +254,8 @@
                                   'directory it is located in.' \
                                   % (getuser(), path)

 -        timeout = int(params.get('timeout', 10000))
          if have_pysqlite == 2:
 +            timeout = int(params.get('timeout', 10)) # 10 seconds
              # Convert unicode to UTF-8 bytestrings. This is case-
 sensitive, so
              # we need two converters
              sqlite.register_converter('text', str)
 @@ -264,6 +264,7 @@
              cnx = sqlite.connect(path,
 detect_types=sqlite.PARSE_DECLTYPES,
                                   check_same_thread=False,
 timeout=timeout)
          else:
 +            timeout = int(params.get('timeout', 10000)) # 10 seconds
              cnx = sqlite.connect(path, timeout=timeout)
          ConnectionWrapper.__init__(self, cnx)
 }}}

-- 
Ticket URL: <http://projects.edgewall.com/trac/ticket/2170>
The Trac Project <http://trac.edgewall.com/>