Bug #336866 “When adding tag or updating description, lp_save() ...” : Bugs : lazr.restful

Bryce Harrington (bryce) on 2009-03-02

description:

updated

Bryce Harrington (bryce) wrote on 2009-03-02:

#2

log of session that generated traceback in description Edit (30.4 KiB, text/plain)

Leonard Richardson (leonardr) wrote on 2009-03-02:

#3

Here are the last two requests:

send: 'PATCH /beta/bugs/292317
if-match: "72a9365dbdc47f3cfeb7e05896b38208e23ddc75
send: '{"tags": ["needs-xorglog"]}'
reply: 'HTTP/1.1 209 Content Returned\r\n'

send: 'PATCH /beta/bugs/292317
if-match: "7f60495c065527a42d5d0e5bc4aaf14be1e73123"
send: '{"tags": ["needs-xorglog", "needs-lspci-vvnn"]}'
reply: 'HTTP/1.1 412 Precondition Failed\r\n'

Are you calling lp_save() twice, or just once? It would be helpful if you made a GET request after every call to lp_save(), to see what the server thinks the ETag is at each stage.

This might be a problem with the way launchpadlib handles the 209 response code.

Bryce Harrington (bryce) wrote on 2009-03-02:

#4

test-http412 Edit (851 bytes, text/plain)

Attached is a minimal script to reproduce the issue.

It seems the issue is not making multiple changes, nor calling lp_save() multiple times. It is sufficient to simply reference a field once before and once after calling lp_save().

Bryce Harrington (bryce) wrote on 2009-03-02:

#5

test-http412-working Edit (1.1 KiB, text/plain)

If I re-get the bug after the lp_save(), it seems to work (attached script is applying both tags properly)

Bryce Harrington (bryce) wrote on 2009-03-02:

#6

log-working Edit (10.4 KiB, text/plain)

Here is a log from the working script in comment #5

Bryce Harrington (bryce) wrote on 2009-03-02:

#7

Ran into the 412 error again with a script that doesn't set any tags, only updates description. Also gets the error after a call to lp_save().

Bryce Harrington (bryce) wrote on 2009-03-06:

#8

This seems to have gone away now.

Martin Pitt (pitti) wrote on 2009-03-12:

#9

I get this problem when trying to set a duplicate:

>>> b.duplicate_of
>>> b.duplicate_of = 341478
>>> b.lp_save()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/lib/python2.6/dist-packages/launchpadlib/resource.py", line 489, in lp_save
    URI(self.self_link), representation, headers)
  File "/usr/lib/python2.6/dist-packages/launchpadlib/_browser.py", line 266, in patch
    'PATCH', extra_headers=extra_headers)
  File "/usr/lib/python2.6/dist-packages/launchpadlib/_browser.py", line 212, in _request
    raise HTTPError(response, content)
launchpadlib.errors.HTTPError: HTTP Error 412: Precondition Failed

And unlike for comments, it does not actually set the duplicate, so the HTTPError cannot just be ignored.

Changed in launchpadlib:
status:	New → Confirmed

Markus Korn (thekorn) wrote on 2009-03-13:

#10

I cannot confirm this, trying to change the duplicate_of attribute of a bug works for me, I don't get a 'HTTP Error 412'.

Martin, as a side note, giving the bug id in your last example won't work, it has to either

>>> b.duplicate_of = launchpad.bugs[123456]
or
>>> b.duplicate_of = "https://api.staging.launchpad.net/beta/bugs/123456"

Markus

Martin Pitt (pitti) wrote on 2009-03-13:

#11

I found a workaround for this now. Previously I was doing

bug = self.launchpad.bugs[id]

            for a in bug.attachments:
                if a.title in (...):
                    try:
                        a.removeFromBug()
                    except HTTPError:
                        pass # workaround for 404 error, see LP #315387

            # MARKER1
            if not bug.duplicate_of:
                bug.duplicate_of = master

self.launchpad.lp_save() # MARKER2

This gave me the afforementioned 412 error. After a looong time of fiddling, I found out the following:

* Deleting attachmends and then changing properties leads to this error in lp_save()
* Calling lp_save() twice in a row leads to this error.

So what I did to circumvent the crash:

* at MARKER1: get a new bug object with "bug = self.launchpad.bugs[id]"

* at MARKER2:

if bug._dirty_attributes: # avoid "412: Precondition Failed"
bug.lp_save()

I really shouldn't have to explicitly query a private attribute (_dirty_attributes). If it's empty, lp_save() should just be a no-op.

Markus Korn (thekorn) wrote on 2009-03-17:

#12

I think https://bugs.edge.launchpad.net/launchpadlib/+bug/341950/comments/2 also explains this issue described here, but I'm not sure if both bugs are related and can be fixed the same way.
Maybe some insider of launchpad's code can mark them as duplicates and rise priority of this bug, for me it looks like a design issue which should be fixed in an early stage of launchpadlib and/or the API

Martin Pitt (pitti) wrote on 2009-04-06:

#13

Argh, this is a nuisance. It also happens in this code:

        bug = self.launchpad.bugs[id]
        bug.newMessage(content='This crash has the same stack trace characteristics as bug #%i. \
However, the latter was already fixed in an earlier package version than the \
one in this report. This might be a regression or because the problem is \
in a dependent package.' % master,
            subject='Possible regression detected')
        bug.tags = bug.tags + ['regression-retracer'] # LP#254901 workaround

print bug._dirty_attributes # confirms that .tags is dirty
bug.lp_save() # causes HTTP Error 412: Precondition Failed

Leonard Richardson (leonardr) on 2009-04-20

Changed in launchpadlib:
importance:	Undecided → High
status:	Confirmed → Triaged

Martin Pitt (pitti) wrote on 2009-04-22:

#14

I just got yet another incarnation of that in the retracers. Good debugging hint from James:

james_w| pitti: and you can "import httplib2;httplib2.debuglevel = 1" to get more info about the reuests

Leonard Richardson (leonardr) wrote on 2009-04-22:

#15

jkakar reports the same problem running this code: http://pastebin.ubuntu.com/156109/

Martin Pitt (pitti) wrote on 2009-04-22:

#16

Did anything change in LP recently in that regard? The retracers crash all over the place since today, while they were grinding happily for over a week before.

I added some debugging code to print the exception's message and content fields, but both are empty. This is from very simple code:

def _mark_dup_checked(self, id, report):
'''Mark crash id as checked for being a duplicate.'''

        bug = self.launchpad.bugs[id]
        if 'need-duplicate-check' in bug.tags:
            x = bug.tags[:] # LP#254901 workaround
            x.remove('need-duplicate-check')
            bug.tags = x
            bug.lp_save()

I. ee. I just create a bug object, change .tags, and save it again. No re-use, or other things.

Do you need more information about this?

Martin Pitt (pitti) wrote on 2009-04-22:

#17

Or is there a workaround for this? This is quite urgent, since crash reports bitrot veeery fast.

Leonard Richardson (leonardr) wrote on 2009-04-23:

#18

I've finally been able to duplicate this. Here's a very edited HTTP dump that shows the problem

===
GET /beta/bugs/353805 HTTP/1.1
if-none-match: "7f7f5e3c50396d650b625b8172b225368bfeecb2" (???)

HTTP/1.1 200 Ok
Etag: "3c1d2fa23419ec334f1fbaf4ca2ca94fbd2a949a"
---
PATCH /beta/launchpadlib/+bug/353805 HTTP/1.1
if-match: "34ed5fed814bac8755c4ac50c19acc76667e3bdb" (???)

HTTP/1.1 412 Precondition Failed
===

The values for If-None-Match and If-Match are totally random. They don't show up anywhere in the cache or anywhere else in the HTTP dump. In fact, even the initial requests to /beta/ have a random If-None-Match.

If I clear the cache, I don't send any If-None-Match headers, but eventually I do send a random If-Match and I get the same error.

Leonard Richardson (leonardr) wrote on 2009-04-23:

#19

OK, I found at least one problem that causes 412 errors. When you PATCH a representation you get back 209 ("Content Returned") with a new representation. The http_etag in this representation is the random ETag that's sent on a subsequent PATCH and then you get 412.

---
PATCH /+bug/353805: Sending If-Match with http_etag "84bb970299f2ae35a4aad2d1d71cba62392dacf3"
209 Content Returned: New representation has http_etag "53a61af57b930f89814823ebedaaa3e48679a6bd"
---
PATCH /+bug/353805: Sending If-Match with http_etag "53a61af57b930f89814823ebedaaa3e48679a6bd"
412 Precondition Failed
---

The http_etag here is probably generated from some sort of transitional state that's neither the original state nor the final state. I'm looking into it now.

Leonard Richardson (leonardr) wrote on 2009-04-23:

#20

This is a problem specific to Launchpad bugs. The problem does not exist in the lazr.restful example web service, and it doesn't exist for other Launchpad resources (such as people). Everyone who's commented on this thread has had a problem with bugs.

The culprit is the date_last_updated field. Here are the only differences between the version of the bug received along with a 209, and the same bug retrieved an instant later with a fresh GET request.

date_last_updated: 2006-07-14T08:54:19.453881+00:00 became 2009-04-23T15:03:50.557586+00:00
http_etag: "490b68f89bc09bc705018ee8066eb985261e55bd" became "fcbc53f773fe21b99154c7fd41c04facbf415477"

date_last_updated is updated after the ETag is calculated, possibly in response to the ObjectModifiedEvent. Or maybe it's done by a database trigger. I'm not sure. Anyway, the bug gets changed twice, and the effect is the same as if someone else modified the bug after you did: your copy of the bug is no longer valid.

Leonard Richardson (leonardr) wrote on 2009-04-23:

#21

The culprit is a combination of the unmarshalled_field_cache and the ObjectModifiedEvent. The OME modified date_last_updated, but lazr.restful didn't hear about it, and only removed the fields the client modified from unmarshalled_field_cache. So the old date_last_updated stays in there.

I have a fix but since the lazr.restful example service doesn't use OMEs at all, a proper test will take a little while.

Bryce Harrington (bryce) wrote on 2009-04-23: Re: [Bug 336866] Re: When adding tag or updating description, lp_save() gives "HTTP Error 412: Precondition Failed"

#22

Awesome! Looking forward to trying it out.

On Thu, Apr 23, 2009 at 05:53:03PM -0000, Leonard Richardson wrote:
> The culprit is a combination of the unmarshalled_field_cache and the
> ObjectModifiedEvent. The OME modified date_last_updated, but
> lazr.restful didn't hear about it, and only removed the fields the
> client modified from unmarshalled_field_cache. So the old
> date_last_updated stays in there.
>
> I have a fix but since the lazr.restful example service doesn't use OMEs
> at all, a proper test will take a little while.
>
> --
> When adding tag or updating description, lp_save() gives "HTTP Error 412: Precondition Failed"
> https://bugs.launchpad.net/bugs/336866
> You received this bug notification because you are a direct subscriber
> of the bug.
>
> Status in Launchpad web services client library: Triaged
>
> Bug description:
> Getting this error consistently when attempting to add a tag using the following code (which worked last time I ran it a few weeks ago).
>
> if not tag in bug.tags:
> #bug.tags.append(tag)
> # Workaround bug #254901
> tag_list = bug.tags
> tag_list.append(tag)
> bug.tags = tag_list
>
> print " ---> Tagged ",tag
> bug.lp_save()
>
> I also tested with the commented line instead of the workaround code; same error.
>
> Traceback (most recent call last):
> File "./process-new-bugs.py", line 175, in <module>
> bug.append_tag("needs-lspci-vvnn")
> File "/home/bryce/src/Arsenal/arsenal/contrib/arsenal_lib.py", line 125, in append_tag
> self.bug.lp_save()
> File "build/bdist.linux-x86_64/egg/launchpadlib/resource.py", line 489, in lp_save
> File "build/bdist.linux-x86_64/egg/launchpadlib/_browser.py", line 266, in patch
> File "build/bdist.linux-x86_64/egg/launchpadlib/_browser.py", line 212, in _request
> launchpadlib.errors.HTTPError: HTTP Error 412: Precondition Failed

Leonard Richardson (leonardr) on 2009-04-24

affects:	launchpadlib → lazr.restful
Changed in lazr.restful:
assignee:	nobody → Leonard Richardson (leonardr)

James Westby (james-w) wrote on 2009-04-24:

#23

Adding a python-launchpadlib task in Ubuntu, as I will want to port your
changes to the Jaunty package.

I'll package the new python-launchpadlib for Karmic with lazr-restfulclient
and any other new packages that will be needed, but doing that for Jaunty
is not really possible.

Thanks,

James

Leonard Richardson (leonardr) wrote on 2009-04-24:

#24

This is a server-side bug, so there's nothing to do for launchpadlib.

I've gotten my branch reviewed and landed in the main lazr.restful branch. Because Launchpad doesn't use that branch yet I'm going to be backporting it.

James Westby (james-w) wrote on 2009-04-24:

#25

Ah, sorry, I got confused between lazr.restful and lazr.restfulclient.

Thanks for fixing this, I'm sure that there will be a lot less hair torn out
by some of my fellow developers now.

Thanks,

James

Changed in python-launchpadlib (Ubuntu):
status:	New → Invalid

Leonard Richardson (leonardr) wrote on 2009-04-27:

#26

I've backported the fix to the lazr.restful branch used by Launchpad.

Changed in lazr.restful:
status:	Triaged → Fix Committed

Martin Pitt (pitti) wrote on 2009-06-29:

#27

I still get daily crashes from the Apport retracer in this simple code:

        bug = self.launchpad.bugs[id]
        if self.arch_tag in bug.tags:
            x = bug.tags[:] # LP#254901 workaround
            x.remove(self.arch_tag)
            bug.tags = x
            bug.lp_save()

  File "/home/ubuntu-archive/launchpadlib/launchpadlib/src/launchpadlib/resource.py", line 487, in lp_save
    URI(self.self_link), representation, headers)
  File "/home/ubuntu-archive/launchpadlib/launchpadlib/src/launchpadlib/_browser.py", line 265, in patch
    'PATCH', extra_headers=extra_headers)
  File "/home/ubuntu-archive/launchpadlib/launchpadlib/src/launchpadlib/_browser.py", line 210, in _request
    raise HTTPError(response, content)
launchpadlib.errors.HTTPError: HTTP Error 412: Precondition Failed

So it doesn't actually seem fixed yet?

James Westby (james-w) wrote on 2009-07-07:

#28

I've just hit Precondition Failed as well, just with

branch.lifecycle_status = 'Abandoned'
branch.lp_save()

though maybe it's a case of different bug, same manifestation.

Any advice would be appreciated, as I know of no other way to achieve this.

Thanks,

James

James Westby (james-w) wrote on 2009-07-07:

#29

Hi,

I may have spoken too soon. I can't reproduce the error in testing, so
I've added some code to give more information if this happens again and
will wait and see what happens.

Thanks,

James

Leonard Richardson (leonardr) on 2009-10-08

Changed in lazr.restful:
status:	Fix Committed → Fix Released

Curtis Hovey (sinzui) on 2009-10-09

tags:

added: tech-debt

Martin Pitt (pitti) wrote on 2010-01-20:

#30

Reopening. When I remove the workarounds for this bug in Apport's launchpad module, I still get the same problem:

  File "apport/crashdb_impl/launchpad.py", line 614, in close_duplicate
    bug.lp_save()
  File "/usr/lib/pymodules/python2.6/lazr/restfulclient/resource.py", line 630, in lp_save
    URI(self.self_link), representation, headers)
  File "/usr/lib/pymodules/python2.6/lazr/restfulclient/_browser.py", line 277, in patch
    'PATCH', extra_headers=extra_headers)
  File "/usr/lib/pymodules/python2.6/lazr/restfulclient/_browser.py", line 217, in _request
    raise HTTPError(response, content)
HTTPError: HTTP Error 412: Precondition Failed
Response headers:
---
content-length: 0
content-type: text/plain
date: Wed, 20 Jan 2010 11:48:55 GMT
server: zope.server.http (HTTP)
status: 412
vary: Cookie,Authorization,Accept
via: 1.1 wildcard.staging.launchpad.net
x-content-type-warning: guessed from content
x-powered-by: Zope (www.zope.org), Python (www.python.org)
---
Response body:
---

---

Changed in lazr.restful:
status:	Fix Released → Confirmed

Martin Pool (mbp) wrote on 2010-02-15:

#31

This is hitting me too in Hydrazine, and it's fairly easily reproducible there if you make changes quickly. It does seems timing-dependent which would be consistent with it relating to a last-modified field stored on the server: it seems like if you get two updates within a 1s window then it crashes.

Martin Pitt (pitti) wrote on 2010-03-02:

#32

Apport already has workarounds for this, but apparently still not enough. This still keeps people from submitting debug data to Launchpad, see bug 528680.

Can the priority of this please be bumped?

affects:	python-launchpadlib (Ubuntu) → lazr.restfulclient (Ubuntu)
Changed in lazr.restfulclient (Ubuntu):
importance:	Undecided → High
status:	Invalid → Triaged

James Westby (james-w) wrote on 2010-03-02: Re: [Bug 336866] Re: When adding tag or updating description, lp_save() gives "HTTP Error 412: Precondition Failed"

#33

On Tue, 02 Mar 2010 11:11:47 -0000, Martin Pitt <email address hidden> wrote:
> Apport already has workarounds for this, but apparently still not
> enough. This still keeps people from submitting debug data to Launchpad,
> see bug 528680.
>
> Can the priority of this please be bumped?

Martin, how sure are you that these are spurious?

Is there a chance that they are actually legitimate errors due to
something else modifying the bug between you fetching it and saving it?

Thanks,

James

Martin Pitt (pitti) wrote on 2010-03-02:

#34

The window for that is pretty small, since it's an automated script with not much in between. Martin-Eric said that he tried this a number of times, and other people saw this as well.

Also, it's perfectly reproducible in the Apport test suite if I remove all the workarounds for this bug.

James Westby (james-w) wrote on 2010-03-02:

#35

On Tue, 02 Mar 2010 12:39:09 -0000, Martin Pitt <email address hidden> wrote:
> The window for that is pretty small, since it's an automated script with
> not much in between. Martin-Eric said that he tried this a number of
> times, and other people saw this as well.
>
> Also, it's perfectly reproducible in the Apport test suite if I remove
> all the workarounds for this bug.

Ok, thanks. I don't do either of these things in scripts myself, so
haven't seen it.

I did however do things with branches over the API that was getting 412
a lot, but this came down to automated tasks that LP does in the
background the modify the branch happening in about the same amount of
time after pushing the branch that my script took to get to the API
stage, leading to legitimate 412 errors that were easy to work around
once I understood what was going on.

Thanks,

James

James Westby (james-w) wrote on 2010-03-02:

#36

Right, I can still reproduce by doing

  bug = lp.bugs[12345]
  bug.newMessage(content="foo", subject="bar)
  bug.tags = ["foo"]
  bug.lp_save()

because date_last_updated and date_last_message change when we call the
newMessage method, but we don't update the representation.

The original fix for this bug was server side. Leonard, is there something we can
change server side for this?

On the client side, we could fix this problem by changing NamedOpearation.__call__
which currently does

        if response.status == 201:
            return self._handle_201_response(url, response, content)
        else:
            if http_method == 'post':
                # The method call probably modified this resource in
                # an unknown way. Refresh its representation.
                self.resource.lp_refresh()
            return self._handle_200_response(url, response, content)

where we could move the the if http_method block outside the other if block, so that
we refresh when we create the new message.

What's the best approach?

Thanks,

James

Leonard Richardson (leonardr) wrote on 2010-03-03:

#37

If creating a new resource secretly modifies the parent resource, then the client-side fix is the correct thing to do. But I don't know if that would help the apport people. Can someone show me the apport code that has the problem, and the workarounds devised for it?

Martin Pool (mbp) wrote on 2010-03-08:

#38

https://bugs.edge.launchpad.net/malone/+bug/534066 is perhaps a new variation of this that has just arisen.

James Westby (james-w) wrote on 2010-03-09:

#39

I believe all the API using code for apport can be found in

http://bazaar.launchpad.net/~apport-hackers/apport/trunk/annotate/head:/apport/crashdb_impl/launchpad.py

It all looks pretty straightforward to me.

You could grab lp:apport and try running the testsuite, and find and remove the
workarounds if it doesn't show the failures.

Thanks,

James

James Westby (james-w) wrote on 2010-03-09:

#40

So, Martin helpfully labelled all the places where workarounds were added,
we have them after

a.removeFromBug()

where a is an attachment

bug.newMessage

and changing bug.tags, which is one that I can't reproduce.

Thanks,

James

Leonard Richardson (leonardr) wrote on 2010-03-09:

#41

Download full text (3.2 KiB)

I know of two new bug fields that change behind-the-scenes automatically, bug_heat and task_age. task_age is going away, so let's ignore that. I'd like to fix bug_heat and then see if there's a separate problem to do with named operations.

Here's a paste of a message I posted to launchpad-dev about solving the bug_heat problem. I'm still working on this.

1. If a field is important enough to include in the representation, it's
important enough to include in the ETag. As Robert points out, omitting
a read-only field from the ETag will stop clients from knowing when the
value changes.

2. I like Bjorn's idea of a two-part ETag, where both parts are checked
for GET requests/caching, but only one part is checked for PATCH/PUT
requests. But, I don't think this would comply with the HTTP standard.

There are two types of ETags, "strong" and "weak". A strong ETag changes
whenever "the entity (the entity-body or any entity-headers) changes in
any way". A weak ETag changes "only on semantically significant changes,
and not when insignificant aspects of the entity change". These quotes
are from section 13.3.3.

Consider a two-part ETag, where one part describes the state of the
read-only fields and the other part describes the state of the
read-write fields. Taken together, the whole thing is a strong ETag.
Look at only the second part and you have a weak ETag.

But (13.3.3 again) "The only function that the HTTP/1.1 protocol defines
on [ETags] is comparison." There's no looking at the second half of an
ETag. The whole thing has to match.

OK, so let's define another function on ETags, another "weak comparison
function" which only looks at the second half of the ETag. That goes
beyond HTTP/1.1 but it doesn't contradict the standard. Now:

We would like to validate GET requests using the strong comparison
function (looking at the strong ETag), so that even minor changes will
invalidate the cache and the client will always have the most up-to-date
information. We would like to validate PATCH requests by using the weak
comparison function, so that irrelevant changes to the resource don't
affect the success of the PATCH.

But, the HTTP standard says we have to do the opposite. Section 14.26
says "The weak comparison function can only be used with GET or HEAD
requests."

The IETF draft that defines PATCH says, "Clients wishing to apply a
patch document to a known entity can first acquire the strong ETag of
the resource to be modified, and use that Etag in the If-Match header on
the PATCH request to verify that the resource is still unchanged."

As I read the standards, if bug_heat has changed and I try to PATCH an
unrelated field, the correct behavior is that my PATCH should fail. I
don't think this makes sense for us given the way we implement PATCH,
but it does make sense in general.

I don't think anything bad will happen if we implement the two-part
ETag. The whole ETag string is in fact a strong ETag, so anything that
treats it as a strong ETag will still work. We'll just have some
server-side magic that secretly implements a weak comparison function to
make PATCH requests work. And if anyone actually tries to PATCH bug_heat
they'll still get an error...

tags:	added: qa-ok removed: qa-needstesting
Changed in lazr.restfulclient (Ubuntu Lucid):
status:	Triaged → Invalid

lazr.restful

When adding tag or updating description, lp_save() gives "HTTP Error 412: Precondition Failed"

Bug Description

Related branches

Duplicates of this bug

Other bug subscribers

Bug attachments

Changed in lazr.restful:
status:	Confirmed → Fix Committed
tags:	added: qa-needstesting