nextcloud / mail

💌 Mail app for Nextcloud
https://apps.nextcloud.com/apps/mail
GNU Affero General Public License v3.0
840 stars 260 forks source link

Error Log entrys #8151

Open KoMa1012 opened 1 year ago

KoMa1012 commented 1 year ago

Steps to reproduce

  1. no trigger point found, just happens

Expected behavior

no entry in error log

I don't know if it is related, but I'm seeing issues with drafts, it stores multiple drafts if I create an e-mail, it seems like it's not recognizing old drafts.

Actual behavior

Multiple entries in error log, I'm not sure how they relate to each other, but they show up indipendendly.

Error Entry1:

[mail] Error: OCA\Mail\Exception\ServiceException: Deserialized estimator has an unknown type Rubix\ML\Encoding at <<closure>>

 0. /var/www/html/custom_apps/mail/lib/Service/Classification/PersistenceService.php line 162
    OCA\Mail\Service\Classification\PersistenceService->load(96)
 1. /var/www/html/custom_apps/mail/lib/Service/Classification/ImportanceClassifier.php line 300
    OCA\Mail\Service\Classification\PersistenceService->loadLatest(OCA\Mail\Account {})
 2. /var/www/html/custom_apps/mail/lib/Listener/NewMessageClassificationListener.php line 118
    OCA\Mail\Service\Classification\ImportanceClassifier->classifyImportance(OCA\Mail\Account {}, OCA\Mail\Db\Mailbox {id: 21}, [OCA\Mail\Db\Message {id: null}])
 3. /var/www/html/lib/private/EventDispatcher/ServiceEventListener.php line 87
    OCA\Mail\Listener\NewMessageClassificationListener->handle(OCA\Mail\Events\ ... {})
 4. /var/www/html/3rdparty/symfony/event-dispatcher/EventDispatcher.php line 251
    OC\EventDispatcher\ServiceEventListener->__invoke(OCA\Mail\Events\ ... {}, "OCA\\Mail\\Even ... d", Symfony\Componen ... {})
 5. /var/www/html/3rdparty/symfony/event-dispatcher/EventDispatcher.php line 73
    Symfony\Component\EventDispatcher\EventDispatcher->callListeners([Closure {}], "OCA\\Mail\\Even ... d", OCA\Mail\Events\ ... {})
 6. /var/www/html/lib/private/EventDispatcher/EventDispatcher.php line 88
    Symfony\Component\EventDispatcher\EventDispatcher->dispatch(OCA\Mail\Events\ ... {}, "OCA\\Mail\\Even ... d")
 7. /var/www/html/custom_apps/mail/lib/Service/Sync/ImapToDbSynchronizer.php line 401
    OC\EventDispatcher\EventDispatcher->dispatch("OCA\\Mail\\Even ... d", OCA\Mail\Events\ ... {})
 8. /var/www/html/custom_apps/mail/lib/Service/Sync/ImapToDbSynchronizer.php line 235
    OCA\Mail\Service\Sync\ImapToDbSynchronizer->runPartialSync(OCA\Mail\Account {}, OCA\Mail\Db\Mailbox {id: 21}, OC\AppFramework\ScopedPsrLogger {}, 42, null)
 9. /var/www/html/custom_apps/mail/lib/Service/Sync/ImapToDbSynchronizer.php line 136
    OCA\Mail\Service\Sync\ImapToDbSynchronizer->sync(OCA\Mail\Account {}, OCA\Mail\Db\Mailbox {id: 21}, OC\AppFramework\ScopedPsrLogger {}, 42, null, false, true)
10. /var/www/html/custom_apps/mail/lib/BackgroundJob/SyncJob.php line 110
    OCA\Mail\Service\Sync\ImapToDbSynchronizer->syncAccount(OCA\Mail\Account {}, OC\AppFramework\ScopedPsrLogger {})
11. /var/www/html/lib/public/BackgroundJob/Job.php line 78
    OCA\Mail\BackgroundJob\SyncJob->run([3])
12. /var/www/html/lib/public/BackgroundJob/TimedJob.php line 103
    OCP\BackgroundJob\Job->start(OC\BackgroundJob\JobList {})
13. /var/www/html/lib/public/BackgroundJob/TimedJob.php line 93
    OCP\BackgroundJob\TimedJob->start(OC\BackgroundJob\JobList {})
14. /var/www/html/cron.php line 152
    OCP\BackgroundJob\TimedJob->execute(OC\BackgroundJob\JobList {}, OC\Log {})

at 2023-02-26T18:30:05+01:00

Error Entry 2 (account is working, this shows up irregularily all the other accounts are working) :

[mail] Error: OCA\Mail\Exception\ServiceException: IMAP error synchronizing account 1: Authentication failed. at <<closure>>

0. /var/www/html/custom_apps/mail/lib/Service/MailManager.php line 140
   OCA\Mail\IMAP\MailboxSync->sync(OCA\Mail\Account {}, OC\AppFramework\ScopedPsrLogger {})
1. /var/www/html/custom_apps/mail/lib/Controller/PageController.php line 130
   OCA\Mail\Service\MailManager->getMailboxes(OCA\Mail\Account {})
2. /var/www/html/custom_apps/mail/lib/Controller/PageController.php line 252
   OCA\Mail\Controller\PageController->index()
3. /var/www/html/lib/private/AppFramework/Http/Dispatcher.php line 225
   OCA\Mail\Controller\PageController->thread(6, 4370)
4. /var/www/html/lib/private/AppFramework/Http/Dispatcher.php line 133
   OC\AppFramework\Http\Dispatcher->executeController(OCA\Mail\Controller\PageController {}, "thread")
5. /var/www/html/lib/private/AppFramework/App.php line 172
   OC\AppFramework\Http\Dispatcher->dispatch(OCA\Mail\Controller\PageController {}, "thread")
6. /var/www/html/lib/private/Route/Router.php line 298
   OC\AppFramework\App::main("OCA\\Mail\\Controller\\PageController", "thread", OC\AppFramework\ ... {}, ["6","4370","mail.page.thread"])
7. /var/www/html/lib/base.php line 1047
   OC\Route\Router->match("/apps/mail/box/6/thread/4370")
8. /var/www/html/index.php line 36
   OC::handleRequest()

GET /apps/mail/box/6/thread/4370
from 172.68.253.132 by hedwig at 2023-02-26T20:19:09+01:00

Error Entry 3:

[mail] Error: TypeError: Rubix\ML\Persisters\Filesystem::save(): Argument #1 ($encoding) must be of type Rubix\ML\Encoding, Rubix\ML\Classifiers\GaussianNB given, called in /var/www/html/custom_apps/mail/lib/Service/Classification/PersistenceService.php on line 118 at <<closure>>

0. /var/www/html/custom_apps/mail/lib/Service/Classification/PersistenceService.php line 118
   Rubix\ML\Persisters\Filesystem->save(Rubix\ML\Classifiers\GaussianNB {})
1. /var/www/html/custom_apps/mail/lib/Service/Classification/ImportanceClassifier.php line 220
   OCA\Mail\Service\Classification\PersistenceService->persist(OCA\Mail\Db\Classifier {id: 249}, Rubix\ML\Classifiers\GaussianNB {})
2. /var/www/html/custom_apps/mail/lib/BackgroundJob/TrainImportanceClassifierJob.php line 97
   OCA\Mail\Service\Classification\ImportanceClassifier->train(OCA\Mail\Account {}, OC\AppFramework\ScopedPsrLogger {})
3. /var/www/html/lib/public/BackgroundJob/Job.php line 78
   OCA\Mail\BackgroundJob\TrainImportanceClassifierJob->run([5])
4. /var/www/html/lib/public/BackgroundJob/TimedJob.php line 103
   OCP\BackgroundJob\Job->start(OC\BackgroundJob\JobList {})
5. /var/www/html/lib/public/BackgroundJob/TimedJob.php line 93
   OCP\BackgroundJob\TimedJob->start(OC\BackgroundJob\JobList {})
6. /var/www/html/cron.php line 152
   OCP\BackgroundJob\TimedJob->execute(OC\BackgroundJob\JobList {}, OC\Log {})

at 2023-02-25T15:24:50+01:00

Warning entry 1 (show up quite often, once or twice per hour):

[mail] Warning: Horde_Imap_Client_Exception: Authentication failed. at <<closure>>

 0. /var/www/html/custom_apps/mail/vendor/bytestream/horde-imap-client/lib/Horde/Imap/Client/Socket.php line 4565
    Horde_Imap_Client_Socket->_responseCode(Horde_Imap_Clien ... }}, Horde_Imap_Clien ... "})
 1. /var/www/html/custom_apps/mail/vendor/bytestream/horde-imap-client/lib/Horde/Imap/Client/Socket.php line 4313
    Horde_Imap_Client_Socket->_getLine(Horde_Imap_Clien ... }})
 2. /var/www/html/custom_apps/mail/vendor/bytestream/horde-imap-client/lib/Horde/Imap/Client/Socket.php line 4241
    Horde_Imap_Client_Socket->_sendCmdChunk(Horde_Imap_Clien ... }}, [Horde_Imap_Clie ... }])
 3. /var/www/html/custom_apps/mail/vendor/bytestream/horde-imap-client/lib/Horde/Imap/Client/Socket.php line 849
    Horde_Imap_Client_Socket->_sendCmd(Horde_Imap_Clien ... }})
 4. /var/www/html/custom_apps/mail/vendor/bytestream/horde-imap-client/lib/Horde/Imap/Client/Socket.php line 512
    Horde_Imap_Client_Socket->_tryLogin("*** sensitive parameters replaced ***")
 5. /var/www/html/custom_apps/mail/vendor/bytestream/horde-imap-client/lib/Horde/Imap/Client/Base.php line 850
    Horde_Imap_Client_Socket->_login("*** sensitive parameters replaced ***")
 6. /var/www/html/custom_apps/mail/vendor/bytestream/horde-imap-client/lib/Horde/Imap/Client/Base.php line 2507
    Horde_Imap_Client_Base->login("*** sensitive parameters replaced ***")
 7. /var/www/html/custom_apps/mail/vendor/bytestream/horde-imap-client/lib/Horde/Imap/Client/Base.php line 2490
    Horde_Imap_Client_Base->_fetchWrapper("INBOX", Horde_Imap_Client_Fetch_Query {}, [Horde_Imap_Clie ... }])
 8. /var/www/html/custom_apps/mail/lib/IMAP/MessageMapper.php line 674
    Horde_Imap_Client_Base->fetch("INBOX", Horde_Imap_Client_Fetch_Query {}, [Horde_Imap_Clie ... }])
 9. /var/www/html/custom_apps/mail/lib/IMAP/PreviewEnhancer.php line 86
    OCA\Mail\IMAP\MessageMapper->getBodyStructureData(Horde_Imap_Clien ... e}, "INBOX", [7563,7565,7568, ... "])
10. /var/www/html/custom_apps/mail/lib/Service/PreprocessingService.php line 81
    OCA\Mail\IMAP\PreviewEnhancer->process(OCA\Mail\Account {}, OCA\Mail\Db\Mailbox {id: 6}, [OCA\Mail\Db\Mes ... "])
11. /var/www/html/custom_apps/mail/lib/BackgroundJob/PreviewEnhancementProcessingJob.php line 94
    OCA\Mail\Service\PreprocessingService->process(1676171985, OCA\Mail\Account {})
12. /var/www/html/lib/public/BackgroundJob/Job.php line 78
    OCA\Mail\BackgroundJob\PreviewEnhancementProcessingJob->run([1])
13. /var/www/html/lib/public/BackgroundJob/TimedJob.php line 103
    OCP\BackgroundJob\Job->start(OC\BackgroundJob\JobList {})
14. /var/www/html/lib/public/BackgroundJob/TimedJob.php line 93
    OCP\BackgroundJob\TimedJob->start(OC\BackgroundJob\JobList {})
15. /var/www/html/cron.php line 152
    OCP\BackgroundJob\TimedJob->execute(OC\BackgroundJob\JobList {}, OC\Log {})

at 2023-02-26T04:20:04+01:00

Mail app version

2.2.3

Mailserver or service

netcup

Operating system

docker container (official)

PHP engine version

PHP 8.1

Web server

Apache (supported)

Database

MariaDB

Additional info

can provide full error log if necessary

ChristophWurst commented 1 year ago

Auth and Rubix are unrelated

Rubix probably shows because you just updated the app. Check again tomorrow when all ML models have been regenerated with the new version of the Rubix lib.

KoMa1012 commented 1 year ago

rubix is appearing every ~2-3times per day since a while now, not only since the update.

ChristophWurst commented 1 year ago

:eyes: @st3iny

st3iny commented 1 year ago

Something weird is going on here. Did you downgrade the Mail app recently?

The stable2.2 branch is still on the old persistence code and should not throw those errors.

KoMa1012 commented 1 year ago

no, I never downgraded, I only went up in versions.

ChristophWurst commented 1 year ago

Navigate to your Nextcloud root directory and search for the Encoding.php class like

$ find . -path "*/src/Encoding.php"
./apps/mail/vendor/rubix/ml/src/Encoding.php
./apps/suspicious_login/vendor/rubix/ml/src/Encoding.php
KoMa1012 commented 1 year ago

find . -path "*/src/Encoding.php" returns: ./apps/suspicious_login/vendor/rubix/ml/src/Encoding.php

KoMa1012 commented 1 year ago

is there any more information required by me? Because it is still labeled as "needs info"

st3iny commented 1 year ago

is there any more information required by me? Because it is still labeled as "needs info"

No, all good. Thank your for helping with debugging.

We had a suspicion which you confirmed. The suspicious_login app is shipping a newer version of Rubix which is overriding the version of the mail app. That is problematic because there are incompatibilities between the two versions which break classification if both apps are used together.

We will work on a solution when time permits. Please be patient or disable the suspicious_login login app in the meantime.

KoMa1012 commented 1 year ago

suspicious_login app is and was deactivated, it's still howing up in the app list (there is no remove button). If you don't remove the data manually your explanation doesn't fit my experience.

st3iny commented 1 year ago

Right, the app is shipped and can't be removed. I forgot about that, sorry :sweat_smile:

In that case, I fear we have to work on a solution with a bit more urgency.

marianionut commented 1 year ago

This is happening to me also, I have ubuntu 22.04 and nextcloud snap version 25.0.6

I disabled the suspicious_login app, but I'm still seeing

Errormail2023-04-28T20:20:10+0300
OCA\Mail\Exception\ServiceException: Deserialized estimator has an unknown type Rubix\ML\Encoding
vitis586 commented 1 year ago

Personally I had to delete suspicious login folder from my Nextcloud apps folder.

KoMa1012 commented 1 year ago

still active in mail 2.2.6 with NC 25.0.7.