Recover from Zeitgeist database corruption (detected at query time)

[Martin Mrazik]

This is based on the checkbox test:
1. Start gedit.
2. Save a file named "foo" in your home folder.
1. Tap super to open the dash
2. Enter "f"
   -> The results should contain at least the "foo" file and "Firefox"
3. Click on the cross next to "f", in the textentry
   -> The "f" search should be canceled, bringing you back to the generic "Search" entry with the default elements

I slightly modified it and instead of file called foo I have a "hello_world_file" (as foo returned far too many other results).

Actual result:
The file can not be found via dash (or file lens).

ProblemType: Bug
DistroRelease: Ubuntu 12.04
Package: unity 5.6.0+bzr2156ubuntu0+670 [origin: LP-PPA-unity-team-staging]
ProcVersionSignature: Ubuntu 3.2.0-19.31-generic-pae 3.2.12
Uname: Linux 3.2.0-19-generic-pae i686
ApportVersion: 1.94.1-0ubuntu2
Architecture: i386
CompizPlugins: [core,composite,opengl,compiztoolbox,decor,vpswitch,snap,mousepoll,resize,place,move,wall,grid,regex,imgpng,session,gnomecompat,animation,fade,unitymtgrabhandles,workarounds,scale,expo,ezoom,unityshell]
CrashDB: unity
Date: Thu Mar 22 10:00:40 2012
InstallationMedia: Ubuntu 11.10 "Oneiric Ocelot" - Release i386 (20111012)
SourcePackage: unity
UpgradeStatus: Upgraded to precise on 2012-02-17 (33 days ago)

[Martin Mrazik (mrazik)]

It actually looks like the searching is completely broken. If I'm in a file lens and search for something nothing really happens. If I search for a specific file all the files from default view are still there.

[Ilya Flyamer (flyamer)]

The same problem, but Dash sees absolutely no files even without any searching (but sees music and videos! application search also works, thow it doesn't remember the usage and doesn't show the most used ones first).
Also I don't get a home screen, it is just empty, except for applications, previously found, which do not disappear.

[Michal Hruby (mhr3)]

@Ilya, although that sounds like a different issue, could you run `zeitgeist-daemon --replace --log-file zg.log --log-level=debug` and attach the log file to this bug?

[Ilya Flyamer (flyamer)]

@Michal, I'd be glad to, but I don't understand, where that log file is?.. If it is mentioned in the output of this command, which of them is the needed one?

[Ilya Flyamer (flyamer)]

If it is the zg.log file you want to see, it is in the attachment.

If you want to see the output in terminal, this is it:

ilya@ilya-laptop:~$ sudo zeitgeist-daemon --replace --log-file zg.log --log-level=debug
[sudo] password for ilya:
[15:28:09.158893 DEBUG] utils.vala:58: DATA_PATH = /root/.local/share/zeitgeist
[15:28:09.159108 DEBUG] utils.vala:77: DATABASE_FILE_PATH = /root/.local/share/zeitgeist/activity.sqlite
[15:28:09.160815 DEBUG] sql-schema.vala:138: schema_version is 6
[15:28:09.163352 DEBUG] extension.vala:146: Loaded extension: ZeitgeistDataSourceRegistry
[15:28:09.163677 DEBUG] extension.vala:146: Loaded extension: ZeitgeistBlacklist
[15:28:09.163858 DEBUG] extension.vala:146: Loaded extension: ZeitgeistHistogram
[15:28:09.164456 DEBUG] extension.vala:146: Loaded extension: ZeitgeistStorageMonitor
[15:28:09.165247 DEBUG] notify.vala:290: Installed new monitor for org.gnome.zeitgeist.SimpleIndexer
[15:28:09.168173 DEBUG] extension.vala:146: Loaded extension: ZeitgeistSearchEngine
[15:28:09.168408 DEBUG] extension.vala:146: Loaded extension: ZeitgeistBenchmarker
[15:28:09.168497 DEBUG] utils.vala:110: LOCAL_EXTENSIONS_PATH = /root/.local/share/zeitgeist/extensions
[15:28:09.177974 DEBUG] ext-storage-monitor.vala:451: Creating NetworkManager network monitor
[15:28:09.185742 DEBUG] ext-storage-monitor.vala:470: NetworkManager network state: 70
[15:28:09.187754 DEBUG] ext-storage-monitor.vala:366: VOLUME ADDED: net
[15:28:09.291008 DEBUG] ext-data-source-registry.vala:254: Zeitgeist.DataSourceRegistry.register_data_source: com.zeitgeist-project,datahub,gio-launch-listener, Launched desktop files, Logs events about launched desktop files using GIO
[15:28:09.294343 DEBUG] ext-data-source-registry.vala:254: Zeitgeist.DataSourceRegistry.register_data_source: com.zeitgeist-project,datahub,downloads-monitor, Downloads Directory Monitor, Logs files in the XDG downloads directory
[15:28:09.298099 DEBUG] ext-data-source-registry.vala:254: Zeitgeist.DataSourceRegistry.register_data_source: com.zeitgeist-project,datahub,kde-recent, Recently Used Documents (KDE), Logs events from KRecentDocument
[15:28:09.301017 DEBUG] ext-data-source-registry.vala:254: Zeitgeist.DataSourceRegistry.register_data_source: com.zeitgeist-project,datahub,recent, Recently Used Documents, Logs events from GtkRecentlyUsed

[Michal Hruby (mhr3)]

Sorry, forgot to say that you need to summon the dash, switch between lenses and do some searches while it's logging.

And, I can't stress this enough, don't run it with sudo.

[Ilya Flyamer (flyamer)]

I am afraid, without sudo it doesn't work properly, or I don't get it...

ilya@ilya-laptop:~$ zeitgeist-daemon --replace --log-file zg.log --log-level=debug
[15:55:09.908631 DEBUG] utils.vala:58: DATA_PATH = /home/ilya/.local/share/zeitgeist
[15:55:09.908971 DEBUG] utils.vala:77: DATABASE_FILE_PATH = /home/ilya/.local/share/zeitgeist/activity.sqlite
[15:55:09.912654 DEBUG] sql-schema.vala:138: schema_version is 6
[15:55:09.916513 WARNING] sql.vala:331: Can't query database: 11, database disk image is malformed

[15:55:09.916763 WARNING] zeitgeist-daemon.vala:473: Can't query database: 11, database disk image is malformed

And it just ends... Or I still should do smth with the Dash and then get some file?

[Michal Hruby (mhr3)]

That's exactly what we needed, thanks!

[Ilya Flyamer (flyamer)]

OK, I'm really glad, I could help!
*Waiting for the bugfix =)*

[Ilya Flyamer (flyamer)]

Wanted to add: today Dash stopped searching for applications, so I can't launch them..

[Michal Hruby (mhr3)]

Your /home/ilya/.local/share/zeitgeist/activity.sqlite is corrupted, remove it, restart and everything should be fine.

[Ilya Flyamer (flyamer)]

Great. it worked, thank you!

[Siegfried Gevatter (rainct)]

[Development discussion, bug reporters feel free to ignore this]

OK, so the plan is to improve Zeitgeist's database corruption recovery.

The log provided in this bug report is for the get_last_id() query. I don't know how many cases that'll cover, but if we want to be comprehensive it won't be enough.

I'd prefer doing the checking at startup time, but I don't see any good way:
 a) PRAGMA integrity_check: way too slow
 b) PRAGMA quick_check: not sure if it'll catch everything? also, in my quick testing it scaled super-linearly (0.08s for 8MB DB, 0.16 for 13MB DB)
 c) SELECT from all tables: also likely not comprehensive enough.

The alternative would be checking all (?) queries we do for SQLITE_CORRUPT and in that case calling Utils.retire_database. (We may want some constraint though, to avoid ending up with 50 databases if there's some serious file system problem with a system).

Comments?

[Michal Hruby (mhr3)]

> b) PRAGMA quick_check: not sure if it'll catch everything? also, in my quick testing it scaled super-linearly (0.08s for 8MB DB, 0.16 for 13MB DB)

That's pretty slow considering we use dbus-activation a lot and need a reply asap.

I'd say that if the initial opening of DB doesn't fail (+the get_last_id) we could assume that the DB is fine. If we then get SQLITE_CORRUPT during one of the regular queries, we should do something about that - perhaps mark the DB tainted and retire it on next startup? The question then is if the tainted flag will survive in the corrupted DB.

[Siegfried Gevatter (rainct)]

2012/3/30 Michal Hruby <email address hidden>:
> perhaps mark the DB tainted and retire it on next startup?
> The question then is if the tainted flag will survive in the corrupted
> DB.

Thought about doing it this way, but really what does it get us? We
can just rename the file (retire_database()) and quit, so the next
start will see it's gone and re-cerate it.

[Michal Hruby (mhr3)]

Basically yea, it's a question of way the DB is corrupted, if there's some misbehaving dataprovider that corrupts it (yes there'd had to be some vulnerability in our code and sqlite) we could end up just retiring the DB all the time.

That said my concern was more because some requests might be queued up which might not fail, but that could be solved by firing a low prio timer to retire the DB and quit.

[Michal Hruby (mhr3)]

Marking as fixed in unity because of the ZG fix.