Could not deserialize persisted model
leaderred opened this issue · 31 comments
I have a lot of following errors on NC protocol:
"Could not deserialize persisted model 254: Missing class definition for unserialized object."
Here are the raw data:
{"reqId":"tDWLs8oLa6wApE1uFe9r","level":4,"time":"2021-04-12T10:19:43+00:00","remoteAddr":"192.168.1.101","user":"sync","app":"suspicious_login","method":"REPORT","url":"/remote.php/dav/addressbooks/users/sync/gemeinsam/","message":"Could not deserialize persisted model 254: Missing class definition for unserialized object.","userAgent":"macOS/11.2.3 (20D91) AddressBookCore/2452.4","version":"21.0.1.1","id":"60741ec2b4442"}
Steps to reproduce
Expected behaviour
Contact sync is ok. I have very much denied http request regarding to contact/calendar sync. I dont know, if this have something to do with each other.
Actual behaviour
This error in nc protocol
Server configuration
**Operating system: linuxserver/nextcloud docker image
**Web server: nginx (linuxserver/nextcloud docker image)
**Database: MariaDB (linuxserver/nextcloud docker image)
**PHP version: 7.4.15
**Nextcloud version: 21.0.1
**Updated from an older Nextcloud/ownCloud or fresh install: Updated from 20.xx
**Where did you install Nextcloud from: docker image
Signing status:
Signing status
No errors have been found.
List of activated apps:
App list
Enabled:
- accessibility: 1.7.0
- activity: 2.14.3
- admin_audit: 1.11.0
- bruteforcesettings: 2.1.0
- calendar: 2.2.0
- cloud_federation_api: 1.4.0
- contacts: 3.5.1
- contactsinteraction: 1.2.0
- dashboard: 7.1.0
- dav: 1.17.1
- federatedfilesharing: 1.11.0
- files: 1.16.0
- files_pdfviewer: 2.1.0
- files_rightclick: 1.0.0
- files_sharing: 1.13.1
- files_trackdownloads: 1.10.0
- files_trashbin: 1.11.0
- files_versions: 1.14.0
- files_videoplayer: 1.10.0
- firstrunwizard: 2.10.0
- forms: 2.2.4
- logreader: 2.6.0
- lookup_server_connector: 1.9.0
- mail: 1.9.5
- nextcloud_announcements: 1.10.0
- notifications: 2.9.0
- oauth2: 1.9.0
- password_policy: 1.11.0
- photos: 1.3.0
- previewgenerator: 3.1.1
- privacy: 1.5.0
- provisioning_api: 1.11.0
- recommendations: 1.0.0
- serverinfo: 1.11.0
- settings: 1.3.0
- support: 1.4.0
- suspicious_login: 4.0.0
- systemtags: 1.11.0
- tasks: 0.13.6
- text: 3.2.0
- theming: 1.12.0
- twofactor_backupcodes: 1.10.0
- twofactor_totp: 6.0.0
- updatenotification: 1.11.0
- user_status: 1.1.1
- viewer: 1.5.0
- weather_status: 1.1.0
- workflowengine: 2.3.0
Disabled:
- comments
- encryption
- federation
- files_external
- sharebymail
- spreed
- survey_client
- user_ldap
Nextcloud configuration:
Config report
{
"system": {
"memcache.local": "\\OC\\Memcache\\APCu",
"datadirectory": "***REMOVED SENSITIVE VALUE***",
"instanceid": "***REMOVED SENSITIVE VALUE***",
"passwordsalt": "***REMOVED SENSITIVE VALUE***",
"secret": "***REMOVED SENSITIVE VALUE***",
"trusted_domains": [
"local_name:9443",
"my_domain.me"
],
"trusted_proxies": "***REMOVED SENSITIVE VALUE***",
"dbtype": "mysql",
"version": "21.0.1.1",
"overwrite.cli.url": "https:\/\/local_name:9443",
"dbname": "***REMOVED SENSITIVE VALUE***",
"dbhost": "***REMOVED SENSITIVE VALUE***",
"dbport": "",
"dbtableprefix": "oc_",
"mysql.utf8mb4": true,
"dbuser": "***REMOVED SENSITIVE VALUE***",
"dbpassword": "***REMOVED SENSITIVE VALUE***",
"installed": true,
"maintenance": false,
"twofactor_enforced": "false",
"twofactor_enforced_groups": [],
"twofactor_enforced_excluded_groups": [],
"theme": "",
"loglevel": 0,
"mail_from_address": "***REMOVED SENSITIVE VALUE***",
"mail_smtpmode": "smtp",
"mail_sendmailmode": "smtp",
"mail_domain": "***REMOVED SENSITIVE VALUE***",
"mail_smtpauthtype": "LOGIN",
"mail_smtpsecure": "tls",
"mail_smtphost": "***REMOVED SENSITIVE VALUE***",
"mail_smtpport": "587",
"mail_smtpauth": 1,
"mail_smtpname": "***REMOVED SENSITIVE VALUE***",
"mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
"app_install_overwrite": [
"calendar",
"bruteforcesettings"
],
"default_phone_region": "DE"
}
}
**Are you using external storage, if yes which one: no
**Are you using encryption: no
**Are you using an external user-backend, if yes which one: no
Client configuration
**Browser: Brave
**Operating system: MacOS
Logs
Web server error log
Web server error log
Insert your webserver log here
Nextcloud log (data/nextcloud.log)
Nextcloud log
{"reqId":"9bA52GmunmHWrJpsINnX","level":4,"time":"2021-04-12T10:31:17+00:00","remoteAddr":"192.168.1.101","user":"my_second_user","app":"suspicious_login","method":"REPORT","url":"/remote.php/dav/addressbooks/users/my_second_user/gemeinsam/","message":"Could not deserialize persisted model 254: Missing class definition for unserialized object.","userAgent":"macOS/11.2.3 (20D91) AddressBookCore/2452.4","version":"21.0.1.1"}
{"reqId":"9bA52GmunmHWrJpsINnX","level":2,"time":"2021-04-12T10:31:17+00:00","remoteAddr":"192.168.1.101","user":"my_second_user","app":"suspicious_login","method":"REPORT","url":"/remote.php/dav/addressbooks/users/my_second_user/gemeinsam/","message":"Could not predict suspiciousness: Could not load model to classify UID sync and IP 192.168.1.101: Missing class definition for unserialized object.","userAgent":"macOS/11.2.3 (20D91) AddressBookCore/2452.4","version":"21.0.1.1"}
{"reqId":"bmpsLJ0UpDOFP1Rq8qKM","level":0,"time":"2021-04-12T10:31:20+00:00","remoteAddr":"192.168.1.101","user":"my_user","app":"suspicious_login","method":"PROPFIND","url":"/remote.php/dav/files/my_user/","message":"/appinfo/app.php is deprecated, use \\OCP\\AppFramework\\Bootstrap\\IBootstrap on the application class instead.","userAgent":"Mozilla/5.0 (Macintosh) mirall/3.1.3git (build 4850) (Nextcloud)","version":"21.0.1.1"}
{"reqId":"bmpsLJ0UpDOFP1Rq8qKM","level":0,"time":"2021-04-12T10:31:20+00:00","remoteAddr":"192.168.1.101","user":"my_user","app":"contacts","method":"PROPFIND","url":"/remote.php/dav/files/my_user/","message":"/appinfo/app.php is deprecated, use \\OCP\\AppFramework\\Bootstrap\\IBootstrap on the application class instead.","userAgent":"Mozilla/5.0 (Macintosh) mirall/3.1.3git (build 4850) (Nextcloud)","version":"21.0.1.1"}
{"reqId":"bmpsLJ0UpDOFP1Rq8qKM","level":0,"time":"2021-04-12T10:31:20+00:00","remoteAddr":"192.168.1.101","user":"my_user","app":"files_sharing","method":"PROPFIND","url":"/remote.php/dav/files/my_user/","message":"/appinfo/app.php is deprecated, use \\OCP\\AppFramework\\Bootstrap\\IBootstrap on the application class instead.","userAgent":"Mozilla/5.0 (Macintosh) mirall/3.1.3git (build 4850) (Nextcloud)","version":"21.0.1.1"}
I see similar messages (at warning, error and fatal level) in my log (using NC 21.0.1 with suspicious_login 4.0.0):
Error: Minimum value must be less than or equal to the maximum value
/var/www/nextcloud/apps/suspicious_login/lib/Service/NegativeSampleGenerator.php - line 74:
random_int()
/var/www/nextcloud/apps/suspicious_login/lib/Service/NegativeSampleGenerator.php - line 114:
OCA\SuspiciousLogin\Service\NegativeSampleGenerator->generateFromRealData()
<<closure>>
OCA\SuspiciousLogin\Service\NegativeSampleGenerator->OCA\SuspiciousLogin\Service\{closure}("*** sensiti ... *")
/var/www/nextcloud/apps/suspicious_login/lib/Service/NegativeSampleGenerator.php - line 115:
array_map()
/var/www/nextcloud/apps/suspicious_login/lib/Service/DataLoader.php - line 123:
OCA\SuspiciousLogin\Service\NegativeSampleGenerator->generateShuffledFromPositiveSamples()
/var/www/nextcloud/apps/suspicious_login/lib/Service/TrainService.php - line 72:
OCA\SuspiciousLogin\Service\DataLoader->generateRandomShuffledData()
/var/www/nextcloud/apps/suspicious_login/lib/BackgroundJob/TrainJobIpV6.php - line 64:
OCA\SuspiciousLogin\Service\TrainService->train()
/var/www/nextcloud/lib/public/BackgroundJob/Job.php - line 80:
OCA\SuspiciousLogin\BackgroundJob\TrainJobIpV6->run()
/var/www/nextcloud/lib/public/BackgroundJob/TimedJob.php - line 61:
OCP\BackgroundJob\Job->execute()
/var/www/nextcloud/cron.php - line 128:
OCP\BackgroundJob\TimedJob->execute()
and
[suspicious_login] Fatal: Could not deserialize persisted model 960: Missing class definition for unserialized object.
POST /login
from [ipv6 address] by [username] at 2021-04-13T13:33:08+02:00
and
[suspicious_login] Warning: Could not predict suspiciousness: Could not load model to classify UID [username] and IP [ipv6 address]: Missing class definition for unserialized object.
POST /login
from [ipv6 address] by [username] at 2021-04-13T13:33:08+02:00
I redacted [username] and [ipv6 address]. At first sight there seems to be an issue with how ipv6 addresses are handled.
did this possibly happen shortly after an upgrade? do you have the mail app enabled as well?
@ChristophWurst Yes happened shortly after the upgrade (both NC and suspicious_login), a couple of times. After that I didn't see it happen back again. No, mail app isn't enabled.
I see. Then this is actually expected. With v4 we had to switch out the old ML lib. The new lib can't load the serialized object of the old lib. Once the app did a daily retraining of the model the error should go away.
OK; that's definitely consistent with what I observed. But perhaps the case should be provided for somewhere in the code such that no errors result?
Yeah, ideally. Right now the best you can do as admin is running a training job from the CLI manually right after the upgrade. I should have included that in the changelog.
OK, I think we can close this one. There's more obscure issues that need attention.
Hey, the error still occures. Can i execute a cli command to fix it?
Yeah we may have concluded to soon. The errors are coming back, even when more than 24h have passed since upgrading to V4.
Could you please share the contents of such a model file? You'll find that in data/appdata_xyz/suspicious_login/models/123
@ChristophWurst Attached.
960.zip
I'm seeing Error: Minimum value must be less than or equal to the maximum value once every 24 hours at around the same time.
Sometimes I see Could not deserialize persisted model 709: Missing class definition for unserialized object. but not on a daily basis.
Hello,
similar here, but with mail-app enabled.
I've attached a model-file. but it seems that the latest one was not updatyed for quite some time (2021/02/02).
HTH & Thanks
{“reqId”:“FSkb8TJpvQQvZf7dR0kx”,“level”:4,“time”:“2021-04-19T20:42:29+00:00”,“remoteAddr”:“xxx.xx.x.x”,“user”:“xxxxxx”,“app”:“suspicious_login”,“method”:“GET”,“url”:"/index.php/apps/bookmarks/public/rest/v2/folder/36/children?layers=1",“message”:“Could not deserialize persisted model 14: Missing class definition for unserialized object.”,“userAgent”:“Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:87.0) Gecko/20100101 Firefox/87.0”,“version”:“21.0.1.1”} {“reqId”:“FSkb8TJpvQQvZf7dR0kx”,“level”:2,“time”:“2021-04-19T20:42:29+00:00”,“remoteAddr”:“xxx.xx.x.x”,“user”:“xxxxxx”,“app”:“suspicious_login”,“method”:“GET”,“url”:"/index.php/apps/bookmarks/public/rest/v2/folder/36/children?layers=1",“message”:“Could not predict suspiciousness: Could not load model to classify UID binky and IP xxx.xx.x.x: Missing class definition for unserialized object.”,“userAgent”:“Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:87.0) Gecko/20100101 Firefox/87.0”,“version”:“21.0.1.1”}
but it seems that the latest one was not updatyed for quite some time (2021/02/02)
Could you elaborate on this?
I checked my personal instance, the last model from oc_suspicious_login_model was created at 1619395504 -> tonight. That means the automatic retraining still happens. Is that not the case for you?
Hello Christoph,
indeed - I just checked again: the latest file in data/appdata_xyz/suspicious_login/models/ is from Feb 2nd.
The suspicious_login-app is (and always was) enabled (now at v4.0.0).
The visualization of historic model performance under admin=>settigs=>administration=>security stops also at that time - text above says During evaluation, the latest model (trained vor 3 Monaten) has shown to capture.
Happy to dig further in case that helps - just let me know.
LG - tullsta
Whoops. Do you have a job for OCA\SuspiciousLogin\BackgroundJob\TrainJobIpV4 in your oc_jobs table?
Hi Christoph,
maybe stupid question: how do I report the oc_jobs table?
In case it gives additional info:
admin=>settings=>Administration=>Overview also does not give any warnings about cron-jobs not being run (set to Ajax at the moment)
LG - tullsta
PS: Running official NC docker image
SELECT * FROM oc_jobs where class="OCA\\SuspiciousLogin\\BackgroundJob\\TrainJob"
Hi - hope I got things right:
MariaDB [(none)]> use nextcloud
MariaDB [nextcloud]> SELECT * FROM oc_jobs where class="OCA\SuspiciousLogin\BackgroundJob\TrainJob";
Empty set (0.000 sec)
nope, you forgot to double-escape the string
\\ vs \
Hi Christoph,
was now a little puzzled, but I did double-escape like:
SELECT * FROM oc_jobs where class="OCA\\SuspiciousLogin\\BackgroundJob\\TrainJob".
it's just that Github replaces double-escapes with single ones when pasting as normal text.
Here the same Ctrl-V w/o code-formatting:
SELECT * FROM oc_jobs where class="OCA\SuspiciousLogin\BackgroundJob\TrainJob"
Database changed
MariaDB [nextcloud]> SELECT * FROM oc_jobs where class="OCA\\SuspiciousLogin\\BackgroundJob\\TrainJob";
Empty set (0.001 sec)
LG - tullsta
Try disabling and re-enabling the app. I hope that brings the job back. I don't know why it's missing for you.
Hey Christoph,
re-installed app and restarted container now, but could not see any change yet.
If there is anything else to try pls. let me know.
LG - tullsta
Hello.
teh re-install/re-start did not change anything.
What I noticed, however, is that the login-count is steadily increasing - see screenshot
below.
Hello - just wanted to ask whether there is a way to re-enable the background job.
Would it be possible to de-install the app such that it starts from a clean status when re-installing again?
Thanks - tullsta
I am still seeing Error: Minimum value must be less than or equal to the maximum value on a daily basis. My background jobs are fine and models are generated daily as expected.
I am still seeing
Error: Minimum value must be less than or equal to the maximum valueon a daily basis. My background jobs are fine and models are generated daily as expected.
I do have these Error: Minimum value must be less than or equal to the maximum value errors as well.
SELECT * FROM oc_jobs where class like "%SuspiciousLogin%"; returns 3 jobs:
- ETLJob
- TrainJobByIpV4
- TrainJobByIpV6
I have no TrainJob.
Whether I disable the app or reactivate it, these jobs stay.... not sure if normal or not.
I'd prefer not removing the app yet as I don't want to lose the trained data.
Meanwhile, I manually launched occ suspiciouslogin:etl occ suspiciouslogin:optimize occ suspiciouslogin:train
Just in case.
I also can see those errors for some of the models, they seem to be all of the removed Phpml type:
[suspicious_login] loading latest model
[suspicious_login] using cached model 685
[suspicious_login] seralized model size: 144554
[suspicious_login] Could not predict suspiciousness: Could not load model to classify UID randomuserid IP 2001:16b8:REMOVED Missing class for object data.
MariaDB [nextcloud]> select * from oc_suspicious_login_model where id = 685;
+-----+------------+------------------------------------+-------------+------------------+------------------+----------------+--------+--------+------------+---------------+-------------+-------------+----------+----------+----------+--------------+
| id | created_at | type | app_version | samples_positive | samples_shuffled | samples_random | epochs | layers | vector_dim | learning_rate | precision_y | precision_n | recall_y | recall_n | duration | address_type |
+-----+------------+------------------------------------+-------------+------------------+------------------+----------------+--------+--------+------------+---------------+-------------+-------------+----------+----------+----------+--------------+
| 685 | 1598248205 | Phpml\Classification\MLPClassifier | 3.1.0 | 597 | 895 | 597 | 20 | 14 | 80 | 0.07000 | 1.00000 | 1.00000 | 1.00000 | 1.00000 | 14 | ipv6 |
+-----+------------+------------------------------------+-------------+------------------+------------------+----------------+--------+--------+------------+---------------+-------------+-------------+----------+----------+----------+--------------+
MariaDB [nextcloud]> select count(*) from oc_suspicious_login_model where type like "Phpml%";
+----------+
| count(*) |
+----------+
| 685 |
+----------+
1 row in set (0.001 sec)
MariaDB [nextcloud]> select count(*) from oc_suspicious_login_model where type not like "Phpml%";
+----------+
| count(*) |
+----------+
| 164 |
+----------+
1 row in set (0.001 sec)
The actual file is also untouched since two years: -rw-rw-r-- 1 www-data www-data 90859 Aug 24 2020 685
@ChristophWurst Should those models be cleaned up im some way? I couldn't find anything in that regard in the code base.
All right, seems to be mostly because the model for ipv6 was never generated on my instance with the Rubix\ML classes, after applying #644 and running occ suspiciouslogin:train --v6 it looks better, but I'll keep monitoring the logs a bit further.