808720 - stub installer ping is not consistent

Status: RESOLVED FIXED

(Firefox :: Installer, defect)

Description

[juan becerra [:juanb]]

While trying to verify bug 808110 I found that the stub installer ping doesn't happen all the time. So far I have only seen it once. In order to do this I downloaded the latest (11/5) stub installer from the latest-mozilla-central directory and ran it while using Fiddler with the https-capture option on.

So far I have ran this around 10 times and only once did I get the ping pointing to download-stats. I've also tried the latest aurora stub installer with similar results.

We should be seeing this ping every time we install Firefox using the stub installer, but so far that's not the case.

Comment 1

[Alex Keybl [:akeybl]]

Might be bug 808153? Assigning to bbondy assuming that this isn't just a download issue.

Comment 2

[Brian R. Bondy [:bbondy]]

I'm on a B2G task today and possibly tomorrow.  Did we find out if this was related to bug 808153 yet?

Comment 3

[Brian R. Bondy [:bbondy]]

I finished the B2G task I was working on last night and am available to work on this, but will put it on hold until I hear confirmation on if it is related to bug 808153 or not.

Comment 4

[raymond [:retornam] (inactive)]

(In reply to Brian R. Bondy [:bbondy] from comment #3)
> I finished the B2G task I was working on last night and am available to work
> on this, but will put it on hold until I hear confirmation on if it is
> related to bug 808153 or not.

Brian, can you please tell us how often the ping is? For example is the ping on Firefox startup or based on the number of hours you have the browser running?

I tested this today and I also could not see the ping

Comment 5

[Robert Strong (they/them - no direct email)]

The ping happens during the install performed by the stub installer and does not involve Firefox.

Comment 6

[raymond [:retornam] (inactive)]

(In reply to Robert Strong [:rstrong] (vac 10/26-11/4) (do not email) from comment #5)
> The ping happens during the install performed by the stub installer and does
> not involve Firefox.

Thanks rstrong. I'll check again and update

Comment 7

[raymond [:retornam] (inactive)]

Jakem and I tried the install process several times  whiles Jakem checked the server logs for our IP. He couldn't find any of our IPs after several attempts.

Comment 8

[Jake Maul [:jakem]]

I was installing using the SI linked to here: https://nightly.mozilla.org/. Specifically:

http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/latest-trunk/firefox-19.0a1.en-US.win32.installer-stub.exe

From the directory listing:
firefox-19.0a1.en-US.win32.installer-stub.exe	06-Nov-2012 06:17 	614K

No pings received from either my IP or :retornam's during testing, at any point in the download/install process, even after SI completed and exited. I confirmed the "send metrics" checkbox under "Options" was checked.

Comment 9

[juan becerra [:juanb]]

This is consistent to what I have been seeing yesterday and today, which is why I asked for more eyeballs to look into this.

Comment 10

[Alex Keybl [:akeybl]]

bbondy/rstrong - please connect with Juan if you're unable to repro the issue. Goal should be to resolve for today, since this is blocking deployment to Beta/Release and data collection.

Comment 11

[Brian R. Bondy [:bbondy]]

OK I started looking into this and I know what's going on.

I can reproduce the ping only sometimes being sent.  I can reproduce it both with the downloaded builds and my local builds.

If I throw up a MessageBox after I send the ping, the ping is always sent 100% of the time.

So what I think is happening is that sometimes the program closes before the HTTP request gets sent out.  

Working on a patch now.

Comment 12

[Brian R. Bondy [:bbondy]]

Attachment: Patch v1 - consistent pings being sent impl

So the bug was in the NSIS plugin InetBgDL.

The bug happens because this ping is sent just before the program closes.
That's the reason why we didn't see this bug from the other uses of InetBgDL.

The problem was that the transfer lock is sometimes acquired 
in the Reset() call before the thread that is started from 
Get() gets to acquire the lock.

The bug fix is documented in the patch, but basically what is happening is that there is a lock and we acquire that lock in a thread we spawn from an HTTP get call. But also we acquire that lock when the program shuts down in a Reset() function call. If the Reset() function call gets the lock before the HTTP get then the ping is not sent.

To fix the problem we ensure that we always acquire the lock in the HTTP get thread that is spawned first.

Comment 13

[Brian R. Bondy [:bbondy]]

Attachment: Patch v1 - New DLL compiled with MSVC6 for smaller size

Comment 14

[Jim Mathies [:jimm]]

Comment on attachment 679349 [details] [diff] [review]
Patch v1 - consistent pings being sent impl

Makes sense from my limited understanding of this plugin. After a thread is spawned and if Reset gets called and the thread's g_hGETStartedEvent is valid, Reset waits until the thread sets g_hGETStartedEvent?

If that's right then that's what I see this coding doing, correctly! :)

Comment 15

[Brian R. Bondy [:bbondy]]

(In reply to Jim Mathies [:jimm] from comment #14)
> Comment on attachment 679349 [details] [diff] [review]
> Patch v1 - consistent pings being sent impl
> 
> Makes sense from my limited understanding of this plugin. After a thread is
> spawned and if Reset gets called and the thread's g_hGETStartedEvent is
> valid, Reset waits until the thread sets g_hGETStartedEvent?
> 
> If that's right then that's what I see this coding doing, correctly! :)

Thanks for the quick review.
Yup that is correct, and since g_hGETStartedEvent is created before we even attempt to create the thread, we know that it will wait on the Reset call if there is a pending GET.

Comment 16

[Brian R. Bondy [:bbondy]]

Comment on attachment 679351 [details] [diff] [review]
Patch v1 - New DLL compiled with MSVC6 for smaller size

[Approval Request Comment]
Bug caused by (feature/regressing bug #): Original ping submission bug, bug 802734
User impact if declined: Pings will not always be sent 
Testing completed (on m-c, etc.): no, but tested locally and a try run is currently running.
Risk to taking this patch (and alternatives if risky): Low since it'll be QA'ed 
String or UUID changes made by this patch: none

Comment 17

[Brian R. Bondy [:bbondy]]

Comment on attachment 679349 [details] [diff] [review]
Patch v1 - consistent pings being sent impl

[Approval Request Comment]
Ditto Comment 16

Comment 18

[Brian R. Bondy [:bbondy]]

http://hg.mozilla.org/releases/mozilla-aurora/rev/360cc4d99e6b
http://hg.mozilla.org/releases/mozilla-aurora/rev/c686c2eb54d6
http://hg.mozilla.org/mozilla-central/rev/423e9423d693
http://hg.mozilla.org/mozilla-central/rev/36e99ea02c05

I accidentally put Bug 808270 in the commit message, I'll leave it as is and comment in that bug about the wrong bug number referring back to this bug.

Comment 19

[juan becerra [:juanb]]

I've verified that the ping now happens all the time when you complete the installation using the stub installer (Nightly and Aurora) with default options, and that there is no ping when you disable the option to send the information about the installation. The pings look like:

GET /stub/v1/nightly/en-US/0/2/12/19905/1/0/ HTTP/1.1
User-Agent: NSIS InetBgDL (Mozilla)
Host: download-stats.mozilla.org

GET /stub/v1/aurora/en-US/0/2/12/20452/1/0/ HTTP/1.1
User-Agent: NSIS InetBgDL (Mozilla)
Host: download-stats.mozilla.org

Thanks Brian!

Comment 20

[raymond [:retornam] (inactive)]

I also see the pings now. Thanks Brian!