Sdk: Dart File.writeAsString() method does not write to file if await is not done immediately

[renatoathaydes]

• Dart SDK Version (dart --version)

Dart VM version: 2.2.0 (Unknown timestamp) on "linux_x64"

• Whether you are using Windows, MacOSX, or Linux (if applicable)

Linux 4.4.0-139-generic #165-Ubuntu SMP Wed Oct 24 10:58:50 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

• Whether you are using Chrome, Safari, Firefox, Edge (if applicable)

N/A

---

I have the following Dart code that doesn't behave as I expected:

final File file = File("result.csv");

Future send(String message) async {
  try {
    await file.writeAsString(message + '\n',
        mode: FileMode.append, flush: true);
  } catch (e) {
    print("Error: $e");
  }
  return await file.length();
}

main() async {
  final futures = <Future>[];
  for (int i = 0; i < 100; i++) {
    futures.add(send("$i"));
  }
  for (int i = 0; i < 100; i++) {
    print(await futures[i]);
  }
}

Expected behaviour

I expected the file to be written as soon as each call to await futures[i] in the second loop returned. However this does not seem to be happening.

The file should contain one line for each index from 0 to 99.

The length of the file that is printed on each iteration of the await loop should show the file's length increasing on each call. Example:

3
6
9
12
...

Observed behaviour

Only the last call in the loop seems to write to the file. The resulting file contains a line with 99 followed by an empty line.

The print calls in the second loop always print the same file length, 3:

3
3
3
3
...

The event loop seems to be somehow merging the calls and only actually executing the last call, even though I still get 100 different futures that I await in the second loop.

The argument for each call to file.writeAsString() is different on every call, so there should be no merging happening.

If the code is modified to await on each call to send(), then the expected behaviour is observed, but that means the caller of send() cannot proceed without waiting for the file to be written to, which is not the desired behaviour (the caller does wait later, in the second loop).

Posted on StackOverflow: https://stackoverflow.com/questions/54958346/dart-file-writeasstring-method-does-not-write-to-file-if-await-is-not-done-imm

---

[lrhn]

You are asking the operating system to append to a file 100 times, before any of them get the chance to actually do the append. So, all of them see the existing zero-length file, then all of them increase the length, and then all of them write into the newly allocated space, overwriting each other.
Which write finally succeeds is random (mine was 97, then 99).

The documentation for O_APPEND says that a file opened with that must seek to the end of the file before each write, and the seek and write are atomic. It seems that the dart:io write operations with append mode are not using O_APPEND (a realtively safe bet since O_APPEND does not occur in the source code).
We should probably make it do that, so appending has the expected behavior.

[renatoathaydes]

Thank you very much for the answer. I had already opened a question on StackOverflow, if you'd like to add details there later (or when the issue is resolved) it could be helpful for others: https://stackoverflow.com/questions/54958346/dart-file-writeasstring-method-does-not-write-to-file-if-await-is-not-done-imm

[sortie]

Yeah it doesn't look like appending is actually implemented in the Dart SDK. I'll turn this bug into a request for implementing the appending behavior.

[sortie]

Alright, I understand how FileMode.append is implemented. It is implemented, but not quite as I expected. The file handled is seeked to the end after it's opened. That's why it's possible that the send() calls all write to the start of the file, which is where they were opened. If they are done sequentially, the correct file offset is used.

The current documentation for FileMode.append is:

/// Mode for opening a file for reading and writing to the
/// end of it. The file is created if it does not already exist.
static const append = const FileMode._internal(2);

This technically doesn't mention the append semantics, though "writing to the end of it" does a bit suggest the O_APPEND POSIX semantics.

The action items I see here is perhaps clarifying the documentation and potentially implementing the O_APPEND mode (and its Windows equivalent) as this is a useful feature for things like log files and such (although ensuring concurrent long writes to those files are atomic and don't interleave may not be possible without file locking).

[attdona]

If I understand correctly the problem is in the actual File implementation.

File.writeAsString calls writeAsBytes that opens each time the file:

Future<File> writeAsBytes(List<int> bytes,
    {FileMode mode: FileMode.write, bool flush: false}) {
  return open(mode: mode).then((file) {
    return file.writeFrom(bytes, 0, bytes.length).then<File>((_) {
      if (flush) return file.flush().then((_) => this);
      return this;
    }).whenComplete(file.close);
  });
}

If open allocates a new file descriptor with open(2) then synchronization is not possible.

[sortie]

Synchronization is possible using if O_APPEND at the open(2) system call level since that atomically sets the file offset to the file's length and does the write.

[renatoathaydes]

I experienced this problem also when I was calling file.open(FileMode.write) ... before... I changed to writeAsString() imagining it would help.... pretty sure the same thing happened in both cases.

[renatoathaydes]

This program in Go, which should be roughly equivalent to the Dart one, writes every line (though out-of-order, as I expected) and prints the expected output:

package main

import (
    "fmt"
    "os"
    "sync"
)

const filename = "results.txt"

func main() {
    var wg sync.WaitGroup
    wg.Add(100)
    for i := 0; i < 100; i++ {
        go send(fmt.Sprintln(i), &wg)
    }
    wg.Wait()
    print("Done")
}

func send(msg string, wg *sync.WaitGroup) {
    defer wg.Done()
    f, err := os.OpenFile(filename, os.O_APPEND|os.O_WRONLY|os.O_CREATE, 0600)
    if err != nil {
        panic(err)
    }
    defer f.Close()
    _, err = f.WriteString(msg)
    if err != nil {
        panic(err)
    }
    stat, err := f.Stat()
    if err != nil {
        panic(err)
    }
    fmt.Println(stat.Size())
}

[attdona]

Synchronization is possible using if O_APPEND at the open(2) system call level since that atomically sets the file offset to the file's length and does the write.

Yes, I confirm. I was reproducing the problem in C using a wrong combination of open(2) flags/mode that make me wrong about open(2) behavoir.

Sorry for the noise!

[b-cancel]

I believe this might help someone
The example is for writing to a file but can easily be adapted to appending

Basically here I'm handling things myself so that I don't have to rely on the system to handle it for me
I needed this because, in my program, I am sometimes writing to the file many times per every 2 or 3 seconds
Ever so often I would get an invalid data format (since I am encoding into JSON)
Since I am writing multiple times within a short span of time and since what I am writing is at times large
Sometimes I would request a write before the previous had completed
And this would cause my file to have a weird mesh of both request and break things

I could have used writeAsStringSync (which I imagine would have fixed this problem) but I didn't want to slow anything down since the data being saved is just for the user's convenience
So, If they lose their last edit then no big deal
BUT if the app slows down then I'm DEFINITELY making things LESS convenient NOW just so that I can MAYBE make things MORE convenient LATER...
Which is not a good trade-off (for me)

So I instead opted for simply creating a request Write function that I called "safeSave"
It simply saves all the request to a queue and then another function is constantly trying to empty the queue

You could just finish the current request and then process the next newest one
EX: REQ1 [processing] , REQ2[no longer in memory], REQ 3[processing after REQ1]
which is what I'll end up doing after this but this worked for me

import 'dart:collection';
import 'dart:io';

Map<File, Queue<String>> fileToWriteRequests = new Map<File, Queue<String>>();
Map<File, bool> fileToIsWriting = new Map<File, bool>();

//NOTE: this assumes that the file atleast exists
safeSave(File file, String data){
  //this is the first time we are told to write to this particular file
  //so we create the slot for it
  if(fileToWriteRequests.containsKey(file) == false){
    fileToWriteRequests[file] = new Queue<String>();
    fileToIsWriting[file] = false;
  }

  //add this to the queue
  fileToWriteRequests[file].add(data);

  //check if this file is already being written to asyncronously
  //IF it is then eventually this write request will process
  //ELSE begin the process
  if(fileToIsWriting[file] == false){
    fileToIsWriting[file] = true;
    startProcessingRequests(file);
  }
}

startProcessingRequests(File file)async{
  //keep processing write request until the queue is empty
  while(fileToWriteRequests[file].isNotEmpty){
    //grab the next bit of data to write
    String dataToWrite = fileToWriteRequests[file].removeFirst();

    //write it
    //1. keeps things asynchronous for less app jitter
    //2. in the worst case we lose some data (very little)
    await file.writeAsString(
      dataToWrite,
      //overwrite the file if its already been written to and opens it only for writing
      mode: FileMode.writeOnly,
      //ensure data integrity but takes a bit longer
      flush: true,
    );
  }

  //queue is empty and writing is complete
  fileToIsWriting[file] = false;
}

[b-cancel]

Here is the version that just keeps track of 2 things

1. whether the file is being written to or not
2. what is the last string that wanted to be written but could not because the file was being written to already

import 'dart:io';

//keep track of the files current being written to
Set<File> filesWeAreWritingTo = new Set<File>();

//keep track of the newest waiting data
Map<File, String> fileToNextDataToBeWritten  = new Map<File, String>();

//NOTE: this assumes that the file atleast exists
safeSave(File file, String data){
  //If the file is already being written to
  if(filesWeAreWritingTo.contains(file)){
    //save our data for writing after it completes
    //NOTE: may have overwritten old waiting data
    fileToNextDataToBeWritten[file] = data;
  }
  else _writeToFile(file, data);
}

//write to file is a seperate function so we can easily recurse
_writeToFile(file, data) async {
  //mark this file as being written into
  filesWeAreWritingTo.add(file);

  //write into it
  await file.writeAsString(
    data,
    //overwrite the file if its already been written to and opens it only for writing
    mode: FileMode.writeOnly,
    //ensure data integrity but takes a bit longer
    flush: true,
  );

  //once finished check if something else was waiting
  if(fileToNextDataToBeWritten.containsKey(file)){
    //grab data waiting
    String data = fileToNextDataToBeWritten.remove(file);
    //NOTE: we keep the being written to flag on
    _writeToFile(file, data);
  }
  else{ //we finished writing to this file (for now)
    filesWeAreWritingTo.remove(file);
  }
}