[perl #74484] Regex causing exponential runtime+mem usage

# New Ticket Created by  "perl@0ne.us" 
# Please include the string:  [perl #74484]
# in the subject line of all future correspondence about this issue. 
# <URL: http://rt.perl.org/rt3/Ticket/Display.html?id=74484 >



This is a bug report for perl from cpan@ubuntu-server64.0ne.us,
generated with the help of perlbug 1.39 running under perl 5.12.0.


-----------------------------------------------------------------
[Please describe your issue here]

Hello,

    I've been smoking CPAN modules for CPANTesters and noticed that my 
bots got OOMKilled
from time to time. At first I thought it was the bot itself and blamed 
my VM system for
being wonky. After it happened one too many times I gave up and decided 
to do a full-blown
investigation. Turned out the culprit was Router::Generic's testsuite. 
Whenever it runs,
the parent POE::Component::SmokeBox process kept dying.

    The problem is that SmokeBox uses String::Perl::Warnings to check 
incoming strings for sanity.
S::P::W uses Regexp::Assemble to build a super-big regex of *ALL* Perl 
warnings and uses that to match
against the string.

    I'm using Regexp::Assemble v0.34 and String::Perl::Warnings v1.04 in 
the app. After eliminating
the POE+CPAN stuff, I've come up with a testcase that is guaranteed to 
consume all RAM on my machine
and take a long time to complete. I'm not a regex whiz so I have no idea 
why it's happening so I've
decided to post this perlbug so the right people can look at it.

    After playing around with this script I made some observations:

    * I've tested that this blows up on 5.12.0 and 5.10.0.
    * Leaving the string as-is will result in the pathological behavior 
in the regex engine
    * Changing the string to "a" results in constant memory usage but 
slightly increased
        runtime each loop ( this makes sense, as the string is getting 
bigger and bigger )
    * Having spaces in the string seems to be the culprit, as doing "a 
a" results in mem usage going up
        but not as fast as the default!
    * At first I thought it was the \r but having a string of "\ra" 
behaves the same as "a"

        string "a":    Loop 300: 0.00176382064819336s rss(9340 kB)
        string "a a":    Loop 300: 0.0624589920043945s rss(23836 kB)
        string default:    Loop 300: 1.41920399665833s rss(238724 kB)

    * I thought it might be my script, so I bypassed the loop and just 
did "foreach my $c ( 1000 )" and it
        promptly got OOMKilled. Trying it with 300 resulted in pretty 
much the same runtime/mem usage
        as the one above for default.

    * Look at the DATA section of the testcase, and wonder why it 
suddenly gets exponential after around
        520 loops for runtime... However, the memory increase is pretty 
constant per loop... Also, it
        somehow "stabilizes" after 520 loops - did the perlinternals 
know memory is running out and
        behaved differently?

    Hope you'll have as much fun playing with this testcase as I did :)

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

use String::Perl::Warnings qw( is_warning );
use Time::HiRes qw( time );

# Let Regexp::Assemble init the regex
my $result = is_warning( '' );

# Loop over the test string and find out where Perl hits the OOMKill 
problem ( my VM has 768M of RAM )
foreach my $c ( 0 .. 1000 ) {
    # Construct the test string
    my $string = '';
    for ( 0 .. $c ) {
        $string .= "\radd_route: $_/1000";
    }

    # Time the regex engine
    my $starttime = time;
    $result = is_warning( $string );
    my $stoptime = time;

    # Print diag messages every 10 loops
    unless ( $c % 10 ) {
        # Argh, get the mem usage
        my $rss = get_memory();
        warn "Loop $c: " . ($stoptime - $starttime) . "s rss($rss)\n";
    }
}

sub get_memory {
    # hackish way, but works for now :(
    my @data = `cat /proc/$$/status`;
    foreach my $line ( @data ) {
        if ( $line =~ /^VmRSS:\s+(.+)$/ ) {
            return $1;
        }
    }
}

1;

__DATA__

I've ran this program on my VM and here's the output:
[cpan@ubuntu-server64 ~]$ perls/perl_5.12.0_default/bin/perl regex_crash.pl
Loop 0: 0.0791380405426025s rss(9336 kB)
Loop 10: 0.00212907791137695s rss(9340 kB)
Loop 20: 0.00815701484680176s rss(9340 kB)
Loop 30: 0.015045166015625s rss(9800 kB)
Loop 40: 0.0259301662445068s rss(11144 kB)
Loop 50: 0.0399010181427002s rss(13280 kB)
Loop 60: 0.0568771362304688s rss(16080 kB)
Loop 70: 0.0785748958587646s rss(19384 kB)
Loop 80: 0.096937894821167s rss(23176 kB)
Loop 90: 0.130855083465576s rss(27480 kB)
Loop 100: 0.153497934341431s rss(32284 kB)
Loop 110: 0.180907964706421s rss(37600 kB)
Loop 120: 0.216251134872437s rss(43448 kB)
Loop 130: 0.258400201797485s rss(49816 kB)
Loop 140: 0.313691854476929s rss(56716 kB)
Loop 150: 0.344374895095825s rss(64144 kB)
Loop 160: 0.387225151062012s rss(72096 kB)
Loop 170: 0.438238859176636s rss(80572 kB)
Loop 180: 0.498692989349365s rss(89580 kB)
Loop 190: 0.550199031829834s rss(99112 kB)
Loop 200: 0.604217052459717s rss(109168 kB)
Loop 210: 0.675564050674438s rss(119756 kB)
Loop 220: 0.791208028793335s rss(130864 kB)
Loop 230: 0.850717067718506s rss(142504 kB)
Loop 240: 0.894576072692871s rss(154668 kB)
Loop 250: 0.97498893737793s rss(167360 kB)
Loop 260: 1.04289603233337s rss(180584 kB)
Loop 270: 1.14439296722412s rss(194328 kB)
Loop 280: 1.20763897895813s rss(208596 kB)
Loop 290: 1.31933212280273s rss(223396 kB)
Loop 300: 1.41920399665833s rss(238724 kB)
Loop 310: 1.48294711112976s rss(254572 kB)
Loop 320: 1.59841012954712s rss(270952 kB)
Loop 330: 1.70976114273071s rss(287856 kB)
Loop 340: 1.80522298812866s rss(305284 kB)
Loop 350: 1.92089986801147s rss(323248 kB)
Loop 360: 2.01572108268738s rss(341728 kB)
Loop 370: 2.15599703788757s rss(360748 kB)
Loop 380: 2.27072596549988s rss(380276 kB)
Loop 390: 2.40587496757507s rss(400348 kB)
Loop 400: 2.51369595527649s rss(420940 kB)
Loop 410: 2.63296818733215s rss(442056 kB)
Loop 420: 2.76079702377319s rss(463700 kB)
Loop 430: 2.90137791633606s rss(485872 kB)
Loop 440: 3.00859093666077s rss(508572 kB)
Loop 450: 3.19537901878357s rss(531792 kB)
Loop 460: 3.36626696586609s rss(555548 kB)
Loop 470: 3.49290084838867s rss(579828 kB)
Loop 480: 3.5871410369873s rss(604636 kB)
Loop 490: 3.73700594902039s rss(629964 kB)
Loop 500: 3.89036107063293s rss(655824 kB)
Loop 510: 4.06298685073853s rss(682212 kB)
Loop 520: 4.23448181152344s rss(709124 kB)
Loop 530: 6.80471897125244s rss(705788 kB)
Loop 540: 10.8200550079346s rss(709936 kB)
Loop 550: 14.4348080158234s rss(698272 kB)
Loop 560: 21.236438035965s rss(700008 kB)
Loop 570: 25.1975688934326s rss(700464 kB)
Killed

[Please do not change anything below this line]
-----------------------------------------------------------------
---
Flags:
    category=core
    severity=high
---
Site configuration information for perl 5.12.0:

Configured by cpan at Mon Apr 12 10:44:17 MST 2010.

Summary of my perl5 (revision 5 version 12 subversion 0) configuration:
   
  Platform:
    osname=linux, osvers=2.6.31-14-server, archname=x86_64-linux
    uname='linux ubuntu-server64 2.6.31-14-server #48-ubuntu smp fri oct 
16 15:07:34 utc 2009 x86_64 gnulinux '
    config_args='-des -Dprefix=/home/cpan/perls/perl_5.12.0_default'
    hint=recommended, useposix=true, d_sigaction=define
    useithreads=undef, usemultiplicity=undef
    useperlio=define, d_sfio=undef, uselargefiles=define, usesocks=undef
    use64bitint=define, use64bitall=define, uselongdouble=undef
    usemymalloc=n, bincompat5005=undef
  Compiler:
    cc='cc', ccflags ='-fno-strict-aliasing -pipe -fstack-protector 
-I/usr/local/include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64',
    optimize='-O2',
    cppflags='-fno-strict-aliasing -pipe -fstack-protector 
-I/usr/local/include'
    ccversion='', gccversion='4.4.1', gccosandvers=''
    intsize=4, longsize=8, ptrsize=8, doublesize=8, byteorder=12345678
    d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=16
    ivtype='long', ivsize=8, nvtype='double', nvsize=8, Off_t='off_t', 
lseeksize=8
    alignbytes=8, prototype=define
  Linker and Libraries:
    ld='cc', ldflags =' -fstack-protector -L/usr/local/lib'
    libpth=/usr/local/lib /lib /usr/lib /lib64 /usr/lib64
    libs=-lnsl -ldl -lm -lcrypt -lutil -lc
    perllibs=-lnsl -ldl -lm -lcrypt -lutil -lc
    libc=/lib/libc-2.10.1.so, so=so, useshrplib=false, libperl=libperl.a
    gnulibc_version='2.10.1'
  Dynamic Linking:
    dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-Wl,-E'
    cccdlflags='-fPIC', lddlflags='-shared -O2 -L/usr/local/lib 
-fstack-protector'

Locally applied patches:
    

---
@INC for perl 5.12.0:
    /home/cpan/perls/perl_5.12.0_default/lib/site_perl/5.12.0/x86_64-linux
    /home/cpan/perls/perl_5.12.0_default/lib/site_perl/5.12.0
    /home/cpan/perls/perl_5.12.0_default/lib/5.12.0/x86_64-linux
    /home/cpan/perls/perl_5.12.0_default/lib/5.12.0
    .

---
Environment for perl 5.12.0:
    HOME=/home/cpan
    LANG=en_US.UTF-8
    LANGUAGE (unset)
    LD_LIBRARY_PATH (unset)
    LOGDIR (unset)
    
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games
    PERL_BADLANG (unset)
    SHELL=/bin/bash

• [perl #74484] Regex causing exponential runtime+mem usage by perl@0ne.us
• Re: [perl #74484] Regex causing exponential runtime+mem usage by Dave Mitchell
• Re: [perl #74484] Regex causing exponential runtime+mem usage by Dave Mitchell
• Re: [perl #74484] Regex causing exponential runtime+mem usage by demerphq