896737 - Limit the length of Slow SQL statements reported to Telemetry

Status: RESOLVED FIXED

(Toolkit :: Telemetry, defect)

Description

[Vladan Djeric (:vladan)]

Some FormHistory and Places statements can contain thousands of arguments, causing the Telemetry ping to become very large. One slowSQL section I looked at was 1.3 MBs!

We should limit the length of reported slowSQL statements to 100 chars each, and ~5KB total.

Comment 1

[Marco Bonardo [:mak]]

do you have an example of these statements?
thousands of arguments doesn't look sane, we should probably also fix the backend.

Comment 2

[Vladan Djeric (:vladan)]

Attachment: Examples of very long SQL statements

(In reply to Marco Bonardo [:mak] from comment #1)
> do you have an example of these statements?
> thousands of arguments doesn't look sane, we should probably also fix the
> backend.

I attached a sample from one of the large Telemetry pings

Comment 3

[Marco Bonardo [:mak]]

yeah, that's horrible. it's ok to do the limitation here, but I'd also appreciate a bug to investigate alternatives to those very long lists of ids... We can probably do better.

Comment 4

[Vladan Djeric (:vladan)]

Attachment: Another example from form history

Another example from form history

Comment 5

[Vladan Djeric (:vladan)]

(In reply to Marco Bonardo [:mak] from comment #3)
> [...] I'd also appreciate a bug to investigate alternatives to those 
> very long lists of ids... We can probably do better.

I filed bug 897074 and bug 897081

Comment 6

[Kamil Muszynski (:kamilm)]

I'd like to get involved in Firefox development. Vladan, is one of the bugs you reported above simple enough to get me started? :)

Comment 7

[Vladan Djeric (:vladan)]

(In reply to Kamil Muszyński (:kamilm) from comment #6)
> I'd like to get involved in Firefox development. Vladan, is one of the bugs
> you reported above simple enough to get me started? :)

Hi Kamil. This bug is pretty straight-forward but it's probably not the best for a first bug. If you're feeling a little bit brave, I can still walk you through it :) You can email me at [e-mail] for the details

Comment 8

[Kamil Muszynski (:kamilm)]

Attachment: Proposed patch - first version

Changes only in Telemetry.cpp file

Comment 9

[Vladan Djeric (:vladan)]

Comment on attachment 793583 [details] [diff] [review]
Proposed patch - first version

This looks good :) Just a few small suggestions

>+const uint32_t kMaxSlowStatementLength = 50;

Let's make the max statement length 1000 for now actually. I took a look at my about:telemetry and there were several statements near that length. Assuming we limit Telemetry to max 50 SQL statements, that would still be only ~50KB of memory.

>   nsAutoCString fullSQL(sql);
>-  fullSQL.AppendPrintf(" /* %s */", dbName.BeginReading());
>-
>+  

You don't need to keep the fullSQL variable at the top anymore. You can just pass sql directly to sanitizeSQL() and declare fullSQL closer to where it is used (the last call to StoreSlowSQL).

>+  nsAutoCString dbNameComment;
>+  dbNameComment.AppendPrintf(" /* %s */", dbName.BeginReading());
>+  
>   bool isFirefoxDB = sTelemetry->mTrackedDBs.Contains(dbName);
>   if (isFirefoxDB) {
>     nsAutoCString sanitizedSQL(SanitizeSQL(fullSQL));
>+    if (sanitizedSQL.Length() + dbNameComment.Length() > kMaxSlowStatementLength ){
>+	  sanitizedSQL.SetLength(kMaxSlowStatementLength - dbNameComment.Length() - 3);	// minus 3 to add space for '...'

It's unlikely to happen, but if someone changed kMaxSlowStatementLength to some smaller value (like 20) and there was a database with a long filename (e.g. 25 chars), the calculated length passed to SetLength() would be negative. And since SetLength takes an unsigned int, the negative number might get interpreted as a very large positive number. 
I suggest we just apply the maximum length to the SQL portion of the string, and disregard the length of the DB filename portion.

Comment 10

[Kamil Muszynski (:kamilm)]

Attachment: Proposed changes in Telemetry.cpp - after the first review

Hi Vladan,
I've attached second patch for Telemetry.cpp for a review. Trimming is now only applied to the SQL statement, after that the ("..." + DB name) string is added and stored in Telemetry. I've also made a comment for kMaxSlowStatementLength constant, as it now may be a little misleading, since the actual length of a string that is stored may be greater than kMaxSlowStatementLength:)

Comment 11

[Vladan Djeric (:vladan)]

Comment on attachment 795180 [details] [diff] [review]
Proposed changes in Telemetry.cpp - after the first review

A few small style comments:
- There are trailing spaces at the end of several lines, remove them please
- Indent using 2 spaces in this file, don't use tabs
- spacing in an if-statement is as follows: "if (some_condition) {"
- Start comment lines with only two slashes: // an example comment

For future reference, the coding style can be found here: https://developer.mozilla.org/en-US/docs/Developer_Guide/Coding_Style

Comment 12

[Kamil Muszynski (:kamilm)]

Attachment: Code style fixes after the second review

Comment 13

[Vladan Djeric (:vladan)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/98c209ce2408

Comment 14

[Vladan Djeric (:vladan)]

Congrats on your first patch, Kamil :)

I was also planning to limit the number of unique slow SQL statements reported per session in this bug, but I've decided against it.. I don't think the limit will get used often (if at all) and even if it did somehow, we still wouldn't want to lose any of the data. I'm marking the bug resolved.

Comment 15

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/98c209ce2408

Comment 16

[Ryan VanderMeulen [:RyanVM]]

Don't resolve bugs until they hit m-c. We have merge scripts that handle the job and ensure that details don't get missed in the process.