Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Tons of "General error: 1205" in php error log while importing via the python log importer #16924

Closed
adrianlambertz opened this issue Dec 9, 2020 · 17 comments · Fixed by #16925
Labels
c: Performance For when we could improve the performance / speed of Matomo.
Milestone

Comments

@adrianlambertz
Copy link

It seems that there is a problem with the user_token_auth while importing log via the python logimporter.
While looking at the SQL processlist I see several UPDATE queries for the matomo_user_token_auth table, they run the entire time until the timeout:

[09-Dec-2020 09:28:08 UTC] Error in Matomo (tracker): Error query: SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction In query: UPDATE 'matomo_user_token_auth' SET 'last_used' = ? WHERE 'idusertokenauth' = ? Parameters: array ( 0 => '2020-12-09 09:27:17', 1 => '207', )

Manually executing one of these queries works like a charm in some milliseconds. But not while the python script runs.

After the timeout the python script echoes this:

2020-12-09 09:28:08,641: [INFO] Error when connecting to Matomo: HTTP Error 500: Internal Server Error
2020-12-09 09:28:08,642: [INFO] Retrying request, attempt number 2

That's since the latest 4.0.4 update (I updated from v3) and I use Python 3.7 to execute the script.

@sgiehl
Copy link
Member

sgiehl commented Dec 9, 2020

Thanks for creating the issue @adrianlambertz
Maybe we should avoid updating the usage timestamp for token_auths when doing log imports

@adrianlambertz
Copy link
Author

adrianlambertz commented Dec 9, 2020

Is there a quick fix to disable the timestamp update while using the python log import? Because we are heavily relying on this script - we import logs from about 100 sites every night.

Because of this issue the imported statistics arent complete or missing.

@sgiehl
Copy link
Member

sgiehl commented Dec 9, 2020

You can change the code so the update isn't done here:

public function setTokenAuthWasUsed($tokenAuth, $dateLastUsed)
{
$token = $this->getTokenByTokenAuth($tokenAuth);
if (!empty($token)) {
$this->updateTokenAuthTable($token['idusertokenauth'], array(
'last_used' => $dateLastUsed
));
}
}

@adrianlambertz
Copy link
Author

Perfect thanks, temporarily commenting out the updateTokenAuthTable function seems to work. I'll try to report tomorrow morning after the import of all sites.

@L3on1d
Copy link

L3on1d commented Dec 9, 2020

Hi @adrianlambertz

Have you managed to solve this problem? If yes could please share your change?

Thanks!

@adrianlambertz
Copy link
Author

Hi @adrianlambertz

Have you managed to solve this problem? If yes could please share your change?

Thanks!

See this pull request from @sqiehl

@L3on1d
Copy link

L3on1d commented Dec 9, 2020

@adrianlambertz thanks, I have updated code according to @sgiehl pull request, but problem still exists, very poor import speed.

@tsteur
Copy link
Member

tsteur commented Dec 9, 2020

Hi @L3on1d are there also other queries causing these errors maybe?

Is the Provider plugin enabled maybe?

@L3on1d
Copy link

L3on1d commented Dec 9, 2020

Provider plugin is disabled. I'm just started another log import, if these errors will appear again, I will update you. Anyway speed is very slow.

@L3on1d
Copy link

L3on1d commented Dec 9, 2020

@tsteur yes you are right, this error:

"PHP message: Error in Matomo (tracker): Error query: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction In query: UPDATE mtm_log_visit SET profilable = ?, visitor_seconds_since_order = ?, visit_exit_idaction_url = ?, visit_total_actions = visit_total_actions + 1 , visit_total_interactions = visit_total_interactions + 1 , visit_total_time = ? WHERE idsite = ? AND idvisit = ? Parameters: array ( 0 => 0, 1 => NULL, 2 => 2588680546, 3 => 589, 4 => 6, 5 => '3037957010', )" while reading response header from upstream

not related to log import,

but main problem that I have pretty big log volume, and with such big drop in import speed I'm unable to import logs.

@tsteur
Copy link
Member

tsteur commented Dec 10, 2020

What's your log import command parameters?

In config/config.ini.php you could also try setting this as a test:

[Tracker]
bulk_requests_use_transaction = 0

Might not help but worth a try. Otherwise you could also try and play around with different settings to see if that helps.

@L3on1d
Copy link

L3on1d commented Dec 10, 2020

At the moment, I use this command:

python3.9 /path/to/misc/log-analytics/import_logs.py --url=https://mymatomourl --idsite=6 --recorders=8 --enable-bots --recorder-max-payload-size=400 /path/to/logs

UPD

I have tried import with bulk_requests_use_transaction = 0 - same results.

Thank you.

@L3on1d
Copy link

L3on1d commented Dec 10, 2020

I found another thing which can be directly related to speed problems, according to monitoring, after upgrade to Matomo 4 log import start consuming more CPU and load average increased x3 times. :(

Before upgrade:

image

After upgrade:

image

@adrianlambertz
Copy link
Author

adrianlambertz commented Dec 10, 2020

Perfect thanks, temporarily commenting out the updateTokenAuthTable function seems to work. I'll try to report tomorrow morning after the import of all sites.

This night our import worked smoothly like a charm. No SQL Timeouts and all statistics/logs are correctly imported. Thank you @sgiehl

EDIT:
But it seems that it was much slower than before the update. This night it took 02:18 hours to import (but i have to say: with 4 recorders instead of 8).
The last import on version 3 took only 23 Minutes with 8 recorders.

I changed the amount of recorders to 8 today and i'll report tomorrow morning.

@adrianlambertz
Copy link
Author

Yes, tonight it took 1:38 hour to complete the import with 8 recorders. It's much slower than before the update.

@L3on1d
Copy link

L3on1d commented Dec 13, 2020

@adrianlambertz have you checked your server load during import?

@adrianlambertz
Copy link
Author

@adrianlambertz have you checked your server load during import?

Yes, nothing unusual. Same load as before.

@tsteur tsteur added this to the 4.1.0 milestone Dec 16, 2020
@tsteur tsteur added the c: Performance For when we could improve the performance / speed of Matomo. label Dec 16, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
c: Performance For when we could improve the performance / speed of Matomo.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants