Arbitrary 10ms minimum for perl timeout_add functions

[irssibot]

• • • Issue #812 opened by @shabble

The timeout_add and timeout_add_once functions defined in perl/common/Core.xs both have checks which croak() the caller if the timeout period/delay is less than 10ms. This appears to be an arbitrary number, and removing the checks doesn't seem to impact Irssi significantly.

The logs show:

commit 8cbb0c8ce2dd659c8fcf9d4373fa2c0adcc1f854 Author: cras cras@dbcabf3a-b0e7-0310-adc4-f8d773084564 Date: Tue Apr 9 05:18:11 2002 +0000

    Irssi::timeout_add() - don't allow smaller values than 10

    git-svn-id: http://svn.irssi.org/repos/irssi/trunk@2658 dbcabf3a-b0e7-0310-adc4-f8d773084564

so it may well be a legacy from when computers were much slower, and unable to reasonably handle timeouts lower than 10ms.

I have written a test script to check the accuracy of the sub-10ms delays, with results below. The irssi binary used is built from the current git trunk head, and the benchmark is run on OSX 10.5.8 on a macbook pro 2.4Ghz. There's plenty of background stuff running which might account for some jitter, and the Irssi instance isn't connected to any servers.

Here are some results from the attached script. The values are all in ms, and show the requested timeout, the mean delta (called_time - previous_called_time), and its standard deviation.

Results for timeouts run concurrently:

number of iterations: 1000 Duration: 1, mean: 0.227 std dev: 0.151 Duration: 2, mean: 0.399 std dev: 0.315 Duration: 3, mean: 0.546 std dev: 0.483 Duration: 4, mean: 0.728 std dev: 1.216 Duration: 5, mean: 0.605 std dev: 1.153 Duration: 6, mean: 0.592 std dev: 1.112 Duration: 7, mean: 0.632 std dev: 1.142 Duration: 8, mean: 0.667 std dev: 1.148 Duration: 9, mean: 0.704 std dev: 1.682 Duration: 10, mean: 0.702 std dev: 1.753 Duration: 11, mean: 0.684 std dev: 1.659 Duration: 12, mean: 0.708 std dev: 1.618 Duration: 13, mean: 0.760 std dev: 1.486 Duration: 14, mean: 0.722 std dev: 1.403 Duration: 15, mean: 0.689 std dev: 1.196 Duration: 16, mean: 0.719 std dev: 1.262 Duration: 17, mean: 0.728 std dev: 1.294 Duration: 18, mean: 0.726 std dev: 1.360 Duration: 19, mean: 0.716 std dev: 1.643 Duration: 20, mean: 0.697 std dev: 1.479

Results for timeouts run sequentially:

number of iterations: 1000 Duration: 1, mean: 0.205 std dev: 0.110 Duration: 2, mean: 0.282 std dev: 0.273 Duration: 3, mean: 0.387 std dev: 0.541 Duration: 4, mean: 0.478 std dev: 0.565 Duration: 5, mean: 0.598 std dev: 0.659 Duration: 6, mean: 0.680 std dev: 0.616 Duration: 7, mean: 0.712 std dev: 0.537 Duration: 8, mean: 0.705 std dev: 0.573 Duration: 9, mean: 0.613 std dev: 0.589 Duration: 10, mean: 0.546 std dev: 0.414 Duration: 11, mean: 0.525 std dev: 0.588 Duration: 12, mean: 0.506 std dev: 0.663 Duration: 13, mean: 0.537 std dev: 0.422 Duration: 14, mean: 0.564 std dev: 0.521 Duration: 15, mean: 0.612 std dev: 0.447 Duration: 16, mean: 0.642 std dev: 0.509 Duration: 17, mean: 0.623 std dev: 0.429 Duration: 18, mean: 0.637 std dev: 0.530 Duration: 19, mean: 0.604 std dev: 0.712 Duration: 20, mean: 0.564 std dev: 0.511

There's clearly a bit of contention in the concurrent test, but it doesn't seem to be too significant, and in all cases, the mean delta is <1ms. The sequential test shows again fairly consistent values, and are all lower due to the lack of contention.

Is there a reason why there is a 10ms lower bound, or can it be safely removed? (patch attached)

Cheers,

Tom.

[irssibot]

• • • Attachment 262 by @shabble

remove-timeout-bound.diff

--- a/src/perl/common/Core.xs
+++ b/src/perl/common/Core.xs
@@ -237,12 +237,7 @@ timeout_add(msecs, func, data)
    SV *func
    SV *data
 CODE:
-   if (msecs < 10) {
-       croak("Irssi::timeout() : msecs must be >= 10");
-       RETVAL = -1;
-   } else {
-       RETVAL = perl_timeout_add(msecs, func, data, FALSE);
-   }
+   RETVAL = perl_timeout_add(msecs, func, data, FALSE);
 OUTPUT:
    RETVAL

@@ -252,12 +247,7 @@ timeout_add_once(msecs, func, data)
    SV *func
    SV *data
 CODE:
-   if (msecs < 10) {
-       croak("Irssi::timeout_once() : msecs must be >= 10");
-       RETVAL = -1;
-   } else {
-       RETVAL = perl_timeout_add(msecs, func, data, TRUE);
-   }
+   RETVAL = perl_timeout_add(msecs, func, data, TRUE);
 OUTPUT:
    RETVAL

[irssibot]

• • • Attachment 263 by @shabble

timer-test.pl

=pod

=head1 NAME

template.pl

=head1 DESCRIPTION

A minimalist template useful for basing actual scripts on.

=head1 INSTALLATION

Copy into your F<~/.irssi/scripts/> directory and load with
C</SCRIPT LOAD F<filename>>.

=head1 USAGE

None, since it doesn't actually do anything.

=head1 AUTHORS

Copyright E<copy> 2011 Tom Feist C<E<lt>shabble+irssi@metavore.orgE<gt>>

=head1 LICENCE

Permission is hereby granted, free of charge, to any person obtaining a copy
of this software and associated documentation files (the "Software"), to deal
in the Software without restriction, including without limitation the rights
to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
copies of the Software, and to permit persons to whom the Software is
furnished to do so, subject to the following conditions:

The above copyright notice and this permission notice shall be included in
all copies or substantial portions of the Software.

THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
THE SOFTWARE.

=head1 BUGS

=head1 TODO

Use this template to make an actual script.

=cut

use strict;
use warnings;

use Irssi;
use Irssi::Irc;
use Irssi::TextUI;
use Time::HiRes qw/time/;
use IO::File;
use List::Util qw/sum/;
use Statistics::Basic qw(:all);

use Data::Dumper;

our $VERSION = '0.1';
our %IRSSI = (
              authors     => 'shabble',
              contact     => 'shabble+irssi@metavore.org',
              name        => '',
              description => '',
              license     => 'MIT',
              updated     => '$DATE'
             );

my @counters;
my @values;
my @tags;

my $fh = IO::File->new('timings.txt', 'w')  or die "Couldn't open timings file: $!";
my $count_max = 1000;
sub handler {
    my $arg = shift;
    #print "Handler fired with arg: " . $tags[$arg];
    $values[$arg]->[$counters[$arg]] = time();
    $counters[$arg]++;
    if ($counters[$arg] == $count_max) {
        Irssi::timeout_remove($tags[$arg]);
        done($arg);
    }
}

sub done {
    my $arg = shift;
    my @results;
    my $max_idx = scalar(@{$values[$arg]}) -1;
    for (1..$max_idx) {
        my $delta = $values[$arg]->[$_] - $values[$arg]->[$_ -1];
        $results[$_ -1] = sprintf("%.2f", ($delta * 1000) - $arg);
    }
    my $mean     = mean(@results);
    my $v1       = $mean->query_vector;
    my $stddev   = stddev($v1);

    $fh->printf("Duration: %2d, mean: %.3f std dev: %.3f\n", $arg, $mean, $stddev);
    # print "results for: $arg";
    # $fh->print("results for: ${arg}ms:\n");

    # print Dumper(\@results);
    # $fh->print(Dumper(\@results));

    # my $avg = sum(@results) / @results;
    # $fh->printf("Average: %.3f\n\n", $avg);
    print "$arg is done";

    if ($arg == 20) {
        $fh->close;
        print "Done";
    }

}

$fh->print("number of iterations: $count_max\n");
my $run_sequentially = 1;

for (1..20) {
    $values[$_] = [];
    $counters[$_] = 0;
    if ($run_sequentially) {
        my $time_to_finish_prev = ($_ - 1) * $count_max;
        $time_to_finish_prev ||= 1;
        Irssi::timeout_add_once($time_to_finish_prev,
                                sub { my $arg = shift; 
                                      print "Starting up timer for: $arg";
                                      $tags[$arg]
                                        = Irssi::timeout_add($arg, 'handler', $arg);
                                  }, $_);
    } else {
        print "Starting up timer for: $arg";
        $tags[$_]
          = Irssi::timeout_add($_, 'handler', $_);
    }
}

[irssibot]

• • • Comment 1328 by @shabble

Having thought about it slightly more, and to protect users from themselves, here is an alternative patch which reduces the timeout minimum from 10ms to 1ms (It appears that a timeout value of 0 does not actually do anything. The exact behaviour probably depends on whatever Glib does, since the functions are mostly just a wrapper around its timers).

[irssibot]

• • • Attachment 264 by @shabble

reduce-timeout-bound.diff

--- a/src/perl/common/Core.xs
+++ b/src/perl/common/Core.xs
@@ -237,8 +237,8 @@ timeout_add(msecs, func, data)
    SV *func
    SV *data
 CODE:
-   if (msecs < 10) {
-       croak("Irssi::timeout() : msecs must be >= 10");
+   if (msecs < 1) {
+       croak("Irssi::timeout() : msecs must be >= 1");
        RETVAL = -1;
    } else {
        RETVAL = perl_timeout_add(msecs, func, data, FALSE);
@@ -252,8 +252,8 @@ timeout_add_once(msecs, func, data)
    SV *func
    SV *data
 CODE:
-   if (msecs < 10) {
-       croak("Irssi::timeout_once() : msecs must be >= 10");
+   if (msecs < 1) {
+       croak("Irssi::timeout_once() : msecs must be >= 1");
        RETVAL = -1;
    } else {
        RETVAL = perl_timeout_add(msecs, func, data, TRUE);