(RACE CONDITION, only happens for files of small size, < ~ 10KB) No file-completion signal at the receiver

[ajay_garg]

1. Initiate a file-transfer from the sender XO.

2. "Accept" the invitation at the receiver XO.

3. File gets transmitted (almost instanataneously) (note that it must be a file of small size). The file is also seen received in the journal at the receiving end.

4. However, at the receiving or the sending end, there is no "Dismiss" option (that signifies end-of-transfer).

5. Left with no choice, the receiver is forced to click the "Cancel" button.

6. The received file in the journal, gets deleted.

Again note, that this happens only for files of small size, and that too intermittently.

The issue did not surface even once, when I tested with MP3s (of the order of Megabytes.)

This (intermittent behaviour for small files) occurs on both os883.img and dx3g091.img.

Also, see screenshots.

[ajay_garg]

I need some help.

=================================================================================
Please find attached the following ::

1. culprit_success.log : shell.log contents, when a 860B file (init.py) is transferred successfully - that is, the "Dismiss" option is seen at the receiving end.

2. culprit_failure.log : shell.log contents, when the same 860B file (init.py) is transferred at the other end, but the "Dismiss" option is not seen; rather it hangs at "Cancel" at the receiving and the sending end.

=================================================================================

I have figured out the workflow disruption that happens in the case when the race condition is hit. It happens in

"def read_async_cb(self, input_stream, result)"

of file

"install/lib/python2.7/site-packages/jarabe/model/filetransfer.py".

After the first successful "data = input_stream.read_finish(result)" that reads in 860B, the call never comes again to "data = input_stream.read_finish(result)" that should try to read in the next (zero) bits - which would then cause the input_stream to be closed.

I tried simplifying the class definition of "class StreamSplicer(gobject.GObject)" from

#############################################################
class StreamSplicer(gobject.GObject):

_CHUNK_SIZE = 10240 # 10K
gsignals = {

'finished': (gobject.SIGNAL_RUN_FIRST,

gobject.TYPE_NONE,
([])),

}

def init(self, input_stream, output_stream):

gobject.GObject.init(self)

self._input_stream = input_stream
self._output_stream = output_stream
self._pending_buffers = []

def start(self):

self._input_stream.read_async(self._CHUNK_SIZE, self.read_async_cb,

gobject.PRIORITY_LOW)

def read_async_cb(self, input_stream, result):

data = input_stream.read_finish(result)

if not data:

logging.debug('closing input stream')
self._input_stream.close()

else:

self._pending_buffers.append(data)
self._input_stream.read_async(self._CHUNK_SIZE,

self.read_async_cb,
gobject.PRIORITY_LOW)

self._write_next_buffer()

def write_async_cb(self, output_stream, result, user_data):

count_ = output_stream.write_finish(result)

if not self._pending_buffers and \

not self._output_stream.has_pending() and \
not self._input_stream.has_pending():

logging.debug('closing output stream')
output_stream.close()
self.emit('finished')

else:

self._write_next_buffer()

def _write_next_buffer(self):

if self._pending_buffers and not self._output_stream.has_pending():

data = self._pending_buffers.pop(0)
# TODO: we pass the buffer as user_data because of
# ​http://bugzilla.gnome.org/show_bug.cgi?id=564102
self._output_stream.write_async(data, self.write_async_cb,

gobject.PRIORITY_LOW,
user_data=data)

#############################################################

to

#############################################################
class StreamSplicer(gobject.GObject):

_CHUNK_SIZE = 10240 # 10K
gsignals = {

'finished': (gobject.SIGNAL_RUN_FIRST,

gobject.TYPE_NONE,
([])),

}

def init(self, input_stream, output_stream):

gobject.GObject.init(self)

self._input_stream = input_stream
self._output_stream = output_stream

def start(self):

self._input_stream.read_async(self._CHUNK_SIZE, self.read_async_cb,

gobject.PRIORITY_LOW)

def read_async_cb(self, input_stream, result):

data = input_stream.read_finish(result)

if not data:

logging.debug('closing input stream')
self._input_stream.close()
logging.debug('closing output stream')
self._output_stream.close()

else:

self._output_stream.write_async(data, self.write_async_cb,

gobject.PRIORITY_LOW,
user_data=data)

def write_async_cb(self, output_stream, result, user_data):

output_stream.write_finish(result)
self._input_stream.read_async(self._CHUNK_SIZE,

self.read_async_cb,
gobject.PRIORITY_LOW)

#############################################################

but i still managed to get the same intermittent buggy behaviour.

=================================================================================

I am now trying to understand the backend-architecture of send-to-friend feature, and I am not able to figure out the following ::

In the call

"datastore.write(self._ds_object, transfer_ownership=True,

reply_handler=self.reply_handler_cb,
error_handler=self.error_handler_cb)"

and

"datastore.write(self._ds_object, update_mtime=False)"

in "class IncomingTransferButton" in "install/lib/python/site-packages/jarabe/frame/activitiestray.py"

we don't seem to pass any bytes, that could be written on the datastore. I have the intuition that at the time of creating the "self._ds_object" when the OPEN state callback is called, there is somehow a link established between the "self._ds_object" and the "file-transfer" channel; however, I am not sure, and neither am I able to "find" any code which might give a clue to this. (I only see "self._ds_object = datastore.create()" in "class IncomingTransferButton", with absolutely no hint of the linkage between the self._ds_object and the file-transfer-channel/socket/bytes-read-in.).

I will be grateful, if someone could please point me to any information regarding the architecture of this feature (at a technical/code level; however, I do not need any step-by-step code explanation :) ). In particular, if I can know how the linkage to "datastore.write()" and the bytes-read-in-from-the-gio.Unix.InputStream-socket is done, the pieces will fit in together.

Meanwhile, I will continue looking for any "hints in the code" to see the linkage between the "self._ds_object" and the bytes-read-in-from-the-socket.

=================================================================================

[ajay_garg]

Attaching the "culprit" file "init.py" (size : 860 bits), that has been used for testing.

[ajay_garg]

Replying to ajay_garg:

Attaching the "culprit" file "init.py" (size : 860 bits), that has been used for testing.

Pardon me.. the size is 860 bytes.

[ajay_garg]

The changed definition for "class StreamSplicer" does work (earlier I had replaced the file only at the receiving side). After replacing the file at both the sending, AND the receiving side, I did not face the issue, even after about 30 quick-succession tests of sending and receiving the same 860 bytes "init.py" file.

The patch has been posted at ​http://patchwork.sugarlabs.org/patch/1132/

[ajay_garg]

Attaching the patch, after changing patch description (courtesy Sascha)

[dnarvaez]

We are not taking patches in trac anymore. Please submit a pull request.

[dnarvaez]

Milestone 0.94 deleted