Second queue is growing forever #153
Comments
|
@marcinzp thanks for reaching out. You could use the command To give you some hint we would need to understand a bit better how you track data. Are you using the JavaScript tracker? If you are using log importer then please note that we usually don't recommend using log importer in combination with queued tracking (since they are both doing some kind of queued tracking but in a different way). And if there's no other way around this would maybe need to try applying some settings. |
|
@tsteur thank you for your answer and explanations. In the night, the growing queue was "magically" processed, but I think I still need to prepare for the return of the problem, it returns every few days. If I understand properly, queues as numbered from 0, so the second one has id == 1, right? We're tracking data for multiple sites using JS tracker and two of our sites are our mobile application, which use SDK for tracking (we have two sites, separately for Android and iOS app). What I also noticed, CPU was more busy, but it didn't process the queue even when heaving more "headroom" in processing power:
|
That's the case as far as I know. If it happens every few days you might want to look at the content of these requests using the command I mention to see what is different there. In the past we've seen eg people using the userId feature I mentioned and there was a bug where the same userId was tracked for every visitor (eg |
|
Thank you @tsteur By userId feature you mean this one? |
Yes 👍
Not that I know but I don't think that's the issue (at least whenever I've seen this it's never been that problem) |
|
Thank you. I've checked, that we are using userId both in JS and SDK clients. So if my problem returns, I need to check what is different in requests in this not/slowly processed queue, and especially look at userId if it's not the same for all requests? (what would be an incarnation of some old error) |
|
I didn't need to wait long @tsteur :-) I got WARNING of "Invalid argument" /usr/share/piwik/console queuedtracking:monitor /usr/share/piwik/console queuedtracking:print-queued-requests --queue-id=1 | head and request contain particularly many times one user id: /usr/share/piwik/console queuedtracking:print-queued-requests --queue-id=1 | grep "'uid'" | sort | uniq -c /usr/share/piwik/console queuedtracking:print-queued-requests --queue-id=1 | grep "'uid'" | sort | uniq -c |
|
After two hours: /usr/share/piwik/console queuedtracking:monitor /usr/share/piwik/console queuedtracking:print-queued-requests --queue-id=1 | grep "'uid'" | sort | uniq -c |
refs matomo-org/plugin-QueuedTracking#153 (comment) Possible warning: > /usr/share/piwik/core/Tracker/RequestSet.php(36): Warning - Invalid argument supplied for foreach() - Not sure how this would happen and it might hide an actual error maybe. I've been looking through code for a while and couldn't really see where this might happen. The only one I could find was bulk tracking a wrong JSON being set. Maybe we should throw an invalid tracking parameter exception when `requests` is not an array? https://github.com/matomo-org/matomo/blob/4.4.1/plugins/BulkTracking/Tracker/Requests.php#L78
|
@marcinzp could you try to apply this patch if any possible to see if the error goes away? https://github.com/matomo-org/matomo/pull/17877/files |
|
Thank you @tsteur - EDITED ~2 hours after patching, I see that queue is indeed decreasing its size AND I don't see requests from that 179829 (50+179622+13+53+26+13+47+5) request sets left in queue. 413.77M used memory (588.55M peak). 1 workers active. So either the problem is solved or it disappeared again. MY PREVIOUS COMMENT:
|
|
Great, thanks for the update. Keep us informed 👍 |
|
So far so good :-) |
|
Great, thanks for letting us know and fingers crossed. We'll merge the PR very likely soon and then it would be included in the next release. |
…#17877) refs matomo-org/plugin-QueuedTracking#153 (comment) Possible warning: > /usr/share/piwik/core/Tracker/RequestSet.php(36): Warning - Invalid argument supplied for foreach() - Not sure how this would happen and it might hide an actual error maybe. I've been looking through code for a while and couldn't really see where this might happen. The only one I could find was bulk tracking a wrong JSON being set. Maybe we should throw an invalid tracking parameter exception when `requests` is not an array? https://github.com/matomo-org/matomo/blob/4.4.1/plugins/BulkTracking/Tracker/Requests.php#L78
|
@tsteur The problem is back :-( /usr/share/piwik/console queuedtracking:monitor sudo -u www-data /usr/share/piwik/console queuedtracking:print-queued-requests --queue-id=0 | grep "'uid'" | sort | uniq -c |
|
@tsteur could you possible reopen this issue? Thank you, |
|
@marcinzp can you also check if there are maybe a lot of requests with the same visitorId (this is the Have you checked if there is any kind of information in any error log? |
|
|
So @tsteur ... I'm trying to catch the problem again: /usr/share/piwik/console queuedtracking:monitor /usr/share/piwik/console queuedtracking:print-queued-requests --queue-id=0 | grep "'uid'" | sort | uniq -c /usr/share/piwik/console queuedtracking:print-queued-requests --queue-id=0 | grep "'_id'" | sort | uniq -c I still have most request from the same user. Those requests come from our application (using Matomo SDK). There are in fact, some occurrences of this user id in access.log, but...: grep -c "qn5flmc4uvua9bs4mso81ku46ejd1htr3pt6iakog7" /var/log/nginx/access.log zgrep -c "qn5flmc4uvua9bs4mso81ku46ejd1htr3pt6iakog7" /var/log/nginx/access.log-20211001.gz As you can see, it's not that often as in the queue. And: grep "qn5flmc4uvua9bs4mso81ku46ejd1htr3pt6iakog7" /var/log/nginx/access.log | cut -f5 -d\ | tail -n5 Last occurrences today were 4 hours ago... So I took a look at the contents of those records and I see them to be almost the same: /usr/share/piwik/console queuedtracking:print-queued-requests | grep -C4 qn5flmc4uvua9bs4mso81ku46ejd1htr3pt6iakog7 | csplit --suppress-matched - "/^--$/" '{*}' md5sum xx* | cut -f1 -d\ | sort | uniq -c | sort -nr |
|
@marcinzp thanks for the update. You could exclude specific user ID from being tracked like this see https://matomo.org/faq/how-to/how-do-i-exclude-specific-tracking-requests-in-matomo/ Edit your |
|
@tsteur Thank you, I've added recommended entry: [Tracker] but the queue still seems to be growing: /usr/share/piwik/console queuedtracking:print-queued-requests --queue-id=0 | grep -c qn5flmc4uvua9bs4mso81ku46ejd1htr3pt6iakog7 |
|
... but after a longer while, the queue is melting indeed :-) /usr/share/piwik/console queuedtracking:monitor |
|
@tsteur we are facing a similar issue after updating Matomo from 3.14 to 4.6.2. we are using for tracking, we are using
before the update, the requests were getting processed correctly. Output of Output of I also checked |
|
@rishabhkailey the requests from the java tracker, are they maybe mostly sent from the same IP address or maybe you are using the Matomo User ID feature and there could be a bug that many users have the same user ID? |
|
The requests from the java tracker are from the same IP and have the same user id ( |
This would be expected behaviour in that case. Queued tracking would put these requests all in the same queue to make sure the data for these are processed correctly. Otherwise there could be issues that data would be processed out of order and then the data could become inaccurate. |
|
I will check with the team. I think we are only using user id for creating segments in Matomo. we can try to use custom variables instead.
We didn't face this issue in Matomo 3.14, is the above behavior have been added after Matomo 3.14? |
|
and If we do not set the user id then will it work? does the same IP for all the requests will cause problems without user id? |
That should have been always there. So it's not clear why this changed now. Maybe it didn't happen exactly since the update to a newer Matomo version and was caused by something else?
The same IP for all the requests will cause the same issue. This is the case because requests of the same IP might belong to the same visitor which means we have to put these requests into the same queue. A workaround would be, if possible, to set a custom IP in the tracker ( |
|
@tsteur Thanks for the help, setting the Custom IP for the Matomo requests, seems to solve the problem. |
|
Hi, we have the same issue. Since days, I have tested a lot of tricks I've found. Like :
By deactivating ProcessDuringTrackingRequest there is no way to treat all off the 5M process. I re-create empty table matomo_queuedtracking_list_trackingQueueV1_1 |
|
I moved all to Redis database that is the same : Peek.14-12-2023.16-23.mp4Nothing seems to be treated |
|
@loris-av Does running this command works ? |
|
Hi @AltamashShaikh I've playe by changing number of With very low number of element (50-100) I've running And it was running without finish.. Your command dont work
|
|
It's look like the problem is like described before the uid, our Android App introduced an user_id, uid -1 when user is not connected. It seems le process method dont like like this value. Maybe this boke the while or anything else, if someone can help me for investigating by adding some debug in the code ? I've read the trick by dealing with auth_token and cip, but for now we cannot fix this for all users because deploy new App version on the Play Store should not solve this immediately (because all users have to do the update etc..). |
|
I temporary fixed the problem by ignoring request directly into piwik.php..
|
@loris-av Which version of plugin are you using and can you give more details about your setup ? |
|
We added something in this PR to help debugging such cases. If your plugin is upto date, you might need to add |
|
Yes log_failed_tracking_request_body=1 is set since few days. Today I have some errors due to dead locks, and others not due to this uid -1. I've solved "blocked" queue by adding this temporary trick into piwik.php if (isset($_GET['uid']) && $_GET['uid'] === '-1') {
@file_put_contents('../logs-blocked-1-' . date('Y-m-d') . '.txt', json_encode(['GET' => $_GET, 'POST' => $_POST, 'REQUEST' => $_REQUEST]) . PHP_EOL, FILE_APPEND | LOCK_EX);
header('HTTP/1.1 200 OK');
return;
}
$requests = json_decode(file_get_contents('php://input'))->requests ?? [];
foreach ($requests as $request) {
if (str_contains($request, 'uid=-1')) {
@file_put_contents('../logs-blocked-1-multi-' . date('Y-m-d') . '.txt', json_encode(['GET' => $_GET, 'POST' => $_POST, 'STREAM' => $requests, 'REQUEST' => $_REQUEST]) . PHP_EOL, FILE_APPEND | LOCK_EX);
header('HTTP/1.1 200 OK');
return;
}
}
@file_put_contents('../logs-passed-' . date('Y-m-d') . '.txt', json_encode(['GET' => $_GET, 'POST' => $_POST, 'REQUEST' => $_REQUEST]) . PHP_EOL, FILE_APPEND | LOCK_EX); |
|
I've backuped the MySQL table with 5M records containing these events with this I know these line are saved as longblog and ar gzipped with gzuncompress |
QueuedTracking (v4.0.7) Details : Click to view System CheckMandatory checksVersion PHP >= 7.2.5:✔ 8.1.17RC1 PDO extension:✔ PDO\MYSQL extension:✔ MYSQLI extension:✔ Connexion au lecteur de la base de données:✔ Autres extensions requises:✔ zlib ✔ json ✔ filter ✔ hash ✔ session Fonctions requises:✔ debug_backtrace ✔ eval ✔ hash ✔ gzcompress ✔ gzuncompress ✔ pack Configuration PHP requise (php.ini):✔ session.auto_start = 0 ✔ max_execution_time = 0 OR = -1 OR >= 30 Répertoires avec les droits d'accès en écriture:✔ $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 Répertoires avec accès en écriture pour Gestionnaire de balises:✔ $DOC_ROOT/js Optional checksRépertoires privés requis:✔ Tous les répertoires privés sont inaccessibles depuis Internet. Répertoires privés recommandés:✔ Tous les répertoires privés sont inaccessibles depuis Internet. Intégrité des fichiers:⚠ Warning: Le contrôle d'intégrité a échoué et a rapporté des erreurs. Vous devriez corriger ces problèmes puis rafraîchir cette page jusqu'à ce qu'il n'y ait plus d'erreur. Binaire PHP 64 bits:✔ État du traqueur:✔ Limite mémoire:✔ 8192M Fuseau horaire:✔ Ouvrir l'URL:✔ curl PageSpeed est désactivé:✔ GD > 2.x + FreeType (graphics):✔ Autres extensions:✔ json ✔ libxml ✔ dom ✔ SimpleXML ✔ openssl Autres fonctions:✔ shell_exec ✔ set_time_limit ✔ mail ✔ parse_ini_file ✔ glob ✔ gzopen ✔ md5_file Système de fichiers:⚠ Warning: Votre serveur utilise un système de fichier NFS. Paramétrer une tâche Cron - Gestion des processus via la ligne de commande:✔ Ok Dernière exécution d'archivage réussie:✔ Le processus d'archivage s'est terminé avec succès il y a 01:15:46. Capacités de la base de données:✔ UTF8mb4 charset ⚠ Warning: LOAD DATA INFILE Taille maximale des paquets:✔ Connexion SSL forcée:✔ Géolocalisation:✔ geoip2php (continent_code, continent_name, country_code, country_name, region_code, region_name, city_name, postal_code, lat, long) Mettre à jour via HTTPS:✔ Traceur JavaScript inscriptible ("/matomo.js" & "/piwik.js"):✔ Informational resultsMatomo Version:4.16.0 Matomo Update History:4.14.2,4.3.1,4.3.0-b3,4.2.1,3.14.1, Matomo Install Version:Unknown - pre 3.8. Latest Available Version:4.16.0 Is Git Deployment:0 PHP_OS:Linux PHP_BINARY:/opt/remi/php81/root/usr/sbin/php-fpm PHP SAPI:fpm-fcgi Timezone Version:2022.1 PHP Timezone:UTC PHP Time:1702636201 PHP Datetime:2023-12-15 10:30:01 PHP INI max_execution_time:0 PHP INI post_max_size:8M PHP INI max_input_vars:1000 PHP INI zlib.output_compression:Curl Version:7.29.0, NSS/3.53.1 Suhosin Installed:0 DB Prefix:matomo_ DB Charset:utf8mb4 DB Adapter:MYSQLI MySQL Version:5.7.34-log Num Tables:425 Browser Segment Archiving Enabled:0 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, CustomReports 4.1.8, CustomVariables 4.1.3, Dashboard, DevicePlugins, DevicesDetection, Diagnostics, Ecommerce, Events, Feedback, Funnels 4.1.7, GeoIp2, Goals, Heartbeat, ImageGraph, Insights, Installation, Intl, IntranetMeasurable, LanguagesManager, Live, Login, MarketingCampaignsReporting 4.1.3, Marketplace, MobileMessaging, Monolog, Morpheus, MultiSites, Overlay, PagePerformance, PrivacyManager, ProfessionalServices, Proxy, QueuedTracking 4.0.7, 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, Provider 4.0.5 Plugins Invalid:Server Info:nginx/1.22.0 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-12-15 10:05:02 Archive Time Last Finished:2023-12-15 09:14:14 User Agent:Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0 Browser Language:fr-fr,fr Total Invalidation Count:382 In Progress Invalidation Count:41 Scheduled Invalidation Count:341 Earliest invalidation ts_started:2023-12-14 12:34:17 Latest invalidation ts_started:2023-12-15 11:26:17 Earliest invalidation ts_invalidated:2022-12-22 16:05:03 Latest invalidation ts_invalidated:2023-12-15 10:05:19 Number of segment invalidations:373 Number of plugin invalidations:0 List of plugins being invalidated:Anonymize Referrer:Do Not Track enabled:1 |
|
@loris-av Do you have the stack trace for
@loris-av You meant removing the |
|
@loris-av I think this should work |
I've tested this params --force-num-requests-process-at-once without success. Do you thing reduce it to 5 work (i've tested it setted to 10) |
|
@AltamashShaikh I found the error mentioned in the previous comment and it looks like it's because the core code says that the request is too old and requires an auth token. Does the QueuedTracking plugin supply a token when processing requests? I wonder if it should. |
|
Thanks for all these returns, Maybe we have multiple "issues", for now I've fixed it manually by ignoring the requests #153 (comment) we will see |
Hello, since few Matomo versions we have returning problem with the second queue which is growing forever (until I remove this plugin and reinstall it back, as I haven't found better method yet).
Matomo version: 4.4.1
MySQL version: 5.7.34-37-log
PHP version: 7.3.29-1+0
20210701.86+debian101.gbp7ad6ebBackend: Redis
sudo -u www-data /usr/share/piwik/console queuedtracking:monitor
Queue is enabled
The command ./console queuedtracking:process has to be executed to process request sets within queue
Up to 8 workers will be used
Processor will start once there are at least 5 request sets in the queue
218717 (53+218338+68+60+54+60+40+44) request sets left in queue. 464.62M used memory (588.55M peak). 1 workers act...
How can I debug this?
Thanks :-)
The text was updated successfully, but these errors were encountered: