Spontaneous reboots because of of an error in sqliteformat.cpp
asked 2016-04-15 12:14:32 +0300
Since my Jolla is a friend of spontaneous reboots (on the previous version and now on SailfishOS 2.0.1.7 (Taalojärvi), too) and it happened two times in a row a few minutes ago, I decided to finally look at the system logs.
You won’t believe what happened. Item 1 will blow your mind.
(reversed logs)
-- Reboot --
Apr 15 10:56:36 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:36 mushu simkit[1238]: [D] AppManager::updateDesktop:47 - updating .desktop true
Apr 15 10:56:36 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:36 mushu simkit[1238]: [D] StkOfonoSimToolkit::stkPropertyChanged:97 - stk property changed "MainMenu" QVariant(QDBusArgument, )
Apr 15 10:56:36 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:36 mushu simkit[1238]: [D] StkOfonoSimToolkit::stkPropertyChanged:97 - stk property changed "MainMenuIcon" QVariant(uchar, 0)
Apr 15 10:56:36 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:36 mushu simkit[1238]: [D] StkOfonoSimToolkit::stkPropertyChanged:97 - stk property changed "MainMenuTitle" QVariant(QString, "SMS Services")
Apr 15 10:56:36 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:36 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:36 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:36 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu alien_bridge_server[1358]: getListenerService !
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:35 mushu [1172]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:56:34 mushu start_alien.sh[1269]: 04-15 10:56:34.978 1352 1352 E OMXMaster: A component of name 'OMX.qcom.audio.decoder.aac' already exists, ignoring this one.
Apr 15 10:56:34 mushu systemd[1]: Unit mount-sd@mmcblk1.service entered failed state.
Apr 15 10:56:34 mushu systemd[1]: Failed to start Handle sdcard.
Apr 15 10:56:34 mushu mount-sd[1611]: Waiting 1 seconds for tracker
Apr 15 10:56:34 mushu systemd[1]: mount-sd@mmcblk1.service: main process exited, code=exited, status=1/FAILURE
Apr 15 10:56:34 mushu mount-sd[1612]: ERROR: Filesystem type missing for /dev/mmcblk1.
Apr 15 10:56:34 mushu rescue-password-off[1560]: pam_unix(rescue-password-off:auth): authentication failure; logname= uid=0 euid=0 tty= ruser= rhost= user=nemo
Apr 15 10:56:34 mushu systemd[1]: Started Oneshot stuff for root (late run).
Apr 15 10:56:33 mushu mount-sd[1583]: Called to add mmcblk1p1
Apr 15 10:56:33 mushu mount-sd[1582]: Called to add mmcblk1
Apr 15 10:56:33 mushu systemd[1]: Starting Turn rescue passwords off...
Apr 15 10:56:33 mushu systemd[1]: Starting Oneshot stuff for root (late run)...
Apr 15 10:56:33 mushu systemd[1]: Starting Handle sdcard...
Apr 15 10:56:33 mushu systemd[1]: Starting Handle sdcard...
Apr 15 10:56:33 mushu systemd[1]: Started Inform dsme about runlevel change.
Apr 15 10:56:33 mushu systemd[1]: Started Indicate boot is done.
Apr 15 10:56:33 mushu runlevel-change-done[1521]: Reached new runlevel USER
Apr 15 10:56:33 mushu init-done[1520]: INIT DONE in 39.49 s
and for a second time:
-- Reboot --
Apr 15 10:58:00 mushu [1173]: [C] mKCal::SqliteFormat::selectComponents:1112 - sqliteformat.cpp: 1112 - sqlite3_step error: 11
Apr 15 10:57:59 mushu fingerterm[1065]: [D] Terminal::ansiSequence:940 - unhandled ansi sequence 'h' (1034) "?"
Apr 15 10:57:58 mushu statefs[462]: Cellular_interfaces=( CallBarring , CallForwarding , CallSettings , CallVolume , ConnectionManager , MessageManager , MessageWaiting , NetworkR
Apr 15 10:57:58 mushu lipstick[981]: [D] CoverActionModel::update:131 - void CoverActionModel::update() Clearing model
Apr 15 10:57:58 mushu fingerterm[1065]: [W] err_method_notfound:2153 - QObject::connect: No such signal QScreen::currentOrientationChanged(Qt::ScreenOrientation)
How is it even possible to crash a Linux system, seriously? I’m using the probably most experimental Linux Distro out there (NixOS) and it never once happened to me.
Please, get your s* together. How about finally open-sourcing all of it and making it possible to compile master for interested developers, so we can finally fix those annoying bugs ourselves? As you can tell I’m a bit pissed by now. Don’t get me started on the Cal/CardDav implementation THAT IS F* S*.
How do you connect the sql error to a full reboot?
tortoisedoc ( 2016-04-16 01:30:03 +0300 )editYou change the dumb Sailfish defaults for journald to keep logs over reboots (and actually write them to storage). See
Profpatsch ( 2016-04-17 18:01:38 +0300 )editman journald.conf@Profpatsch Are you certain that the reboot is due to the sqlite3 error, though? Or is it just temporally correlated in the log? sqlite3 is extremely robust, even if the calendar storage backend which uses it (mkcal) has bugs. I think it highly unlikely that a ring3 process using sqlite3 could directly cause a reboot, although obviously I might be wrong.
Can you get an strace log from the process which you believe is causing the crash? Or provide a dmesg log?
To answer your other questions: the entire middleware stack is opensource, including all of the calendar middleware, calendar APIs, and sync plugins including CalDAV and CardDAV. Patches are more than welcome, as stated in the SailfishOS wiki for the Calendar core area. I look forward to receiving your patches soon, and am always available on IRC or via email for discussion.
chris.adams ( 2016-04-18 04:54:08 +0300 )edit@chris.adams Throwing 20 errors is extremely robust? Interesting. In my experience it’s very tiring to develop stuff when traces point to proprietary closed symbols. That could be just me, though.
Profpatsch ( 2016-04-18 18:33:12 +0300 )editsqlite3 is not proprietary, and is extremely robust. The errors you are seeing are caused by mKCal's incorrect use of sqlite3, not due to sqlite3 itself.
mKCal, which uses sqlite3, is not extremely robust. But it is not closed source - see https://git.merproject.org/mer-core/mkcal for that. Nor is kcal, for which mKCal is an extension + backend, see https://git.merproject.org/mer-core/kcalcore for that. Nor is the CalDAV sync plugin, see https://git.merproject.org/mer-core/buteo-sync-plugin-caldav/ for that. Nor is the Buteo sync scheduler, see https://git.merproject.org/mer-core/buteo-syncfw for that. Nor are the UI bindings for the calendar backend, see https://git.merproject.org/mer-core/nemo-qml-plugin-calendar/ for that.
There are only two closed source pieces of code related to Calendar: the first is the Jolla Calendar application itself (which is literally a thin UI layer which exposes the data from nemo-qml-plugin-calendar), and the second is the Accounts code which creates the CalDAV account using the (surprise!) opensource Accounts&SSO framework - see https://github.com/mer-packages/libaccounts-qt.
I'll be the first to admit that there is a LOT of improvement needed on the Calendar side, and the Calendar sync side. But to claim that it's all closed source is simply not true. The vast majority of it is open source, and we've always been open to community contribution in the open source parts of the stack.
I hope you choose to contribute.
Thanks, Chris.
chris.adams ( 2016-04-19 04:30:45 +0300 )edit