Landscape Client

broker fails on startup with "HTTPCodeError: Server returned HTTP code 0"

Bug #567515 reported by Andreas Hasenack on 2010-04-20

This bug affects 1 person

	Status	Importance	Assigned to	Milestone
Landscape Client	Fix Released	Critical	Thomas Herve	Landscape Client 1.5.1
landscape-client (Ubuntu)	Fix Released	Undecided	Unassigned
Jaunty	Fix Released	Undecided	Unassigned
Karmic	Fix Released	Undecided	Unassigned
Lucid	Fix Released	Undecided	Unassigned

Bug Description

Etienne reported that the official landscape karmic instance he started more than 1h ago wasn't communicating with Landscape (AMI-1515F67C, us-east). I tried to start it too and got this error in the broker log, and also when starting landscape-client interactively:
2010-04-20 20:28:50,961 INFO [MainThread] Broker started on 'system' bus with config /etc/landscape/client.conf
2010-04-20 20:28:51,023 ERROR [MainThread] None
Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/twisted/python/threadpool.py", line 210, in _worker
    result = context.call(ctx, function, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/twisted/python/context.py", line 59, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python2.6/dist-packages/twisted/python/context.py", line 37, in callWithContext
    return func(*args,**kw)
  File "/usr/lib/python2.6/dist-packages/landscape/lib/fetch.py", line 86, in fetch
    raise HTTPCodeError(http_code, body)
HTTPCodeError: Server returned HTTP code 0
2010-04-20 20:29:50,965 INFO [MainThread] Starting urgent message exchange with https://landscape.canonical.com/message-system.
2010-04-20 20:29:52,325 INFO [Dummy-1 ] Sent 549 bytes and received 146 bytes in 1.36s.
2010-04-20 20:29:52,328 INFO [MainThread] Switching to normal exchange mode.
2010-04-20 20:29:52,330 INFO [MainThread] Server UUID changed (old=None, new=af6f2dcf-1967-11de-8dd0-001a4b4d8d10).
2010-04-20 20:29:52,332 INFO [MainThread] Accepted types changed: +test +register +register-cloud-vm
2010-04-20 20:29:52,334 INFO [MainThread] Starting message exchange with https://landscape.canonical.com/message-system.
2010-04-20 20:29:52,334 INFO [MainThread] Message exchange completed in 1.37s.
2010-04-20 20:29:53,582 INFO [Dummy-1 ] Sent 549 bytes and received 70 bytes in 1.25s.
2010-04-20 20:29:53,587 INFO [MainThread] Message exchange completed in 1.25s.
2010-04-20 20:37:16,044 INFO [MainThread] Broker stopped on 'system' bus with config /etc/landscape/client.conf
2010-04-20 20:37:17,780 INFO [MainThread] Broker started on 'system' bus with config /etc/landscape/client.conf
2010-04-20 20:37:17,836 ERROR [MainThread] None
Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/twisted/python/threadpool.py", line 210, in _worker
    result = context.call(ctx, function, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/twisted/python/context.py", line 59, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python2.6/dist-packages/twisted/python/context.py", line 37, in callWithContext
    return func(*args,**kw)
  File "/usr/lib/python2.6/dist-packages/landscape/lib/fetch.py", line 86, in fetch
    raise HTTPCodeError(http_code, body)
HTTPCodeError: Server returned HTTP code 0
2010-04-20 20:37:32,824 INFO [MainThread] Broker stopped on 'system' bus with config /etc/landscape/client.conf
2010-04-20 20:37:40,105 INFO [MainThread] Broker started on 'system' bus with config /etc/landscape/client.conf
2010-04-20 20:37:40,139 ERROR [MainThread] None
Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/twisted/python/threadpool.py", line 210, in _worker
    result = context.call(ctx, function, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/twisted/python/context.py", line 59, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python2.6/dist-packages/twisted/python/context.py", line 37, in callWithContext
    return func(*args,**kw)
  File "/usr/lib/python2.6/dist-packages/landscape/lib/fetch.py", line 86, in fetch
    raise HTTPCodeError(http_code, body)
HTTPCodeError: Server returned HTTP code 0
2010-04-20 20:38:22,274 INFO [MainThread] Broker stopped on 'system' bus with config /etc/landscape/client.conf

Don't know yet what is going on. Etienne then said he started two more karmic instances, and one of them eventually worked.

Related branches

lp:~therve/landscape-client/broken-ec2-api-endpoint

Merged into lp:~landscape/landscape-client/trunk

Free Ekanayaka (community): Approve on 2010-04-21

Kevin McDermott (community): Approve on 2010-04-21

lp:~free.ekanayaka/landscape-client/lucid-1.5.0.1-0ubuntu0.10.04.0

lp:~free.ekanayaka/landscape-client/jaunty-1.5.0.1-0ubuntu0.9.04.0

lp:~free.ekanayaka/landscape-client/karmic-1.5.0.1-0ubuntu0.9.10.0

lp:ubuntu/lucid/landscape-client

lp:ubuntu/jaunty-proposed/landscape-client

lp:ubuntu/karmic-proposed/landscape-client

Revision history for this message

Andreas Hasenack (ahasenack) wrote on 2010-04-20:

This is the user-data from that running instance which has landscape-client backtracing:
root@ip-10-242-58-193:~# curl http://169.254.169.254/1.0/user-data/;echo
ds12:exchange-urls46:https://landscape.canonical.com/message-systems4:otpsls64:X9bqtt30Ja64x6uLgiRz0VnlyCbc4nsx85k0NKW78SYdB2BxaZ4ZrcFNI8lrqr6I;s8:ping-urls35:http://landscape.canonical.com/ping;

I also tried upgrading to landscape-client 1.4.4, same error.

Changed in landscape:
importance:	Undecided → Critical
milestone:	none → 1.5.1

Revision history for this message

Thomas Herve (therve) wrote on 2010-04-21:

OK... I know what's going on, but I wish I don't. I tried to reproduce it a couple of times, and it seems random. For example, adding a tcpdump in parallel makes the issue disappear. Finally I added some debugging in the fetch call in Landscape, and here's what I saw returned by the EC2 API server:

2010-04-21 07:21:14: (server.c.1357) [note] sockets disabled, connection limit reached \nHTTP/1.0 200 OK\r\nContent-Type: application/octet-stream\r\nAccept-Ranges: bytes\r\nETag: "1976824587"\r\nLast-Modified: Wed, 21 Apr 2010 07:10:35 GMT\r\nContent-Length: 195\r\nConnection: close\r\nDate: Wed, 21 Apr 2010 07:21:14 GMT\r\nServer: EC2ws\r\n\r\nds12:exchange-urls46:https://landscape.canonical.com/message-systems4:otpsls64:hv1dsip9GPOCp6Qgs0kdCEQuT248rTM6IgYaX1VEDzz6ovu1I70QfqJL0eAiXFXs;s8:ping-urls35:http://landscape.canonical.com/ping;

Basically, it adds a stupid warning *in the middle of the body response*: "2010-04-21 07:21:14: (server.c.1357) [note] sockets disabled, connection limit reached \n"

I guess Amazon changed his backend to limit the number of parallel connections. Or maybe they're having high load. Of course, it's completely retarded that it appears in the middle of response.

The solution is to run those HTTP calls one by one instead of in parallel.

affects:	landscape → landscape-client
Changed in landscape-client:
milestone:	1.5.1 → none

Thomas Herve (therve) on 2010-04-21

Changed in landscape-client:
assignee:	nobody → Thomas Herve (therve)
milestone:	none → 1.5.1
status:	New → In Progress

Thomas Herve (therve) on 2010-04-22

Changed in landscape-client:
status:	In Progress → Fix Committed

Free Ekanayaka (free.ekanayaka) on 2010-04-23

visibility:

private → public

Revision history for this message

Launchpad Janitor (janitor) wrote on 2010-04-23:

This bug was fixed in the package landscape-client - 1.5.0.1-0ubuntu0.10.04.0

---------------
landscape-client (1.5.0.1-0ubuntu0.10.04.0) lucid; urgency=low

  * New upstream version
    - Fix smart-update failing its very first run (LP: #562496)
    - Depend on pythonX.Y-dbus and pythonX.Y-pycurl (LP: #563063)
    - Make only one request at a time to retrieve EC2 instances (LP: #567515)
-- Free Ekanayaka <email address hidden> Wed, 21 Apr 2010 12:31:28 +0200

Changed in landscape-client (Ubuntu Lucid):
status:	New → Fix Released

Revision history for this message

Martin Pitt (pitti) wrote on 2010-05-09: Please test proposed package

Accepted landscape-client into karmic-proposed, the package will build now and be available in a few hours. Please test and give feedback here. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you in advance!

Changed in landscape-client (Ubuntu Karmic):
status:	New → Fix Committed
tags:	added: verification-needed
Changed in landscape-client (Ubuntu Jaunty):
status:	New → Fix Committed

Revision history for this message

Martin Pitt (pitti) wrote on 2010-05-09:

Accepted landscape-client into jaunty-proposed, the package will build now and be available in a few hours. Please test and give feedback here. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you in advance!

Andreas Hasenack (ahasenack) on 2010-05-10

tags:

added: needs-testing

Revision history for this message

Launchpad Janitor (janitor) wrote on 2010-05-18:

This bug was fixed in the package landscape-client - 1.5.0.1-0ubuntu0.9.04.0

---------------
landscape-client (1.5.0.1-0ubuntu0.9.04.0) jaunty-proposed; urgency=low

  * New upstream version (LP: #557244)
    - Fix package-changer running before smart-update has completed (LP: #542215)
    - Report the version of Eucalyptus used to generate topology data (LP: #554007)
    - Enable the Eucalyptus plugin by default, if supported (LP: #546531)
    - Use a whitelist of allowed filesystem types to instead of a blacklist (LP: #351927)
    - Report the update-manager logs to the server (LP: #503384)
    - Turn off Curl's DNS caching for requests. (LP: #522668)
-- Free Ekanayaka <email address hidden> Wed, 21 Apr 2010 12:31:28 +0200

Changed in landscape-client (Ubuntu Jaunty):
status:	Fix Committed → Fix Released

Revision history for this message

Launchpad Janitor (janitor) wrote on 2010-05-18:

This bug was fixed in the package landscape-client - 1.5.0.1-0ubuntu0.9.10.0

---------------
landscape-client (1.5.0.1-0ubuntu0.9.10.0) karmic-proposed; urgency=low

Changed in landscape-client (Ubuntu Karmic):
status:	Fix Committed → Fix Released

Andreas Hasenack (ahasenack) on 2010-06-09

Changed in landscape-client:
status:	Fix Committed → Fix Released

Andreas Hasenack (ahasenack) on 2010-08-23

tags:

removed: needs-testing verification-needed

Revision history for this message

Martin Pitt (pitti) wrote on 2010-08-23: Re: [Bug 567515] Re: broker fails on startup with "HTTPCodeError: Server returned HTTP code 0"

Andreas Hasenack [2010-08-23 17:38 -0000]:
> ** Tags removed: needs-testing verification-needed

Andreas, why did you remove all the v-needed tasks?

Martin

Revision history for this message

Andreas Hasenack (ahasenack) wrote on 2010-08-23: Re: [Bug 567515] Re: broker fails on startup with "HTTPCodeError: Server returned HTTP code 0"

Because these packages were already released, no?

Martin Pitt <email address hidden> wrote:

>Andreas Hasenack [2010-08-23 17:38 -0000]:
>> ** Tags removed: needs-testing verification-needed
>
>Andreas, why did you remove all the v-needed tasks?
>
>Martin
>
>--
>broker fails on startup with "HTTPCodeError: Server returned HTTP code 0"
>https://bugs.launchpad.net/bugs/567515
>You received this bug notification because you are a direct subscriber
>of the bug.
>

Revision history for this message

Martin Pitt (pitti) wrote on 2010-08-24:

#10

Andreas Hasenack [2010-08-23 22:54 -0000]:
> Because these packages were already released, no?

Ah, those were the older updates, I see. We don't usually care about
closed bug tags.

Martin
--
Martin Pitt | http://www.piware.de
Ubuntu Developer (www.ubuntu.com) | Debian Developer (www.debian.org)

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

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