| **** BEGIN LOGGING AT Wed Apr 7 17:08:25 2004 | ||
| -->You are now talking on #schooltool | 17:08 | |
| mgedmin | aargh, libxml2 returns UTF-8 strings instead of Unicode strings | 17:08 |
|---|---|---|
| SteveA | ugh | 17:38 |
| mgedmin | I'm currently composing a long email to all@pov.lt | 17:40 |
| SteveA | about? | 18:08 |
| mgedmin | charset troubles | 18:09 |
| mgedmin | I've sent it already | 18:09 |
| mgedmin | oh wow | 18:28 |
| mgedmin | make ftest just gave me | 18:28 |
| mgedmin | exceptions.AttributeError: 'NoneType' object has no attribute 'invalidate' | 18:28 |
| SteveA | yug | 18:28 |
| mgedmin | somewhere in ZODB code | 18:28 |
| mgedmin | this does not seem to be reproducible :/ | 18:28 |
| SteveA | oh | 18:29 |
| SteveA | hmm... | 18:29 |
| SteveA | what kind of thing is asked to invalidate? | 18:29 |
| mgedmin | None, apparently | 18:30 |
| SteveA | other than None | 18:31 |
| mgedmin | txn.commit() -> txn._cleanup() -> txn._finish_one() -> jar.tpc_finish() -> _storage.tpc_finish() -> f(self._tid) -> _db.invalidate(tid, d, self) -> exceptions.AttributeError | 18:31 |
| mgedmin | apparently it happened when creating a relationship (the fourth one) | 18:31 |
| mgedmin | I'll try running make ftest in a loop and see if it recurs | 18:32 |
| SteveA | _db... | 18:33 |
| SteveA | when is _db set to None? | 18:33 |
| mgedmin | is that a rhetorical question? | 18:34 |
| SteveA | no, an exploratory one | 18:37 |
| mgedmin | all I have in front of me is a rather terse traceback | 18:40 |
| mgedmin | unless I manage to reproduce the bug, I cannot answer such questions :( | 18:40 |
| SteveA | Connection.close | 18:42 |
| SteveA | that's it I think | 18:42 |
| mgedmin | I'm not following | 18:42 |
| SteveA | so, the connection was closed, before tp_finish | 18:43 |
| SteveA | so, the connection was closed, before tpc_finish | 18:43 |
| SteveA | are these multiple threads in effect? | 18:43 |
| SteveA | could be a race in the test | 18:43 |
| mgedmin | hmm | 18:44 |
| mgedmin | the test runner is single-threaded | 18:44 |
| mgedmin | and there shouldn't have been anything else accessing the server | 18:44 |
| mgedmin | besides it was a functional test | 18:46 |
| mgedmin | it was talking to the server over HTTP | 18:46 |
| mgedmin | the server opens a db connection for each thread | 18:47 |
| mgedmin | the traceback begins in src/schooltool/main.py, line 355, in _process | 18:47 |
| mgedmin | the bug is reproducible | 18:50 |
| mgedmin | on another machine | 18:50 |
| mgedmin | 1 failure in 32 runs | 18:51 |
| mgedmin | 2 failures in 34 runs | 18:52 |
| mgedmin | slightly different error message | 18:52 |
| mgedmin | the realtime log of this is in muskatas:/home/mg/schooltool/make-ftest-in-a-loop in case you're interested | 18:53 |
| mgedmin | 3 failures in 80 runs | 19:04 |
| mgedmin | instrumented test: 0 failures in 35 runs so far | 19:19 |
| mgedmin | instrumented test: 0 failures in 74 runs so far | 19:28 |
| SteveA | ah, the log filename changed | 19:31 |
| mgedmin | yes | 19:34 |
| mgedmin | 0 failures in 100 runs, I'm trying a different approach | 19:35 |
| SteveA | um | 19:35 |
| SteveA | so, getting a trackback in conection.close fixed the bug? | 19:35 |
| mgedmin | hid it at least | 19:35 |
| SteveA | oh | 19:35 |
| SteveA | that sucks | 19:35 |
| mgedmin | if it's a race condition, I expect that printing huge tracebacks changed the timings sufficiently | 19:35 |
| mgedmin | now I'm saving the stack trace in an attribute and only print it when self._db is None near the line where the original exception took place | 19:36 |
| mgedmin | let's see what happens | 19:36 |
| mgedmin | the log file is now make-ftest-in-a-loop-*-2 | 19:36 |
| mgedmin | (no stderr this time, oops) | 19:39 |
| mgedmin | grr | 19:52 |
| mgedmin | even the lightweight instrumentation version did not show any errors in 70 tries | 19:53 |
| <--SteveA has quit ("Client exiting") | 20:23 | |
| **** ENDING LOGGING AT Wed Apr 7 21:17:50 2004 | ||
Generated by irclog2html.py 2.15.1 by Marius Gedminas - find it at mg.pov.lt!