Bug 352756

Summary: Database corruption upon upgrading to 5.14.0
Product: [Frameworks and Libraries] frameworks-kservice Reporter: Hrvoje Senjan <hrvoje.senjan>
Component: generalAssignee: David Faure <faure>
Status: RESOLVED FIXED    
Severity: major CC: jos, kdelibs-bugs
Priority: NOR    
Version: unspecified   
Target Milestone: ---   
Platform: Other   
OS: Linux   
Latest Commit: Version Fixed In:
Sentry Crash Report:

Description Hrvoje Senjan 2015-09-15 16:39:36 UTC
kdeinit5: Got EXT_EXEC '/usr/bin/kbuildsycoca5' from launcher.
kdeinit5: preparing to launch '/usr/bin/kbuildsycoca5'
kbuildsycoca5 running...
Recreating ksycoca file ("/home/hrvoje/.cache/ksycoca5", version 302)
Saving
Emitting notifyDatabaseChanged ("services", "servicetypes", "xdgdata-mime", "apps")
kdeinit5: PID 2668 terminated.
ERROR: KSycoca database corruption!
kbuildsycoca5 running...
Reusing existing ksycoca
Recreating ksycoca file ("/home/hrvoje/.cache/ksycoca5", version 302)
Still in the time dict (i.e. deleted files) ("apps")
Saving
Emitting notifyDatabaseChanged ("apps")
ERROR: KSycoca database corruption!
Accessed invalid KPluginInfo object
KCrash: Attempting to start /usr/bin/kdeinit5 from kdeinit
kdeinit5: Got EXEC_NEW '/usr/bin/kdeinit5' from wrapper.
kdeinit5: preparing to launch '/usr/bin/kdeinit5'
KCrash: Application 'kdeinit5' crashing...

kdeinit5 is sparse at BT:
Thread 1 (LWP 1221):
#0  0x8a6ebabd in ?? ()
Backtrace stopped: Cannot access memory at address 0x8d02f850


Reproducible: Always

Steps to Reproduce:
1. have KF5 5.13.0 installed with Plasma 5.4.x on top
2. upgrade to 5.14.0

Actual Results:  
Crash
Comment 1 David Faure 2015-09-15 21:24:52 UTC
Ouch ouch ouch.

Can you
export QT_MESSAGE_PATTERN='%{appname}(%{pid})/%{category} %{function}: %{message}'
so that debug output indicates which process outputs each line?

I'll try going back in time (to KF 5.13,  then back to 5.14) with kservice to see if I can reproduce this.

Please make a backup of /home/hrvoje/.cache/ksycoca5 before deleting it (which is the workaround). But without a backup we'll never know if the upgrade bug is fixed.
Comment 2 Hrvoje Senjan 2015-09-15 21:45:37 UTC
I'll try dowgrading to 5.13 tommorow so i can repeat the process. Please note that after initial post upgrade crash, things seem to run fine.
Comment 3 David Faure 2015-09-15 22:15:51 UTC
I can't trigger the crash in my test (which is admittedly just downgrading kservice, removing ksycoca5, running kbuildsycoca5 (-> version 300), upgrading kservice again, running kbuildsycoca5... which says this, as expected:

kbuildsycoca5 running...
kbuildsycoca5(5760)/kf5.kservice.sycoca KSycocaPrivate::openDatabase: Trying to open ksycoca from "/home/dfaure/.cache/ksycoca5"
kbuildsycoca5(5760)/kf5.kservice.sycoca KSycocaPrivate::checkVersion: Found version 300 , expecting version 302 or higher.
kbuildsycoca5(5760)/kf5.kservice.sycoca KSycocaPrivate::checkVersion: Found version 300 , expecting version 302 or higher.
kbuildsycoca5(5760)/default KBuildSycoca::recreate: Recreating ksycoca file ("/home/dfaure/.cache/ksycoca5", version 302)
(and it proceeds as usual)

I also tried not running kbuildsycoca5 myself but letting an app trigger it (after reverting to a copy of the v300 sycoca), no crash.
Not denying there's a bug of course, but either
- I'm not testing this correctly, or
- the incompatibility only happens with specific data in the db (so no matter what I try it won't happen here), or
- the bug only happens on a specific architecture (is this x86_64 ?)

d46be24c9fb583183cefabec045a7a4b93c714a1 is the obvious suspect commit. I changed the QDataStream serialization version, but the sycoca version increase is supposed to force a rebuild before reading the old data with the new serialization version... I also changed a 32 bit int to 64 bit, but only in the ksycoca5-timestamp file which isn't really used.

The interesting bt would be the one from "ERROR: KSycoca database corruption!" .... i.e. maybe put an abort() in KSycoca::flagError(), to get a core dump of how we get there....
Comment 4 David Faure 2015-09-16 08:16:39 UTC
Note: I had the corruption error when *downgrading* kservice.

I think I understand what's happening then. If someone logs out, upgrades, logs in, it should all be fine.
But if someone upgrades kservice while plasma5 is running, the new kbuildsycoca5 will generate a v302 db which existing apps will try to read with v300 code, and break.

Usually when we extend the db, we do so in a way so that old apps can read the new db (and skip over the stuff they don't know). My datastream versioning change doesn't do that, unfortunately.
I can revert that for now (I'm changing filenames soon anyway, which will be the right opportunity for it).
http://www.davidfaure.fr/2015/revert_format_change.diff

If this works for you, I'll make a 5.14.1 tarball for kservice.
Comment 5 Hrvoje Senjan 2015-09-16 15:51:26 UTC
David, the diff seems to be empty...
I've tried changing the version to Qt_3_1 by hand (plus bumping ksyscoca version), xsession still reports the corruption in ~/.xsession-errors-:0, though now kdeinit5 doesn't crash...
Comment 6 David Faure 2015-09-16 17:23:53 UTC
Ooops, I made a local commit and then git diff > file. Doh.

Now the link to the diff should work.
And yes this isn't just changing the datastream version but also going back to a uint32 (in seconds) instead of a uint64 (in ms) for the timestamp field.
Comment 7 Hrvoje Senjan 2015-09-16 17:46:21 UTC
Ok, now newTimestamp is left undeclared ;-)
Comment 8 Hrvoje Senjan 2015-09-16 17:58:45 UTC
So things are working fine it seems with this patch (sed 's/newTimestamp/m_newTimestamp/'). No corruption mentioned, no crash, so a ship it from me =)
Comment 9 David Faure 2015-09-16 19:22:33 UTC
This was a patch for v5.14.0, it applies and compiles there. Were you trying to apply it to git master maybe? Otherwise I don't understand the compilation problem you had.
Comment 10 Hrvoje Senjan 2015-09-16 20:36:30 UTC
(In reply to David Faure from comment #9)
> This was a patch for v5.14.0, it applies and compiles there. Were you trying
> to apply it to git master maybe? 
Yep
Comment 11 David Faure 2015-09-16 21:28:42 UTC
Fixed in 5.14.1.

Not yet fixed in git master, I'd rather switch to a different filename soon than apply this.
Comment 12 Jos van den Oever 2016-04-24 15:36:56 UTC
I'm seeing something similar with 5.19.0. Did the mentioned patch make it into master?

$ kbuildsycoca5 --version
kbuildsycoca5 5.19.0
$ kbuildsycoca5 --noincremental --global
kbuildsycoca5 running...
kbuildsycoca5(3331)/default unknown: Recreating ksycoca file ("/home/oever/.local/share/ksycoca/ksycoca5_en", version 303)
kbuildsycoca5(3331)/default unknown: Menu "applications-kmenuedit.menu" not found.
kbuildsycoca5(3331)/default unknown: Saving
$ kcminit
kcminit(3336)/kf5.kservice.sycoca unknown: ERROR: KSycoca database corruption!
kcminit(3336)/kf5.kservice.sycoca unknown: ERROR: KSycoca database corruption!
kcminit(3336)/kf5.kservice.sycoca unknown: ERROR: KSycoca database corruption!
kcminit(3336)/kf5.kservice.sycoca unknown: ERROR: KSycoca database corruption!
kcminit(3336)/default unknown: Recreating ksycoca file ("/home/oever/.cache/ksycoca5_en_ZDaXpKg+fqgYRYEHHfhMEXeSCyc=", version 303)
kcminit(3336)/default unknown: Menu "applications-kmenuedit.menu" not found.
kcminit(3336)/default unknown: Saving
kcminit(3336)/kf5.kservice.sycoca unknown: ERROR: KSycoca database corruption!
kcminit(3336)/default unknown: Initializing  "kded_touchpad" :  "kcminit_touchpad"
kcminit(3336)/default unknown: Width:  3852  height:  3046
kcminit(3336)/default unknown: Approx. resX:  42  resY:  60
kcminit(3336)/default unknown: Touchpad resolution: x:  53  y:  55
kcminit(3336)/default unknown: Final resolution x: 53  y: 55
kcminit(3336)/default unknown: Initializing  "kcm_style" :  "kcminit_style"
kcminit(3336)/default unknown: QFile::copy: Empty or null file name
kcminit(3336)/default unknown: Initializing  "kcm_input" :  "kcminit_mouse"
kcminit(3336)/default unknown: Initializing  "kcm_access" :  "kcminit_access"