Fresh install gives error on every launch

[nephros]

On a new/fresh install I get the error in the logs:

Jul 28 22:10:48 harbour-captains-log[21529]: [C] onError:371 - an error occurred in the Python backend, traceback:
Jul 28 22:10:48 harbour-captains-log[21529]: [C] onError:372 - Function not found: 'diary.normalize_text' (Traceback (most recent call last):

File "<string>", line 1, in <module>

NameError: name 'diary' is not defined

)
Jul 28 22:10:48 harbour-captains-log[21529]:

The app gives a popup about an error and to check the logs.

I guess the database is never created, or at least can not be accessed properly.

Entries can be created, but are not saved and lost on next app launch.

[nephros]

Correction: DB is created, and entries are written to it normally, and show up rhe next launch.

But UI popup "An error occurred" and log message appear on each launch.

[nephros]

Actually, there's both variants.

Sometimes, an error popup "The Database could not be loaded" appears. After this, no new entries are saved.

As long as this does not appear, entries get saved and restored normally.

[ichthyosaurus]

Thanks for reporting, that is a nasty bug! I just fixed a bug that I encountered when creating a new database. However, I can't reproduce your exact problems. I'll create a new release later, and maybe the issues you encountered will be fixed by that already. Otherwise I'll have to investigate further.

[nephros]

Thanks for reporting, that is a nasty bug! I just fixed a bug that I encountered when creating a new database. However, I can't reproduce your exact problems. I'll create a new release later, and maybe the issues you encountered will be fixed by that already. Otherwise I'll have to investigate further.

I have applied b77c36386b1c93093bd0263e9751abb60de9bbef.diff locally but the issue remains the same AFAICS.
I noticed I have quite some pip install --user packages in ~/.local. I'll remove them and try again. Although the error does not seem to point to local package overrides.

[nephros]

Some more sleuthing (and this is without b77c36386b1c93093bd0263e9751abb60de9bbef), on a Gemini PDA running 4.6.0.13. (The original error appears on a XPeria10III running 4.4.0.72).

Removed ~/.local/share/harbour-captains-log, ~/.config/harbour-captains-log, and reset the dconf key /apps/harbour-captains-log/.

Launching manually: sailjail /usr/bin/harbour-captains-log gives:

defaultuser@GeminiPDA:~ $ sailjail /usr/bin/harbour-captains-log
Warning: "shell none" command in the profile file is done by default; the command will be deprecated
constructing /run/firejail/mnt/privileged:  ...
mounting /run/firejail/mnt/privileged @ /home/defaultuser/.local/share/system/privileged
hiding /run/firejail/mnt/privileged
[D] unknown:0 - Using Wayland-EGL
library "libwlparser.so" not found
[D] unknown:0 - Got library name:  "/usr/lib/qt5/qml/io/thp/pyotherside/libpyothersideplugin.so"
[D] :456 - python backend loaded
using local data at /home/defaultuser/.local/share/harbour-captains-log/harbour-captains-log
creating new database in /home/defaultuser/.local/share/harbour-captains-log/harbour-captains-log
updating database from version -1...
updating database from version 0...
updating database from version 1...
updating database from version 2...
updating database from version 3...
updating database from version 4...
updating database from version 5...
updating database from version 6...
updating database from version 7...
updating database from version 8...
database has been updated to version 8
[C] :382 - an error occurred in the Python backend: database-update-failed
[C] :383 - error details:
[C] :384 - {"database":"","exception":"None: [Errno 2] No such file or directory: ''\nTraceback (most recent call last):\n  File \"/usr/lib/python3.8/shutil.py\", line 791, in move\n    os.rename(src, real_dst)\nFileNotFoundError: [Errno 2] No such file or directory: '' -> '/home/defaultuser/.local/share/harbour-captains-log/harbour-captains-log/2024-07-30 - backups'\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n  File \"/usr/share/harbour-captains-log/qml/py/diary.py\", line 102, in __init__\n    latest_db = self._update_schema(latest_db)\n  File \"/usr/share/harbour-captains-log/qml/py/diary.py\", line 471, in _update_schema\n    shutil.move(str(source_db), str(backup_path))\n  File \"/usr/lib/python3.8/shutil.py\", line 811, in move\n    copy_function(src, real_dst)\n  File \"/usr/lib/python3.8/shutil.py\", line 435, in copy2\n    copyfile(src, dst, follow_symlinks=follow_symlinks)\n  File \"/usr/lib/python3.8/shutil.py\", line 264, in copyfile\n    with open(src, 'rb') as fsrc, open(dst, 'wb') as fdst:\nFileNotFoundError: [Errno 2] No such file or directory: ''"}
[C] :460 - failed to initialize backend

Prettified stack trace:

Traceback (most recent call last):
  File \"/usr/lib/python3.8/shutil.py\", line 791, in move
    os.rename(src, real_dst)
FileNotFoundError: [Errno 2] No such file or directory: '' -> '/home/defaultuser/.local/share/harbour-captains-log/harbour-captains-log/2024-07-30 - backups'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File \"/usr/share/harbour-captains-log/qml/py/diary.py\", line 102, in __init__
    latest_db = self._update_schema(latest_db)
  File \"/usr/share/harbour-captains-log/qml/py/diary.py\", line 471, in _update_schema
    shutil.move(str(source_db), str(backup_path))
  File \"/usr/lib/python3.8/shutil.py\", line 811, in move
    copy_function(src, real_dst)
  File \"/usr/lib/python3.8/shutil.py\", line 435, in copy2
    copyfile(src, dst, follow_symlinks=follow_symlinks)
  File \"/usr/lib/python3.8/shutil.py\", line 264, in copyfile
    with open(src, 'rb') as fsrc, open(dst, 'wb') as fdst:
FileNotFoundError: [Errno 2] No such file or directory: ''"}

After this, dconf key is:

$ dconf dump /apps/harbour-captains-log/
[/]
configMigrated=1

 ls -l ~/.local/share/harbour-captains-log/harbour-captains-log/
total 8
-rw------- 1 defaultuser defaultuser 8192 Jul 30 11:43 diary-v008.db

defaultuser@GeminiPDA:~ $ sqlite3 ~/.local/share/harbour-captains-log/harbour-captains-log/diary-v008.db  .dump
PRAGMA foreign_keys=OFF;
BEGIN TRANSACTION;
CREATE TABLE IF NOT EXISTS "diary"(
            create_order INTEGER NOT NULL,
            entry_order INTEGER NOT NULL,
            entry_addenda_day INTEGER NOT NULL,
            entry_addenda_seq INTEGER NOT NULL,
            create_date TEXT NOT NULL, create_tz TEXT DEFAULT '',
            entry_date TEXT NOT NULL, entry_tz TEXT DEFAULT '',
            modify_date TEXT NOT NULL, modify_tz TEXT DEFAULT '',
            title TEXT DEFAULT '', entry TEXT DEFAULT '',
            entry_normalized TEXT DEFAULT '', preview TEXT DEFAULT '',
            tags TEXT DEFAULT '', tags_normalized TEXT DEFAULT '',
            mood INTEGER, bookmark BOOLEAN,
            attachments_id TEXT DEFAULT ''
        );
COMMIT;

If I now reset the dconf key dconf reset -f /apps/harbour-captains-log/ and launch again, NO ERRORS! (And an immediate message in the app that a database backup has been created.)

It seems some part of the migration fails, but dconf records it as successful. Or something like this.

[nephros]

Aha! trying the same thing on the Gemini with b77c3638 applied shows no errors!

Summarizing the differences:

GeminiPDA, SFOS 4.6, b77c3638 seems to fix things.

• Python 3.8.18, python3-base-3.8.18+git1-1.9.3
• pyotherside-qml-plugin-python3-qt5-1.5.9+git4-1.5.4

Xperia 10 III, SFOS 4.4, always shows the originally reported error, both with and without b77c3638.

• Python 3.8.11, python3-base-3.8.11+git3-1.7.29
• pyotherside-qml-plugin-python3-qt5-1.5.9+git3-1.5.2

(The pyotherside difference is just packaging, no functional changes.)

[nephros]

Hm. Going back to qml: file:///usr/share/harbour-captains-log/qml/harbour-captains-log.qml:375 Function not found: 'diary.normalize_text'.

That is called from harbour-captains-log.qml normalizeText(). That in turn is referenced in components/SearchModel.qml and components/TagSuggestionsView.qml.

It appears initialization of those components triggers a call to the function at a point in time when py has not been initialized.

At least adding some prints seems to indicate this:

    function normalizeText(string) {
        if (!py) console.log ("trying to call py while not ready!")
        if (!py.ready) console.log ("trying to call py while py.ready not ready!")
        return py.call_sync('diary.normalize_text', [string])
    }
[...]
    Python {
        id: py
        property bool ready: false
[...]

            importModule('diary', function() {
                console.log("python backend loaded")
                py.ready = true
[...]
            }
    }

gives the "expected":

 qml: file:///usr/share/harbour-captains-log/qml/harbour-captains-log.qml:140 normalizeText trying to call py while py.ready not ready!
 unknown:0 unknown "PyOtherSide error: Traceback (most recent call last):\n\n  File \"<string>\", line 1, in <module>\n\nNameError: name 'diary' is not defined\n"
 qml: file:///usr/share/harbour-captains-log/qml/harbour-captains-log.qml:374  an error occurred in the Python backend, traceback:
 qml: file:///usr/share/harbour-captains-log/qml/harbour-captains-log.qml:375  Function not found: 'diary.normalize_text' (Traceback (most recent call last):

  File "<string>", line 1, in <module>

NameError: name 'diary' is not defined
)
 qml: file:///usr/share/harbour-captains-log/qml/harbour-captains-log.qml:459  python backend loaded

AFAIK initialization order of components in QML is more or less undefined, which would explain the "raciness" of the error.

[nephros]

Some other changes to normalizeText():

    function normalizeText(string) {
        if (!py) console.log ("trying to call py while not ready!")
        if (!py.ready) console.log ("trying to call py while py.ready not ready!")
        if (typeof string == "undefined") {
            console.log ("trying to call py with an undefined string!")
            return ""
        }
        if (string.length < 1) {
            console.log ("trying to call py with an empty string!")
            return ""
        }
        return py.call_sync('diary.normalize_text', [string])
    }

reveals that it is indeed called with empty strings sometimes.

The return "" in these cases makes the original issue go away, although it's probably not the correct fix.

[ichthyosaurus]

Thank you for the analysis! I adapted the code from your last comment and I think that should properly fix it.

My theory is this: when the app is started without a lock code and the database creation is slow, then normalizeText() is called from the tags model on the attached write page before the backend is ready. In that case it's ok to fail gracefully, as no data should be entered at this point.