search

pgaskin / dictutil

Tools, documentation, and libraries related to Kobo dictionaries.
https://pgaskin.net/dictutil
MIT License
58 stars 4 forks source link

Issues with setting dictionaries as read-only #6

Open pgaskin opened 4 years ago

pgaskin commented 4 years ago

This seems to be a firmware issue (may not be specific to Windows). The following patch can be used as a temporary workaround for now:

# kobopatch v0.15.0, firmware 4.20.14601+ (last tested on 4.20.14622)
Never sync dictionaries:
- Enabled: no
- BaseAddress:  {Sym: "SyncDictionariesCommand::prepareDownloadList()"}
- ReplaceBytes: {Offset: 1048, FindH: 0CD5,     ReplaceH:       0CE0}   #permissions
- ReplaceBytes: {Offset: 1026, FindH: FFF68DAE, ReplaceInstNOP: true}   #size
- ReplaceBytes: {Offset:  992, FindH: 3FF49EAE, ReplaceInstNOP: true}   #isSynced
# firmware 4.20.14622
Never sync dictionaries:
- Enabled: no
- ReplaceBytes:    {Offset: 0x6108B0, FindH: 0CD5, ReplaceH: 0CE0} #permissions
- ReplaceBytesNOP: {Offset: 0x61089A, FindH: FFF68DAE}             #size
- ReplaceBytesNOP: {Offset: 0x610878, FindH: 3FF49EAE}             #isSynced

The issue seems to be that under some (TBD) conditions, the permissions check never gets reached, presumably due to the size or isSynced check bypassing it. It was first seen on firmware 4.20.14622, but could have existed as early as 4.20.14601 (but I never noticed it myself).

I'll be looking into this further later.

So far, I've confirmed this bug with two Windows users, both when setting it read-only through dictutil and manually. The write bit isn't present when checking over telnet, and a trace of libnickel shows that it was seen, but the logs don't show it being skipped.

pgaskin commented 4 years ago

On a slightly unrelated note, @davidfor pointed out how this read-only functionality has been around for a while, but we never ended up noticing it before my work in #3 (prior to the recent firmware versions, the dicthtml-micthtml patch prevented overwriting overridden dictionaries, and before #3, I found that IsSynced in the DB could be used to skip the sync process, but that was obsoleted by the removal of the table in 14622). This read-only functionality seems to have been present as early 11655.

pgaskin commented 4 years ago

@gtalusan, is this a bug in the firmware (the size or issynced check preventing the permission check from actually having an effect)?

Also, another bug which is more visible (it's cosmetic only), but just as simple: sideloaded dictionaries always appear as pending.

pgaskin commented 4 years ago

Some stuff I've been looking into on 14622:

Some context about where Dictionary::isSynced() comes from now that the DB isn't used:
0x6be680 - Dictionary::isSynced() gets the value stored at *(Dictionary + 0x18), which is set to
0x6be454 - r5, which is:
0x6be410 - the stack argument at 0x20 to the constructor Dictionary::Dictionary(QString const&, QString const&, bool, long long, bool), which is passed from
0x55b980 - DictionaryFileManager::getAll(*Device), which sets it to
0x55b96c - *(r8 - 0x8), which is set from:
0x55bec8 - ^ which is actually N/A, since Dictionary::setSynced(QVariant const&) is called later on, with the argument being:
0x55bec0 -     set to a QVariant of a bool, initialized from r1, which is set
0x55beba -     to true if
0x55beb2 -       sb == r1
0x55beb6 -       && r8 == r0, where
0x55beac -         sb = r1 (making the first comparision always true), and
0x55beae -         r0 = Dictionary::size(), and
0x55bea4 -         r8 = IOUtil::sizeIncludingSubdirectories(QFileInfo const&) (!?!, why?, I thought it already checked if it was a dir earlier, because this is basically always true if the dictionary is a file)
0x55bec8 - thus, meaning Dictionary::isSynced() essentially always returns true

The list of dictionaries to skip comes from SyncDictionariesCommand::prepareDownloadList():
0x6105ae - the first step of the check is Dictionary::isInstalled(), which passes if:
0x6105b2 -   Dictionary::isInstalled() == true (which will be true if the file exists, which it always will for sideloaded dictionaries)
0x610872 - the second step is Dictionary::isSynced(), which passes if:
0x610876 -   Dictionary::isSynced() == true (which will always be true, see above) (this is also why my old trick of setting IsSynced to false in the DB worked)
0x610888 - the third step is DictionaryFileManager::getDictionarySizeOnDisk(Device const&, Dictionary const&), which passes if:
0x610890 -   DictionaryFileManager::getDictionarySizeOnDisk(Device const&, Dictionary const&) >= 1 (it's possible the bug could be in the file size checking, will check after this)
0x6108aa - the last step is DictionaryFileManager::getDictionaryPermissionsOnDisk(Device const&, Dictionary const&), which passes if:
0x6108b0 -   the file is not writable (it checks if the 12th bit of the permissions is 0)
0x6108d8 - and if the checks all passed, a log message to the sync log is written with the text
0x61092a -   "marked as read-only.. skipping"
0x610712 -   and the file is skipped
0x6105c6 - otherwise, if any check failed, the dictionary is appended to the resulting QList<Dictionary>

Therefore, the bug likely comes from DictionaryFileManager::getDictionarySizeOnDisk (or possibly a prior step if something caused them not to be actually set in the Dictionary constructor).

So, as a sanity check, we'll patch it:

  Test:
  - Enabled: yes
  - ReplaceBytesNOP: {Offset: 0x61089A, FindH: FFF68DAE}

Which does work (but it causes sync errors because the check is needed for the built-in dictionaries), so it's very likely to be an issue with getDictionarySizeOnDisk or the logic around it.

TODO: try and fix the issue, maybe test by hooking or live-patching the checks

cc @davidfor

pgaskin commented 4 years ago

Yay! I've EDIT: almost (see the comment a few ones down, this was partly a false positive because I missed a step) tracked down the bug. Now I just need to figure out how to fix it.

So, I have multiple dictionaries installed:

I then installed my updated version of dictbug-trace, and ran a sync with the sync logging category enabled, and found that dicthtml-pt.zip was replaced. These were the relevant logs:

May 15 12:13:35 nickel: (    84.744 @ 0x1b9c930 / sync.debug) =================== SYNC QUEUE [ SyncClient(0x1c5fbb0) ] ==================== 
May 15 12:13:35 nickel: (    84.744 @ 0x1b9c930 / sync.debug)  ----- Queued ------- 
May 15 12:13:35 nickel: (    84.745 @ 0x1b9c930 / sync.debug)  [ SyncDictionariesCommand(0x1c22e70) ] 
May 15 12:13:35 nickel: (    84.745 @ 0x1b9c930 / sync.debug)  [ FrictionlessReadingCommand(0x1c80610) ] 
May 15 12:13:35 nickel: (    84.745 @ 0x1b9c930 / sync.debug)  [ DownloadQueuedBooksCommand(0x19e72c8) ] 
May 15 12:13:35 nickel: (    84.746 @ 0x1b9c930 / sync.debug)  [ CleanupCommand(0x17d3b78) ] 
May 15 12:13:35 nickel: (    84.746 @ 0x1b9c930 / sync.debug) =================================================== 
May 15 12:13:35 nickel: (    84.746 @ 0x1b9c930 / sync.debug)    
May 15 12:13:35 nickel: (    84.746 @ 0x1b9c930 / sync.debug) pumping with 4 pending commands and 0 active commands 
May 15 12:13:35 nickel: (    84.747 @ 0x1b9c930 / sync.debug) executing SyncDictionariesCommand(0x1c22e70) 
May 15 12:13:35 nickel: (    84.747 @ 0x1b9c930 / sync.debug) virtual void SyncDictionariesCommand::execute() 
May 15 12:13:35 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-fr-en.zip)
May 15 12:13:35 nickel: (dictbug-trace) QFileInfo::size() = 1586132
May 15 12:13:35 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-it-en.zip)
May 15 12:13:35 nickel: (dictbug-trace) QFileInfo::size() = 1019627
May 15 12:13:35 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml.zip)
May 15 12:13:35 nickel: (dictbug-trace) QFileInfo::size() = 7454432
May 15 12:13:35 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-de-en.zip)
May 15 12:13:35 nickel: (dictbug-trace) QFileInfo::size() = 926221
May 15 12:13:35 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-es-en.zip)
May 15 12:13:35 nickel: (dictbug-trace) QFileInfo::size() = 1666763
May 15 12:13:35 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-pt-en.zip)
May 15 12:13:35 nickel: (dictbug-trace) QFileInfo::size() = 513597
May 15 12:13:36 nickel: (    85.111 @ 0x1b9c930 / packetdump.warning) "https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-ox.zip" => "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-ox.zip - server replied: Not Found" 
May 15 12:13:36 nickel: (    85.111 @ 0x1b9c930) void FileSizeGetter::onFinished() FAILED! 203 "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-ox.zip - server replied: Not Found" 
May 15 12:13:36 nickel: (    85.111 @ 0x1b9c930 / sync.warning) void SyncDictionariesCommand::prepareDownloadList() Get size failed:  203 0 
May 15 12:13:36 nickel: (    85.273 @ 0x1b9c930 / packetdump.warning) "https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-wb.zip" => "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-wb.zip - server replied: Not Found" 
May 15 12:13:36 nickel: (    85.273 @ 0x1b9c930) void FileSizeGetter::onFinished() FAILED! 203 "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-wb.zip - server replied: Not Found" 
May 15 12:13:36 nickel: (    85.274 @ 0x1b9c930 / sync.warning) void SyncDictionariesCommand::prepareDownloadList() Get size failed:  203 0 
May 15 12:13:36 nickel: (    85.429 @ 0x1b9c930 / packetdump.warning) "https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-gt.zip" => "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-gt.zip - server replied: Not Found" 
May 15 12:13:36 nickel: (    85.430 @ 0x1b9c930) void FileSizeGetter::onFinished() FAILED! 203 "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-gt.zip - server replied: Not Found" 
May 15 12:13:36 nickel: (    85.430 @ 0x1b9c930 / sync.warning) void SyncDictionariesCommand::prepareDownloadList() Get size failed:  203 0 
May 15 12:13:36 nickel: (dictbug-trace) QNetworkAccessManager::get(QNetworkRequest.url:`https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-pt.zip`)
May 15 12:13:36 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/tmpDictionary)
May 15 12:13:36 nickel: (dictbug-trace) QFileInfo::size() = 0
May 15 12:13:40 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-pt.zip)
May 15 12:13:40 nickel: (dictbug-trace) QFileInfo::size() = 10331401

That's mostly fine in general, but notice the last 5 lines. Also notice how it never got to the read-only check because it failed the size one.

It checks the size of tmpDictionary, which is what is causing the size check to be incorrect I misinterpreted the logs, the issue is actually before that, it's around the server size check.

I'm going to check to make sure I'm correct after this.

cc @gtalusan @davidfor

pgaskin commented 4 years ago

For comparison, here's the logs for the automatic sync after installing the Italian dictionary from the settings:

May 15 12:22:42 nickel: (dictbug-trace) QNetworkAccessManager::get(QNetworkRequest.url:`https://ssl.google-analytics.com/collect?v=1&tid=UA-6177406-38&cid=1c07203a-97e7-4736-abaf-b5dc36b47513&uid=c72e7cce-ece3-4e3b-9e6f-7b6cf28f189b&av=4.20.14622&an=nickel&sr=758x1024&ul=en-us&cd60=Sleep&cd64=application/x-kobo-epub+zip&t=event&ec=ReadingExperience&ea=OpenContent&el=application/x-kobo-epub+zip`)
May 15 12:22:49 nickel: (dictbug-trace) QNetworkAccessManager::get(QNetworkRequest.url:`https://ssl.google-analytics.com/collect?v=1&tid=UA-6177406-38&cid=1c07203a-97e7-4736-abaf-b5dc36b47513&uid=c72e7cce-ece3-4e3b-9e6f-7b6cf28f189b&av=4.20.14622&an=nickel&sr=758x1024&ul=en-us&t=screenview&cd=/AppSettings`)
May 15 12:22:54 nickel: (dictbug-trace) QNetworkAccessManager::get(QNetworkRequest.url:`https://ssl.google-analytics.com/collect?v=1&tid=UA-6177406-38&cid=1c07203a-97e7-4736-abaf-b5dc36b47513&uid=c72e7cce-ece3-4e3b-9e6f-7b6cf28f189b&av=4.20.14622&an=nickel&sr=758x1024&ul=en-us&t=event&ec=Home&ea=MainNavOption&el=Settings`)
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-it.zip)
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::size() = 0
May 15 12:22:56 nickel: (   645.109 @ 0x14d6308 / sync.warning) SyncCommand::SyncCommand(SyncState*, QObject*) no sync state provided -- using current device 
May 15 12:22:56 nickel: (   645.110 @ 0x14d6308 / ui.debug) Authenticated user: "c72e7cce-ece3-4e3b-9e6f-7b6cf28f189b" 
May 15 12:22:56 nickel: (   645.118 @ 0x21c7240 / sync.debug) =================== SYNC QUEUE [ SyncClient(0x1c7d038) ] ==================== 
May 15 12:22:56 nickel: (   645.157 @ 0x21c7240 / sync.debug)  ----- Queued ------- 
May 15 12:22:56 nickel: (   645.157 @ 0x21c7240 / sync.debug)  [ ResetSyncActivitiesCommand(0x2191d30) ] 
May 15 12:22:56 nickel: (   645.157 @ 0x21c7240 / sync.debug) =================================================== 
May 15 12:22:56 nickel: (   645.157 @ 0x21c7240 / sync.debug)    
May 15 12:22:56 nickel: (   645.158 @ 0x21c7240 / sync.debug) =================== SYNC QUEUE [ SyncClient(0x1c7d038) ] ==================== 
May 15 12:22:56 nickel: (   645.158 @ 0x21c7240 / sync.debug)  ----- Queued ------- 
May 15 12:22:56 nickel: (   645.158 @ 0x21c7240 / sync.debug)  [ ResetSyncActivitiesCommand(0x2191d30) ] 
May 15 12:22:56 nickel: (   645.158 @ 0x21c7240 / sync.debug)  [ SyncDictionariesCommand(0x19a9860) ] 
May 15 12:22:56 nickel: (   645.158 @ 0x21c7240 / sync.debug) =================================================== 
May 15 12:22:56 nickel: (   645.158 @ 0x21c7240 / sync.debug)    
May 15 12:22:56 nickel: (   645.159 @ 0x21c7240 / sync.debug) Sync queue:  (ResetSyncActivitiesCommand(0x2191d30) ,  SyncDictionariesCommand(0x19a9860) )  
May 15 12:22:56 nickel: (   645.159 @ 0x21c7240 / sync.debug) =================== SYNC QUEUE [ SyncClient(0x1c7d038) ] ==================== 
May 15 12:22:56 nickel: (   645.159 @ 0x21c7240 / sync.debug)  ----- Queued ------- 
May 15 12:22:56 nickel: (   645.159 @ 0x21c7240 / sync.debug)  [ ResetSyncActivitiesCommand(0x2191d30) ] 
May 15 12:22:56 nickel: (   645.159 @ 0x21c7240 / sync.debug)  [ SyncDictionariesCommand(0x19a9860) ] 
May 15 12:22:56 nickel: (   645.159 @ 0x21c7240 / sync.debug) =================================================== 
May 15 12:22:56 nickel: (   645.159 @ 0x21c7240 / sync.debug)    
May 15 12:22:56 nickel: (   645.159 @ 0x21c7240 / sync.debug) pumping with 2 pending commands and 0 active commands 
May 15 12:22:56 nickel: (   645.160 @ 0x21c7240 / sync.debug) executing ResetSyncActivitiesCommand(0x2191d30) 
May 15 12:22:56 nickel: (   645.160 @ 0x21c7240 / sync.debug) ResetSyncActivitiesCommand(0x2191d30) finished 
May 15 12:22:56 nickel: (   645.160 @ 0x21c7240 / sync.debug) =================== SYNC QUEUE [ SyncClient(0x1c7d038) ] ==================== 
May 15 12:22:56 nickel: (   645.160 @ 0x21c7240 / sync.debug)  ----- Queued ------- 
May 15 12:22:56 nickel: (   645.160 @ 0x21c7240 / sync.debug)  [ SyncDictionariesCommand(0x19a9860) ] 
May 15 12:22:56 nickel: (   645.160 @ 0x21c7240 / sync.debug) =================================================== 
May 15 12:22:56 nickel: (   645.160 @ 0x21c7240 / sync.debug)    
May 15 12:22:56 nickel: (   645.161 @ 0x21c7240 / sync.debug) pumping with 1 pending commands and 0 active commands 
May 15 12:22:56 nickel: (   645.161 @ 0x21c7240 / sync.debug) executing SyncDictionariesCommand(0x19a9860) 
May 15 12:22:56 nickel: (   645.161 @ 0x21c7240 / sync.debug) virtual void SyncDictionariesCommand::execute() 
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-fr-en.zip)
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::size() = 1586132
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-it-en.zip)
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::size() = 1019627
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-pt.zip)
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::size() = 10331401
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml.zip)
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::size() = 7454432
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-de-en.zip)
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::size() = 926221
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-es-en.zip)
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::size() = 1666763
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-pt-en.zip)
May 15 12:22:56 nickel: (dictbug-trace) QFileInfo::size() = 513597
May 15 12:22:56 nickel: (   645.797 @ 0x21c7240 / packetdump.warning) "https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-ox.zip" => "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-ox.zip - server replied: Not Found" 
May 15 12:22:56 nickel: (   645.798 @ 0x21c7240) void FileSizeGetter::onFinished() FAILED! 203 "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-ox.zip - server replied: Not Found" 
May 15 12:22:56 nickel: (   645.798 @ 0x21c7240 / sync.warning) void SyncDictionariesCommand::prepareDownloadList() Get size failed:  203 0 
May 15 12:22:57 nickel: (   646.064 @ 0x21c7240 / packetdump.warning) "https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-wb.zip" => "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-wb.zip - server replied: Not Found" 
May 15 12:22:57 nickel: (   646.065 @ 0x21c7240) void FileSizeGetter::onFinished() FAILED! 203 "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-wb.zip - server replied: Not Found" 
May 15 12:22:57 nickel: (   646.065 @ 0x21c7240 / sync.warning) void SyncDictionariesCommand::prepareDownloadList() Get size failed:  203 0 
May 15 12:22:57 nickel: (   646.309 @ 0x21c7240 / packetdump.warning) "https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-gt.zip" => "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-gt.zip - server replied: Not Found" 
May 15 12:22:57 nickel: (   646.310 @ 0x21c7240) void FileSizeGetter::onFinished() FAILED! 203 "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-gt.zip - server replied: Not Found" 
May 15 12:22:57 nickel: (   646.310 @ 0x21c7240 / sync.warning) void SyncDictionariesCommand::prepareDownloadList() Get size failed:  203 0 
May 15 12:22:57 nickel: (dictbug-trace) QNetworkAccessManager::get(QNetworkRequest.url:`https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-it.zip`)
May 15 12:22:57 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/tmpDictionary)
May 15 12:22:57 nickel: (dictbug-trace) QFileInfo::size() = 0
May 15 12:22:58 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-it.zip)
May 15 12:22:58 nickel: (dictbug-trace) QFileInfo::size() = 2759697
May 15 12:22:58 nickel: (   647.498 @ 0x21c7240 / sync.debug) SyncDictionariesCommand(0x19a9860) finished 
May 15 12:22:58 nickel: (   647.498 @ 0x21c7240 / sync.debug) =================== SYNC QUEUE [ SyncClient(0x1c7d038) ] ==================== 
May 15 12:22:58 nickel: (   647.498 @ 0x21c7240 / sync.debug) =================================================== 
May 15 12:22:58 nickel: (   647.499 @ 0x21c7240 / sync.debug)    
May 15 12:22:58 nickel: (   647.499 @ 0x21c7240 / sync.debug) pumping with 0 pending commands and 0 active commands 
May 15 12:22:58 nickel: (   647.499 @ 0x21c7240 / sync.debug) finished sync client

And a sync after it's been installed:

May 15 12:23:12 nickel: (   661.563 @ 0x20e5360 / sync.debug) =================== SYNC QUEUE [ SyncClient(0x21d8300) ] ==================== 
May 15 12:23:12 nickel: (   661.563 @ 0x20e5360 / sync.debug)  ----- Queued ------- 
May 15 12:23:12 nickel: (   661.563 @ 0x20e5360 / sync.debug)  [ SyncDictionariesCommand(0x20f2828) ] 
May 15 12:23:12 nickel: (   661.563 @ 0x20e5360 / sync.debug)  [ FrictionlessReadingCommand(0x215f768) ] 
May 15 12:23:12 nickel: (   661.563 @ 0x20e5360 / sync.debug)  [ DownloadQueuedBooksCommand(0x2130860) ] 
May 15 12:23:12 nickel: (   661.564 @ 0x20e5360 / sync.debug)  [ CleanupCommand(0x21899b0) ] 
May 15 12:23:12 nickel: (   661.564 @ 0x20e5360 / sync.debug) =================================================== 
May 15 12:23:12 nickel: (   661.564 @ 0x20e5360 / sync.debug)    
May 15 12:23:12 nickel: (   661.564 @ 0x20e5360 / sync.debug) pumping with 4 pending commands and 0 active commands 
May 15 12:23:12 nickel: (   661.564 @ 0x20e5360 / sync.debug) executing SyncDictionariesCommand(0x20f2828) 
May 15 12:23:12 nickel: (   661.564 @ 0x20e5360 / sync.debug) virtual void SyncDictionariesCommand::execute() 
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-fr-en.zip)
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::size() = 1586132
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-it-en.zip)
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::size() = 1019627
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-pt.zip)
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::size() = 10331401
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-it.zip)
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::size() = 2759697
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml.zip)
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::size() = 7454432
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-de-en.zip)
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::size() = 926221
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-es-en.zip)
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::size() = 1666763
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::QFileInfo(/mnt/onboard/.kobo/dict/dicthtml-pt-en.zip)
May 15 12:23:12 nickel: (dictbug-trace) QFileInfo::size() = 513597
May 15 12:23:13 nickel: (   662.060 @ 0x20e5360 / packetdump.warning) "https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-ox.zip" => "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-ox.zip - server replied: Not Found" 
May 15 12:23:13 nickel: (   662.061 @ 0x20e5360) void FileSizeGetter::onFinished() FAILED! 203 "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-ox.zip - server replied: Not Found" 
May 15 12:23:13 nickel: (   662.061 @ 0x20e5360 / sync.warning) void SyncDictionariesCommand::prepareDownloadList() Get size failed:  203 0 
May 15 12:23:13 nickel: (   662.310 @ 0x20e5360 / packetdump.warning) "https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-wb.zip" => "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-wb.zip - server replied: Not Found" 
May 15 12:23:13 nickel: (   662.310 @ 0x20e5360) void FileSizeGetter::onFinished() FAILED! 203 "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-wb.zip - server replied: Not Found" 
May 15 12:23:13 nickel: (   662.311 @ 0x20e5360 / sync.warning) void SyncDictionariesCommand::prepareDownloadList() Get size failed:  203 0 
May 15 12:23:13 nickel: (   662.564 @ 0x20e5360 / packetdump.warning) "https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-gt.zip" => "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-gt.zip - server replied: Not Found" 
May 15 12:23:13 nickel: (   662.565 @ 0x20e5360) void FileSizeGetter::onFinished() FAILED! 203 "Error downloading https://kbdownload1-a.akamaihd.net/ereader/dictionaries/v2/dicthtml-gt.zip - server replied: Not Found" 
May 15 12:23:13 nickel: (   662.565 @ 0x20e5360 / sync.warning) void SyncDictionariesCommand::prepareDownloadList() Get size failed:  203 0 
May 15 12:23:13 nickel: (   662.565 @ 0x20e5360 / sync.debug) SyncDictionariesCommand(0x20f2828) finished

So, I'll need to figure out what conditions the file size check with tmpDictionary is called under (notice how it was only called in the first of these logs).

pgaskin commented 4 years ago

Using this, I've narrowed down further. It's not related to tmpDictionary directly, but it's still related to the size check in prepareDownloadList.

pgaskin commented 4 years ago

This is an educated guess (I'm still looking at it), but I think the issue can be fixed by swapping the order of the size/permission checks so permissions come first.

EDIT: Even after my discovery below, this would likely still fix it, but it may not be the root cause of the bug.

pgaskin commented 4 years ago

An update for the comment a few ones above (I missed the FileSizeGetter stuff, which is probably why some parts of this bug didn't make complete sense to me after I eliminated tmpDictionary as the cause):

Some context about where Dictionary::isSynced() comes from now that the DB isn't used:
0x6be680 - Dictionary::isSynced() gets the value stored at *(Dictionary + 0x18), which is set to
0x6be454 - r5, which is:
0x6be410 - the stack argument at 0x20 to the constructor Dictionary::Dictionary(QString const&, QString const&, bool, long long, bool), which is passed from
0x55b980 - DictionaryFileManager::getAll(*Device), which sets it to
0x55b96c - *(r8 - 0x8), which is set from:
0x55bec8 - ^ which is actually N/A, since Dictionary::setSynced(QVariant const&) is called later on, with the argument being:
0x55bec0 -     set to a QVariant of a bool, initialized from r1, which is set
0x55beba -     to true if
0x55beb2 -       sb == r1
0x55beb6 -       && r8 == r0, where
0x55beac -         sb = r1 (making the first comparision always true), and
0x55beae -         r0 = Dictionary::size(), and
0x55bea4 -         r8 = IOUtil::sizeIncludingSubdirectories(QFileInfo const&) (!?!, why?, I thought it already checked if it was a dir earlier, because this is basically always true if the dictionary is a file)
0x55bec8 - thus, meaning Dictionary::isSynced() essentially always returns true

The list of dictionaries to skip comes from SyncDictionariesCommand::prepareDownloadList():
0x610618 - UPDATE: the server file size was retrieved here, stored into *(r4 + 0x24)
0x610622 -   UPDATE: if it was 0, it logs "Get size failed: ...", and does the next dictionary
0x6105aa -   UPDATE: otherwise, it continues with the checks
0x6105ae - the first step of the check is Dictionary::isInstalled(), which passes if:
0x6105b2 -   Dictionary::isInstalled() == true (which will be true if the file exists, which it always will for sideloaded dictionaries)
0x610872 - the second step is Dictionary::isSynced(), which passes if:
0x610876 -   Dictionary::isSynced() == true (which will always be true, see above) (this is also why my old trick of setting IsSynced to false in the DB worked)
0x610888 - the third step is DictionaryFileManager::getDictionarySizeOnDisk(Device const&, Dictionary const&), which passes if:
0x610890 -   DictionaryFileManager::getDictionarySizeOnDisk(Device const&, Dictionary const&) >= 1 (it's possible the bug could be in the file size checking, will check after this)
0x6108aa - the last step is DictionaryFileManager::getDictionaryPermissionsOnDisk(Device const&, Dictionary const&), which passes if:
0x6108b0 -   the file is not writable (it checks if the 12th bit of the permissions is 0)
0x6108d8 - and if the checks all passed, a log message to the sync log is written with the text
0x61092a -   "marked as read-only.. skipping"
0x610712 -   and the file is skipped
0x6105c6 - otherwise, if any check failed, the dictionary is appended to the resulting QList<Dictionary>
0x6108c4 -   UPDATE: but if it was the permission check which failed, the server size is compared to the disk size, and the dictionary is only appended to the list if it differs

This means the fact that the size check patch worked was likely a coincidence, and the real issue is either there or in the permissions check.

I'm going to need to add some hooks at each of the checks (which show the result and value) to figure this out. Since this is a bit more work to do, and the bug seems relatively straightforward overall, I'll wait and see if this is fixed in the next firmware version (if there's one within the next week or two) before looking at this further.

ViieeS commented 4 years ago

@geek1011 I copied your patch to src/nickel.yaml, but it doesn't work. I tried to set Enabled: yes, but then kobopatch.bat crashes. What am I doing wrong?

dictutil v0.3.1 FW v4.22.15190

pgaskin commented 4 years ago

You need to put it into libnickel, not nickel.

ViieeS commented 4 years ago

@geek1011 Thank you, also I missed this:

Never sync dictionaries:
- Enabled: no
- BaseAddress:  {Sym: "SyncDictionariesCommand::prepareDownloadList()"}
- ReplaceBytes: {Offset: 922, FindH: 0CD5,     ReplaceH:       0CE0}   #permissions
- ReplaceBytes: {Offset: 900, FindH: FFF6CAAE, ReplaceInstNOP: true}   #size
- ReplaceBytes: {Offset: 866, FindH: 3FF4DBAE, ReplaceInstNOP: true}   #isSynced

https://pgaskin.net/dictutil/dicthtml/install.html#issues-with-the-read-only-method-for-preventing-dictionaries-from-being-overwritten

loyukfai commented 4 years ago

@geek1011 Thanks a lot for your work. It seems with the latest firmware, regardless of the read only flag, the device will still replace custom dicts.

Right now, am using the custom (translation) dicts + 'Enable searches on extra dictionaries patch'. Which means firmware patching is still needed.

Cheers.

pgaskin commented 4 years ago

This issue is still there in 15268.

pgaskin commented 4 years ago

Same with 15505.