Compressed activity log database storage

Compressed activity log database storage

Initial draft of a policy that should reduce activity log storage
requirements.  We do a few things:
  - Strip out arguments in many cases (like before)
  - When storing identical rows for the same day, simply increment a row
    count and track the time of the latest occurrence
  - Move strings to separate tables and just use id numbers in the log
    table, so that we're not storing repeated strings many times over

The last optimization also removes the need for maintaining a table of
API names in the source code for compression.

BUG=238256
Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=216424

[mvrable, 2013-08-02 05:18:13]

This isn't ready for review quite yet, but I'm sending out an early version of
the patch for feedback.  This is some initial work on managing database size.

I need to implement (though perhaps as a future patch) the deleting of old
activity log records after some period of time.

In terms of database size, right now we're still dominated by the large argument
strings from serializing the entire DOM tree.  With factoring strings into a
separate table I'm probably making this worse for now, since I've created an
index and strings are probably being stored twice--for unique (especially large
unique) strings, this is a loss.  I'll need to do some analysis later, and we
can revisit that string compression method.

Something feedback would be good on: do we want to use the same database table
for the full logging policy (without using counts) and the counting policy? 
We'd set the count to 1 for all rows in the full-logging case.  That would unify
code for reading, but it would slightly complicate writing in the counting case.

--Michael Vrable

[felt, 2013-08-02 13:56:53]

> In terms of database size, right now we're still dominated by the large
argument
> strings from serializing the entire DOM tree.  With factoring strings into a
> separate table I'm probably making this worse for now, since I've created an
> index and strings are probably being stored twice--for unique (especially
large
> unique) strings, this is a loss.  I'll need to do some analysis later, and we
> can revisit that string compression method.

OK, I will lean on Petr to get this done soon.

[felt, 2013-08-02 14:04:19]

> Something feedback would be good on: do we want to use the same database table
> for the full logging policy (without using counts) and the counting policy? 
> We'd set the count to 1 for all rows in the full-logging case.  That would
unify
> code for reading, but it would slightly complicate writing in the counting
case.

The full stream & end user stream policies are currently parent/child classes.
This does not need to stay the same, and I have long expected that this
relationship will eventually fall apart as the end user stream diverges more and
more from the full stream. The only thing that needs to remain the same between
them is the API so that we can always look up data regardless of the policy. So
I don't have any strong preference except to do what is simplest.

How would setting the count to 1 complicate writing in the counting case?

[mvrable, 2013-08-02 14:24:27]

On 2013/08/02 14:04:19, felt wrote:
> How would setting the count to 1 complicate writing in the counting case?

The counting code assumes there is zero or one row for each action (all unique
arguments) on each day.  What I do now is attempt to increment the count on a
rows for the current day with the specified arguments.  If no rows were
modified, I insert one.

If we stored the full (non-aggregated) log in the same table, and that table
were later used by the counting code, then the update step could increment
multiple identical rows that fell on the same day.  I'd need code to handle
this.  (However, perhaps that is worth doing since there could be other
scenarios such as a time zone change that could cause similar problems.)

[felt, 2013-08-02 16:24:59]

On 2013/08/02 14:24:27, mvrable wrote:
> On 2013/08/02 14:04:19, felt wrote:
> > How would setting the count to 1 complicate writing in the counting case?
> 
> The counting code assumes there is zero or one row for each action (all unique
> arguments) on each day.  What I do now is attempt to increment the count on a
> rows for the current day with the specified arguments.  If no rows were
> modified, I insert one.
> 
> If we stored the full (non-aggregated) log in the same table, and that table
> were later used by the counting code, then the update step could increment
> multiple identical rows that fell on the same day.  I'd need code to handle
> this.  (However, perhaps that is worth doing since there could be other
> scenarios such as a time zone change that could cause similar problems.)

Ah, I see. Unfortunately I have no clever ideas. I'm fine with splitting them
into two separate databases.

[felt, 2013-08-02 16:36:28]

https://codereview.chromium.org/21646004/diff/1/chrome/browser/extensions/act...
File chrome/browser/extensions/activity_log/counting_policy.h (right):

https://codereview.chromium.org/21646004/diff/1/chrome/browser/extensions/act...
chrome/browser/extensions/activity_log/counting_policy.h:16: class
CountingPolicy : public StreamWithoutArgsUIPolicy {
Is there a reason to keep the StreamWithoutArgsUIPolicy around and separate? The
only historical reason that exists is because I once did a halfassed privacy
hack, which was to put a flag around recording arguments. ;) However, if you
think it makes sense to keep it now, that's fine.

https://codereview.chromium.org/21646004/diff/1/chrome/browser/extensions/act...
File chrome/browser/extensions/activity_log/database_interned_string.h (right):

https://codereview.chromium.org/21646004/diff/1/chrome/browser/extensions/act...
chrome/browser/extensions/activity_log/database_interned_string.h:30: class
DatabaseStringTable {
I notice that there aren't any deletion or cleanup methods. Is that planned for
a follow-up CL? I know this patch doesn't cover time-based deletions, but
Karen's history CL is going to need to be able to delete segments of this too.

[mvrable, 2013-08-02 17:16:58]

https://codereview.chromium.org/21646004/diff/1/chrome/browser/extensions/act...
File chrome/browser/extensions/activity_log/counting_policy.h (right):

https://codereview.chromium.org/21646004/diff/1/chrome/browser/extensions/act...
chrome/browser/extensions/activity_log/counting_policy.h:16: class
CountingPolicy : public StreamWithoutArgsUIPolicy {
On 2013/08/02 16:36:28, felt wrote:
> Is there a reason to keep the StreamWithoutArgsUIPolicy around and separate?
The
> only historical reason that exists is because I once did a halfassed privacy
> hack, which was to put a flag around recording arguments. ;) However, if you
> think it makes sense to keep it now, that's fine.

Probably not.  I need to do some cleanup work here--right now I think URL
sanitization isn't being done in the new policy.  I might pull out common code
and perhaps get rid of StreamWithoutArgsUIPolicy.

https://codereview.chromium.org/21646004/diff/1/chrome/browser/extensions/act...
File chrome/browser/extensions/activity_log/database_interned_string.h (right):

https://codereview.chromium.org/21646004/diff/1/chrome/browser/extensions/act...
chrome/browser/extensions/activity_log/database_interned_string.h:30: class
DatabaseStringTable {
On 2013/08/02 16:36:28, felt wrote:
> I notice that there aren't any deletion or cleanup methods. Is that planned
for
> a follow-up CL? I know this patch doesn't cover time-based deletions, but
> Karen's history CL is going to need to be able to delete segments of this too.

Not yet implemented, but it won't be in this file.  There are various cleanups
that might need to happen, some of which might depend on data in the main
logging table.  My plan is to have the cleanup code in the policy itself; if the
policy makes some edits to the mapping table it must then call ClearCache() to
ensure that no stale data is used.

[mvrable, 2013-08-02 21:31:13]

Here's a second iteration of the patch.  Some changes:
  - The policies are now independent rather than one being a subclass of the
other.  The old no-args policy is still there but should be deleted
  - I clean actions older than 10 minutes from the database (for testing--should
be set to a few days later on)
  - General refactoring/cleanup

Still a work in progress.

--Michael Vrable

[mvrable, 2013-08-05 22:29:55]

Would you have a chance to start doing a more serious review of this code
sometime soon?  I've spent some time today cleaning it up and I think it's ready
to be reviewed more closely now.

--Michael Vrable

[felt, 2013-08-07 01:09:42]

Hi Michael, a few questions.

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/activity_log_policy.cc (right):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/activity_log_policy.cc:73: void
ActivityLogPolicy::Util::SanitizeAction(scoped_refptr<Action> action) {
Now that these are all pulled out into their own methods, there should probably
be an activity_log_policy_unittest.cc that tests each of these individually. I
know most of these methods are from old code, so writing tests for them should
be a separate TODO. However, could you add a test for this newer code
(SanitizeAction)?

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/activity_log_policy.cc:91: if
(action->page_url().is_valid())
Can they be set if they aren't valid? Is this a redundant check? (OK to keep
redundant check in case of some kind of database screwup, but we should
definitely should be checking before writing into the db & not writing if it's
invalid.)

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/activity_log_policy.cc:128: return
(incognito_flag ? constants::kIncognitoUrl : "") + url.spec();
Sorry, I'm not sure what the point of this is. Could you explain?

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/activity_log_policy.h (right):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/activity_log_policy.h:108: static void
SanitizeAction(scoped_refptr<Action> action);
could you make the name be related to privacy?

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/activity_log_policy.h:112: static void
StripArguments(const std::set<std::string>& api_whitelist,
is this a legacy thing, meant to be replaced by SanitizeAction? (since
StripArguments was my poor man's version?) or do you foresee other uses of it

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/api_name_constants.h (left):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/api_name_constants.h:12: // All of the
chrome.* API names and events. ADD TO THE END. Do not remove any!
thank god, i was really getting sick of telling people to stop removing their
deprecated API names from this file ;)

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/counting_policy.cc (right):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/counting_policy.cc:224: if (!closing_) {
is closing_ touched on both the DB and UI threads? could that present a problem?

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/fullstream_ui_policy.cc (left):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/fullstream_ui_policy.cc:280: std::string
FullStreamUIPolicy::GetKey(ActivityLogPolicy::KeyType key_ty) const
where did this go?

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/fullstream_ui_policy.cc (right):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/fullstream_ui_policy.cc:120:
statement.BindString(7, constants::kIncognitoUrl);
Probably should have caught this before. Why are we doing the incognito URL for
full stream? We explicitly don't care about privacy in the full stream version.
Same question above.

[mvrable, 2013-08-07 17:01:19]

Thanks for the review!  I made some cleanups, and I also deleted the used of
closing_ (since after thinking about it more I think I came up with a better
fix).

I'll still add a few unit tests and send a note once I've done so.

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/activity_log_policy.cc (right):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/activity_log_policy.cc:73: void
ActivityLogPolicy::Util::SanitizeAction(scoped_refptr<Action> action) {
On 2013/08/07 01:09:42, felt wrote:
> Now that these are all pulled out into their own methods, there should
probably
> be an activity_log_policy_unittest.cc that tests each of these individually. I
> know most of these methods are from old code, so writing tests for them should
> be a separate TODO. However, could you add a test for this newer code
> (SanitizeAction)?

Yes, I should have written unit tests.  I'll add some.

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/activity_log_policy.cc:128: return
(incognito_flag ? constants::kIncognitoUrl : "") + url.spec();
On 2013/08/07 01:09:42, felt wrote:
> Sorry, I'm not sure what the point of this is. Could you explain?

See my later comment on the formatting.

I ended up moving this code snippet into the Action class instead of being a
helper method in Util, since I think that makes more sense.

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/activity_log_policy.h (right):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/activity_log_policy.h:108: static void
SanitizeAction(scoped_refptr<Action> action);
On 2013/08/07 01:09:42, felt wrote:
> could you make the name be related to privacy?

Changed to StripPrivacySensitiveFields; if you can think of a better name I can
use that instead.

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/activity_log_policy.h:112: static void
StripArguments(const std::set<std::string>& api_whitelist,
On 2013/08/07 01:09:42, felt wrote:
> is this a legacy thing, meant to be replaced by SanitizeAction? (since
> StripArguments was my poor man's version?) or do you foresee other uses of it

I was imagining possible use cases where we might want to support a policy that
logs more arguments but still wants to be careful not to log privacy-sensitive
data.  Such a policy could call SanitizeAction, but might not use
StripArguments.

We don't currently have any such policies, though, so maybe this isn't worth
keeping separate?

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/counting_policy.cc (right):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/counting_policy.cc:224: if (!closing_) {
On 2013/08/07 01:09:42, felt wrote:
> is closing_ touched on both the DB and UI threads? could that present a
problem?

You're right, it is.  Thinking about this some more, there are still some
possible races--for example, one thread could call Close() while the database
thread is in the middle of executing FlushDatabase.

The race should be fairly benign (unlikely to occur, and when it does it will
only cause problems in unit tests).  I could add some comments explaining this,
though I think I can also fix it properly by changing ownership of the mock
clock used in unit tests.  I might do that just so we can have a proper fix, and
I can delete closing_ then.

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/fullstream_ui_policy.cc (left):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/fullstream_ui_policy.cc:280: std::string
FullStreamUIPolicy::GetKey(ActivityLogPolicy::KeyType key_ty) const
On 2013/08/07 01:09:42, felt wrote:
> where did this go?

This code isn't being used any longer.  The constants have been moved to
activity_action_constants.cc, and there is no longer a need for a function to
look them up since they don't depend on which policy is installed.

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/fullstream_ui_policy.cc (right):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/fullstream_ui_policy.cc:120:
statement.BindString(7, constants::kIncognitoUrl);
On 2013/08/07 01:09:42, felt wrote:
> Probably should have caught this before. Why are we doing the incognito URL
for
> full stream? We explicitly don't care about privacy in the full stream
version.
> Same question above.

Looks like I forgot to update this code.  The intended new behavior is (unless
you think I should change it): visiting http://google.com/ in an incognito tab
should log the string "<incognito>http://google.com/" to the database.  That way
we have the full URL, but we also know that the access was to an incognito tab.

From the counting policy, we'll log simply "<incognito>" without including the
URL.

[mvrable, 2013-08-07 17:39:05]

Also, I'm considering renaming database_interned_string.cc to
database_interned_string.cc to match the name of the class (I had created the
file before settling on a final name).  If you'd rather have another name for
the class, I can rename either or both.

[mvrable, 2013-08-07 18:49:46]

I added some additional tests (not entirely comprehensive but I'm hoping they
cover the important new parts)--if you think I should add more I can do that.

I also did the file renaming for the DatabaseStringTable class.

[felt, 2013-08-08 02:08:35]

On 2013/08/07 18:49:46, mvrable wrote:
> I added some additional tests (not entirely comprehensive but I'm hoping they
> cover the important new parts)--if you think I should add more I can do that.
> 
> I also did the file renaming for the DatabaseStringTable class.

thanks for the fixes & tests. I like the new name better, it is clearer. lgtm!

[felt, 2013-08-08 02:08:50]

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/activity_log_policy.h (right):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/activity_log_policy.h:108: static void
SanitizeAction(scoped_refptr<Action> action);
On 2013/08/07 17:01:19, mvrable wrote:
> On 2013/08/07 01:09:42, felt wrote:
> > could you make the name be related to privacy?
> 
> Changed to StripPrivacySensitiveFields; if you can think of a better name I
can
> use that instead.

Sounds good.

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/activity_log_policy.h:112: static void
StripArguments(const std::set<std::string>& api_whitelist,
On 2013/08/07 17:01:19, mvrable wrote:
> On 2013/08/07 01:09:42, felt wrote:
> > is this a legacy thing, meant to be replaced by SanitizeAction? (since
> > StripArguments was my poor man's version?) or do you foresee other uses of
it
> 
> I was imagining possible use cases where we might want to support a policy
that
> logs more arguments but still wants to be careful not to log privacy-sensitive
> data.  Such a policy could call SanitizeAction, but might not use
> StripArguments.
> 
> We don't currently have any such policies, though, so maybe this isn't worth
> keeping separate?

Ahh, I see.
After thinking about it more, it does make sense to keep around for now. We
don't need to keep arguments for every API call, purely from a space perspective
it makes sense to have some whitelist for removing arguments we don't think are
important, and I can imagine that differing between policies.

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/counting_policy.cc (right):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/counting_policy.cc:224: if (!closing_) {
On 2013/08/07 17:01:19, mvrable wrote:
> On 2013/08/07 01:09:42, felt wrote:
> > is closing_ touched on both the DB and UI threads? could that present a
> problem?
> 
> You're right, it is.  Thinking about this some more, there are still some
> possible races--for example, one thread could call Close() while the database
> thread is in the middle of executing FlushDatabase.
> 
> The race should be fairly benign (unlikely to occur, and when it does it will
> only cause problems in unit tests).  I could add some comments explaining
this,
> though I think I can also fix it properly by changing ownership of the mock
> clock used in unit tests.  I might do that just so we can have a proper fix,
and
> I can delete closing_ then.

Thanks, I like the updated version better.

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/fullstream_ui_policy.cc (left):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/fullstream_ui_policy.cc:280: std::string
FullStreamUIPolicy::GetKey(ActivityLogPolicy::KeyType key_ty) const
On 2013/08/07 17:01:19, mvrable wrote:
> On 2013/08/07 01:09:42, felt wrote:
> > where did this go?
> 
> This code isn't being used any longer.  The constants have been moved to
> activity_action_constants.cc, and there is no longer a need for a function to
> look them up since they don't depend on which policy is installed.

Ahhh OK, right, I couldn't find them in this CL because that had been done
earlier.

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
File chrome/browser/extensions/activity_log/fullstream_ui_policy.cc (right):

https://codereview.chromium.org/21646004/diff/44001/chrome/browser/extensions...
chrome/browser/extensions/activity_log/fullstream_ui_policy.cc:120:
statement.BindString(7, constants::kIncognitoUrl);
On 2013/08/07 17:01:19, mvrable wrote:
> On 2013/08/07 01:09:42, felt wrote:
> > Probably should have caught this before. Why are we doing the incognito URL
> for
> > full stream? We explicitly don't care about privacy in the full stream
> version.
> > Same question above.
> 
> Looks like I forgot to update this code.  The intended new behavior is (unless
> you think I should change it): visiting http://google.com/ in an incognito tab
> should log the string "<incognito>http://google.com/" to the database.  That
way
> we have the full URL, but we also know that the access was to an incognito
tab.
> 
> From the counting policy, we'll log simply "<incognito>" without including the
> URL.

Hmm. It seems like doing "<incognito>url" is overloading the field and it would
be nicer to have that info in the extras, but OTOH then we'd have "<incognito>"
in two places. So although it sits a little uncomfortably with me I do think
what you have here is the better option, but maybe we could revisit this in the
future (particularly when we start doing more complicated lookups with URL
regexes).

[commit-bot: I haz the power, 2013-08-08 10:19:09]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/mvrable@chromium.org/21646004/82001

[commit-bot: I haz the power, 2013-08-08 19:39:07]

Change committed as 216424