[perl] Useless use of private variable + uninitialized value

Pagina: 1
Acties:

Onderwerpen


Acties:
  • 0 Henk 'm!

  • Booster
  • Registratie: Februari 2000
  • Laatst online: 29-05 13:12

Booster

Superuser

Topicstarter
Ik zet wat eerste stapjes op het gebied van Perl (lezen kon ik wel aardig, maar schrijven niet) en loop bij onderstaande ogenschijnlijk simpele loopje tegen een probleem aan.

De basis is dat een Apache logfile regel voor regel doorlopen wordt en ik voor iedere regel gebruik kan maken van een aantal variabelen. Die kan ik uit iedere regel halen met een regex. Maar nog voor we daar zijn, lijkt er iets mis te gaan met de declaratie van de variabelen, als ik de errors goed begrijp.

Het volledige script:
code:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
#!/usr/bin/perl -w

use strict;
use warnings;

# Continue with unbuffered output
$|=1;

# Every time we're receiving a line on stdin, then...
while (<STDIN>)
{
        # Our vhost_combined Apache LogFormat variables
        my ($host, $ip, $ident_user, $auth_user, $date, $time, $time_zone,
            $method, $url, $protocol, $status, $bytes, $referer, $useragent);

        # From O'reilly's Perl for Web Site Management
        #                        host  ip    ident auth   [ 06/Jul/2012:16:55:15    +0200 ] "method url proto" status bytes "referer" "useragent"
        my $vhost_combined = qr/^(\S+) (\S+) (\S+) (\S+) \[([^:]+):(\d+:\d+:\d+) ([^\]]+)\] "(\S+) (.+?) (\S+)" (\S+) (\S+) "([^"]+)" "([^"]+)"$/;
        # qr = quote regex
        #
        # host:80 1.2.3.4 - - [16/Oct/2012:23:21:25 +0200] "GET /url HTTP/1.1" 400 519 "-" "-"

        # =~ run this against a regex
        ($host, $ip, $ident_user, $auth_user, $date, $time, $time_zone,
         $method, $url, $protocol, $status, $bytes, $referer, $useragent) =~ $vhost_combined or next;
        # next - will proceed to the next value and skip the rest of this block

        print join $host, $ip, $ident_user, $auth_user, $date, $time, $time_zone,
                   $method, $url, $protocol, $status, $bytes, $referer, $useragent;
}


Als ik dit uitvoer dan krijg ik dit:
code:
1
2
3
4
5
Useless use of private variable in void context at ./script.pl line 25.
(hieronder nog 12x dezelfde foutmelding)

Use of uninitialized value $useragent in pattern match (m//) at ./script.pl line 24, <STDIN> line 1.
(hieronder nog 10x dezelfde foutmelding over line 24, maar dan stdin line 2 t/m 11)

De suggestie is dat er iets mis is met de declaratie van de variabelen, maar wat dan precies? Ik begin toch keurig met een my ([...]) en een voorbeeldscriptje dat ik heb bekeken doet niet heel veel anders dan wat ik hier doe.

De inhoud van de logfile is momenteel 11 regels totaal, dus de laatste foutmelding komt 1x voor bij iedere regel in de log. In het script staat al een voorbeeld van hoe een regel van de logfile eruit kan zien. Hier nog een paar van dergelijke regels:
code:
1
2
3
4
host.nl:80 1.2.3.4 - - [16/Oct/2012:22:31:13 +0200] "GET /x.php HTTP/1.1" 200 302 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:16.0) Gecko/20100101 Firefox/16.0"
host.nl:80 1.2.3.4 - - [16/Oct/2012:22:31:34 +0200] "GET /y/ HTTP/1.1" 304 474 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:16.0) Gecko/20100101 Firefox/16.0"
host.nl:80 6.7.8.9 - - [16/Oct/2012:23:21:25 +0200] "GET /w00tw00t.at.ISC.SANS.DFind:) HTTP/1.1" 400 519 "-" "-"
host.nl:80 3.4.5.6 - - [17/Oct/2012:00:45:16 +0200] "HEAD /manager/html HTTP/1.0" 404 182 "-" "-"


De fout zit 100% zeker niet in de output buffering en ook niet in de variabelen die over twee regels verspreid zijn voor de leesbaarheid: uitgebreid getest en dat is niet het issue :)

Ik begrijp niet wat ik fout doe of wat ik verder kan doen om te achterhalen wat er fout gaat. Iemand pointers?

The cake is a lie | The Borealis awaits...


Acties:
  • 0 Henk 'm!

  • Soultaker
  • Registratie: September 2000
  • Laatst online: 14:46
Er valt van alles te verbeteren aan die code, maar laat ik beginnen met het concrete probleem: =~ is een binaire operator die een reguliere expressie (aan de rechter kant) uitvoert op een scalaire waarde (aan de linkerkant) en die verwar je nu met het resultaat (in array-context een lijst gecapturede substrings).

Aangezien je het resultaat van <INPUT> nergens toegekend hebt, zit de regel die je wil matchen nog in de default-variable $_, dus je zou je code kunnen herschrijven als:

Perl:
24
($host, $ip, .. blablabla... $useragent) = ($_ =~ $vhost_combined) or next;

(De extra haakjes rechts van de = zijn eigenlijk niet nodig, maar die heb ik voor de leesbaarheid toegevoegd).

Maar wacht, er is meer. Je hoeft eigenlijk die hele =~ operator niet te gebruiken, want een regular expression match werkt standaard op de default variabele $_. Je kunt het dus ook zo schrijven:
Perl:
24
($host, $ip, .. blablabla... $useragent) = /$vhost_combined/ or next;

De extra slashes om $vhost_combined heen zijn nodig omdat Perl de scalar variable anders niet als regexp herkend. Eventueel zou je hier ook direct die hele $vhost_combined kunnen substituteren, aangezien je 'm toch maar op één plek gebruikt, maar dat is een kwestie van smaak. Zo niet, dan is het wellicht handig om de declaratie van $vhost_combined buiten de lus te plaatsen, want nu herinitialiseer je 'm voor elke inputregel wat niet verkeerd maar wel nodeloos inefficient is.

Maar wacht, er is meer. Je declareert nu je variabelen op regel 13-14 terwijl je ze op regel 24-25 voor het eerst initialiseert. Dat is redundant en omslachtig; je kunt ze beter declareren bij de initialisatie:
Perl:
24
my ($host, $ip, .. blablabla... $useragent) = /$vhost_combined/ or next;

... en dan kun je regel 13-14 weghalen.

Acties:
  • 0 Henk 'm!

  • _Peter2_
  • Registratie: November 2008
  • Laatst online: 13-06 10:19
Soultaker schreef op woensdag 17 oktober 2012 @ 05:24:
Maar wacht, er is meer. Je declareert nu je variabelen op regel 13-14 terwijl je ze op regel 24-25 voor het eerst initialiseert. Dat is redundant en omslachtig; je kunt ze beter declareren bij de initialisatie:
Perl:
24
my ($host, $ip, .. blablabla... $useragent) = /$vhost_combined/ or next;

... en dan kun je regel 13-14 weghalen.
Op zich een goed punt, maar bij grotere scripts kan het wel extra duidelijkheid scheppen om je variabelen aan het begin van een sub (of main) te declareren / initialiseren.

Diablo III: <GOT> Pteer#2475 --- POE: Dwergux


Acties:
  • 0 Henk 'm!

  • Booster
  • Registratie: Februari 2000
  • Laatst online: 29-05 13:12

Booster

Superuser

Topicstarter
goedemorgen :+

Dank je! :) De aanwijzingen voor de optimalisaties zijn ook erg welkom. Met deze veranderingen en een wijziging in de print werkt het zoals ik wil.

Ik was eerder al aan het stoeien met de regex en ik zal niet goed naar de verschillende voorbeelden gekeken hebben. In eerste instantie gezocht naar de mogelijkheid om de regex in een aparte variabele te krijgen, op dat moment puur een kwestie van smaak. Maar later las ik ook dat dit in sommige gevallen voor wat meer performance kon zorgen bij het herhaaldelijk uitvoeren van de regex. Het is niet helemaal duidelijk wanneer je er voordeel van hebt en hoe veel precies, maar baat het niet dan schaad het niet ;)

Uiteindelijk moet dit een script worden waar een log naar gepiped kan worden door Apache, en performance moet zo min mogelijk een issue zijn.

Het logformaat zal nu iets wijzigen: $bytes was voorheen nog een enkele waarde, maar straks komt er vanuit Apache een regel waarbij dit twee losse waardes zullen zijn, $bytes_in en $bytes_out. In dit script wil ik die twee waardes bij elkaar optellen en zo samenvoegen tot een enkele waarde in de uiteindelijke log.

Dus, regex aangepast, variabelen extra. Met de opmerkingen hier erbij heb ik nu dit:

Perl:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
#!/usr/bin/perl -w

use strict;
use warnings;

# Continue with unbuffered output
$|=1;

# From O'reilly's Perl for Web Site Management
#                        host  ip    ident auth   [ 06/Jul/2012:16:55:15    +0200 ] "method url proto" status bytes "referer" "useragent"
my $vhost_combined = qr/^(\S+) (\S+) (\S+) (\S+) \[([^:]+):(\d+:\d+:\d+) ([^\]]+)\] "(\S+) (.+?) (\S+)" (\S+) (\S+) (\S+) "([^"]+)" "([^"]+)"$/;
# qr = quote regex
#
# Possible input:
# host:80 1.2.3.4 - - [16/Oct/2012:23:21:25 +0200] "GET /url HTTP/1.1" 400 20 500 "-" "-"

# Every time we're receiving a line on stdin, then...
while (<STDIN>) {
    # $line is in $_
    # regex will be applied to $_ here
    my ($host, $ip, $ident_user, $auth_user, $date, $time, $time_zone,
                $method, $url, $protocol, $status, $bytes_in, $bytes_out, $referer, $useragent) = /$vhost_combined/ or next;
    # next - will proceed to the next value and skip the rest of this block

    print join  " ",
                $host, $ip, $ident_user, $auth_user, '[' . $date, $time, $time_zone . ']',
                '"' . $method, $url, $protocol . '"', $status, ($bytes_in + $bytes_out), '"' . $referer . '"', '"' . $useragent . '"', "\n";

    # Output: host:80 1.2.3.4 - - [16/Oct/2012:23:21:25 +0200] "GET /url HTTP/1.1" 400 520 "-" "-"
}

The cake is a lie | The Borealis awaits...


Acties:
  • 0 Henk 'm!

  • Soultaker
  • Registratie: September 2000
  • Laatst online: 14:46
_Peter2_ schreef op woensdag 17 oktober 2012 @ 09:32:
Op zich een goed punt, maar bij grotere scripts kan het wel extra duidelijkheid scheppen om je variabelen aan het begin van een sub (of main) te declareren / initialiseren.
De scope van deze variabelen is beperkt tot het lexical block waarin ze staan, dus dat is niet hetzelfde als ze bovenaan declareren. Aangezien de initialisatie in dit geval direct volgt op de declaratie, zou ik de twee tot één statement combineren.
Booster schreef op woensdag 17 oktober 2012 @ 09:53:
Maar later las ik ook dat dit in sommige gevallen voor wat meer performance kon zorgen bij het herhaaldelijk uitvoeren van de regex. Het is niet helemaal duidelijk wanneer je er voordeel van hebt en hoe veel precies, maar baat het niet dan schaad het niet ;)
Ik denk dat Perl slim genoeg is om constante regexes maar één keer te compileren, dus ik vermoed dat mijn advies om de initialisatie van $vhost_combined buiten de lus te halen eigenlijk overbodig was.
Het logformaat zal nu iets wijzigen: $bytes was voorheen nog een enkele waarde, maar straks komt er vanuit Apache een regel waarbij dit twee losse waardes zullen zijn, $bytes_in en $bytes_out.
Jouw implementatie lijkt me prima, maar in het kader van TMTOWTDI: je zou ook kunnen overwegen om alles met een enkele substitutie te doen. Bijvoorbeeld zo:
Perl:
1
2
3
#!/usr/bin/perl -np

s/(^\S+ \S+ \S+ \S+ \[[^:]+:\d+:\d+:\d+ [^\]]+\] "\S+ .+? \S+ \S+ )(\S+) (\S+)( "[^"]+" "[^"]+")$/$1.($2+$3).$4/e

(Ja, dit is het complete programma, maar je moet wel de perl compiler aanroepen zoals op regel 1.)

De reguliere expressie is dezelfde als in jou code, maar ik heb de haakjes verplaatst omdat je eigenlijk alleen geïnteresseerd bent in een klein deel ervan.

[ Voor 4% gewijzigd door Soultaker op 17-10-2012 18:03 ]


Acties:
  • 0 Henk 'm!

  • Booster
  • Registratie: Februari 2000
  • Laatst online: 29-05 13:12

Booster

Superuser

Topicstarter
Leuk! :) Mooie substitute regex met 4 groepen, waarvan je de twee middelste bij elkaar telt.

Ik moet hier later even goed over lezen, want dit implied natuurlijk een hele hoop, bv dat de substitute bij default op $_ plaatsvind (ok, dat is wel min of meer expected), en dat in $_/<> standaard STDIN regel voor regel voorbij komt, én dat je loopt (-n) ook print (-p).

Denk jij (en ik ga dit sowieso nog meten) dat deze implementatie ook een (positief, meetbaar) performanceverschil zal geven t.o.v. mijn implementatie?

The cake is a lie | The Borealis awaits...


Acties:
  • 0 Henk 'm!

  • Soultaker
  • Registratie: September 2000
  • Laatst online: 14:46
Ik denk niet dat 't veel uitmaakt; waarschijnlijk gaat de meeste tijd in het evalueren van de reguliere expressie zitten, en die is ongeveer hetzelfde. Die opties -n en -p besparen je alleen typewerk en zijn verder niet sneller dan dat je die code expliciet zou schrijven.

Maar als je 't echt wil weten, moet je het natuurlijk testen: neem een representatie logfile en run de twee scriptjes erop. Desnoods plak je die logfile een paar keer aan zichzelf om voldoende testdata te krijgen.

Acties:
  • 0 Henk 'm!

  • Booster
  • Registratie: Februari 2000
  • Laatst online: 29-05 13:12

Booster

Superuser

Topicstarter
Ik heb wat metingen gedaan :)

Bronmateriaal: logfile uit een productieomgeving met 222041 logregels. Deze aangepast aan het 'nieuwe' formaat: bytes_in van 150 voor alle requests. Dat is niet hoe het in productie zal zijn, maar dit is denk ik irrelevant voor deze test.

Elk scriptje heb ik vijf keer direct achter elkaar de logfile gevoerd. Gemeten met 'time' op de cli. Telkens naar een (andere) file geschreven, omdat dit in de praktijk ook zo zal zijn. De logfiles bestaan nog niet, dus hij moet de files ook aanmaken, niet alleen aanvullen. Quadcore machine is idle.

code:
1
2
3
4
5
6
w; \
time ./combine_logio_pipe.pl < ~/test_split > ~/1; w; \
time ./combine_logio_pipe.pl < ~/test_split > ~/2; w; \
time ./combine_logio_pipe.pl < ~/test_split > ~/3; w; \
time ./combine_logio_pipe.pl < ~/test_split > ~/4; w; \
time ./combine_logio_pipe.pl < ~/test_split > ~/5; w


Scriptje 1: mijn versie, zoals in Booster in "[perl] Useless use of private variable + uninitialized value":
code:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
 12:49:43 up 218 days, 19:56,  2 users,  load average: 0.42, 0.75, 0.52
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12  0.00s  1:26   2.10s sshd: booster [priv]

real    0m6.035s
user    0m4.600s
sys     0m1.390s
 12:49:49 up 218 days, 19:56,  2 users,  load average: 0.47, 0.75, 0.52
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12  6.00s  1:26   2.10s sshd: booster [priv]

real    0m7.719s
user    0m4.660s
sys     0m1.370s
 12:49:57 up 218 days, 19:57,  2 users,  load average: 0.86, 0.83, 0.55
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12 14.00s  1:26   2.10s sshd: booster [priv]

real    0m6.112s
user    0m4.650s
sys     0m1.450s
 12:50:03 up 218 days, 19:57,  2 users,  load average: 0.95, 0.85, 0.55
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12 20.00s  1:26   2.10s sshd: booster [priv]

real    0m6.073s
user    0m4.630s
sys     0m1.450s
 12:50:09 up 218 days, 19:57,  2 users,  load average: 1.04, 0.87, 0.56
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12 26.00s  1:26   2.10s sshd: booster [priv]

real    0m6.035s
user    0m4.610s
sys     0m1.430s
 12:50:15 up 218 days, 19:57,  2 users,  load average: 1.34, 0.93, 0.59
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12 32.00s  1:26   2.10s sshd: booster [priv]


222.000 logregels in gemiddeld ~6,4 seconden, een slordige 34.700 regels per seconde.

Scriptje 2: versie van Soultaker, zoals in Soultaker in "[perl] Useless use of private variable + uninitialized value":
(met kleine aanpassing, want er miste een aanhalingsteken in de regex)
code:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
 12:55:33 up 218 days, 20:02,  2 users,  load average: 0.70, 0.95, 0.70
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12  0.00s  1:26   2.10s sshd: booster [priv]

real    0m3.718s
user    0m3.300s
sys     0m0.420s
 12:55:36 up 218 days, 20:02,  2 users,  load average: 0.73, 0.95, 0.70
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12  3.00s  1:26   2.10s sshd: booster [priv]

real    0m3.781s
user    0m3.480s
sys     0m0.300s
 12:55:40 up 218 days, 20:02,  2 users,  load average: 0.73, 0.95, 0.70
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12  7.00s  1:26   2.10s sshd: booster [priv]

real    0m3.740s
user    0m3.330s
sys     0m0.410s
 12:55:44 up 218 days, 20:02,  2 users,  load average: 0.83, 0.97, 0.71
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12 11.00s  1:26   2.10s sshd: booster [priv]

real    0m3.699s
user    0m3.260s
sys     0m0.440s
 12:55:48 up 218 days, 20:02,  2 users,  load average: 0.92, 0.99, 0.72
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12 15.00s  1:26   2.10s sshd: booster [priv]

real    0m3.722s
user    0m3.360s
sys     0m0.370s
 12:55:51 up 218 days, 20:02,  2 users,  load average: 1.09, 1.02, 0.73
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12 18.00s  1:26   2.10s sshd: booster [priv]


222.000 logregels in gemiddeld ~3,7 seconden :) ~60.000 regels per seconde.

Bijna een halvering, dat is best fors eigenlijk. Daarom nog even verder kijken: iets dat mist aan de versie van Soultaker is het uitschakelen van de output buffering ($|=1). Deze heb ik toegevoegd aan zijn versie en daarna nogmaals een test gedaan:
code:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
 13:03:09 up 218 days, 20:10,  2 users,  load average: 0.08, 0.74, 0.76
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12  0.00s  1:27   2.10s sshd: booster [priv]

real    0m5.366s
user    0m4.040s
sys     0m1.220s
 13:03:15 up 218 days, 20:10,  2 users,  load average: 0.16, 0.75, 0.76
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12  6.00s  1:27   2.10s sshd: booster [priv]

real    0m5.090s
user    0m3.680s
sys     0m1.410s
 13:03:20 up 218 days, 20:10,  2 users,  load average: 0.38, 0.78, 0.77
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12 11.00s  1:27   2.10s sshd: booster [priv]

real    0m5.186s
user    0m3.990s
sys     0m1.200s
 13:03:25 up 218 days, 20:10,  2 users,  load average: 0.51, 0.80, 0.78
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12 16.00s  1:27   2.10s sshd: booster [priv]

real    0m7.164s
user    0m3.990s
sys     0m1.260s
 13:03:32 up 218 days, 20:10,  2 users,  load average: 0.82, 0.86, 0.80
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12 23.00s  1:27   2.10s sshd: booster [priv]

real    0m5.126s
user    0m3.710s
sys     0m1.420s
 13:03:37 up 218 days, 20:10,  2 users,  load average: 1.00, 0.89, 0.81
USER     TTY      FROM              LOGIN@   IDLE   JCPU   PCPU WHAT
booster  pts/7    [---redacted---] 10Oct12 28.00s  1:27   2.10s sshd: booster [priv]


Nu is het al anders:
222.000 logregels in gemiddeld ~5,5 seconden :) ~40.000 regels per seconde ipv 60.000.

In mijn scriptje heb ik daarna nog eens goed bekeken, en de "print join" vervangen door een gewone print. Daarmee wordt het gemiddeld 222.000 regels in 6 seconden. Het verschil met output buffering uitgeschakeld dus ongeveer een halve seconde bij 222.000 regels, en daarmee dus verwaarloosbaar ;)

Opvallend:
Zelfs op een idle machine laat de processing soms een piek zien. Terwijl ik aan het experimenteren was had ik bv een run 6, 6, 6, 6 en 32 seconden. Dit kwam bij beide scriptjes voor. Is dit een bekend verschijnsel :?

The cake is a lie | The Borealis awaits...


Acties:
  • 0 Henk 'm!

  • Soultaker
  • Registratie: September 2000
  • Laatst online: 14:46
Leuk dat je die stats nog post!
Booster schreef op dinsdag 23 oktober 2012 @ 13:39:
Daarom nog even verder kijken: iets dat mist aan de versie van Soultaker is het uitschakelen van de output buffering ($|=1).
Ah, dat was ik inderdaad vergeten. Eigenlijk zou je de I/O lus dan expliciet moeten programmeren en die buffering erboven aan zetten, anders voer je die statement voor elke regel uit. (Maar geen idee of dat veel scheelt qua performance.)
Opvallend: Zelfs op een idle machine laat de processing soms een piek zien. Terwijl ik aan het experimenteren was had ik bv een run 6, 6, 6, 6 en 32 seconden. Dit kwam bij beide scriptjes voor. Is dit een bekend verschijnsel :?
Vreemd. Is dat alleen een piek in real time? Of ook in system of user time?

De user time zou vrij constant moeten zijn; ik kan me voorstellen dat de real time anders is als je filesystem zo af en toe een journal naar disk schrijft, maar 32 seconden is daarvoor wel belachelijk lang.

Acties:
  • 0 Henk 'm!

  • Booster
  • Registratie: Februari 2000
  • Laatst online: 29-05 13:12

Booster

Superuser

Topicstarter
Good point (2x). Even de cijfers uit mijn console gevist:

code:
1
2
3
real    0m32.413s
user    0m4.710s
sys     0m1.280s


User en sys bleef wel constant, maar real dus niet. Ik zou even op moeten zoeken hoe de definities van deze drie ook alweer is.

Output buffering wordt nu inderdaad in iedere loop geset. Ga ik nog eens over nadenken wat ik daaraan zou kunnen doen. Ik dacht even aan
code:
1
#!/usr/bin/perl -np -e '$|=1'
als hash bang maar het is eigenlijk niet heel waarschijnlijk dat dit de -e eenmalig uitvoert, en vervolgens het script eronder loopt. In de manual lees ik over die situatie zo niets terug though. Ga ik later even testen, moet me nu weer even op andere dingen concentreren :)

The cake is a lie | The Borealis awaits...


Acties:
  • 0 Henk 'm!

  • Soultaker
  • Registratie: September 2000
  • Laatst online: 14:46
Booster schreef op dinsdag 23 oktober 2012 @ 23:09:
User en sys bleef wel constant, maar real dus niet. Ik zou even op moeten zoeken hoe de definities van deze drie ook alweer is.
“User time” is tijd die doorgebracht wordt in user mode. Meestal is dat dus de tijd die Perl zelf aan het rekenen is. “System time” is de tijd die wordt doorgebracht in kernel mode maar wel ten behoeve van het runnende proces (bijvoorbeeld om een system call af te handelen). Bestanden lezen en schrijven gebeurt in de kernel, bijvoorbeeld.

“Real time” is simpelweg de verstreken tijd; als je daar de user en system time van je proces van aftrekt hou je de tijd over die andere processen verbruikt hebben. Dat zou nagenoeg nul moeten zijn op een idle systeem, en dat is het ook in de meeste andere experimenten. Ik vermoed dus dat je systeem niet helemaal idle is (maar dan nog is het verschil extreem groot!)
Ik dacht even aan [i]#!/usr/bin/perl -np -e '$|=1'[/code] als hash bang maar het is eigenlijk niet heel waarschijnlijk dat dit de -e eenmalig uitvoert, en vervolgens het script eronder loopt. In de manual lees ik over die situatie zo niets terug though.
Mja, ik zou m'n verlies nemen en die lus gewoon uitschrijven dan:
Perl:
1
2
3
4
5
6
#!/usr/bin/env perl
$|++;
while (<>) {
    s/.../.../;
    print
}

(Overigens is meerdere spaties in een hashbang niet portable, en in de meeste besturingssystemen wordt alleen op de eerste spatie gesplitst. Jouw regel levert dus maar één argument op, met een spatie erin, en niet twéé, zoals je waarschijnlijk bedoelde.)
Pagina: 1