maas-import-ephemerals crashes with "unexpected checksum 'sha256'" when using a proxy

Bug #1240652 reported by Diogo Matsubara
16
This bug affects 2 people
Affects Status Importance Assigned to Milestone
MAAS
Invalid
Critical
Unassigned
Ubuntu Cloud Archive
Fix Released
High
Unassigned
simplestreams
Fix Released
High
Unassigned
simplestreams (Ubuntu)
Fix Released
High
Unassigned
Saucy
Fix Released
High
Unassigned
Trusty
Fix Released
High
Unassigned

Bug Description

== Begin SRU Info ==
[Impact]
maas-import-ephemerals is the program that is executed to download images from http://maas.ubuntu.com which are then used for the commissioning, enlistment, and curtin install environment.

This bug causes that download to fail in most cases with an http proxy between the user and maas.ubuntu.com. It is also reported to fail under cases where there is no http_proxy set (but may be a proxy in between).

[Test Case]
The bug could be reproduced by simply doing:
  PROXY=http://localhost:3128 # or some valid proxy
  http_proxy=$PROXY python /usr/bin/sstream-mirror -vvv http://maas.ubuntu.com/images/ephemeral/daily/streams/v1/index.json out.d arch=amd64 release=quantal

You would see the download start and then hang. A suitable proxy can be installed just by 'apt-get install squid3' and then using http://localhost:3128.

[Regression Potential]
Regression potential should be very small. Previously each connection we made was doing an open and close and then open again. This was wreaking havoc with urllib3 as used by python-requests. Now, we're only opening and closing a single time during the mirror, and even then,
 a.) the url that is being downloaded will change (by having a '/' inserted into its path) where previously it would be the same url
 b.) step 'a' will only occur if the base url provided by the user did not already end in '/'.
== End SRU Info ==

Since 2013-10-11 we started seeing errors running the MAAS integration tests for saucy[1].

The checksum of the downloaded image wasn't matching the checksum expected[2]. maas-import-pxe-files failed with the following traceback:

Traceback (most recent call last):
  File "/usr/sbin/maas-import-ephemerals", line 26, in <module>
    main(args)
  File "/usr/lib/python2.7/dist-packages/provisioningserver/import_images/ephemerals_script.py", line 450, in main
    target.sync(source, args.path)
  File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 85, in sync
    return self.sync_index(reader, path, data, content)
  File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 230, in sync_index
    self.sync(reader, path=epath)
  File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 83, in sync
    return self.sync_products(reader, path, data, content)
  File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 304, in sync_products
    self.insert_item(item, src, target, pgree, ipath_cs)
  File "/usr/lib/python2.7/dist-packages/provisioningserver/import_images/ephemerals_script.py", line 249, in insert_item
    data, src, target, pedigree, contentsource)
  File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 388, in insert_item
    size=data.get('size'))
  File "/usr/lib/python2.7/dist-packages/simplestreams/objectstores/__init__.py", line 147, in insert
    cksum.hexdigest(), cksum.expected))
Exception: unexpected checksum 'sha256' on precise/release-20131010/precise-daily-maas-amd64.tar.gz (found: 3d99e069e34d031f924689a3c28ea43d4046d8e9a79a2ea9014d35bcbcf57a16 expected: 2c7ab801ffd7e8673b77be828335bac29538f102dbc6baacd4ccc4c0d309a11b)
}}}

Initially it was thought this could be caused by a misconfigured cache in the QA lab, but after re-installing and reconfiguring (and checking with wget that the cache was returning the correct objects for a given URL, as well as checking the checksum of the file matched the one in the json file), the error was still present.

Further investigation[3] raised the suspicion that the downloaded image is being handled by multiple processes. Turns out the code for simplestreams and import_ephemerals.py is not multi process safe, and multiple import-ephemerals processes working with the same datadir can cause problems like this.

[1] http://10.189.74.2:8080/view/MAAS/job/saucy-adt-maas-daily/220/ARCH=amd64,label=lenovo-RD230-01/console
[2] http://10.189.74.2:8080/view/MAAS/job/saucy-adt-maas-manual/95/ARCH=amd64,label=lenovo-RD230-01/console
[3] http://pastebin.ubuntu.com/6247125/

Related branches

Revision history for this message
Scott Moser (smoser) wrote :
Revision history for this message
Gavin Panella (allenap) wrote :

I think it would be preferable to create a lock file just inside the datadir (.lock, say) so that exclusive access works even when running it as a script. I know we want to run everything as tasks via Celery, but I think it's worth having the lock as close to the action as possible.

Changed in maas:
status: New → Triaged
importance: Undecided → Critical
Revision history for this message
Julian Edwards (julian-edwards) wrote :

There's no evidence that this is a thread problem, just a sudden conclusion in the pastebin text. In fact, we know that the import script was only being run once.

Raphaël Badin (rvb)
summary: - import_ephemerals.py script is not multi process safe
+ maas-import-ephemerals crashes with "unexpected checksum 'sha256'" when
+ using a proxy
Revision history for this message
Raphaël Badin (rvb) wrote :

I took the liberty of changing the title of this bug to better reflect what the actual symptom is. And I did that because I think the diagnostic that this is caused by simultaneous runs of the script is wrong: I see the problem happening on a fresh canonistack instance when I'm running the script manually and I'm sure it's run only once.

To reproduce:
- fire up a Saucy canonistack instance
- install maas on it:
    sudo add-apt-repository -y ppa:maas-maintainers/dailybuilds
    sudo apt-get update
    sudo apt-get install -y maas maas-dhcp maas-dns
- switch as root
    sudo su
- configure the proxy (squid3 has been installed by maas already)
     http_proxy="http://localhost:3128"
    export http_proxy
- check that wget (through the proxy) works fine:
    wget http://maas.ubuntu.com/images/ephemeral/releases/precise/release-20131010/precise-daily-maas-amd64.tar.gz
    (have a look in /var/log/squid3/access.log, you should see the hit)
- run maas-import-ephemerals
    maas-import-ephemerals
- wait a *long* time (see bug 1240838)

Revision history for this message
Raphaël Badin (rvb) wrote :

Debugging shows that, after a couple of requests, the code gets stuck waiting for contentsource.py:RequestsUrlReader.read to return. Looks like there is a problem with using python-requests the way it's done in simplestreams with a proxy.

Revision history for this message
Raphaël Badin (rvb) wrote :

When removing the package python-requests, simplestreams falls back to using python's urllib2 reader and simplestreams works fine (using a proxy).

Scott Moser (smoser)
Changed in simplestreams:
status: New → Confirmed
importance: Undecided → High
Revision history for this message
Diogo Matsubara (matsubara) wrote :

FWIW, I ran into this bug yesterday while testing the ISO and there was no proxy involved.

Revision history for this message
Scott Moser (smoser) wrote :

I am pretty sure I understand this bug.
It is a regression caused by changes for bug 1237658.

Under that bug we made each attempt in a UrlMirrorReader basically stat urls by doing an open and then a close to see if they were there. Then, if it wasn't there it would retry with a '/' added to the prefix.

This was all so the user could do:
 sstream-query --keyring /usr/share/keyrings/ubuntu-cloudimage-keyring.gpg -vvv http://cloud-images.ubuntu.com/releases
and have us figure out that they really needed a trailing /

I think the bug is actually lower in the stack somewhere. We were essentially doing:
    fp = open(someurl)
   fp.close()
   return open(someurl)

which should be ok, but I think that the quick open and close was either not correctly getting closed or was ending up triggering squid to do the full download before it started handing us data for the second open (which would then subsequently time out).

python3 seems less likely to show failure. I could not reproduce with python3 via simplestreams, but did see it using the go-requests.py program with both python2 and python3.

I have several test programs here and will attach. go-urllib2 does not show the problem. The others do.
  go-requests.py: use python-requests
  go-sstream-mirror: use UrlMirrorReader from simplestreams
  go-sstreams: use UrlContentSource without the mirror reader
  go-urllib.py

Running them is straight forward enough:
  time env http_proxy=$PROXY python3 ../go-sstreams.py http://maas.ubuntu.com/images/ephemeral/daily/precise/20131017/precise-daily-maas-amd64.tar.gz out.img

Revision history for this message
Scott Moser (smoser) wrote :
Revision history for this message
Scott Moser (smoser) wrote :
Revision history for this message
Scott Moser (smoser) wrote :
Revision history for this message
Scott Moser (smoser) wrote :
Revision history for this message
Scott Moser (smoser) wrote :

I've opened an issue on requests githup at https://github.com/kennethreitz/requests/issues/1686 .

Changed in simplestreams (Ubuntu):
status: New → In Progress
importance: Undecided → Medium
importance: Medium → High
Changed in simplestreams:
status: Confirmed → Fix Committed
Scott Moser (smoser)
description: updated
Revision history for this message
Raphaël Badin (rvb) wrote :

@smoser, I just tested your most recent fix to simplestreams (revision 319) and it seems to fix the problem. I had a successful run in our lab.

Until a package with the fix is published, this can be fixed manually:
$ sudo su
$ cd /usr/share/pyshared && wget http://bazaar.launchpad.net/~smoser/simplestreams/trunk/diff/319 && patch -p0 < 319

Revision history for this message
Dave Walker (davewalker) wrote : Please test proposed package

Hello Diogo, or anyone else affected,

Accepted simplestreams into saucy-proposed. The package will build now and be available at http://launchpad.net/ubuntu/+source/simplestreams/0.1.0~bzr318-0ubuntu1.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

Changed in simplestreams (Ubuntu Saucy):
status: In Progress → Fix Committed
tags: added: verification-needed
Raphaël Badin (rvb)
tags: added: verification-done
removed: verification-needed
Revision history for this message
Raphaël Badin (rvb) wrote :

I've tested this on canonistack and the fix worked: http://paste.ubuntu.com/6278444/

Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package simplestreams - 0.1.0~bzr318-0ubuntu1.1

---------------
simplestreams (0.1.0~bzr318-0ubuntu1.1) saucy-proposed; urgency=low

  * fix bug resulting in 'unexpected checksum' most commonly seen
    if an http proxy was being used (LP: #1240652)
 -- Scott Moser <email address hidden> Thu, 17 Oct 2013 15:25:12 -0400

Changed in simplestreams (Ubuntu Saucy):
status: Fix Committed → Fix Released
Revision history for this message
Colin Watson (cjwatson) wrote : Update Released

The verification of this Stable Release Update has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regresssions.

Revision history for this message
Scott Moser (smoser) wrote :

I just released this to cloud-archive in -updates.
 simplestreams (0.1.0~bzr318-0ubuntu1.1~ctools0) precise; urgency=low
 .
   * New update for the Ubuntu Cloud Archive.
 .
 simplestreams (0.1.0~bzr318-0ubuntu1.1) saucy-proposed; urgency=low
 .
   * fix bug resulting in 'unexpected checksum' most commonly seen
     if an http proxy was being used (LP: #1240652)

Changed in simplestreams (Ubuntu Trusty):
status: In Progress → Fix Released
Changed in cloud-archive:
importance: Undecided → High
status: New → Fix Released
Changed in maas:
status: Triaged → Invalid
Revision history for this message
Scott Moser (smoser) wrote : Fixed in simplestreams version 0.1.0.

This bug is believed to be fixed in simplestreams in version 0.1.0. If this is still a problem for you, please make a comment and set the state back to New

Thank you.

Changed in simplestreams:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.