natevw / sdcard

Tessel library for the SD card module.
Other
11 stars 2 forks source link

writing a file is insanely slow every other time #5

Closed Frijol closed 10 years ago

Frijol commented 10 years ago

Here's the code I'm running:

/*********************************************
This MicroSD card example writes a text file
to the sd card, then reads the file to the
console.
*********************************************/

var tessel = require('tessel');
var sdcard = require('sdcard').use(tessel.port['A']);

sdcard.on('ready', function() {
  sdcard.getFilesystems(function(err, fss) {
    var fat = fss[0];
    console.log('Writing...');
    fat.writeFile('someFile.txt', 'Hey Tessel SDCard!', function(err) {
      console.log('Write complete. Reading...');
      fat.readFile('someFile.txt', function(err, data) {
        console.log('Read:\n', data.toString());
      });
    });
  });
});

On odd-numbered runs, this works pretty fast; on even-numbered runs, it hangs on Writing... for a really long time.

natevw commented 10 years ago

Interesting. This might just be a side-effect of #4 being unimplemented — even a small write needs to zero out a whole bunch of blocks on the card and we're doing that very slowly right now. The every-other thing is odd though; I'm not quite sure if I'm seeing it or not, but will try take a fresh look and with some logging on in the morning.

natevw commented 10 years ago

Hmm, I added an "examples/timed_microsd.js" adding a simple log of elapsed Date.now() between fs ready and readFile complete:

with debug logs

TIME: 83054.886 TIME: 82414.484 TIME: 82800.654

without debug logs

TIME: 73862.746 TIME: 75153.119 TIME: 74271.109

I'll run a few more tests to see if the variance is in card initialization, but regardless this needs to be faster.

natevw commented 10 years ago

I am unable to reproduce the every-other timings on a TM-00-02 with latest public firmware, could you try "examples/timed_microsd.js" with your setup?

time 11756.669 Writing... Write complete. Reading... Read: Hey Tessel SDCard! :TIME: 74896.134

time 11757.429 Writing... Write complete. Reading... Read: Hey Tessel SDCard! :TIME: 74982.382

Frijol commented 10 years ago

Hmm, I'm not seeing the effect anymore either.

➜  examples git:(master) tessel run timed_microsd.js
TESSEL! Connected to TM-00-04-f000da30-00514f3b-38642586.
INFO Bundling directory /Users/timryan/modules/sdcard (~224.48 KB)
INFO Deploying bundle (468.50 KB)...
INFO Running script...
_time_ 11552.901
Writing...
Write complete. Reading...
Read:
 Hey Tessel SDCard!
:TIME: 69035.346
^CINFO Script aborted
➜  examples git:(master) tessel run timed_microsd.js
TESSEL! Connected to TM-00-04-f000da30-00514f3b-38642586.
INFO Bundling directory /Users/timryan/modules/sdcard (~224.48 KB)
INFO Deploying bundle (468.50 KB)...
INFO Running script...
_time_ 11435.117
Writing...
Write complete. Reading...
Read:
 Hey Tessel SDCard!
:TIME: 68634.65
^CINFO Script aborted
➜  examples git:(master) tessel run timed_microsd.js
TESSEL! Connected to TM-00-04-f000da30-00514f3b-38642586.
INFO Bundling directory /Users/timryan/modules/sdcard (~224.48 KB)
INFO Deploying bundle (468.50 KB)...
INFO Running script...
_time_ 11495.502
Writing...
Write complete. Reading...
Read:
 Hey Tessel SDCard!
:TIME: 68484.697
^CINFO Script aborted
➜  examples git:(master) tessel run timed_microsd.js
TESSEL! Connected to TM-00-04-f000da30-00514f3b-38642586.
INFO Bundling directory /Users/timryan/modules/sdcard (~224.48 KB)
INFO Deploying bundle (468.50 KB)...
INFO Running script...
_time_ 11528.83
Writing...
Write complete. Reading...
Read:
 Hey Tessel SDCard!
:TIME: 68753.715
^CINFO Script aborted

Guess I'll close the issue. Thanks for looking into it.

natevw commented 10 years ago

No prob, it is insanely slow but fine to close since we have #7 now too. Thanks for the report!

natevw commented 10 years ago

Update on this: the "sometimes slower than other" was probably when the file already existed (truncating it before the write would be super slow) — so there was something to the "every-other-time". This is variously fixed with https://github.com/natevw/fatfs/issues/10