1359723 - Widevine CDM doesn't download automatically

Status: NEW

(Toolkit :: General, defect)

Description

[Jean-Yves Avenard [:jya]]

Reproduced on both mac and linux (ubuntu 17.04 64 bits)

STR:
1- Start with a fresh profile
2- Go to about:config
3- set media.gmp.log.dump to true, and media.gmp.log.level to 0.
4- Go to Preferences and disable E10s (I don't know if this step is needed)
4bis- If on Linux, enable DRM content (disabled by default)
5- Restart Nightly

Go into about:addons
select plugins

The Widevine content decryption module always show as "Widevine Content Decryption Module provided by Google Inc will be installed shortly"

this status never change...
in the console:
$ ./mach run
 0:00.20 /Applications/Custom/Web\ Browsers/FirefoxNightly.app/Contents/MacOS/firefox -no-remote -foreground -profile /Users/jyavenard/Work/Mozilla/objdir-ff-asan/tmp/scratch_user
1493192690894	Toolkit.GMP	TRACE	GMPProvider.startup - enabled=true, gmpPath=/Users/jyavenard/Work/Mozilla/objdir-ff-asan/tmp/scratch_user/gmp-gmpopenh264/1.6
1493192690896	Toolkit.GMP	INFO	GMPProvider.startup - adding gmp directory /Users/jyavenard/Work/Mozilla/objdir-ff-asan/tmp/scratch_user/gmp-gmpopenh264/1.6
1493192690899	Toolkit.GMP	TRACE	GMPProvider.startup - enabled=true, gmpPath=null
1493192690899	Toolkit.GMP	INFO	GMPProvider.startup - adding clearkey CDM directory /Users/jyavenard/Work/Mozilla/objdir-ff-asan/dist/Nightly.app/Contents/Resources/gmp-clearkey/0.1
1493192752745	Toolkit.GMP	INFO	GMPInstallManager.simpleCheckAndInstall Last check was: 905 seconds ago, minimum seconds: 86400
1493192752746	Toolkit.GMP	INFO	GMPInstallManager.simpleCheckAndInstall Will not check for updates.
1493192852961	Toolkit.GMP	TRACE	GMPWrapper(gmp-gmpopenh264) findUpdates() - gmp-gmpopenh264 - reason=16
1493192852962	Toolkit.GMP	TRACE	GMPWrapper(gmp-gmpopenh264) findUpdates() - gmp-gmpopenh264 - last check was less then a day ago
1493192852963	Toolkit.GMP	TRACE	GMPWrapper(gmp-widevinecdm) findUpdates() - gmp-widevinecdm - reason=16
1493192852964	Toolkit.GMP	TRACE	GMPWrapper(gmp-widevinecdm) findUpdates() - gmp-widevinecdm - last check was less then a day ago
1493192853516	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493192853533	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493192853554	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493192853571	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493192853586	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493192853602	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493192853696	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493192853731	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493192853765	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493192853787	addons.update-checker	WARN	Update manifest for {972ce4c6-7e08-4474-a285-3208198ce6fd} did not contain an updates property
1493192853897	addons.update-checker	WARN	Update manifest for {01A8CA0A-4C96-465b-A49B-65C46FAD54F9} did not contain an updates property
1493192971864	addons.xpi	WARN	Add-on [e-mail] is not correctly signed.
1493192971865	addons.xpi	WARN	Add-on {01A8CA0A-4C96-465b-A49B-65C46FAD54F9} is not correctly signed.


restarting nightly:
$ ./mach run
 0:00.19 /Applications/Custom/Web\ Browsers/FirefoxNightly.app/Contents/MacOS/firefox -no-remote -foreground -profile /Users/jyavenard/Work/Mozilla/objdir-ff-asan/tmp/scratch_user
1493193190245	Toolkit.GMP	TRACE	GMPProvider.startup - enabled=true, gmpPath=/Users/jyavenard/Work/Mozilla/objdir-ff-asan/tmp/scratch_user/gmp-gmpopenh264/1.6
1493193190247	Toolkit.GMP	INFO	GMPProvider.startup - adding gmp directory /Users/jyavenard/Work/Mozilla/objdir-ff-asan/tmp/scratch_user/gmp-gmpopenh264/1.6
1493193190249	Toolkit.GMP	TRACE	GMPProvider.startup - enabled=true, gmpPath=null
1493193190250	Toolkit.GMP	INFO	GMPProvider.startup - adding clearkey CDM directory /Users/jyavenard/Work/Mozilla/objdir-ff-asan/dist/Nightly.app/Contents/Resources/gmp-clearkey/0.1
1493193221450	Toolkit.GMP	TRACE	GMPWrapper(gmp-gmpopenh264) findUpdates() - gmp-gmpopenh264 - reason=16
1493193221451	Toolkit.GMP	TRACE	GMPWrapper(gmp-gmpopenh264) findUpdates() - gmp-gmpopenh264 - last check was less then a day ago
1493193221451	Toolkit.GMP	TRACE	GMPWrapper(gmp-widevinecdm) findUpdates() - gmp-widevinecdm - reason=16
1493193221452	Toolkit.GMP	TRACE	GMPWrapper(gmp-widevinecdm) findUpdates() - gmp-widevinecdm - last check was less then a day ago
1493193221933	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493193221955	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493193221977	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493193221998	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493193222024	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493193222046	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493193222109	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493193222180	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493193222224	addons.update-checker	WARN	Update manifest for {972ce4c6-7e08-4474-a285-3208198ce6fd} did not contain an updates property
1493193222246	addons.update-checker	WARN	Update manifest for [e-mail] did not contain an updates property
1493193222305	addons.update-checker	WARN	Update manifest for {01A8CA0A-4C96-465b-A49B-65C46FAD54F9} did not contain an updates property

Only after manually checking for update widevine will appear to be downloaded, however:
1493193794537	Toolkit.GMP	TRACE	GMPProvider.startup - enabled=true, gmpPath=/Users/jyavenard/Work/Mozilla/objdir-ff-asan/tmp/scratch_user/gmp-gmpopenh264/1.6
1493193794538	Toolkit.GMP	INFO	GMPProvider.startup - adding gmp directory /Users/jyavenard/Work/Mozilla/objdir-ff-asan/tmp/scratch_user/gmp-gmpopenh264/1.6
1493193794539	Toolkit.GMP	TRACE	GMPProvider.startup - enabled=true, gmpPath=null
1493193794539	Toolkit.GMP	INFO	GMPProvider.startup - adding clearkey CDM directory /Applications/Custom/Web Browsers/FirefoxNightly.app/Contents/Resources/gmp-clearkey/0.1
1493193807921	Toolkit.GMP	TRACE	GMPWrapper(gmp-gmpopenh264) findUpdates() - gmp-gmpopenh264 - reason=1
1493193807922	Toolkit.GMP	TRACE	GMPWrapper(gmp-gmpopenh264) findUpdates() - updateTask
1493193807927	Toolkit.GMP	INFO	GMPInstallManager._getURL Using url: https://aus5.mozilla.org/update/3/GMP/%VERSION%/%BUILD_ID%/%BUILD_TARGET%/%LOCALE%/%CHANNEL%/%OS_VERSION%/%DISTRIBUTION%/%DISTRIBUTION_VERSION%/update.xml
1493193807930	Toolkit.GMP	INFO	GMPInstallManager._getURL Using url (with replacement): https://aus5.mozilla.org/update/3/GMP/55.0a1/20170425030221/Darwin_x86_64-gcc3/en-US/nightly/Darwin%2016.5.0/default/default/update.xml
1493193807933	Toolkit.GMP	TRACE	GMPWrapper(gmp-widevinecdm) findUpdates() - gmp-widevinecdm - reason=1
1493193807934	Toolkit.GMP	TRACE	GMPWrapper(gmp-widevinecdm) findUpdates() - updateTask
1493193807934	Toolkit.GMP	INFO	GMPInstallManager._getURL Using url: https://aus5.mozilla.org/update/3/GMP/%VERSION%/%BUILD_ID%/%BUILD_TARGET%/%LOCALE%/%CHANNEL%/%OS_VERSION%/%DISTRIBUTION%/%DISTRIBUTION_VERSION%/update.xml
1493193807935	Toolkit.GMP	INFO	GMPInstallManager._getURL Using url (with replacement): https://aus5.mozilla.org/update/3/GMP/55.0a1/20170425030221/Darwin_x86_64-gcc3/en-US/nightly/Darwin%2016.5.0/default/default/update.xml
1493193808542	Toolkit.GMP	INFO	GMPAddon.constructor Created new addon: gmp-gmpopenh264 (isValid: true, isInstalled: true, hashFunction: sha512, hashValue: 3b52343070a2f75e91b7b0d3bb33935352237c7e1d2fdc6a467d039ffbbda6a72087f9e0a369fe95e6c4c789ff3052f0c134af721d7273db9ba66d077d85b327, size: 390308)
1493193808543	Toolkit.GMP	INFO	GMPAddon.constructor Created new addon: gmp-widevinecdm (isValid: true, isInstalled: false, hashFunction: sha512, hashValue: 1916805e84a49e04748204f4e4c48ae52c8312f7c04afedacacd7dfab2de424412bc988a8c3e5bcb0865f8844b569c0eb9589dae51e74d9bdfe46792c9d1631f, size: 2155607)
1493193808544	Toolkit.GMP	TRACE	GMPWrapper(gmp-widevinecdm) findUpdates() - found update for gmp-widevinecdm, installing
1493193808551	Toolkit.GMP	INFO	GMPAddon.constructor Created new addon: gmp-gmpopenh264 (isValid: true, isInstalled: true, hashFunction: sha512, hashValue: 3b52343070a2f75e91b7b0d3bb33935352237c7e1d2fdc6a467d039ffbbda6a72087f9e0a369fe95e6c4c789ff3052f0c134af721d7273db9ba66d077d85b327, size: 390308)
1493193808552	Toolkit.GMP	INFO	GMPAddon.constructor Created new addon: gmp-widevinecdm (isValid: true, isInstalled: false, hashFunction: sha512, hashValue: 1916805e84a49e04748204f4e4c48ae52c8312f7c04afedacacd7dfab2de424412bc988a8c3e5bcb0865f8844b569c0eb9589dae51e74d9bdfe46792c9d1631f, size: 2155607)
1493193808552	Toolkit.GMP	TRACE	GMPWrapper(gmp-gmpopenh264) findUpdates() - no updates for gmp-gmpopenh264
1493193808552	Toolkit.GMP	INFO	GMPWrapper(gmp-gmpopenh264) findUpdates() - updateTask succeeded for gmp-gmpopenh264
1493193826713	addons.productaddons	WARN	Failed downloading via XHR, status: 0, reason: error
1493193826714	Toolkit.GMP	ERROR	GMPWrapper(gmp-widevinecdm) findUpdates() - updateTask for gmp-widevinecdm threw: Error: Failed downloading via XHR, status: 0, reason: error (resource://gre/modules/addons/ProductAddonChecker.jsm:319:16) JS Stack trace: [e-mail]:319:16 < EventListener.handleEvent*downloadFile/<@ProductAddonChecker.jsm:323:5 < [e-mail]:296:10 < ProductAddonChecker.downloadAddon<@ProductAddonChecker.jsm:450:22

Yet, the plugins tab will show Widevine as now installed.

Comment 1

[Jean-Yves Avenard [:jya]]

Can reproduce on Firefox 53 on mac :(

the CDM doesn't install automatically, making it impossible to watch netflix without navigating in the preferences.

Comment 2

[Stephen A Pohl [:spohl]]

The log shows that the "last check was less then a day ago". Can you make sure that media.gmp-manager.lastCheck pref is reset in about:config before you restart? It seems like there was either a recent check that didn't find a widevine cdm to download, or something is off with our lastCheck pref.

Comment 3

[Jean-Yves Avenard [:jya]]

That's because I restart FF often with the STR above. 
the check fails...

After a few restart, the CDM is still not downloaded. When you manually force to check for an update, only then will it download it.

Comment 4

[Stephen A Pohl [:spohl]]

I'm unable to reproduce this. Widevine is downloaded within a minute after first start. Can you please post a new log that shows the URL that's used by the automatic check? You mention that "the check fails". What exactly is the failure that you see? You will need to make sure that the lastCheck pref is reset to get a log with this URL.

Here is my log for reference:

1493217148049	Toolkit.GMP	TRACE	GMPProvider.startup - enabled=true, gmpPath=null
1493217148050	Toolkit.GMP	TRACE	GMPProvider.startup - enabled=true, gmpPath=null
1493217148051	Toolkit.GMP	INFO	GMPProvider.startup - adding clearkey CDM directory /Applications/Firefox.app/Contents/Resources/gmp-clearkey/0.1
1493217209214	Toolkit.GMP	INFO	GMPInstallManager.simpleCheckAndInstall A version change occurred. Ignoring media.gmp-manager.lastCheck to check immediately for new or updated GMPs.
1493217209215	Toolkit.GMP	INFO	GMPInstallManager._getURL Using url: https://aus5.mozilla.org/update/3/GMP/%VERSION%/%BUILD_ID%/%BUILD_TARGET%/%LOCALE%/%CHANNEL%/%OS_VERSION%/%DISTRIBUTION%/%DISTRIBUTION_VERSION%/update.xml
1493217209217	Toolkit.GMP	INFO	GMPInstallManager._getURL Using url (with replacement): https://aus5.mozilla.org/update/3/GMP/53.0/20170413192749/Darwin_x86_64-gcc3/en-US/release/Darwin%2016.5.0/default/default/update.xml
1493217209783	Toolkit.GMP	INFO	GMPAddon.constructor Created new addon: gmp-gmpopenh264 (isValid: true, isInstalled: false, hashFunction: sha512, hashValue: 3b52343070a2f75e91b7b0d3bb33935352237c7e1d2fdc6a467d039ffbbda6a72087f9e0a369fe95e6c4c789ff3052f0c134af721d7273db9ba66d077d85b327, size: 390308)
1493217209784	Toolkit.GMP	INFO	GMPAddon.constructor Created new addon: gmp-widevinecdm (isValid: true, isInstalled: false, hashFunction: sha512, hashValue: 1916805e84a49e04748204f4e4c48ae52c8312f7c04afedacacd7dfab2de424412bc988a8c3e5bcb0865f8844b569c0eb9589dae51e74d9bdfe46792c9d1631f, size: 2155607)
1493217209785	Toolkit.GMP	INFO	GMPInstallManager.simpleCheckAndInstall Found 2 addons advertised.
1493217209785	Toolkit.GMP	INFO	GMPInstallManager.simpleCheckAndInstall Found addon: gmp-gmpopenh264 (isValid: true, isInstalled: false, hashFunction: sha512, hashValue: 3b52343070a2f75e91b7b0d3bb33935352237c7e1d2fdc6a467d039ffbbda6a72087f9e0a369fe95e6c4c789ff3052f0c134af721d7273db9ba66d077d85b327, size: 390308)
1493217209786	Toolkit.GMP	INFO	GMPInstallManager.simpleCheckAndInstall Found addon: gmp-widevinecdm (isValid: true, isInstalled: false, hashFunction: sha512, hashValue: 1916805e84a49e04748204f4e4c48ae52c8312f7c04afedacacd7dfab2de424412bc988a8c3e5bcb0865f8844b569c0eb9589dae51e74d9bdfe46792c9d1631f, size: 2155607)
1493217210720	Toolkit.GMP	INFO	GMPDownloader install to directory path: /Users/spohl/Library/Application Support/Firefox/Profiles/7v5epolv.widevine/gmp-gmpopenh264/1.6
1493217210720	Toolkit.GMP	INFO	GMPExtractor.install Installing /private/var/folders/ym/8jr8dh4s00zcvk1b30gdr66c0000gn/T/TemporaryItems/tmpaddon...
1493217210731	Toolkit.GMP	INFO	GMPExtractor.install libgmpopenh264.dylib was successfully extracted to: /Users/spohl/Library/Application Support/Firefox/Profiles/7v5epolv.widevine/gmp-gmpopenh264/1.6/libgmpopenh264.dylib
1493217210732	Toolkit.GMP	INFO	GMPExtractor.install gmpopenh264.info was successfully extracted to: /Users/spohl/Library/Application Support/Firefox/Profiles/7v5epolv.widevine/gmp-gmpopenh264/1.6/gmpopenh264.info
1493217210732	Toolkit.GMP	INFO	GMPExtractor.install /private/var/folders/ym/8jr8dh4s00zcvk1b30gdr66c0000gn/T/TemporaryItems/tmpaddon was installed successfully
1493217210751	Toolkit.GMP	INFO	GMPWrapper(gmp-gmpopenh264) onPrefVersionChanged() - registering gmp directory /Users/spohl/Library/Application Support/Firefox/Profiles/7v5epolv.widevine/gmp-gmpopenh264/1.6
1493217212018	Toolkit.GMP	INFO	GMPDownloader install to directory path: /Users/spohl/Library/Application Support/Firefox/Profiles/7v5epolv.widevine/gmp-widevinecdm/1.4.8.903
1493217212018	Toolkit.GMP	INFO	GMPExtractor.install Installing /private/var/folders/ym/8jr8dh4s00zcvk1b30gdr66c0000gn/T/TemporaryItems/tmpaddon...
1493217212019	Toolkit.GMP	INFO	GMPExtractor.install LICENSE.txt was successfully extracted to: /Users/spohl/Library/Application Support/Firefox/Profiles/7v5epolv.widevine/gmp-widevinecdm/1.4.8.903/LICENSE.txt
1493217212057	Toolkit.GMP	INFO	GMPExtractor.install libwidevinecdm.dylib was successfully extracted to: /Users/spohl/Library/Application Support/Firefox/Profiles/7v5epolv.widevine/gmp-widevinecdm/1.4.8.903/libwidevinecdm.dylib
1493217212058	Toolkit.GMP	INFO	GMPExtractor.install manifest.json was successfully extracted to: /Users/spohl/Library/Application Support/Firefox/Profiles/7v5epolv.widevine/gmp-widevinecdm/1.4.8.903/manifest.json
1493217212058	Toolkit.GMP	INFO	GMPExtractor.install /private/var/folders/ym/8jr8dh4s00zcvk1b30gdr66c0000gn/T/TemporaryItems/tmpaddon was installed successfully
1493217212070	Toolkit.GMP	INFO	GMPWrapper(gmp-widevinecdm) onPrefVersionChanged() - registering gmp directory /Users/spohl/Library/Application Support/Firefox/Profiles/7v5epolv.widevine/gmp-widevinecdm/1.4.8.903

Comment 5

[Jean-Yves Avenard [:jya]]

I'm assuming the check fails because the CDM shows up as ""Widevine Content Decryption Module provided by Google Inc will be installed shortly" forever ...

I will retry... but I can consistently reproduce it on Nightly (both mac and linux) and release 53 on mac
on two different physical location and 3 different machines.

Comment 6

[Jean-Yves Avenard [:jya]]

This video https://www.youtube.com/watch?v=HxYIoWO4DoA&feature=youtu.be shows another user struggling to get the CDM to install.

This one is with ESR52...

It's definitely not just me :(

Comment 7

[Chris Pearce [:cpearce (Not reading bugmail)]]

I also cannot reproduce this. Based on your log jya, it seems the XHR to Google's download server is failing.

Comment 8

[alex_mayorga]

¡Hola Chris!

FWIW the error in my case on Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:58.0) Gecko/20100101 Firefox/58.0 ID:20171019222141:

1508537610499	addons.productaddons	WARN	Failed downloading via XHR, status: 0, reason: error
1508537610500	Toolkit.GMP	ERROR	GMPWrapper(gmp-widevinecdm) findUpdates() - updateTask for gmp-widevinecdm threw: Error: Failed downloading via XHR, status: 0, reason: error (resource://gre/modules/addons/ProductAddonChecker.jsm:318:16) JS Stack trace: [e-mail]:318:16 < EventListener.handleEvent*downloadFile/<@ProductAddonChecker.jsm:322:5 < [e-mail]:295:10 < [e-mail]:449:22 < async*[e-mail]:437:12 < [e-mail]:144:12 < findUpdates/this._updateTask<@GMPProvider.jsm:284:17 < async*[e-mail]:275:25 < [e-mail]:1182:9 < [e-mail]:1575:5 < initialize/<@extensions.js:145:5 < EventListener.handleEvent*[e-mail]:144:3 < EventListener.handleEvent*@extensions.js:113:1  Log.jsm:752
Error: Failed downloading via XHR, status: 0, reason: error  ProductAddonChecker.jsm:318:16

How does one fix this?

¡Gracias!
Alex

Comment 9

[alex_mayorga]

¡Hola!

So it turned out that one of the hacks I use to bypass geo blocks was somehow making the connection to https://redirector.gvt1.com/edgedl/widevine-cdm/1.4.8.1008-win-x64.zip insecure.

Undoing the hack allowed the CDM to download correctly.

Mad props to glob and cpeterson for putting up with ranty me on #firefox while helping me to figure out the root of the issue.

Further variants of my particular issue in case I bump into these in the future:

[SW] on message <unavailable>  js/lib/push_worker.js:83
[SW] on message <unavailable>  js/lib/push_worker.js:83
[SW] on message <unavailable>  js/lib/push_worker.js:83
[SW] on message <unavailable>  js/lib/push_worker.js:83
1508898767737	addons.productaddons	WARN	Failed downloading via XHR, status: 0, reason: error
1508898767737	Toolkit.GMP	ERROR	GMPInstallManager.simpleCheckAndInstall Could not check for addons: {"status":"failed","results":[{"id":"gmp-widevinecdm","result":"failed"}]}  Log.jsm:752
[SW] on message <unavailable> js/lib/push_worker.js:83

MediaKeySystemAccess::GetKeySystemStatus(com.widevine.alpha) result=cdm-not-installed msg='CDM is not installed'
GET 
XHR 
https://redirector.gvt1.com/edgedl/widevine-cdm/1.4.8.1008-win-x64.zip 
[372ms]
Cabeceras
Respuesta
Pila de llamadas
	downloadFile/< resource://gre/modules/addons/ProductAddonChecker.jsm:333:7
	downloadFile resource://gre/modules/addons/ProductAddonChecker.jsm:295:10
	downloadAddon resource://gre/modules/addons/ProductAddonChecker.jsm:449:22
	start resource://gre/modules/GMPInstallManager.jsm:437:12
	installAddon resource://gre/modules/GMPInstallManager.jsm:144:12
	simpleCheckAndInstall resource://gre/modules/GMPInstallManager.jsm:266:17
	checkForUpdates/< resource://gre/modules/addons/GMPProvider.jsm:384:9
	notify resource://gre/modules/Timer.jsm:44:7

¡Gracias!
Alex

Comment 10

[alex_mayorga]

[Tracking Requested - why for this release]:

¡Hola!

Seems to still be an issue on 67 https://support.mozilla.org/questions/1261833 and 69 https://support.mozilla.org/questions/1268553

Perhaps worth tracking?

¡Gracias!
Alex

Comment 11

[Liz Henry (:lizzard) (relman/hg->git project)]

Andrei can you help find someone to try to reproduce this? (on 69 but maybe more usefully, on 71 nightly) Thanks!
I'm not tracking unless we know that this is a widespread issue but let's see if we can uncover a problem here.

Comment 12

[Andreas Wagner [:TheOne] [use NI]]

I was able to reproduce this. Turns out, the adblocker module in my router blocked requests to gvt1.com (it's part of https://easylist-downloads.adblockplus.org/easylist.txt)