mediathekview / plugin.video.mediathekview

Kodi plugin that gives access to most video-platforms from German public service broadcasters using the database of MediathekView.de
https://mediathekview.de/download/#mediathekview-f%C3%BCr-kodi-fr%C3%BCher-xbmc
MIT License
55 stars 24 forks source link

Update der DB trotz Update Mode "Disabled" #229

Closed relthyg closed 11 months ago

relthyg commented 1 year ago

Ich nutze eine externe MySQL-Datenbank, die über einen Cronjob unabhängig von der Kodi-Instanz geupdatet wird. Seit einiger Zeit versucht Kodi aber, obwohl der Database Update Mode auf "Disabled" steht, auch noch, diese Datenbank zu updaten, was natürlich sehr langsam ist, und zu Deadlocks führt.

Plugin 1.0.13+matrix.1 Kodi 19.4.3 Raspbian Bullseye

codingPF commented 1 year ago

kannst du mal das debug am Client einschalten und dann die log Zeilen bei „ Update Mode….“ prüfen. Kommt ca 1xpro minute. Wenn dort dann Disabled kommt und er trotzdem ein Update (ca alle 2 Std) macht wäre das komisch

relthyg commented 1 year ago

Yep:

2023-09-12 20:03:59.297 T:1075    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:MediathekViewUpdater]: Update Mode "Disabled"

Aber das Update läuft gerade.

codingPF commented 1 year ago

Dann wären die 10-20 Zeilen darunter auch interessant

relthyg commented 1 year ago

Hier ein Auszug aus grep mediathekview kodi.log:

2023-09-12 21:45:40.202 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:MediathekViewUpdater]: Last Update 1970-01-01 01:00:00
2023-09-12 21:45:40.202 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:MediathekViewUpdater]: Last Full Update 1970-01-01 01:00:00
2023-09-12 21:45:40.202 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:MediathekViewUpdater]: version 0
2023-09-12 21:45:40.202 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:MediathekViewUpdater]: status UNINIT
2023-09-12 21:45:40.202 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:MediathekViewUpdater]: update interval 3600
2023-09-12 21:45:40.202 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:MediathekViewUpdater]: Update Mode "Disabled"
2023-09-12 21:45:40.202 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:MediathekViewUpdater]: Version update or not initialized
2023-09-12 21:45:40.202 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Start DB setup for schema d03c0369
2023-09-12 21:45:40.202 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: query: SHOW DATABASES LIKE 'd03c0369' params None
2023-09-12 21:45:40.202 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: Using MySQL connector version 8.0.33
2023-09-12 21:45:40.549 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: Connected to server katarre.de running 10.5.22-MariaDB-1:10.5.22+maria~ubu2004-log
2023-09-12 21:45:40.684 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: execute: 1 rows in 0.48183679580688477 sec
2023-09-12 21:45:40.684 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: MySql Schema exists - no action
2023-09-12 21:45:40.779 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement '-- ----------------------------
2023-09-12 21:45:40.780 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP PROCEDURE IF EXISTS `ftUpdateEnd`': 0
2023-09-12 21:45:40.780 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP PROCEDURE IF EXISTS `ftInsertShow`': 0
2023-09-12 21:45:40.780 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP PROCEDURE IF EXISTS `ftInsertChannel`': 0
2023-09-12 21:45:40.783 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP TABLE IF EXISTS `status`': 0
2023-09-12 21:45:40.785 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP TABLE IF EXISTS `show`': 0
2023-09-12 21:45:40.796 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP TABLE IF EXISTS `film`': 0
2023-09-12 21:45:40.796 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP TABLE IF EXISTS `channel`': 0
2023-09-12 21:45:40.797 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement '-- ----------------------------
2023-09-12 21:45:40.804 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'CREATE TABLE film (
2023-09-12 21:45:40.811 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement '--
2023-09-12 21:45:40.811 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement '-- ----------------------------
2023-09-12 21:45:40.817 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'CREATE TABLE status (
2023-09-12 21:45:40.817 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement '-- ----------------
2023-09-12 21:45:40.817 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: Number of rows affected by statement '--': 0
2023-09-12 21:45:40.848 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQLSetup]: End DB setup
2023-09-12 21:45:40.848 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: set_status
2023-09-12 21:45:40.852 T:1078    DEBUG <CAddonSettings[plugin.video.mediathekview]>: trying to load setting definitions from old format...
2023-09-12 21:45:41.082 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: Update Status IDLE lastupdate: 0 lastFullUpdate: 0 filmupdate: 0 version: 3
2023-09-12 21:45:41.082 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: get_status
2023-09-12 21:45:41.082 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: query: SELECT status, lastupdate, lastFullUpdate, filmupdate, version FROM status params None
2023-09-12 21:45:41.178 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: execute: 1 rows in 0.09567642211914062 sec
2023-09-12 21:45:41.178 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: query: SELECT count(distinct(channel)),count(distinct(showid)),count(*) FROM film params None
2023-09-12 21:45:41.273 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: execute: 1 rows in 0.0950627326965332 sec
2023-09-12 21:45:41.275 T:1078    DEBUG <CAddonSettings[plugin.video.mediathekview]>: trying to load setting definitions from old format...
2023-09-12 21:45:41.290 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:MediathekViewUpdater]: full update
2023-09-12 21:45:41.290 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:UpdateFileDownload]: Cleaning up old downloads...
2023-09-12 21:45:41.302 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:UpdateFileDownload]: Trying to download Filmliste-akt.xz from https://liste.mediathekview.de/Filmliste-akt.xz...
2023-09-12 21:46:04.896 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:UpdateFileDownload]: downloaded /home/pi/.kodi/userdata/addon_data/plugin.video.mediathekview/Filmliste-akt.xz in 23.605030059814453 sec
2023-09-12 21:46:04.896 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:UpdateFileDownload]: Trying to decompress xz file...
2023-09-12 21:46:24.478 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:UpdateFileDownload]: decompress xz 0 in 19.582319259643555 sec
2023-09-12 21:46:24.479 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:UpdateFileImport]: Initializing update...
2023-09-12 21:46:24.479 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: import_begin
2023-09-12 21:46:24.577 T:1078     INFO <general>: [plugin.video.mediathekview-1.0.13+matrix.1:UpdateFileImport]: Starting import of approximately 754995 records from /home/pi/.kodi/userdata/addon_data/plugin.video.mediathekview/Filmliste-akt
2023-09-12 21:46:24.608 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:UpdateFileImport]: update date 12.09.2023, 20:32
2023-09-12 21:46:24.612 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:UpdateFileImport]: Filmliste dated 12.09.2023, 20:32
2023-09-12 21:46:24.612 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: set_status
2023-09-12 21:46:24.615 T:1078    DEBUG <CAddonSettings[plugin.video.mediathekview]>: trying to load setting definitions from old format...
2023-09-12 21:46:24.746 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: Update Status UPDATING lastupdate: None lastFullUpdate: None filmupdate: 1694543520 version: None
2023-09-12 21:46:26.216 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: import_films
2023-09-12 21:52:05.096 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:UpdateFileImport]: In progress (1%): insert:10000, update:0
2023-09-12 21:52:06.528 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.13+matrix.1:StoreMySQL]: import_films
codingPF commented 1 year ago

Danke! Das ist etwas merkwürdig. Kann es sein, dass sich die Prozesse immer die DB zerschlagen? Das log vom Server sieht wahrscheinlich genau so aus? Kannst du den Client mal einen update cycle Abschalten damit sicher gestellt ist, dass der Server einmal alles sauber verarbeitet hat? Dann sollte der Client dies sauber erkennen und nicht mehr eingreifen. ich überlege mal ob man das fangen kann…

relthyg commented 1 year ago

Logs vom Server, ich schalte den Client mal aus.

Tue Sep 12 19:00:02 CEST 2023
2023-09-12 19:00:02.399744 INFO [mvupdate3-1.0.9+matrix.1:mvupdate]: Python Version3.8.10 (default, May 26 2023, 14:05:08) 
[GCC 9.4.0]

Tue Sep 12 20:00:02 CEST 2023
2023-09-12 20:00:02.327757 INFO [mvupdate3-1.0.9+matrix.1:mvupdate]: Python Version3.8.10 (default, May 26 2023, 14:05:08) 
[GCC 9.4.0]
2023-09-12 20:00:02.656600 INFO [mvupdate3-1.0.9+matrix.1:UpdateFileImport]: Starting import of approximately 4027 records from ./Filmliste-diff
2023-09-12 20:00:03.518814 INFO [mvupdate3-1.0.9+matrix.1:UpdateFileImport]: 3087 records processed in 0 sec. Updated: 1942 Inserted: 1145 deleted: 0

Tue Sep 12 21:00:02 CEST 2023
2023-09-12 21:00:02.251236 INFO [mvupdate3-1.0.9+matrix.1:mvupdate]: Python Version3.8.10 (default, May 26 2023, 14:05:08) 
[GCC 9.4.0]

Tue Sep 12 22:00:01 CEST 2023
2023-09-12 22:01:05.457289 ERROR [mvupdate3-1.0.9+matrix.1:StoreMySQL]: Database error: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
2023-09-12 22:01:05.457331 ERROR [mvupdate3-1.0.9+matrix.1:UpdateFileImport]: Error in data import: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
2023-09-12 22:01:57.941926 ERROR [mvupdate3-1.0.9+matrix.1:StoreMySQL]: Database error: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
2023-09-12 22:01:57.941969 ERROR [mvupdate3-1.0.9+matrix.1:UpdateFileImport]: Error in data import: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
2023-09-12 22:02:50.399525 ERROR [mvupdate3-1.0.9+matrix.1:StoreMySQL]: Database error: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
2023-09-12 22:02:50.399561 ERROR [mvupdate3-1.0.9+matrix.1:UpdateFileImport]: Error in data import: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
2023-09-12 22:04:19.467324 ERROR [mvupdate3-1.0.9+matrix.1:StoreMySQL]: Database error: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
2023-09-12 22:04:19.467366 ERROR [mvupdate3-1.0.9+matrix.1:UpdateFileImport]: Error in data import: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
codingPF commented 1 year ago

Das sieht richtig aus. Der Server war durch. Das muss ich ein paar mal durchspielen…dazu komme ich aber erst die Tage…sry

relthyg commented 1 year ago

Kein Problem. Sag' Bescheid, wenn ich helfen kann.

codingPF commented 1 year ago

Ich habe mir jetzt ein neues env (ohne Docker) frisch aufgesetzt und es läuft seit ein paar Stunden ohne Probleme vor sich hin. Bei den user Rechten ist es immer etwas Problematisch- hast du da grants auf Tabellen Ebene verteilt? Benutzt du Docker oder hast du das ganze selbst aufgesetzt? Im Log sieht man, dass du auf dem Server 1.0.9 hast und auf dem Client 1.0.13 das solltest du grade ziehen. Ich habe jetzt mit 1.0.14 frisch aus dem GIT gearbeitet. Am besten ziehst du das einmal frisch hoch und schmeiß auch das DB Schema Weg und dann mit dem gleichen User auf dem Client (um irgendwelche Rechte Themen zu vermeiden)…

relthyg commented 12 months ago

Okay, ich habe auf dem Server und auf dem Client die 1.0.14 gezogen und auf dem Server das DB-Schema weggeschmissen. Irgendwelche besonderen Grants gibt es nicht.

Update auf dem Server ist durchgelaufen:

2023-09-17 17:53:03.840810 INFO [mvupdate3-1.0.14+matrix.1:mvupdate]: Python Version3.8.10 (default, May 26 2023, 14:05:08) 
[GCC 9.4.0]
2023-09-17 17:53:17.089229 INFO [mvupdate3-1.0.14+matrix.1:UpdateFileImport]: Starting import of approximately 758616 records from ./Filmliste-akt
2023-09-17 17:55:04.366054 INFO [mvupdate3-1.0.14+matrix.1:UpdateFileImport]: 721876 records processed in 114 sec. Updated: 721876 Inserted: 0 deleted: 0

DB sieht gut aus:

> select * from status;
+--------+------------+----------------+------------+---------+
| status | lastupdate | lastFullUpdate | filmupdate | version |
+--------+------------+----------------+------------+---------+
| IDLE   | 1694966104 |     1694966104 | 1694961180 |       3 |
+--------+------------+----------------+------------+---------+
1 row in set (0,001 sec)

Zuerst schien auf dem Client alles gut:

2023-09-17 18:06:50.831 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: Database driver: External (mysql)
2023-09-17 18:06:50.831 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: get_status
2023-09-17 18:06:50.831 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: query: SELECT status, lastupdate, lastFullUpdate, filmupdate, version FROM status params None
2023-09-17 18:06:50.831 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: Using MySQL connector version 8.0.33
2023-09-17 18:06:51.183 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: Connected to server katarre.de running 10.5.22-MariaDB-1:10.5.22+maria~ubu2004-log
2023-09-17 18:06:51.308 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: execute: 1 rows in 0.4764258861541748 sec
2023-09-17 18:06:51.308 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: query: SELECT count(distinct(channel)),count(distinct(showid)),count(*) FROM film params None
2023-09-17 18:06:51.401 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: execute: 1 rows in 0.09276700019836426 sec
2023-09-17 18:06:51.403 T:1078    DEBUG <CAddonSettings[plugin.video.mediathekview]>: trying to load setting definitions from old format...
2023-09-17 18:06:51.416 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: Last Update 2023-09-17 17:55:04
2023-09-17 18:06:51.416 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: Last Full Update 2023-09-17 17:55:04
2023-09-17 18:06:51.416 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: version 3
2023-09-17 18:06:51.416 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: status IDLE
2023-09-17 18:06:51.416 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: update interval 3600
2023-09-17 18:06:51.416 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: Update Mode "Disabled"
2023-09-17 18:06:51.416 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: nothing to do

Aber dann:

2023-09-17 18:10:32.089 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: Database driver: External (mysql)
2023-09-17 18:10:32.089 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: get_status
2023-09-17 18:10:32.089 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: query: SELECT status, lastupdate, lastFullUpdate, filmupdate, version FROM status params None
2023-09-17 18:10:32.089 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: Using MySQL connector version 8.0.33
2023-09-17 18:12:42.075 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: Last Update 1970-01-01 01:00:00
2023-09-17 18:12:42.075 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: Last Full Update 1970-01-01 01:00:00
2023-09-17 18:12:42.075 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: version 0
2023-09-17 18:12:42.075 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: status UNINIT
2023-09-17 18:12:42.075 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: update interval 3600
2023-09-17 18:12:42.075 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: Update Mode "Disabled"
2023-09-17 18:12:42.075 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: Version update or not initialized
2023-09-17 18:12:42.075 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Start DB setup for schema d03c0369
2023-09-17 18:12:42.075 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: query: SHOW DATABASES LIKE 'd03c0369' params None
2023-09-17 18:12:42.075 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: Using MySQL connector version 8.0.33
2023-09-17 18:12:42.425 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: Connected to server katarre.de running 10.5.22-MariaDB-1:10.5.22+maria~ubu2004-log
2023-09-17 18:12:42.552 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: execute: 1 rows in 0.4764845371246338 sec
2023-09-17 18:12:42.552 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: MySql Schema exists - no action
2023-09-17 18:12:42.647 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement '-- ----------------------------
2023-09-17 18:12:42.648 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP PROCEDURE IF EXISTS `ftUpdateEnd`': 0
2023-09-17 18:12:42.648 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP PROCEDURE IF EXISTS `ftInsertShow`': 0
2023-09-17 18:12:42.648 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP PROCEDURE IF EXISTS `ftInsertChannel`': 0
2023-09-17 18:12:42.654 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP TABLE IF EXISTS `status`': 0
2023-09-17 18:12:42.654 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP TABLE IF EXISTS `show`': 0
2023-09-17 18:12:42.704 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP TABLE IF EXISTS `film`': 0
2023-09-17 18:12:42.705 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'DROP TABLE IF EXISTS `channel`': 0
2023-09-17 18:12:42.705 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement '-- ----------------------------
2023-09-17 18:12:42.714 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'CREATE TABLE film (
2023-09-17 18:12:42.720 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement '--
2023-09-17 18:12:42.721 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement '-- ----------------------------
2023-09-17 18:12:42.725 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement 'CREATE TABLE status (
2023-09-17 18:12:42.725 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement '-- ----------------
2023-09-17 18:12:42.726 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: Number of rows affected by statement '--': 0
2023-09-17 18:12:42.757 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQLSetup]: End DB setup
2023-09-17 18:12:42.757 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: set_status
2023-09-17 18:12:42.759 T:1078    DEBUG <CAddonSettings[plugin.video.mediathekview]>: trying to load setting definitions from old format...
2023-09-17 18:12:42.989 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: Update Status IDLE lastupdate: 0 lastFullUpdate: 0 filmupdate: 0 version: 3
2023-09-17 18:12:42.989 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: get_status
2023-09-17 18:12:42.989 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: query: SELECT status, lastupdate, lastFullUpdate, filmupdate, version FROM status params None
2023-09-17 18:12:43.084 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: execute: 1 rows in 0.0948033332824707 sec
2023-09-17 18:12:43.084 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: query: SELECT count(distinct(channel)),count(distinct(showid)),count(*) FROM film params None
2023-09-17 18:12:43.178 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: execute: 1 rows in 0.0936734676361084 sec
2023-09-17 18:12:43.180 T:1078    DEBUG <CAddonSettings[plugin.video.mediathekview]>: trying to load setting definitions from old format...
2023-09-17 18:12:43.193 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: full update
2023-09-17 18:12:43.193 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:MediathekViewUpdater]: use existing full update file
2023-09-17 18:12:43.194 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:UpdateFileImport]: Initializing update...
2023-09-17 18:12:43.194 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: import_begin
2023-09-17 18:12:43.287 T:1078     INFO <general>: [plugin.video.mediathekview-1.0.14+matrix.1:UpdateFileImport]: Starting import of approximately 754995 records from /home/pi/.kodi/userdata/addon_data/plugin.video.mediathekview/Filmliste-akt
2023-09-17 18:12:43.351 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:UpdateFileImport]: update date 12.09.2023, 20:32
2023-09-17 18:12:43.355 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:UpdateFileImport]: Filmliste dated 12.09.2023, 20:32
2023-09-17 18:12:43.355 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: set_status
2023-09-17 18:12:43.358 T:1078    DEBUG <CAddonSettings[plugin.video.mediathekview]>: trying to load setting definitions from old format...
2023-09-17 18:12:43.486 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: Update Status UPDATING lastupdate: None lastFullUpdate: None filmupdate: 1694543520 version: None
2023-09-17 18:12:45.088 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: import_films
2023-09-17 18:18:17.305 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:UpdateFileImport]: In progress (1%): insert:10000, update:0
2023-09-17 18:18:18.845 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: import_films
2023-09-17 18:23:50.469 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:UpdateFileImport]: In progress (2%): insert:20000, update:0
2023-09-17 18:23:51.999 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: import_films
2023-09-17 18:29:24.855 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:UpdateFileImport]: In progress (3%): insert:30000, update:0
2023-09-17 18:29:26.362 T:1078    DEBUG <general>: [plugin.video.mediathekview-1.0.14+matrix.1:StoreMySQL]: import_films

Da sehe ich insbesondere ein

Last Update 1970-01-01 01:00:00

welches zuerst auf

Last Update 2023-09-17 17:55:04

stand.

Was ich nicht verstehe: Wieso will der Client sich überhaupt um irgendwelche Updates kümmern, wenn der Update Mode auf "Disabled" steht?

codingPF commented 12 months ago

Wenn du den cron Eintrag mit -vvv startest bekommst du auch dort debug logs. Wäre interessant warum der Server die Status Tabelle kaputt macht. Das Datum ist dabei nicht wirklich relevant sondern „ status UNINIT“ und „Version 0“. Das deutet darauf hin, dass der select leer war oder einen Fehler produziert hat (Netzwerk instabil)? Warum der Client etwas macht ist, dass der Code von Client und Server identisch ist. Der Server ist eigentlich nur ein wrapper um den Client. Jetzt denkt dieser es gibt keine DB und setzt diese neu auf + initial load. Dieser Zustand ist höchst bewertet als alles andere. Ggf, muss man das aufbohren…

codingPF commented 12 months ago

Ich habe ein update in das preview repo auf 1.0.15 geschoben. Da wird der Client kalt gestellt. Preview Repo

relthyg commented 12 months ago

Wäre interessant warum der Server die Status Tabelle kaputt macht.

Das kann eigentlich nicht der Update-Prozess auf dem Server sein, denn der ist zwischen 18:06 und 18:12 nicht gelaufen, ich habe trotzdem mal das debug logging eingeschaltet.

Ich habe ein update in das preview repo auf 1.0.15 geschoben

Warum wird das Repo hier dann eigentlich nicht aktualisiert?

codingPF commented 12 months ago

Die Änderung ist im dev branch - kannst du auch dort direkt auschecken. Die packages sind im Kodi-repo hinterlegt. Oder was war die Frage 😂

relthyg commented 12 months ago

Das ist auf jeden Fall die Antwort auf die Frage, die ich stellen wollte.

codingPF commented 12 months ago

Am besten das Preview installieren, dann bekommt man auch addon updates automatisch. Wenn man addon zips installiert - ist man selbst für Updates verantwortlich…

relthyg commented 11 months ago

Habe ich gemacht, aber irgendwie kommt das Update auf 1.0.15 nicht automatisch und ich sehe keine Option, wo ich das manuell anstoßen kann.

codingPF commented 11 months ago

Versuch doch mal: Einstellungen - addons - dann nach links und „nach Aktualisierungen suchen“ Dann „Benutzer Addons“ - „Addon Repository“ und über das Kontextmenü „nach Aktualisierungen suchen“ Und zu guter letzt: unter my Addons das entsprechende suchen und das Update installieren. Wenn du vorher ein ZIP installiert hattest oder aus einem anderen Repo, bitte neu installieren.

relthyg commented 11 months ago

Nope, auch mit der Anleitung bekomme ich kein Update. Sogar dann nicht, wenn ich das Plugin deinstalliere und neu installiere.

codingPF commented 11 months ago

Kann es sein, dass du das falsche Repo hast? Richtig wäre: grafik

relthyg commented 11 months ago

Hab jetzt die 1.1.0 und bis jetzt keine Probleme mehr damit, danke!