580422 - Test Pilot Raw Data log randomly resets

Status: RESOLVED FIXED

(Mozilla Labs Graveyard :: Test Pilot, defect, P1)

Description

[Christopher Jung]

I haven't been able to reproduce this on command and it seems to happen randomly.  Here's what happens:

I click 'more info' on the Firefox 4 Beta interface study I have running, then click 'click here' to bring up my raw data log.  Everything is logging fine, and I'll do some more UI interactions (click back, etc) to test the study.  Everything seems to be logging fine, but after a few minutes, I'll click 'Click here' again to refresh the log and the log will be totally blank - no study meta data, no events, no anything.  I'll do some more UI interactions, click 'Click here' again and the new UI interactions I have done are logged correctly but none of the old data is there so my log is only a few lines - its just like the log reset..

Tested against Mozilla/5.0 (Windows; U; Windows NT 6.1; WOW64; en-US; rv:2.0b1) Gecko/20100630 Firefox/4.0b1

Comment 1

[Jinghua zhang]

Attachment: error log

Comment 2

[Jono Xia]

From the error log, it looks like the study status is being repeatedly set to 2, and intentionally wiped each time.

I believe this code in TestPilotExperiment.checkDate() is to blame:

 if ( this._status == TaskConstants.STATUS_STARTING &&
        currentDate >= this._startDate &&
        currentDate <= this._endDate) {
      // (snip)
      // clear the data before starting.
      this._dataStore.wipeAllData();
      this.changeStatus(TaskConstants.STATUS_STARTING, true);
      Application.prefs.setValue(GUID_PREF_PREFIX + this._id, uuid);
      this.onExperimentStartup();
    }

Just from looking at this code, it is obviously wrong -- the status is already STARTING, it should be set to IN_PROGRESS, not set to STARTING again!  As is, the status doesn't change and this code will get run repeatedly, wiping the data each time.

I have no idea how this slipped through our testing for so long, but it is flagrantly incorrect.  (Also, wipeAllData() should take a callback).  Luckily it's an easy thing to fix now that we've found it.

Comment 3

[Jono Xia]

Fixed the study startup logic in http://hg.mozilla.org/labs/testpilot/rev/43b83832e9cd which ought to prevent the study from getting wiped multiple times as was happening before.

Comment 4

[Jono Xia]

Attachment: Patch fixing the study startup logic, preventing database wipes

This patch should go into the Firefox beta as soon as possible.

Comment 5

[Jinghua zhang]

Apparently there are two different bugs:
1, user data wiped every 10 minutes 
2. GUIDs are not getting generated for the study

the first bug may not affect everybody, and the second bug will affect everybody. 

Jono, does this patch fix both two bugs?  Do we know how many people will be affected by the first bug?

Comment 6

[Ed Lee :Mardak]

Looking at the original code, this should only affect 2 sets of users:

1) someone who has unchecked "show notification on new study"
2) someone using the debug page to set the state to STARTING

The bug fixed is that if you get into STARTING, you're stuck in STARTING and have data wiped on every checkDate.

The main question is how many people uncheck that preference.

Comment 7

[Ed Lee :Mardak]

It seems like there is also code on start-up that will set the "show notification on new study" preference to true for firefox 4 beta users, so even fewer people will have it unchecked. (Potentially a bug as if a user unchecks it and restarts firefox, it'll get checked automatically.)

Comment 8

[Ed Lee :Mardak]

So there seems to be another work-around by marking the study as optInRequired: true instead of false. That value seems to be mostly unimplemented but happens to be used in the code path that results in state getting into STARTING.

Comment 9

[Jono Xia]

Jinghua: Yes, my patch fixes both bugs.

Ed: It's not a bug that we set "show notification on new study" pref to true on startup for firefox 4 beta users, because that code is setting it in the *default* branch, therefore it's overridden by the user's actual settings.

You're right that the data deletion should only affect people who don't have "show notification on new study" turned on -- which means, mostly, TP extension users rather than Firefox 4 beta users.

Turning on optInRequired for the study will prevent it from running at all for anyone who has "show notification on new study" turned off.  Which means, again, TP extension users.  Which is pretty much what we want to do anyway.  So let's go with that.

Comment 10

[Jinghua zhang]

I found a new bug that may be related:

Restart FX will automatically recheck "notify me when a new study comes"
https://bugzilla.mozilla.org/show_bug.cgi?id=581611

Comment 11

[Dave Townsend [:mossop]]

Fixed for b3: http://hg.mozilla.org/mozilla-central/rev/3c55795da313

Comment 12

[Tracy Walker [:tracy]]

Hmmm, having to waiting some random time (10 min.  30 min?) doesn't make for a good manual test case.  It wouldn't be automated either.  

Verification of this bug. Then watching out for data loss (which should be on QA's mind)  is all that's needed here.