Archivierung läuft nicht durch und hohe Serverlast

mchammer · September 3, 2023, 4:02pm

Hallo zusammen,

ich habe aktuell leider das Problem, dass sich unter Matomo 4.15.1 keine Archivierung mehr anstoßen lässt.

Bei dem Server handelt es sich um einen Hetzner Managed Virtual Private Server mit 4 Kernen, 16 GB RAM und SSD, auf dem nur ein kleiner Shop läuft. Die Last liegt in der Regel um die 0.4. Sobald ich die Archivierung über den Cronjob oder den Weblink anstoße, geht die Last auf dem Server teils auf über 6 oder sogar 10 hoch.

Der Matomo Archive Log zeigt die folgenden Einträge:

INFO [2023-08-30 14:00:02] 16319  ---------------------------
INFO [2023-08-30 14:00:02] 16319  INIT
INFO [2023-08-30 14:00:02] 16319  Running Matomo 4.15.1 as Super User
INFO [2023-08-30 14:00:02] 16319  ---------------------------
INFO [2023-08-30 14:00:02] 16319  NOTES
INFO [2023-08-30 14:00:02] 16319  - Async process archiving supported, using CliMulti.
INFO [2023-08-30 14:00:02] 16319  - Reports for today will be processed at most every 3600 seconds. You can change this value in Matomo UI > Settings > General Settings.
INFO [2023-08-30 14:00:02] 16319  - Archiving was last executed without error 23 hours 56 min ago.
INFO [2023-08-30 14:00:02] 16319  ---------------------------
INFO [2023-08-30 14:00:02] 16319  START
INFO [2023-08-30 14:00:02] 16319  Starting Matomo reports archiving...
INFO [2023-08-30 14:00:02] 16319  Found 3 failed jobs (ts_invalidated older than 1 day), resetting status to try them again.
INFO [2023-08-30 14:00:02] 16319  Start processing archives for site 1.
INFO [2023-08-30 14:00:02] 16319    Will invalidate archived reports for today in site ID = 1's timezone (2023-08-30 00:00:00).
INFO [2023-08-30 14:00:02] 16319    Will invalidate archived reports for yesterday in site ID = 1's timezone (2023-08-29 00:00:00).
INFO [2023-08-30 14:00:28] 16319  Archived website id 1, period = day, date = 2023-08-30, segment = '', 1789 visits found. Time elapsed: 11.270s
INFO [2023-08-30 14:00:28] 16319  Archived website id 1, period = day, date = 2023-08-29, segment = 'pageUrl=@https%3A%2F%2Fwww.domain.de%2Fen%2F', 8032 visits found. Time elapsed: 25.696s
INFO [2023-08-30 14:00:28] 16319  Archived website id 1, period = day, date = 2023-08-29, segment = 'pageUrl!@https%3A%2F%2Fwww.domain.de%2Fen%2F', 920 visits found. Time elapsed: 25.696s

Der Cronjob selbst sieht wie folgt aus:

/usr/bin/php81 /usr/www/users/user_13/_matomo/console --matomo-domain=matomo.domain.de core:archive --url=https://matomo.domain.de > /usr/www/users/user_13/_matomo/logs/matomo-archive.log

Seitens Hetzner habe ich die folgende Info erhalten:

Wir haben festgestellt, dass Ihr Managed Server aktuell überlastet ist.
Folgende Prozesse führen zu der Überlastung:

MySQL

| 689443 | user_13 | 94.111.10.100:40544 | matomo_database | Query   | 175429 | Sending data | SELECT  /*+ MAX_EXECUTION_TIME(7200000) */
          yyy.idvisit AS idvisit,
          12 AS idgoal,
          4 AS `type`,
          yyy.idaction AS idaction,
          COUNT(*) AS `1`,    
          ROUND(SUM(yyy.revenue_total),2) AS `2`,         
          COUNT(yyy.idvisit) AS `3`,                   
          ROUND(SUM(yyy.revenue_subtotal),2) AS `4`,                
          ROUND(SUM(yyy.revenue_tax),2) AS `5`,
          ROUND(SUM(yyy.revenue_shipping),2) AS `6`,
          ROUND(SUM(yyy.revenue_discount),2) AS `7`,
          SUM(yyy.items) AS `8`,
          yyy.pages_before AS `9`,                   
          SUM(yyy.attribution) AS `10`,                   
          COUNT(*) AS `12`,             
          ROUND(SUM(yyy.revenue),2) AS `15`        
        FROM (
          SELECT
            num_total AS pages_before,
            1 / num_total AS attribution,
            r.idvisit AS idvisit,
            lac.idaction AS idaction,
            lvcon.revenue AS revenue_total,
            1 / num_total * lvcon.revenue AS revenue,
            1 / num_total * lvcon.revenue_subtotal AS revenue_subtotal,
            1 / num_total * lvcon.revenue_tax AS revenue_tax,
            1 / num_total * lvcon.revenue_shipping AS revenue_shipping,
            1 / num_total * lvcon.revenue_discount AS revenue_discount,
            1 / num_total * lvcon.items AS items
          FROM (
            SELECT /* segmenthash d47ae978cdef0d0a30bb0b76f14d31d8 */ /* sites 1 */ /* 2023-08-23,2023-08-24 */ /* Actions */ /* trigger = CronArchive */
                                log_conversion.idvisit, COUNT(*) AS num_total
                        FROM
                                matomo_logtmpsegmentb97a8ba18189d04de26a38be6c3b5d9a AS logtmpsegmentb97a8ba18189d04de26a38be6c3b5d9a INNER JOIN matomo_log_conversion AS log_conversion ON log_conversion.idvisit = logtmpsegmentb97a8ba18189d04de26a38be6c3b5d9a.idvisit RIGHT JOIN matomo_log_link_visit_action AS log_vpast ON log_conversion.idvisit = log_vpast.idvisit LEFT JOIN matomo_log_action AS lac_past ON log_vpast.idaction_name = lac_past.idaction
                        WHERE
                                log_conversion.idgoal = 12
                          AND log_vpast.server_time <= log_conversion.server_time
                          AND lac_past.type = 4
                        GROUP BY
                                log_conversion.idvisit
          ) AS r
          LEFT JOIN matomo_log_conversion lvcon ON lvcon.idgoal = 12 AND lvcon.idvisit = r.idvisit
          RIGHT JOIN matomo_log_link_visit_action logv ON logv.idvisit = r.idvisit
          LEFT JOIN matomo_log_action lac ON logv.idaction_name = lac.idaction
          WHERE logv.server_time >= '2023-08-23 22:00:00'
            AND logv.server_time <= '2023-08-24 21:59:59'
            AND logv.idsite IN (1)
            AND lac.type = 4
            AND logv.server_time <= lvcon.server_time
          ) AS yyy
        GROUP BY yyy.idaction
        ORDER BY `9` DESC | 0.000    |
| 689443 | user_13 | 94.111.10.100:40544 | matomo_database | Query   | 148872 | Sending data | SELECT  /*+ MAX_EXECUTION_TIME(7200000) */
          yyy.idvisit AS idvisit,
          8 AS idgoal,
          4 AS `type`,
          yyy.idaction AS idaction,
          COUNT(*) AS `1`,    
          ROUND(SUM(yyy.revenue_total),2) AS `2`,         
          COUNT(yyy.idvisit) AS `3`,                  
          ROUND(SUM(yyy.revenue_subtotal),2) AS `4`,                
          ROUND(SUM(yyy.revenue_tax),2) AS `5`,
          ROUND(SUM(yyy.revenue_shipping),2) AS `6`,
          ROUND(SUM(yyy.revenue_discount),2) AS `7`,
          SUM(yyy.items) AS `8`,
          yyy.pages_before AS `9`,                    
          SUM(yyy.attribution) AS `10`,                   
          COUNT(*) AS `12`,             
          ROUND(SUM(yyy.revenue),2) AS `15`        
        FROM (
          SELECT
            num_total AS pages_before,
            1 / num_total AS attribution,
            r.idvisit AS idvisit,
            lac.idaction AS idaction,
            lvcon.revenue AS revenue_total,
            1 / num_total * lvcon.revenue AS revenue,
            1 / num_total * lvcon.revenue_subtotal AS revenue_subtotal,
            1 / num_total * lvcon.revenue_tax AS revenue_tax,
            1 / num_total * lvcon.revenue_shipping AS revenue_shipping,
            1 / num_total * lvcon.revenue_discount AS revenue_discount,
            1 / num_total * lvcon.items AS items
          FROM (
            SELECT /* segmenthash d47ae978cdef0d0a30bb0b76f14d31d8 */ /* sites 1 */ /* 2023-08-24,2023-08-25 */ /* Actions */ /* trigger = CronArchive */
                                log_conversion.idvisit, COUNT(*) AS num_total
                        FROM
                                matomo_logtmpsegment49b8d3569e62742b93981d7518fed0cd AS logtmpsegment49b8d3569e62742b93981d7518fed0cd INNER JOIN matomo_log_conversion AS log_conversion ON log_conversion.idvisit = logtmpsegment49b8d3569e62742b93981d7518fed0cd.idvisit RIGHT JOIN matomo_log_link_visit_action AS log_vpast ON log_conversion.idvisit = log_vpast.idvisit LEFT JOIN matomo_log_action AS lac_past ON log_vpast.idaction_name = lac_past.idaction
                        WHERE
                                log_conversion.idgoal = 8
                          AND log_vpast.server_time <= log_conversion.server_time
                          AND lac_past.type = 4
                        GROUP BY
                                log_conversion.idvisit
          ) AS r
          LEFT JOIN matomo_log_conversion lvcon ON lvcon.idgoal = 8 AND lvcon.idvisit = r.idvisit
          RIGHT JOIN matomo_log_link_visit_action logv ON logv.idvisit = r.idvisit
          LEFT JOIN matomo_log_action lac ON logv.idaction_name = lac.idaction
          WHERE logv.server_time >= '2023-08-24 22:00:00'
            AND logv.server_time <= '2023-08-25 21:59:59'
            AND logv.idsite IN (1)
            AND lac.type = 4
            AND logv.server_time <= lvcon.server_time
          ) AS yyy
        GROUP BY yyy.idaction
        ORDER BY `9` DESC    | 0.000    |
| 689443 | user_13 | 94.111.10.100:40544 | matomo_database | Query   | 135371 | Sending data | SELECT  /*+ MAX_EXECUTION_TIME(7200000) */
          yyy.idvisit AS idvisit,
          12 AS idgoal,
          4 AS `type`,
          yyy.idaction AS idaction,
          COUNT(*) AS `1`,    
          ROUND(SUM(yyy.revenue_total),2) AS `2`,         
          COUNT(yyy.idvisit) AS `3`,                  
          ROUND(SUM(yyy.revenue_subtotal),2) AS `4`,                
          ROUND(SUM(yyy.revenue_tax),2) AS `5`,
          ROUND(SUM(yyy.revenue_shipping),2) AS `6`,
          ROUND(SUM(yyy.revenue_discount),2) AS `7`,
          SUM(yyy.items) AS `8`,
          yyy.pages_before AS `9`,                   
          SUM(yyy.attribution) AS `10`,                   
          COUNT(*) AS `12`,             
          ROUND(SUM(yyy.revenue),2) AS `15`        
        FROM (
          SELECT
            num_total AS pages_before,
            1 / num_total AS attribution,
            r.idvisit AS idvisit,
            lac.idaction AS idaction,
            lvcon.revenue AS revenue_total,
            1 / num_total * lvcon.revenue AS revenue,
            1 / num_total * lvcon.revenue_subtotal AS revenue_subtotal,
            1 / num_total * lvcon.revenue_tax AS revenue_tax,
            1 / num_total * lvcon.revenue_shipping AS revenue_shipping,
            1 / num_total * lvcon.revenue_discount AS revenue_discount,
            1 / num_total * lvcon.items AS items
         FROM (
            SELECT /* segmenthash d47ae978cdef0d0a30bb0b76f14d31d8 */ /* sites 1 */ /* 2023-08-23,2023-08-24 */ /* Actions */ /* trigger = CronArchive */
                                log_conversion.idvisit, COUNT(*) AS num_total
                        FROM
                                matomo_logtmpsegmentb97a8ba18189d04de26a38be6c3b5d9a AS logtmpsegmentb97a8ba18189d04de26a38be6c3b5d9a INNER JOIN matomo_log_conversion AS log_conversion ON log_conversion.idvisit = logtmpsegmentb97a8ba18189d04de26a38be6c3b5d9a.idvisit RIGHT JOIN matomo_log_link_visit_action AS log_vpast ON log_conversion.idvisit = log_vpast.idvisit LEFT JOIN matomo_log_action AS lac_past ON log_vpast.idaction_name = lac_past.idaction
                        WHERE
                                log_conversion.idgoal = 12
                          AND log_vpast.server_time <= log_conversion.server_time
                          AND lac_past.type = 4
                        GROUP BY
                                log_conversion.idvisit
          ) AS r
          LEFT JOIN matomo_log_conversion lvcon ON lvcon.idgoal = 12 AND lvcon.idvisit = r.idvisit
          RIGHT JOIN matomo_log_link_visit_action logv ON logv.idvisit = r.idvisit
          LEFT JOIN matomo_log_action lac ON logv.idaction_name = lac.idaction
          WHERE logv.server_time >= '2023-08-23 22:00:00'
            AND logv.server_time <= '2023-08-24 21:59:59'
            AND logv.idsite IN (1)
            AND lac.type = 4
            AND logv.server_time <= lvcon.server_time
          ) AS yyy
        GROUP BY yyy.idaction
        ORDER BY `9` DESC | 0.000    |
| 689443 | user_13 | 94.111.10.100:40544 | matomo_database | Query   | 91082  | Sending data | SELECT  /*+ MAX_EXECUTION_TIME(7200000) */
          yyy.idvisit AS idvisit,
          12 AS idgoal,
          4 AS `type`,
          yyy.idaction AS idaction,
          COUNT(*) AS `1`,    
          ROUND(SUM(yyy.revenue_total),2) AS `2`,         
          COUNT(yyy.idvisit) AS `3`,                  
          ROUND(SUM(yyy.revenue_subtotal),2) AS `4`,                
          ROUND(SUM(yyy.revenue_tax),2) AS `5`,
          ROUND(SUM(yyy.revenue_shipping),2) AS `6`,
          ROUND(SUM(yyy.revenue_discount),2) AS `7`,
          SUM(yyy.items) AS `8`,
          yyy.pages_before AS `9`,                   
          SUM(yyy.attribution) AS `10`,                   
          COUNT(*) AS `12`,             
          ROUND(SUM(yyy.revenue),2) AS `15`        
        FROM (
          SELECT
            num_total AS pages_before,
            1 / num_total AS attribution,
            r.idvisit AS idvisit,
            lac.idaction AS idaction,
            lvcon.revenue AS revenue_total,
            1 / num_total * lvcon.revenue AS revenue,
            1 / num_total * lvcon.revenue_subtotal AS revenue_subtotal,
            1 / num_total * lvcon.revenue_tax AS revenue_tax,
            1 / num_total * lvcon.revenue_shipping AS revenue_shipping,
            1 / num_total * lvcon.revenue_discount AS revenue_discount,
            1 / num_total * lvcon.items AS items
          FROM (
            SELECT /* sites 1 */ /* 2023-08-23,2023-08-24 */ /* Actions */ /* trigger = CronArchive */
                                log_conversion.idvisit, COUNT(*) AS num_total
                        FROM
                                matomo_log_conversion AS log_conversion RIGHT JOIN matomo_log_link_visit_action AS log_vpast ON log_conversion.idvisit = log_vpast.idvisit LEFT JOIN matomo_log_action AS lac_past ON log_vpast.idaction_name = lac_past.idaction
                        WHERE
                                log_conversion.server_time >= '2023-08-23 22:00:00'
                                AND log_conversion.server_time <= '2023-08-24 21:59:59'
                                AND log_conversion.idsite IN ('1')AND log_conversion.idgoal = 12
                          AND log_vpast.server_time <= log_conversion.server_time
                          AND lac_past.type = 4
                        GROUP BY
                                log_conversion.idvisit
          ) AS r
          LEFT JOIN matomo_log_conversion lvcon ON lvcon.idgoal = 12 AND lvcon.idvisit = r.idvisit
          RIGHT JOIN matomo_log_link_visit_action logv ON logv.idvisit = r.idvisit
          LEFT JOIN matomo_log_action lac ON logv.idaction_name = lac.idaction
          WHERE logv.server_time >= '2023-08-23 22:00:00'
            AND logv.server_time <= '2023-08-24 21:59:59'
            AND logv.idsite IN (1)
            AND lac.type = 4
            AND logv.server_time <= lvcon.server_time
          ) AS yyy
        GROUP BY yyy.idaction
        ORDER BY `9` DESC

In der Datenbank sind auch diverse Tabellen im Format “matomo_archive_blog_20xx_xx” sowie “matomo_archive_numberic_20xx_xx” zu finden, welche größtenteils ohne Einträge sind.

Folgende Tabellen haben Datensätze:

matomo_archive_blob_2023_01 -> 699 Einträge

matomo_archive_numeric_2023_01 -> 464 Einträge
matomo_archive_numeric_2023_07 -> 1.245 Einträge
matomo_archive_numeric_2023_08 -> 12.876 Einträge
matomo_archive_numeric_2023_09 -> 250 Einträge

Die Tabelle “matomo_archive_invalidations” hat diverse Einträge, welche teils einfach nur “done” als “Name” aufweisen, aber teils auch “done” mit einem Hash dahinter haben (z.B. doned47ae978cdef0d0a30bb0b76f14d31d9).

.
Der Systemcheck beinhaltet folgende Infos und zeigt keine Fehler an:

### Mandatory checks

#### PHP-Version >= 7.2.5:
 ✔ 8.1.22

#### PDO Erweiterung:
 ✔ 

#### PDO\MYSQL Erweiterung:
 ✔ 

#### MYSQLI Erweiterung:
 ✔ 

#### Weitere erforderliche Anforderungen:
 ✔ zlib ✔ json ✔ filter ✔ hash ✔ session

#### Erforderliche Funktionen:
 ✔ debug_backtrace ✔ eval ✔ hash ✔ gzcompress ✔ gzuncompress ✔ pack

#### Benötigte PHP Konfiguration (php.ini):
 ✔ session.auto_start = 0 ✔ max_execution_time = 0 OR = -1 OR >= 30

#### Verzeichnisse mit Schreibzugriff:
 ✔ $DOC_ROOT/tmp ✔ $DOC_ROOT/tmp/assets ✔ $DOC_ROOT/tmp/cache ✔ $DOC_ROOT/tmp/climulti ✔ $DOC_ROOT/tmp/latest ✔ $DOC_ROOT/tmp/logs ✔ $DOC_ROOT/tmp/sessions ✔ $DOC_ROOT/tmp/tcpdf ✔ $DOC_ROOT/tmp/templates_c

#### Verzeichnisse mit Schreibzugriff auf Tag Manager:
 ✔ $DOC_ROOT/js


### Optional checks

#### Verzeichnisse, welche privat sein müssen:
 ✔ Alle privaten Verzeichnisse sind nicht aus dem Internet zugänglich.

#### Empfohlene private Verzeichnisse:
 ✔ Alle privaten Verzeichnisse sind nicht aus dem Internet zugänglich.

#### 64-bit PHP Binär:
 ✔ 

#### Tracker-Status:
 ✔ 

#### Speicherlimit:
 ✔ 512M

#### Zeitzone:
 ✔ 

#### Öffnen einer URL:
 ✔ curl

#### PageSpeed ist deaktiviert:
 ✔ 

#### GD > 2.x + FreeType (Grafiken):
 ✔ 

#### Andere Erweiterungen:
 ✔ json ✔ libxml ✔ dom ✔ SimpleXML ✔ openssl

#### Andere Funktionen:
 ✔ shell_exec ✔ set_time_limit ✔ mail ✔ parse_ini_file ✔ glob ✔ gzopen ✔ md5_file

#### Dateisystem:
 ✔ 

#### Cron einrichten - Prozesse via CLI steuern:
 nicht unterstützt (wahlweise) (Gründe: unbekannt) Erfahren Sie mehr

#### Letzter erfolgreicher Abschluss der Archivierung:
⚠ Error: Die Archivierung ist zuletzt am Dienstag, 29. August 2023 14:03:09 erfolgreich gelaufen, also vor 5 Tage 01:52:59.<br/><br/>Bitte überprüfen Sie, ob Sie einen Crontab eingerichtet haben, der den <code>core:archive</code> Konsolenbefehl aufruft, und ob Sie einen <code>MAILTO</code> konfiguriert haben, um Fehler per E-Mail zu erhalten, wenn die Archivierung fehlschlägt. Sie können auch versuchen, den Konsolenbefehl auszuführen, um Ihre Berichte manuell zu archivieren: <code>$DOC_ROOT/console --matomo-domain=matomo.domain.de core:archive</code>.  Mehr erfahren.

#### Datenbankfähigkeiten:
 ✔ UTF8mb4 charset ✔ LOAD DATA INFILE ✔ CREATE TEMPORARY TABLES ✔ Changing transaction isolation level

#### Maximale Packetgröße:
 ✔ 

#### Erzwungene SSL Verbindung:
 ✔ 

#### Standorterkennung:
 ✔ geoip2php (continent_code, continent_name, country_code, country_name, region_code, region_name, city_name, postal_code, lat, long)

#### Update über HTTPS:
 ✔ 

#### Schreibbarer JavaScript-Tracker ("/matomo.js"):
 ✔ 


### Informational results

#### Matomo Version:
 4.15.1

#### Matomo Update History:
 4.15.0,

#### Matomo Install Version:
 4.15.0

#### Latest Available Version:
 4.15.1

#### Is Git Deployment:
 0

#### PHP_OS:
 Linux

#### PHP_BINARY:
 /home/httpd/cgi-bin/php81.bin.fcgi

#### PHP SAPI:
 cgi-fcgi

#### Timezone Version:
 2023.3

#### PHP Timezone:
 UTC

#### PHP Time:
 1693756568

#### PHP Datetime:
 2023-09-03 15:56:08

#### PHP INI max_execution_time:
 240

#### PHP INI post_max_size:
 200M

#### PHP INI max_input_vars:
 1000

#### PHP INI zlib.output_compression:
 0

#### Curl Version:
 7.74.0, OpenSSL/1.1.1n

#### Suhosin Installed:
 0

#### DB Prefix:
 matomo_

#### DB Charset:
 utf8mb4

#### DB Adapter:
 PDO\MYSQL

#### MySQL Version:
 10.5.19-MariaDB-0+deb11u2

#### Num Tables:
 99

#### Browser Segment Archiving Enabled:
 1

#### Development Mode Enabled:
 0

#### Internet Enabled:
 1

#### Multi Server Environment:
 0

#### Auto Update Enabled:
 1

#### Custom User Path:
 0

#### Custom Include Path:
 0

#### Release Channel:
 latest_stable

#### Plugins Activated:
 API, Actions, Annotations, BulkTracking, Contents, CoreAdminHome, CoreConsole, CoreHome, CorePluginsAdmin, CoreUpdater, CoreVisualizations, CoreVue, CustomDimensions, CustomJsTracker, Dashboard, DevicePlugins, DevicesDetection, Diagnostics, Ecommerce, Events, Feedback, GeoIp2, Goals, Heartbeat, ImageGraph, Insights, Installation, Intl, IntranetMeasurable, InvalidateReports 4.1.1, LanguagesManager, Live, Login, Marketplace, MobileMessaging, Monolog, Morpheus, MultiSites, Overlay, PagePerformance, PrivacyManager, ProfessionalServices, Proxy, Referrers, Resolution, RssWidget, SEO, ScheduledReports, SegmentEditor, SitesManager, TagManager, Tour, Transitions, TwoFactorAuth, UserCountry, UserCountryMap, UserId, UserLanguage, UsersManager, VisitFrequency, VisitTime, VisitorInterest, VisitsSummary, WebsiteMeasurable, Widgetize

#### Plugins Deactivated:
 DBStats, MobileAppMeasurable

#### Plugins Invalid:
 

#### Server Info:
 Apache

#### Had visits in last 1 day:
 1

#### Had visits in last 3 days:
 1

#### Had visits in last 5 days:
 1

#### Archive Time Last Started:
 2023-08-30 14:00:02

#### Archive Time Last Finished:
 2023-08-29 14:03:09

#### User Agent:
 Mozilla/5.0 (Macintosh; Intel Mac OS X 11.11; rv:109.0) Gecko/20100101 Firefox/115.0

#### Browser Language:
 de,en-us,en

#### Total Invalidation Count:
 31

#### In Progress Invalidation Count:
 9

#### Scheduled Invalidation Count:
 22

#### Earliest invalidation ts_started:
 2023-08-27 16:57:02

#### Latest invalidation ts_started:
 2023-08-30 16:00:29

#### Earliest invalidation ts_invalidated:
 2023-08-24 22:00:02

#### Latest invalidation ts_invalidated:
 2023-08-31 13:37:11

#### Number of segment invalidations:
 20

#### Number of plugin invalidations:
 0

#### List of plugins being invalidated:
 

#### Anonymize Referrer:
 

#### Do Not Track enabled:
 0

</details>

Ich hoffe, dass mir hier jemand weiterhelfen kann.
Vielen lieben Dank!

Beste Grüße,
Tim

melbao · September 3, 2023, 5:51pm

Das Logfile muss so enden:

...
INFO [2023-08-31 22:24:04] 64979  Done archiving!
INFO [2023-08-31 22:24:04] 64979  ---------------------------
INFO [2023-08-31 22:24:04] 64979  SUMMARY
INFO [2023-08-31 22:24:04] 64979  Processed 0 archives.
INFO [2023-08-31 22:24:04] 64979  Total API requests: 0
INFO [2023-08-31 22:24:04] 64979  done: 0 req, 2578 ms, no error
INFO [2023-08-31 22:24:04] 64979  Time elapsed: 2.578s
INFO [2023-08-31 22:24:04] 64979  ---------------------------
INFO [2023-08-31 22:24:04] 64979  SCHEDULED TASKS
INFO [2023-08-31 22:24:04] 64979  Starting Scheduled tasks... 
INFO [2023-08-31 22:24:04] 64979  Scheduler: executing task Piwik\Plugins\PrivacyManager\Tasks.deleteLogData...
INFO [2023-08-31 22:24:04] 64979  Scheduler: finished. Time elapsed: 0.048s
INFO [2023-08-31 22:24:04] 64979  Scheduler: executing task Piwik\Plugins\PrivacyManager\Tasks.anonymizePastData...
INFO [2023-08-31 22:24:04] 64979  Scheduler: finished. Time elapsed: 0.003s
INFO [2023-08-31 22:24:04] 64979  done
INFO [2023-08-31 22:24:04] 64979  ---------------------------

Wird dein Logfile so beendet? Oder bricht der Server die Archivierung ab?

Wenn die Archivierung das erste Mal mit Cronjob gemacht wird, bzw. vorher die Archivierung per Browser-Triggering nicht alles geschafft hat, dann sind mehrere Archivierungen notwendig, bis erst einmal der alte Kram archiviert wurde. Diese ersten Archivierungen laufen sehr lange und sehr intenstiv. Ist der alte Kram erledigt, wird es easyer. Dazu muss die Frequenz des Cronjobs an die zu bewältigende Masse an Daten angepasst werden.

Siehe auch meine Kommentare hier:

mchammer · September 8, 2023, 2:21pm

Hallo melbao,

schon einmal vielen Dank für deine Antwort

Ich habe es mit ein paar Einstellungen in der config jetzt schon einmal geschafft, dass die Serverlast wesentlich geringer ist. Folgende Einstellungen habe ich gesetzt:

; Archivierung nach einer Stunde automatisch stoppen - https://matomo.org/faq/how-to/how-can-i-automatically-stop-long-running-database-queries/
archiving_query_max_execution_time = 3600

; Stoppen von Live queries nach einer gewissen Zeit - https://matomo.org/faq/how-to/how-can-i-automatically-stop-long-running-database-queries/
live_query_max_execution_time = 60


; Enable Matomo application logging to both file and screen
[log]
log_writers[] = "file"
log_writers[] = "screen"
; log_level = DEBUG


[Debug]
enable_sql_profiler = 1
;always_archive_data_day=1 ; force archiving of all daily reports
;always_archive_data_period=1 ; force archiving for all period reports (week, month, year)


; Do not allow users to trigger the Matomo archiving process.
; Ensures that no unexpected data processing triggers from UI or API.
enable_browser_archiving_triggering = 0

; Disable OPTIMIZE TABLE statement which can create dead-locks
; and prevent MySQL backups
enable_sql_optimize_queries = 0


[CustomReports]
custom_reports_max_execution_time = 2700
;custom_reports_disabled_dimensions = "CoreHome.VisitLastActionDate"

Ich hatte heute Morgen die Archivierung noch einmal direkt über die Konsole angestoßen. Dabei wurde es wie folgt ausgeführt, bevor die Verbindung beendet wurde:

INFO [2023-09-08 05:56:58] 90991  ---------------------------
INFO [2023-09-08 05:56:58] 90991  INIT
INFO [2023-09-08 05:56:58] 90991  Running Matomo 4.15.1 as Super User
INFO [2023-09-08 05:56:58] 90991  ---------------------------
INFO [2023-09-08 05:56:58] 90991  NOTES
INFO [2023-09-08 05:56:58] 90991  - Async process archiving supported, using CliMulti.
INFO [2023-09-08 05:56:58] 90991  - Reports for today will be processed at most every 3600 seconds. You can change this value in Matomo UI > Settings > General Settings.
INFO [2023-09-08 05:56:58] 90991  - Archiving was last executed without error 9 days 15 hours ago.
INFO [2023-09-08 05:56:58] 90991  ---------------------------
INFO [2023-09-08 05:56:58] 90991  START
INFO [2023-09-08 05:56:58] 90991  Starting Matomo reports archiving...
INFO [2023-09-08 05:56:58] 90991  Found 6 failed jobs (ts_invalidated older than 1 day), resetting status to try them again.
INFO [2023-09-08 05:56:58] 90991  Start processing archives for site 1.
INFO [2023-09-08 05:56:58] 90991    Will invalidate archived reports for today in site ID = 1's timezone (2023-09-08 00:00:00).
INFO [2023-09-08 05:56:58] 90991    Will invalidate archived reports for yesterday in site ID = 1's timezone (2023-09-07 00:00:00).
INFO [2023-09-08 05:57:14] 90991  Archived website id 1, period = day, date = 2023-09-08, segment = '', 546 visits found. Time elapsed: 1.597s
INFO [2023-09-08 05:57:14] 90991  Archived website id 1, period = day, date = 2023-09-07, segment = '', 2666 visits found. Time elapsed: 15.850s
INFO [2023-09-08 05:57:14] 90991  Archived website id 1, period = day, date = 2023-08-30, segment = 'pageUrl!@https%3A%2F%2Fwww.domain.de%2Fen%2F', 1760 visits found. Time elapsed: 15.851s
INFO [2023-09-08 05:57:24] 90991  Archived website id 1, period = day, date = 2023-09-08, segment = 'pageUrl=@https%3A%2F%2Fwww.domain.de%2Fen%2F', 1460 visits found. Time elapsed: 2.841s
INFO [2023-09-08 05:57:24] 90991  Archived website id 1, period = day, date = 2023-09-08, segment = 'pageUrl!@https%3A%2F%2Fwww.domain.de%2Fen%2F', 188 visits found. Time elapsed: 2.842s
INFO [2023-09-08 05:57:24] 90991  Archived website id 1, period = day, date = 2023-09-07, segment = 'pageUrl=@https%3A%2F%2Fwww.domain.de%2Fen%2F', 2833 visits found. Time elapsed: 9.536s

Nachdem ich dann festgestellt hatte, dass für den 06.09. in Matomo nur ca. 1/4 der eigentlichen Besucher angezeigt wurden, habe ich die Archivierung noch einmal neu angestoßen. Dies war dann dazu die folgende Info. Dabei steht zwar 2023-09-08 und 2023-09-07, aber danach waren die Daten für den 06.09. in Matomo auch korrekt verarbeitet.

INFO [2023-09-08 06:57:20] 10419  ---------------------------
INFO [2023-09-08 06:57:20] 10419  INIT
INFO [2023-09-08 06:57:20] 10419  Running Matomo 4.15.1 as Super User
INFO [2023-09-08 06:57:20] 10419  ---------------------------
INFO [2023-09-08 06:57:20] 10419  NOTES
INFO [2023-09-08 06:57:20] 10419  - Async process archiving supported, using CliMulti.
INFO [2023-09-08 06:57:20] 10419  - Reports for today will be processed at most every 3600 seconds. You can change this value in Matomo UI > Settings > General Settings.
INFO [2023-09-08 06:57:20] 10419  - Archiving was last executed without error 9 days 16 hours ago.
INFO [2023-09-08 06:57:20] 10419  ---------------------------
INFO [2023-09-08 06:57:20] 10419  START
INFO [2023-09-08 06:57:20] 10419  Starting Matomo reports archiving...
INFO [2023-09-08 06:57:20] 10419  Start processing archives for site 1.
INFO [2023-09-08 06:57:20] 10419    Will invalidate archived reports for today in site ID = 1's timezone (2023-09-08 00:00:00).
INFO [2023-09-08 06:57:20] 10419    Will invalidate archived reports for yesterday in site ID = 1's timezone (2023-09-07 00:00:00).

Im Matomo Log habe ich die folgenden Einträge gefunden. Ich bin mir nicht sicher, ob sie damit zusammenhängen, aber zeitlich würde es passen:

ERROR Piwik\ExceptionHandler[2023-09-08 07:15:30 UTC] [10460] Uncaught exception: /usr/www/users/user/matomo/libs/Zend/Db/Statement/Pdo.php(236): SQLSTATE[HY000]: General error: 2006 MySQL server has gone away [Query: ?module=API&method=CoreAdminHome.archiveReports&idSite=1&period=day&date=2023-08-25&format=json&segment=pageUrl%3D%40https%25253A%25252F%25252Fwww.domain.de%25252Fen%25252F&trigger=archivephp&pid=fa69c78526b0c113d2dd5a350f2c5d63b95961d7622691b96f708d7490287f24a1bc55dab34d250b01093130341bb88c049d2&runid=10419, CLI mode: 1]
ERROR CoreConsole[2023-09-08 07:15:31 UTC] [10419] Got invalid response from API request: ?module=API&method=CoreAdminHome.archiveReports&idSite=1&period=day&date=2023-08-25&format=json&segment=pageUrl%3D%40https%25253A%25252F%25252Fwww.domain.de%25252Fen%25252F&trigger=archivephp. Response was '{"result":"error","message":"SQLSTATE[HY000]: General error: 2006 MySQL server has gone away"}'

Ich habe mir bei bei den letzten Archivierungen mal die SQL-Connections angeschaut und es ist immer die folgende Query, welche sich quasi totläuft und wonach nichts mehr passiert. Genau dieses MySQL Query hatte Hetzner ja auch schon als Prozess identifiziert, der die hohe Last verursacht, da er nicht beendet wird.

SELECT  /*+ MAX_EXECUTION_TIME(3600000) */ 
          yyy.idvisit AS idvisit,
          8 AS idgoal,
          4 AS `type`,
          yyy.idaction AS idaction,
          COUNT(*) AS `1`,     
          ROUND(SUM(yyy.revenue_total),2) AS `2`,          
          COUNT(yyy.idvisit) AS `3`,                   
          ROUND(SUM(yyy.revenue_subtotal),2) AS `4`,                 
          ROUND(SUM(yyy.revenue_tax),2) AS `5`,
          ROUND(SUM(yyy.revenue_shipping),2) AS `6`,
          ROUND(SUM(yyy.revenue_discount),2) AS `7`,
          SUM(yyy.items) AS `8`,
          yyy.pages_before AS `9`,                    
          SUM(yyy.attribution) AS `10`,                    
          COUNT(*) AS `12`,              
          ROUND(SUM(yyy.revenue),2) AS `15`         
        FROM (
          SELECT
            num_total AS pages_before,
            1 / num_total AS attribution,
            r.idvisit AS idvisit,
            lac.idaction AS idaction,
            lvcon.revenue AS revenue_total,
            1 / num_total * lvcon.revenue AS revenue,
            1 / num_total * lvcon.revenue_subtotal AS revenue_subtotal,
            1 / num_total * lvcon.revenue_tax AS revenue_tax,
            1 / num_total * lvcon.revenue_shipping AS revenue_shipping,
            1 / num_total * lvcon.revenue_discount AS revenue_discount,
            1 / num_total * lvcon.items AS items
          FROM (
            SELECT /* sites 1 */ /* 2023-08-24,2023-08-25 */ /* Actions */ /* trigger = CronArchive */
				log_conversion.idvisit, COUNT(*) AS num_total
			FROM
				matomo_log_conversion AS log_conversion RIGHT JOIN matomo_log_link_visit_action AS log_vpast ON log_conversion.idvisit = log_vpast.idvisit LEFT JOIN matomo_log_action AS lac_past ON log_vpast.idaction_name = lac_past.idaction
			WHERE
				log_conversion.server_time >= '2023-08-24 22:00:00'
				AND log_conversion.server_time <= '2023-08-25 21:59:59'
				AND log_conversion.idsite IN ('1')AND log_conversion.idgoal = 8 
                          AND log_vpast.server_time <= log_conversion.server_time
                          AND lac_past.type = 4
			GROUP BY
				log_conversion.idvisit
          ) AS r
          LEFT JOIN matomo_log_conversion lvcon ON lvcon.idgoal = 8 AND lvcon.idvisit = r.idvisit
          RIGHT JOIN matomo_log_link_visit_action logv ON logv.idvisit = r.idvisit
          LEFT JOIN matomo_log_action lac ON logv.idaction_name = lac.idaction
          WHERE logv.server_time >= '2023-08-24 22:00:00'
            AND logv.server_time <= '2023-08-25 21:59:59'
            AND logv.idsite IN (1) 
            AND lac.type = 4
            AND logv.server_time <= lvcon.server_time
          ) AS yyy
        GROUP BY yyy.idaction
        ORDER BY `9` DESC

Es scheint mir so, als hätte die Query etwas mit dem E-Commerce Tracking zu tun, was allerdings gar nicht aktiviert ist.

Ich hoffe, dass hier jemand noch eine Idee hat, woran es liegen könnte

Danke und sonnige Grüße,
Tim

melbao · September 8, 2023, 7:03pm

OK. Jetzt wird es komplex.

SQLSTATE[HY000]: General error: 2006 MySQL server has gone away

Diese Meldung wird geliefert, weil der Server den Prozess gekillt hat und scheinbar weitere blockiert, wohl wegen zu hoher Serverlast.

“E-Commerce Tracking”
Da bestehen meinerseits keine Kenntnisse. Eventuell deinstallieren, falls nachträglich installiert.

Allgemein ist eine ideale Herangehensweise, wenn alles auf default gestellt ist.

Der MySQL Query ist ein SELECT, also nur eine Datenabfrage und keine Datenspeicherung. Allerdings eine sehr komplexe. Eventuell zu komplexe.
Wenn die Möglichkeit (Know How) besteht, dann diesen SQL SELECT mal in der command line (SSH) ausführen und schauen was passiert.

Vielleicht nochmal die Werte heruntersetzen und die Cronjob-Intervalle erhöhen:
archiving_query_max_execution_time = 600

Wenn alles nichts hilft, dann mit Hetzner vereinbaren, dass die Archivierung wegen zu hoher zu archivierender Datenmenge zu Server-Kills führt und diese nach ein paar mal nachlassen, bis endlich ohne Server-Kills archiviert wird - in Cronjob-Intervallen, die an die Datenmenge angepasst sind.

Allerdings wäre das neu, dass es Probleme bei der Archivierung wegen zu hoher zu archivierender Datenmenge gibt. Allerdings müssen einige die Archivierungsprozesse auf andere Server auslagern und eventuell sogar auf mehrere Server aufsplitten. Um welche Höhe der Datenmenge es sich dabei handelt wurde bisher nicht mitgeteilt.

Bedenke: Das ist nur ein User-hilft-User Support. Der echte Support ist nicht kostenfrei.

foxpalace · January 9, 2024, 3:13pm

Hi - du hast deine mysql-db nicht konfiguriert - Default-Einstellungen nach einer MySQL-Installation sind “babyhaft”

a) https://matomo.org/faq/troubleshooting/faq_183/
b) schau dir deine DB mit mysqltuner an - https://github.com/major/MySQLTuner-perl

Gruß Michael

foxpalace · January 9, 2024, 3:18pm

PS: Hier noch die Werte auf die du besonders bei mysqltuner achten solltest:
[OK] Maximum reached memory usage: 48.8G (51.72% of installed RAM)
[OK] Maximum possible memory usage: 68.5G (72.60% of installed RAM)
…
[OK] InnoDB Read buffer efficiency: 99.99% (226269042463 hits/ 226300114291 total)
[OK] InnoDB Write log efficiency: 99.96% (1788433345 hits/ 1789129498 total)