Race condition in Dancer

[choroba]

I had been running a Dancer application for several weeks. Everything was fine, with just occasional complaints in the log about invalid combination of form parameters (I dutifully validate both on client and server sides, so probably some users have disabled their JavaScript). But then, suddenly, the log contained several instances of the following error message:

[14166] error @0.102147> [hit #336]request to GET / crashed: YAML Erro
+r: Invalid element in map
   Code: YAML_LOAD_ERR_BAD_MAP_ELEMENT
   Line: 315
   Document: 1
 at /opt/perl5.14/lib/site_perl/5.14.2/YAML/Loader.pm line 352. in /op
+t/perl5.14/lib/site_perl/5.14.2/Dancer/Handler.pm l. 98

The application uses Dancer::Session::YAML to create and store persistent sessions. I easily identified the problematic session file (I add access time to a session) and found the problem at the end of the file:

...
      question:
        - "You can select more than one answer.\n"
e answer.\n"

Ouch! Seems like the file has been overwritten without being truncated first. The application runs on Starman which forks workers to serve the requests. It seemed to me as if two instances had been trying to write the session file - a race condition. After discussing the issue with a colleague, I inspected the source code of the Dancer::Session::YAML module. The last subroutine was the only one printing anything:

sub flush {
    my $self         = shift;
    my $session_file = yaml_file( $self->id );

    open my $fh, '>', $session_file or die "Can't open '$session_file'
+: $!\n";
    flock $fh, LOCK_EX or die "Can't lock file '$session_file': $!\n";
    set_file_mode($fh);
    print {$fh} YAML::Dump($self);
    close $fh or die "Can't close '$session_file': $!\n";

    return $self;
}

The problem is the open line: it might overwrite (clobber) the file even before the lock is granted. To demonstrate the problem, I wrote the following script:

#!/usr/bin/perl
use warnings;
use strict;

use Fcntl qw(:flock :DEFAULT);

my $pid = fork;
die "Cannot fork.\n" unless defined $pid;

if ($pid) {
    open my $parent, '>', 'tmp'       or die "open parent: $!";
    sleep 1;
    flock   $parent, LOCK_EX          or die "lock parent: $!";
    print  {$parent} "Parent\n";
    close   $parent                   or die "close parent: $!";

} else {
    open my $child, '>', 'tmp'        or die "open child: $!";
    flock   $child, LOCK_EX           or die "lock child: $!";

    # Longer than parent:
    print  {$child} "Child here...\n";
    close   $child                    or die "close child: $!";
}

The parent opens the file, but while it sleeps, the child writes something to it. The parent then wakes up, gets the lock and writes to the file - but it just writes over whatever the child has written. If the child's output is longer than the parent's, the invalid session problem turns up.

I have just read the chapter on file-locking in Programming Perl (the 4^th edition). To obtain the exclusive lock, the book recommends using sysopen, but after some googling and experimenting I found a simpler solution (only works if the file already exists, though, otherwise sysopen is inevitable — or maybe +>> can help?):

open my $fh, '+<', $file or die "Can't open '$file': $!\n";
flock $fh, LOCK_EX or die "Can't lock file '$file': $!\n";
truncate $fh, 0;
print {$fh} $content;
close $fh or die "Can't close '$file': $!\n";

The +< mode does not overwrite the file. truncate deletes the previous content of the file (or shortens the file), so the previous content does not matter.

Proud of myself, I opened the Dancer's bug tracker... only to find the problem has already been fixed on github in a completely different way: the session is written through the Dancer::FileUtil module, using its atomic_write:

sub atomic_write {
    my ($path, $file, $data) = @_;
    my ($fh, $filename) = tempfile("tmpXXXXXXXXX", DIR => $path);
    set_file_mode($fh);
    print $fh $data;
    close $fh or die "Can't close '$file': $!\n";
    rename($filename, $file) or die "Can't move '$filename' to '$file'
+";
}

There is more than one way to... you know what. Anyway, I learned a lot.
Update: The note on file existence with +<.

[Anonymous Monk]

Ah, classic rookie mistakes :) smell so good :)

Here is a tip , development.yml contains

# auto_reload is a development and experimental feature
# you should enable it by yourself if you want it
# Module::Refresh is needed 
# 
# Be aware it's unstable and may cause a memory leak.
# DO NOT EVER USE THIS FEATURE IN PRODUCTION 
# OR TINY KITTENS SHALL DIE WITH LOTS OF SUFFERING

If you saw that and said to yourself : I know how to fix it, I'll use Shotgun!

Don't! At least on win32 mingw perl v5.14.1, it works nicely to eat all memory :)

OTOH auto_reload: 1 does require manual restart after 3-6 edits , irritating :)

[choroba]

classic rookie mistakes

Is it a rookie mistake to believe the modules installed from CPAN? Or is the author of Dancer::Session::YAML a rookie?

[jmlynesjr]

I have wondered the same thing myself.

In a prior life when I was developing life/safety embedded systems in C there were several very attractive 3rd party C Libraries that would have saved a lot of time and effort. However, I could not justify the risk of using these packages. Yes, the C compiler also came from an outside vendor, but at least it was from a large company with deep pockets in case the lawyers ever got involved.

Maybe the CPAN modules you(all) use aren't life/safety related, but CEOs these days can be held criminally liable for failures in information systems(hacking/idenity theft/etc) and most can't evaluate their risk. At least a large user base should shake out problems quicker.

What say you?

James

[Anonymous Monk]

Is it a rookie mistake to believe the modules installed from CPAN? Or is the author of Dancer::Session::YAML a rookie?

IIRC every tutorial on locking/open I've seen warns you about clobbering your files, and before you obtain a lock -- the idiom is open without clobber, obtain lock, trunc/seek/write as needed, close

[Anonymous Monk]

plackup --loader Shotgun ...dancer

[jdporter]

This also reminds me of the Opera browser bug described in Random extracts appended to end of posts after create? although I'm not saying that it is likely the cause of what you're seeing.