crash when joining a shared Read

[gdesmott]

Got this crash when joining a shared instance. Something *could* have been wrong during the transfer (I'm debugging sock5 stream tubes) but Read shoudn't crash anyway.

[morgs]

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@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.

[tomeu]

I think I got it, please retest.