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

In SQL queries, print out the name of the plugin in a SQL comment for troubleshooting which plugin triggered query #7913

Closed
mgazdzik opened this Issue May 15, 2015 · 8 comments

Comments

Projects
None yet
4 participants
@mgazdzik
Contributor

mgazdzik commented May 15, 2015

Goal of this issue is to make recognition of queries easier by marking queries with name of plugin which launched them.
In some cases, when archiving is slow or unefficient we end up having actual MySQL query that timed out or took DB down.
Currently there is no easy way to find which plugin caused this (sometimes it's archiving, or live plugin, sometimes it's custom plugins using core logic).

Maybe it could be tackled by adding one more "SELECT" item like "$pluginName as pluginName".
It will not be used while building additional archive, but still will "brand" each query with parenting plugin and make debug a bit easier.

Obviously not all plugins will be affected by this change (those with custom queries handled by custom code), but at least those which use core logic will be marked.

Please let me know if you have any questions about this request?

@tsteur

This comment has been minimized.

Show comment
Hide comment
@tsteur

tsteur May 18, 2015

Member

I think a good practice is to do something like this SELECT /* myPluginOrMyClass */ FROM if that would help

Member

tsteur commented May 18, 2015

I think a good practice is to do something like this SELECT /* myPluginOrMyClass */ FROM if that would help

@mnapoli

This comment has been minimized.

Show comment
Hide comment
@mnapoli

mnapoli May 19, 2015

Contributor

@mgazdzik where do you want to "mark" the queries? Is it for the log (file, CLI output?)? Or is it for MySQL's query log?

Contributor

mnapoli commented May 19, 2015

@mgazdzik where do you want to "mark" the queries? Is it for the log (file, CLI output?)? Or is it for MySQL's query log?

@mgazdzik

This comment has been minimized.

Show comment
Hide comment
@mgazdzik

mgazdzik May 19, 2015

Contributor

@tsteur - unfortunately such comments aren't visible in mysql logs or in full process lists (or at least weren't visible at moment when we tried them).

@mnapoli - simplest thing that comes to my mind is mysql logs (normal log and slowlog). Also long running queries can be seen using "show full processlist", which would also give clue about problematic plugin at first glance.

Contributor

mgazdzik commented May 19, 2015

@tsteur - unfortunately such comments aren't visible in mysql logs or in full process lists (or at least weren't visible at moment when we tried them).

@mnapoli - simplest thing that comes to my mind is mysql logs (normal log and slowlog). Also long running queries can be seen using "show full processlist", which would also give clue about problematic plugin at first glance.

@mattab

This comment has been minimized.

Show comment
Hide comment
@mattab

mattab May 20, 2015

Member

if adding comments to SQL works I think it would be best/easiest solution

unfortunately such comments aren't visible in mysql logs or in full process lists (or at least weren't visible at moment when we tried them).

according to: http://stackoverflow.com/questions/19705881/how-to-get-mysql-comments-to-show-up-in-the-slow-log-or-processlist - comments are stripped when the queries come from mysql client, but they should be there when coming from other APIs eg. php apps. (note: I didn't test)

Member

mattab commented May 20, 2015

if adding comments to SQL works I think it would be best/easiest solution

unfortunately such comments aren't visible in mysql logs or in full process lists (or at least weren't visible at moment when we tried them).

according to: http://stackoverflow.com/questions/19705881/how-to-get-mysql-comments-to-show-up-in-the-slow-log-or-processlist - comments are stripped when the queries come from mysql client, but they should be there when coming from other APIs eg. php apps. (note: I didn't test)

@mattab

This comment has been minimized.

Show comment
Hide comment
@mattab

mattab Jul 15, 2015

Member

Targetting for 2.15.0 as hopefully this is a quick fix

Member

mattab commented Jul 15, 2015

Targetting for 2.15.0 as hopefully this is a quick fix

@mattab mattab added this to the 2.15.0 milestone Jul 15, 2015

@tsteur tsteur self-assigned this Jul 30, 2015

@tsteur

This comment has been minimized.

Show comment
Hide comment
@tsteur

tsteur Jul 31, 2015

Member

I did some work to see if it's easy to fix in https://github.com/piwik/piwik/compare/7913

It seems to work but only kinda. The comment containing the plugin name is only visible in a subquery since the query generated by the log aggregator is surrounded by a ranking query usually. It looks like this (look for /* Actions */ near the end):

S `33`, sum(`1090`) AS `1090`, sum(`1093`) AS `1093`, min(`1091`) AS `1091`, max(`1092`) AS `1092`, `type`
            FROM ( 
            SELECT
                `idaction`, `name`,

            CASE
                WHEN `type` = 1 AND @counter1 = 50001 THEN 50001
                WHEN `type` = 1 THEN @counter1:=@counter1+1
                WHEN `type` = 2 AND @counter2 = 50001 THEN 50001
                WHEN `type` = 2 THEN @counter2:=@counter2+1
                WHEN `type` = 3 AND @counter3 = 50001 THEN 50001
                WHEN `type` = 3 THEN @counter3:=@counter3+1
                WHEN `type` = 4 AND @counter4 = 50001 THEN 50001
                WHEN `type` = 4 THEN @counter4:=@counter4+1
                WHEN `type` = 8 AND @counter8 = 50001 THEN 50001
                WHEN `type` = 8 THEN @counter8:=@counter8+1
                ELSE 0
            END
         AS counter
                , `url_prefix`, `1`, `12`, `2`, `28`, `29`, `30`, `31`, `32`, `33`, `1090`, `1093`, `1091`, `1092`, `type`
            FROM
                ( SELECT @counter1:=0 ) initCounter1, ( SELECT @counter2:=0 ) initCounter2, ( SELECT @counter3:=0 ) initCounter3, ( SELECT @counter4:=0 ) initCounter4, ( SELECT @counter8:=0 ) initCounter8, 
                ( SELECT /* Actions */
                log_action.name,
                  log_action.type,
                  log_action.idaction,
                  log_action.url_prefix,
                  count(distinct log_link_visit_action.idvisit) as `2`,
                  count(distinct log_link_visit_action.idvisitor) as `1`,
                  count(*) as `12`, sum(
                          case when custom_float is null
                              then 0
                              else custom_float
                          end
                  ) / 1000 as `30`, sum(
                      case when custom_float is null
                          then 0
                          else 1

Why did I not do this within the RankingQuery? Because a RankingQuery is created by each plugin instance see https://github.com/piwik/piwik/blob/2.14.2/plugins/Actions/Archiver.php#L178 . This means we can't solve it within the Piwik Platform but each plugin would have to set it. We could do this for our plugins but for 3rd party plugins it wouldn't work automatically (including Piwik PRO plugins unless it we don't forget to set it everywhere). Not sure if this is an issue and whether one such hint would be enough even if it is a subquery?

Member

tsteur commented Jul 31, 2015

I did some work to see if it's easy to fix in https://github.com/piwik/piwik/compare/7913

It seems to work but only kinda. The comment containing the plugin name is only visible in a subquery since the query generated by the log aggregator is surrounded by a ranking query usually. It looks like this (look for /* Actions */ near the end):

S `33`, sum(`1090`) AS `1090`, sum(`1093`) AS `1093`, min(`1091`) AS `1091`, max(`1092`) AS `1092`, `type`
            FROM ( 
            SELECT
                `idaction`, `name`,

            CASE
                WHEN `type` = 1 AND @counter1 = 50001 THEN 50001
                WHEN `type` = 1 THEN @counter1:=@counter1+1
                WHEN `type` = 2 AND @counter2 = 50001 THEN 50001
                WHEN `type` = 2 THEN @counter2:=@counter2+1
                WHEN `type` = 3 AND @counter3 = 50001 THEN 50001
                WHEN `type` = 3 THEN @counter3:=@counter3+1
                WHEN `type` = 4 AND @counter4 = 50001 THEN 50001
                WHEN `type` = 4 THEN @counter4:=@counter4+1
                WHEN `type` = 8 AND @counter8 = 50001 THEN 50001
                WHEN `type` = 8 THEN @counter8:=@counter8+1
                ELSE 0
            END
         AS counter
                , `url_prefix`, `1`, `12`, `2`, `28`, `29`, `30`, `31`, `32`, `33`, `1090`, `1093`, `1091`, `1092`, `type`
            FROM
                ( SELECT @counter1:=0 ) initCounter1, ( SELECT @counter2:=0 ) initCounter2, ( SELECT @counter3:=0 ) initCounter3, ( SELECT @counter4:=0 ) initCounter4, ( SELECT @counter8:=0 ) initCounter8, 
                ( SELECT /* Actions */
                log_action.name,
                  log_action.type,
                  log_action.idaction,
                  log_action.url_prefix,
                  count(distinct log_link_visit_action.idvisit) as `2`,
                  count(distinct log_link_visit_action.idvisitor) as `1`,
                  count(*) as `12`, sum(
                          case when custom_float is null
                              then 0
                              else custom_float
                          end
                  ) / 1000 as `30`, sum(
                      case when custom_float is null
                          then 0
                          else 1

Why did I not do this within the RankingQuery? Because a RankingQuery is created by each plugin instance see https://github.com/piwik/piwik/blob/2.14.2/plugins/Actions/Archiver.php#L178 . This means we can't solve it within the Piwik Platform but each plugin would have to set it. We could do this for our plugins but for 3rd party plugins it wouldn't work automatically (including Piwik PRO plugins unless it we don't forget to set it everywhere). Not sure if this is an issue and whether one such hint would be enough even if it is a subquery?

@tsteur

This comment has been minimized.

Show comment
Hide comment
@tsteur

tsteur Jul 31, 2015

Member

@mattab @mgazdzik what do you think? I need input on this one to continue

Member

tsteur commented Jul 31, 2015

@mattab @mgazdzik what do you think? I need input on this one to continue

@mattab

This comment has been minimized.

Show comment
Hide comment
@mattab

mattab Aug 10, 2015

Member

Looks good to me @tsteur to have the plugin name in subquery only

Member

mattab commented Aug 10, 2015

Looks good to me @tsteur to have the plugin name in subquery only

@tsteur tsteur closed this in #8538 Aug 13, 2015

@mattab mattab changed the title from Simplify archiving queries recognition to In each SQL query, add the name of the plugin in a comment to make it easy to know which plugin triggered the query Aug 13, 2015

@mattab mattab changed the title from In each SQL query, add the name of the plugin in a comment to make it easy to know which plugin triggered the query to In each SQL query, add the name of the plugin in a SQL comment to make it easy to know which plugin triggered the query Aug 13, 2015

@mattab mattab changed the title from In each SQL query, add the name of the plugin in a SQL comment to make it easy to know which plugin triggered the query to In SQL queries, print out the name of the plugin in a SQL comment for troubleshooting which plugin triggered query Oct 13, 2015

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment