#2522 BLOC Trial-2: Hard hang seen in sugar (presence-service?)

[Zarro Boogs per Child]

#2522: Hard hang seen in sugar (presence-service?)
-------------------------------+--------------------------------------------
  Reporter:  cjb               |       Owner:  morgs  
      Type:  defect            |      Status:  new    
  Priority:  blocker           |   Milestone:  Trial-2
 Component:  presence-service  |     Version:         
Resolution:                    |    Keywords:         
  Verified:  0                 |  
-------------------------------+--------------------------------------------
Changes (by morgs):

 * cc: jg (added)

Comment:

 Unable to duplicate this behaviour. What I can tell from the logs is:

 in shell.log there were many repeated tracebacks with this:

 {{{
 1185481821.0844 WARNING - sugar.presence.presenceservice: Unable to
 retrieve activity handle for
 dbus.String(u'a46c3c36c418e621e16d8e14b7ce39ebc2787b7b') from presence
 service: org.laptop.Sugar.Presence.NotFound: Traceback (most recent call
 last):
   File "/usr/lib/python2.5/site-packages/dbus/service.py", line 664, in
 _message_cb
     retval = candidate_method(self, *args, **keywords)
   File "/usr/share/sugar-presence-service/presenceservice.py", line 582,
 in GetActivityById
     raise NotFoundError("The activity was not found.")
 NotFoundError: org.laptop.Sugar.Presence.NotFound: The activity was not
 found.
 }}}

 We do need to add in some sort of back-off control for repeated errors,
 but that will be quite invasive and too risky for Trial 2.

 The actual cause seems to be that `nelhage` was repeatedly connecting and
 disconnecting from the server, causing many instances of this in jg's
 presenceservice.log - and each triggering the abovementioned failure:

 {{{
 1185481703.8657 DEBUG - s-p-s.telepathy_plugin: <ServerPlugin object
 (telepathy_plugin+TelepathyPlugin) at 0x82a4f2c>: Contacts now online:
 1185481703.8681 DEBUG - s-p-s.telepathy_plugin:   765
 .../keyid/67eaaa6796a64bd0005e96c785d703b65e0b8d3a
 1185481703.8703 DEBUG - s-p-s.presenceservice: Handle 765,
 .../keyid/67eaaa6796a64bd0005e96c785d703b65e0b8d3a is now online
 1185481703.8726 DEBUG - s-p-s.presenceservice: Creating new buddy at
 .../keyid/67eaaa6796a64bd0005e96c785d703b65e0b8d3a
 1185481704.5009 DEBUG - s-p-s.presenceservice: New Buddy: nelhage
 (#00A0FF,#B20008)
 1185481704.8158 DEBUG - s-p-s.presenceservice: Handle 765 activities
 changed: {}
 1185481708.3214 DEBUG - s-p-s.presenceservice: Handle 765 activities
 changed: {}
 1185481712.6672 DEBUG - s-p-s.telepathy_plugin: <ServerPlugin object
 (telepathy_plugin+TelepathyPlugin) at 0x82a4f2c>: Contacts now offline:
 set([dbus.UInt32(765L)])
 1185481712.6793 DEBUG - s-p-s.presenceservice: Buddy left: nelhage
 (#00A0FF,#B20008)
 1185481742.4628 DEBUG - s-p-s.telepathy_plugin: <ServerPlugin object
 (telepathy_plugin+TelepathyPlugin) at 0x82a4f2c>: Contacts now offline:
 set([dbus.UInt32(753L)])
 }}}

 At this stage I can't tell if nelhage was running something abnormal
 causing the repeated connects and disconnects. It could be he was running
 an older version of the PS which didn't have the back-off delay on server
 connection failures. If so, that won't happen in the wild.

 I recommend bumping this to Trial 3/normal, for looking at adding the
 backoff delay on repeated PS failures.

-- 
Ticket URL: <http://dev.laptop.org/ticket/2522#comment:4>
One Laptop Per Child <http://laptop.org/>