File: trace-master.pl

package info (click to toggle)
squid 7.2-2
  • links: PTS, VCS
  • area: main
  • in suites: forky, sid
  • size: 33,440 kB
  • sloc: cpp: 184,513; ansic: 12,442; sh: 5,688; makefile: 5,247; perl: 2,560; sql: 326; python: 240; awk: 141; sed: 1
file content (167 lines) | stat: -rwxr-xr-x 4,087 bytes parent folder | download
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
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
#!/usr/bin/perl -w
#
## Copyright (C) 1996-2025 The Squid Software Foundation and contributors
##
## Squid software is distributed under GPLv2+ license and includes
## contributions from numerous individuals and organizations.
## Please see the COPYING and CONTRIBUTORS files for details.
##

# Reads cache.log and displays lines that correspond to the master transaction
# that has a given async job. Master transaction is all activities tied to a
# a single received HTTP request (client side, ACL, ICAP, server side, etc.).
#
# See trace-job.pl for tracing a single job instead of all jobs related to
# a master transaction.
#
# Currently, many master transaction activities are not tracked because they
# do not use AsyncJob API. Eventually, most activities should be identifiable.
#
# Currently, the script reads and remembers all master transactions because it
# does not know which one should be tracked in advance. Eventually, we may
# have a more efficient way of tying master transaction to a job.
#


use strict;
use warnings;

my @InterestingJobs = @ARGV or die("usage: $0 <job id> ...\n");

my %Jobs = ();

my $inside = 0;
my $entering;

while (<STDIN>) {
    $entering = $_ if !$inside && /[|:] entering\b/;
    undef $entering if /[|:] leaving\b/;

    if (!$inside && /\bstatus in\b.*\b(?:async|job|icapx)(\d+)\b/o) {
        $inside = $1;
        &enterJob($inside);
        &updateJob($inside, $entering) if defined $entering;
        undef $entering;
    }
    elsif (!$inside && /\b(?:async|job|icapx)(\d+)\b/o) {
        updateJob($1, "$_\n"); # isolated line
    }

    next unless $inside;

    &updateJob($inside, $_);

    if (/AsyncJob constructed.*\[\S+?(\d+)\]/) {
        &linkJobs($inside, $1, $_);
    }

    if (/[|:] leaving\b/) {
        $inside = 0;
    }
}

foreach my $id (@InterestingJobs) {
    # Squid uses asyncNNN, jobNNN, icapxNNN for the same job/transaction
    $id =~ s/^(?:async|job|icapx)(\d+)$/$1/;
    reportJob($id, 1);
}

exit(0);


sub enterJob {
    my ($id) = @_;
    my $job = &getJob($id);
}

sub updateJob {
    my ($id, $line) = @_;

    my $job = &getJob($id);
    $job->{history} .= $line;

    if ($line =~ /\bFD (\d+)/) {
        $job->{fds}->{$1} = 1;
    }
}

sub linkJobs {
    my ($parentId, $kidId, $line) = @_;

    my $parent = $Jobs{$parentId} or die("missing linked job $parentId");
    push @{$parent->{kids}}, $kidId;

    my $kid = &getJob($kidId);
    die("two parents for $kidId: ". $kid->{parent}. " and $parentId") if $kid->{parent};
    $kid->{parent} = $parentId;

    $kid->{history} .= $line; # birth
}

sub getJob {
    my $id = shift;

    my $job = $Jobs{$id};
    return $job if $job;

    $job = {
        id => $id,
        kids => [],
        fds => {},
        parent => undef(),
        start => undef(),
        history => '',
        reported => 0,
        };

    $Jobs{$id} = $job;
    return $job;
}


sub reportJob {
    my ($id, $recursive) = @_;

    my $job = $Jobs{$id} or die("Did not see job$id\n");

    # several kids may try to report their common parent
    return if $job->{reported};
    $job->{reported} = 1;

    &reportJob($job->{parent}, 0) if $job->{parent};

    &reportJobParam($id, 'parent');
    &reportJobParam($id, 'kids', join(', ', @{$job->{kids}}));
    &reportJobParam($id, 'FDs', join(', ', keys %{$job->{fds}}));
    &reportJobHistory($id);

    return unless $recursive;

    foreach my $kidId (@{$job->{kids}}) {
        &reportJob($kidId, $recursive);
    }
}

sub reportJobParam {
    my ($id, $name, $value) = @_;
    my $job = $Jobs{$id} or die;

    $value = $job->{$name} if @_ < 3;
    $value = '?' unless defined $value;
    $value = "\n$value" if $value =~ /\n/m;
    printf("job%d %s: %s\n", $id, $name, $value);
}

sub reportJobHistory {
    my ($id) = @_;
    my $job = $Jobs{$id} or die;

    my $history = $job->{history};
    my @lines = split(/\n/, $history);
    &reportJobParam($id, 'history', (scalar @lines) . " entries");

    foreach my $line (@lines) {
        print "$line\n";
        print "\n" if $line =~ /[|:] leaving\b/;
    }
}