[Bugs] #140 MINO: crash when joining a shared Read

[SugarLabs Bugs]

#140: crash when joining a shared Read
-----------------------+----------------------------------------------------
  Reporter:  gdesmott  |       Owner:  tomeu   
      Type:  defect    |      Status:  assigned
  Priority:  minor     |   Milestone:          
 Component:  Read      |     Version:          
Resolution:            |    Keywords:          
-----------------------+----------------------------------------------------
Changes (by morgs):

 * cc: tomeu (removed)
 * cc: morgs, marcopg (added)
  * owner:  morgs => tomeu
  * status:  new => assigned


Comment:

 This seems to be an issue in the (new) datastore.

 I reproduced it now with Read, using two sugar-jhbuild sessions.

 Session A shared Read with a PDF file, over salut. Session B joined, and
 failed. The following is all from session B.

 The top of the Read log contained:
 {{{
 1230065496.266677 DEBUG root: datastore.get
 1230065496.271796 DEBUG root: dbus_helpers.get_properties:
 d6244570-41a2-4857
 -8bf2-e208b94505ee
 }}}

 The first issue is that the file referenced is left over from a previous
 activity - note the earlier date of d62..ee.txt:
 {{{
 morgan at vaio:~/.sugar/two/data$ ls -l d62*
 -rw----r-- 5 morgan morgan 811011 2008-12-23 22:51
 d6244570-41a2-4857-8bf2-e208b94505ee_1.txt
 -rw----r-- 5 morgan morgan 811011 2008-12-23 22:51
 d6244570-41a2-4857-8bf2-e208b94505ee_2.txt
 -rw----r-- 1 morgan morgan    438 2008-12-19 16:44
 d6244570-41a2-4857-8bf2-e208b94505ee.txt
 }}}

 It contains metadata from Browse:
 {{{
 $ cat d6244570-41a2-4857-8bf2-e208b94505ee.txt
 {"deleted":[],"shared_links":[],"history":[{"url":"http://www.google.co.za/","title":"Google"},{"url":"http://www.google.co.za/search?hl=en&q=PDF&btnG=Google+Search&meta=","title":"PDF
 - Google
 Search"},{"url":"http://www.google.co.za/search?hl=en&q=site%3Awiki.laptop.org+pdf&btnG=Search&meta=","title":"site:wiki.laptop.org
 pdf - Google
 Search"},{"url":"http://wiki.laptop.org/go/Image:XO_demo.pdf","title":"Image:XO
 demo.pdf - OLPC"}]}
 }}}

 The next problem is that Read tries to resume this entry, even though we
 are joining a different activity. The Read log shows:

 {{{
 1230065496.727491 DEBUG root: dbus_helpers.get_filename:
 d6244570-41a2-4857-8bf2-e208b94505ee,
 /home/morgan/.sugar/two/data/d6244570-41a2-4857-8bf2-e208b94505ee_3.txt
 1230065496.730018 DEBUG read-activity: ReadActivity.read_file:
 /home/morgan/.sugar/two/data/d6244570-41a2-4857-8bf2-e208b94505ee_3.txt
 ---------------------------------------------------------------------------
 GError                                    Traceback (most recent call
 last)

 /home/morgan/sugar-jhbuild/install/lib/python2.5/site-
 packages/sugar/activity/activity.pyc in __canvas_map_cb(self=<ReadActivity
 object at 0x9f7b784 (SugarActivity at 0x9fbd038)>,
 canvas=<gtk.ScrolledWindow object at 0x9fa19b4 (GtkScrolledWindow at
 0xa29cda0)>)
     626     def __canvas_map_cb(self, canvas):
     627         if self._jobject and self._jobject.file_path:
 --> 628             self.read_file(self._jobject.file_path)
     629
     630     def __jobject_create_cb(self):

 /home/morgan/sugar-
 jhbuild/install/share/sugar/activities/Read.activity/readactivity.pyc in
 read_file(self=<ReadActivity object at 0x9f7b784 (SugarActivity at
 0x9fbd038)>,
 file_path=dbus.String(u'/home/morgan/.sugar/two/data/d6244570-41a2-4857-8bf2-e208b94505ee_3.txt'))
     277         os.link(file_path, tempfile)
     278         self._tempfile = tempfile
 --> 279         self._load_document('file://' + self._tempfile)
     280
     281         # FIXME: This should obviously be fixed properly

 /home/morgan/sugar-
 jhbuild/install/share/sugar/activities/Read.activity/readactivity.pyc in
 _load_document(self=<ReadActivity object at 0x9f7b784 (SugarActivity at
 0x9fbd038)>,
 filepath='file:///home/morgan/.sugar/two/org.laptop.sugar.ReadActivity/instance/tmp1230065496')
     445
     446         """
 --> 447         self._document = evince.factory_get_document(filepath)
     448         self._want_document = False
     449         self._view.set_document(self._document)

 GError: File type unknown (application/octet-stream) is not supported
 }}}

 This all might be the same issue as when we saw recent problems with Marco
 sharing Write, and me seeing Browse metadata in the document when joining
 instead of the Write document. It seems the datastore is providing a file
 to resume from some unrelated previous activity, when you are expecting to
 join an activity and start a new file.

 Anyway, evince fails to load the document so we continue. The failure
 which Guillaume and I ultimately experienced seems to be a result of the
 above, as Read has the following code:

 {{{
         # Assign a file path to download if one doesn't exist yet
         if not self._jobject.file_path:
             path = os.path.join(self.get_activity_root(), 'instance',
                                 'tmp%i' % time.time())
         else:
             path = self._jobject.file_path
 }}}

 The expected code path on joining is the first option, creating a
 temporary filename for the download to be saved as, but the second option
 happened, populating the filename with the existing datastore entry.

 Read then downloaded the PDF into that file. I expected it to be
 ~/.sugar/two/org.laptop.sugar.ReadActivity/instance/tmp1230065496 but the
 file was saved as
 ~/.sugar/two/data/d6244570-41a2-4857-8bf2-e208b94505ee_3.txt which was
 then presumably clobbered by the datastore write. That file was then
 presumed to be intact, which it normally is at that point, and evince
 failed to load it.

 Read log:
 {{{
 1230065515.549483 DEBUG read-activity: Downloaded 811008 of 811011 bytes
 from tube 1303825112...
 1230065516.254343 DEBUG read-activity: Downloaded 811011 of 811011 bytes
 from tube 1303825112...
 1230065516.259600 DEBUG read-activity: Saving file
 /home/morgan/.sugar/two/org.laptop.sugar.ReadActivity/instance/1230065516
 to datastore...
 1230065516.261071 DEBUG root: datastore.write
 1230065516.264935 DEBUG root: dbus_helpers.update:
 d6244570-41a2-4857-8bf2-e208b94505ee,
 /home/morgan/.sugar/two/org.laptop.sugar.ReadActivity/instance/1230065516,
 {dbus.String(u'activity_id'):
 dbus.ByteArray('002b931dc7a7ef5d66c5b2e676fb7dd6896b8ff8',
 variant_level=1), dbus.String(u'title_set_by_user'): dbus.ByteArray('1',
 variant_level=1), dbus.String(u'uid'):
 dbus.ByteArray('d6244570-41a2-4857-8bf2-e208b94505ee', variant_level=1),
 dbus.String(u'title'): dbus.ByteArray('Image:XO demo.pdf - OLPC',
 variant_level=1), dbus.String(u'timestamp'): 1230065516,
 dbus.String(u'checksum'):
 dbus.ByteArray('d345268c3611085aab5804040356516a', variant_level=1),
 dbus.String(u'activity'): dbus.ByteArray('org.laptop.WebActivity',
 variant_level=1), dbus.String(u'share-scope'): 'public',
 dbus.String(u'keep'): dbus.ByteArray('0', variant_level=1), dbus.String(u
 'icon-color'): dbus.ByteArray('#5E008C,#00EA11', variant_level=1),
 dbus.String(u'mtime'): '2008-12-23T20:51:56.264701',
 dbus.String(u'preview'): '<omitted>', dbus.String(u'mime_type'):
 dbus.ByteArray('text/plain', variant_level=1)}, True
 1230065516.341989 DEBUG root: Written object
 d6244570-41a2-4857-8bf2-e208b94505ee to the datastore.
 }}}

 So in summary: The Read sharing download worked fine, but something
 provided the activity with the wrong datastore id when it wasn't supposed
 to be resuming at all, leading to all kinds of fail.

-- 
Ticket URL: <http://dev.sugarlabs.org/ticket/140#comment:2>
Sugar Labs <http://sugarlabs.org/>
Sugar Labs bug tracking system