[Aptitude-devel] Aptitude History Tracking progress report, Week 6

[Daniel Burrows]

On Wed, Jul 08, 2009 at 08:42:27AM -0700, Daniel Burrows <dburrows at debian.org> was heard to say:
>   I tried running an upgrade with this version of aptitude and then
> checking the history of one of the upgraded packages.  "aptitude
> history" crashed with a segmentation fault.  I tried running it as root,
> just to see whether maybe there was a permissions problem, and it
> crashed with a glibc invalid free() error.  When I run the GUI, it
> crashes on start-up.  Also, the text history file that aptitude
> generated is empty.

  I tried one more test.  If I run the GUI as root, it starts correctly,
but I get the invalid free() crash when I try to actually view the
history tab.  So it looks like there are two bugs: the program is
crashing when it tries to read the log database if it isn't root, and
once it does read the database, it crashes when it tries to actually use
that information.

  It looks like the problem in the non-root case is that the text log
code unconditionally opens the file for writing, even if you're only
planning to read from it.  At a high level, I don't think it makes sense
at all to have a class to represent the text log file: you just need one
function to read it into a vector of entries, and another function to
append to it from a vector of entries.  But even within the current
design, you could work around this by just only initializing a log file
when you're about to write it to disk.

  Also, it should go without saying that you need to handle error
conditions from fopen().  They're currently being detected in
log_initialize(), but the other functions don't handle the fact that
this leaves the object in an invalid state (something that wouldn't be a
problem if you weren't using a stateful object here...)


  According to valgrind, the invalid free happens when you invoke
sqlite3_free() on a stack address:

==7224== Invalid free() / delete / delete[]
==7224==    at 0x4024E3A: free (vg_replace_malloc.c:323)
==7224==    by 0x461341F: (within /usr/lib/libsqlite3.so.0.8.6)
==7224==    by 0x45A6533: sqlite3_free (in /usr/lib/libsqlite3.so.0.8.6)
==7224==    by 0x8412D1D: aptitude::history::database::get_history_from_history_entries(std::vector<aptitude::history::entry, std::allocator<aptitude::history::entry> >&, std::string) (database.cc:417)
==7224==    by 0x828B38D: do_cmdline_show_history_package(std::string, int) (cmdline_history.cc:61)
==7224==    by 0x828BACF: do_cmdline_show_history(std::string, int) (cmdline_history.cc:130)
==7224==    by 0x828BBCC: cmdline_history(int, char**, int) (cmdline_history.cc:149)
==7224==    by 0x80799CB: main (main.cc:1006)
==7224==  Address 0xbe9f5124 is on thread 1's stack

  This is because you free database::zErrMsg, which is stack-allocated
since your database object itself is stack-allocated:

      if(rc != SQLITE_OK)
      {
        fprintf(stderr, "SQL error: %s\n", zErrMsg);
        sqlite3_free(&zErrMsg);
        sqlite3_close(db);
        return false;
      }

  Obviously this would have been wrong, just in a different way, if
the database object was heap-allocated.

  I have fixed these cases for you.  I still don't get output from
"aptitude history" because the database is empty:

$ sqlite3 /var/lib/aptitude/history.db 
SQLite version 3.6.13
Enter ".help" for instructions
Enter SQL statements terminated with a ";"
sqlite> .tables
sqlite> .quit

  It looks to me like there are no "commit" statements anywhere in the
code, so this is expected.  Am I missing something obvious here?


  I also still get an invalid free() after I fixed the way zErrMsg was
being used.  After looking over the sqlite3 docs, it looks like I made
an incorrect assumption: I assumed that because it was called an error
message, you were passing it in a parameter that was reserved for use as
an error message.  Instead, you were passing it in places that return
random strings, and moreover places that return strings which are not
newly allocated and hence shouldn't be freed!  In fact, no overload of
sqlite3_prepare() takes an error out parameter.

  I have further changed the code to never invoke sqlite3_free() in this
case.  However, this will not fix the error reporting.  It looks like
you should invoke sqlite3_errmsg() to retrieve the most recent error
message:

http://www.sqlite.org/c3ref/errcode.html

  Note that (from the above page):

    Memory to hold the error message string is managed internally. The
    application does not need to worry about freeing the result.
    However, the error string might be overwritten or deallocated by
    subsequent calls to other SQLite interface functions.

  I've tweaked the code for you so I can see error messages like this:

SQL error: no such table: history_entries
Package: mercurial



  Two notes about zErrMsg:

    (1) You should probably be allocating zErrMsg (ew, Hungarian) as
        a local variable; it has no need to be class-scoped, so making
        it class-scoped just invites trouble (leaks from one method to
        another, concurrency/reetrancy issues, etc).
    (2) It might be good to write a small wrapper class for this sort of
        pointer that handles the freeing in its destructor -- that way
        you don't have to worry about forgetting to free it, about
        exceptions, etc.  e.g., something like this:

template<typename T>
class sqlite_ptr_wrapper
{
  T *val;

public:
  sqlite_ptr_wrapper(T *_val) : val(_val) { }

  operator T*() { return val; }
  operator const T*() const { return val; }

  ~sqlite_ptr_wrapper() { sqlite3_free((void*)val); }
};

  Then you could change the type of zErrMsg to sqlite_ptr_wrapper<char>
and everything should work automatically.

  Disclaimer: I just wrote this code inline and I have not tested it.
If you use it, you should test it to make sure it works.

  I also noticed that the unit tests don't link in your branch -- you
probably need to add the history library to the link line (LDADD).


  OK, I really need to get to work.

    Later,
  Daniel