Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fresh install gives error on every launch #22

Open
nephros opened this issue Jul 28, 2024 · 9 comments
Open

Fresh install gives error on every launch #22

nephros opened this issue Jul 28, 2024 · 9 comments

Comments

@nephros
Copy link

nephros commented Jul 28, 2024

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
Copy link
Author

nephros commented Jul 28, 2024

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
Copy link
Author

nephros commented Jul 28, 2024

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
Copy link
Owner

ichthyosaurus commented Jul 29, 2024

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
Copy link
Author

nephros commented Jul 30, 2024

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 b77c363.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
Copy link
Author

nephros commented Jul 30, 2024

Some more sleuthing (and this is without b77c363), 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
Copy link
Author

nephros commented Jul 30, 2024

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

Summarizing the differences:

GeminiPDA, SFOS 4.6, b77c363 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 b77c363.

  • 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
Copy link
Author

nephros commented Jul 30, 2024

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
Copy link
Author

nephros commented Jul 30, 2024

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
Copy link
Owner

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants