1# This program is copyright 2008-2011 Baron Schwartz, 2011 Percona Ireland Ltd.
2# Feedback and improvements are welcome.
3#
4# THIS PROGRAM IS PROVIDED "AS IS" AND WITHOUT ANY EXPRESS OR IMPLIED
5# WARRANTIES, INCLUDING, WITHOUT LIMITATION, THE IMPLIED WARRANTIES OF
6# MERCHANTIBILITY AND FITNESS FOR A PARTICULAR PURPOSE.
7#
8# This program is free software; you can redistribute it and/or modify it under
9# the terms of the GNU General Public License as published by the Free Software
10# Foundation, version 2; OR the Perl Artistic License.  On UNIX and similar
11# systems, you can issue `man perlgpl' or `man perlartistic' to read these
12# licenses.
13#
14# You should have received a copy of the GNU General Public License along with
15# this program; if not, write to the Free Software Foundation, Inc., 59 Temple
16# Place, Suite 330, Boston, MA  02111-1307  USA.
17# ###########################################################################
18# Processlist package
19# ###########################################################################
20{
21# Package: Processlist
22# Processlist makes events when used to poll SHOW FULL PROCESSLIST.
23package Processlist;
24
25use strict;
26use warnings FATAL => 'all';
27use English qw(-no_match_vars);
28use Time::HiRes qw(time usleep);
29use List::Util qw(max);
30use Data::Dumper;
31$Data::Dumper::Indent    = 1;
32$Data::Dumper::Sortkeys  = 1;
33$Data::Dumper::Quotekeys = 0;
34
35use constant PTDEBUG => $ENV{PTDEBUG} || 0;
36use constant {
37   # 0-7 are the standard processlist columns.
38   ID      => 0,
39   USER    => 1,
40   HOST    => 2,
41   DB      => 3,
42   COMMAND => 4,
43   TIME    => 5,
44   STATE   => 6,
45   INFO    => 7,
46   # 8, 9 and 10 are extra info we calculate.
47   START   => 8,  # Calculated start time of statement ($start - TIME)
48   ETIME   => 9,  # Exec time of SHOW PROCESSLIST (margin of error in START)
49   FSEEN   => 10, # First time ever seen
50   PROFILE => 11, # Profile of individual STATE times
51};
52
53
54# Sub: new
55#
56# Parameters:
57#   %args - Arguments
58#
59# Required Arguments:
60#   MasterSlave - MasterSlave obj for finding replicationt threads
61#
62# Optional Arguments:
63#   interval - Hi-res sleep time before polling processlist in <parse_event()>.
64#
65# Returns:
66#   Processlist object
67sub new {
68   my ( $class, %args ) = @_;
69   foreach my $arg ( qw(MasterSlave) ) {
70      die "I need a $arg argument" unless $args{$arg};
71   }
72   # Convert the list of kill commands (Query, Execute, etc) to a hashref for
73   # faster check later
74   my $kill_busy_commands = {};
75   if ($args{kill_busy_commands}) {
76       for my $command (split /,/,$args{kill_busy_commands}) {
77           $command =~ s/^\s+|\s+$//g;
78           $kill_busy_commands->{$command} = 1;
79       }
80   } else {
81       $kill_busy_commands->{Query} = 1;
82   }
83   $args{kill_busy_commands} = $kill_busy_commands;
84
85   my $self = {
86      %args,
87      polls       => 0,
88      last_poll   => 0,
89      active_cxn  => {},  # keyed off ID
90      event_cache => [],
91      _reasons_for_matching => {},
92   };
93   return bless $self, $class;
94}
95
96# Sub: parse_event
97#   Parse rows from PROCESSLIST to make events when queries finish.
98#
99# Parameters:
100#   %args - Arguments
101#
102# Required Arguments:
103#   code - Callback that returns an arrayref of rows from SHOW PROCESSLIST.
104#          Replication threads and $dbh->{mysql_thread_id} should be removed
105#          from the return value.
106#
107# Returns:
108#   Hashref of a completed event.
109#
110# Technical Details:
111#   Connections (cxn) are tracked in a hashref ($self->{active_cxn}) by their
112#   Id from the proclist.  Each poll of the proclist (i.e. each call to the
113#   code callback) causes the current cxn/queries to be compared to the saved
114#   (active) cxn. One of three things can happen: a new cxn appears, a query
115#   ends/changes/restarts, or a cxn ends (and thus ends its query).
116#
117#   When a new connect appears, we only begin tracking it when the Info column
118#   from the proclist is not null, indicating that the cxn is executing a
119#   query.  The full proclist for this cxn is saved for comparison with later
120#   polls.  This is $prev in the code which really references
121#   $self->{active_cxn}.
122#
123#   For existing cxn, if the Info is the same (i.e. same query), and the Time
124#   hasn't decreased, and the query hasn't restarted (look below in the code
125#   for how we detect this), then the cxn is still executing the same query.
126#   So we do nothing.  But if any one of those 3 conditions is false, that
127#   signals a new query.  So we make an event based on saved info from the
128#   last poll, then updated the cxn for the new query already in progress.
129#
130#   When a previously active cxn no longer appears in a poll, then that cxn
131#   has ended and so did it's query, so we make an event for the query and
132#   then delete the cxn from $self->{active_cxn}.  This is checked in the
133#   PREVIOUSLY_ACTIVE_CXN loop.
134#
135#   The default MySQL server has one-second granularity in the Time column.
136#   This means that a statement that starts at X.9 seconds shows 0 seconds
137#   for only 0.1 second.  A statement that starts at X.0 seconds shows 0 secs
138#   for a second, and 1 second up until it has actually been running 2 seconds.
139#   This makes it tricky to determine when a statement has been restarted.
140#   Further, this program and MySQL may have some clock skew.  Even if they
141#   are running on the same machine, it's possible that at X.999999 seconds
142#   we get the time, and at X+1.000001 seconds we get the snapshot from MySQL.
143#   (Fortunately MySQL doesn't re-evaluate now() for every process, or that
144#   would cause even more problems.)  And a query that's issued to MySQL may
145#   stall for any amount of time before it's executed, making even more skew
146#   between the times.
147#
148#   One worst case is,
149#     * The processlist measures time at 100.01 and it's 100.
150#     * We measure the time.  It says 100.02.
151#     * A query was started at 90.  Processlist says Time=10.
152#     * We calculate that the query was started at 90.02.
153#     * Processlist measures it at 100.998 and it's 100.
154#     * We measure time again, it says 100.999.
155#     * Time has passed, but the Time column still says 10.
156#
157#   Another is,
158#     * We get the processlist, then the time.
159#     * A second later we get the processlist, but it takes 2 sec to fetch.
160#     * We measure the time and it looks like 3 sec have passed, but proclist
161#       says only one has passed.  This is why etime is necessary.
162#   What should we do?  Well, the key thing to notice here is that a new
163#   statement has started if a) the Time column actually decreases since we
164#   last saw the process, or b) the Time column does not increase for 2
165#   seconds, plus the etime of the first and second measurements combined!
166sub parse_event {
167   my ( $self, %args ) = @_;
168   my @required_args = qw(code);
169   foreach my $arg ( @required_args ) {
170     die "I need a $arg argument" unless $args{$arg};
171   }
172   my ($code) = @args{@required_args};
173
174   # Our first priority is to return cached events.  The caller expects
175   # one event per return so we have to cache our events.  And the caller
176   # should accept events as fast as we can return them; i.e. the caller
177   # should not sleep between polls--that's our job in here (below).
178   # XXX: This should only cause a problem if the caller is really slow
179   # between calls to us, in which case polling may be delayed by the
180   # caller's slowness plus our interval sleep.
181   if ( @{$self->{event_cache}} ) {
182      PTDEBUG && _d("Returning cached event");
183      return shift @{$self->{event_cache}};
184   }
185
186   # It's time to sleep if we want to sleep and this is not the first poll.
187   # Again, this assumes that the caller is not sleeping before calling us
188   # and is not really slow between calls.  By "really slow" I mean slower
189   # than the interval time.
190   if ( $self->{interval} && $self->{polls} ) {
191      PTDEBUG && _d("Sleeping between polls");
192      usleep($self->{interval});
193   }
194
195   # Poll the processlist and time how long this takes.  Also get
196   # the current time and calculate the poll time (etime) unless
197   # these values are given via %args (for testing).
198   # $time is the time after the poll so that $time-TIME should equal
199   # the query's real start time, but see $query_start below...
200   PTDEBUG && _d("Polling PROCESSLIST");
201   my ($time, $etime) = @args{qw(time etime)};
202   my $start          = $etime ? 0 : time;  # don't need start if etime given
203   my $rows           = $code->();
204   if ( !$rows ) {
205      warn "Processlist callback did not return an arrayref";
206      return;
207   }
208   $time  = time           unless $time;
209   $etime = $time - $start unless $etime;
210   $self->{polls}++;
211   PTDEBUG && _d('Rows:', ($rows ? scalar @$rows : 0), 'in', $etime, 'seconds');
212
213   my $active_cxn = $self->{active_cxn};
214   my $curr_cxn   = {};
215   my @new_cxn    = ();
216
217   # First look at each currently active process/cxn in the processlist.
218   # From these we can determine:
219   #   1. If any of our previously active cxn are still active.
220   #   2. If there's any new cxn.
221   CURRENTLY_ACTIVE_CXN:
222   foreach my $curr ( @$rows ) {
223
224      # Each currently active cxn is saved so we can later determine
225      # (3) if any previously active cxn ended.
226      $curr_cxn->{$curr->[ID]} = $curr;
227
228      # $time - TIME should equal the query's real start time, but since
229      # the poll may be delayed, the more-precise start time is
230      # $time - $etime - TIME; that is, we compensate $time for the amount
231      # of $etime we were delay before MySQL returned us the proclist rows,
232      # *But*, we only compensate with $etime for the restart check below
233      # because otherwise the start time just becomes the event's ts and
234      # that doesn't need to be so precise.
235      my $query_start = $time - ($curr->[TIME] || 0);
236
237      if ( $active_cxn->{$curr->[ID]} ) {
238         PTDEBUG && _d('Checking existing cxn', $curr->[ID]);
239         my $prev      = $active_cxn->{$curr->[ID]}; # previous state of cxn
240         my $new_query = 0;
241         my $fudge     = ($curr->[TIME] || 0) =~ m/\D/ ? 0.001 : 1; # micro-t?
242
243         # If this is true, then the cxn was executing a query last time
244         # we saw it.  Determine if the cxn is executing a new query.
245         if ( $prev->[INFO] ) {
246            if ( !$curr->[INFO] || $prev->[INFO] ne $curr->[INFO] ) {
247               # This is a new/different query because what's currently
248               # executing is different from what the cxn was previously
249               # executing.
250               PTDEBUG && _d('Info is different; new query');
251               $new_query = 1;
252            }
253            elsif ( defined $curr->[TIME] && $curr->[TIME] < $prev->[TIME] ) {
254               # This is a new/different query because the current exec
255               # time is less than the previous exec time, so the previous
256               # query ended and a new one began between polls.
257               PTDEBUG && _d('Time is less than previous; new query');
258               $new_query = 1;
259            }
260            elsif ( $curr->[INFO] && defined $curr->[TIME]
261                    && $query_start - $etime - $prev->[START] > $fudge)
262            {
263               # If the query's recalculated start time minus its previously
264               # calculated start time is greater than the fudge factor, then
265               # the query has restarted.  I.e. the new start time is after
266               # the previous start time.
267               my $ms = $self->{MasterSlave};
268
269               my $is_repl_thread = $ms->is_replication_thread({
270                                        Command => $curr->[COMMAND],
271                                        User    => $curr->[USER],
272                                        State   => $curr->[STATE],
273                                        Id      => $curr->[ID]});
274               if ( $is_repl_thread ) {
275                  PTDEBUG &&
276                  _d(q{Query has restarted but it's a replication thread, ignoring});
277               }
278               else {
279                  PTDEBUG && _d('Query restarted; new query',
280                     $query_start, $etime, $prev->[START], $fudge);
281                  $new_query = 1;
282               }
283            }
284
285            if ( $new_query ) {
286               # The cxn is executing a new query, so the previous query
287               # ended.  Make an event for the previous query.
288               $self->_update_profile($prev, $curr, $time);
289               push @{$self->{event_cache}},
290                  $self->make_event($prev, $time);
291            }
292         }
293
294         # If this is true, the cxn is currently executing a query.
295         # Determine if that query is old (i.e. same one running previously),
296         # or new.  In either case, we save it to recheck it next poll.
297         if ( $curr->[INFO] ) {
298            if ( $prev->[INFO] && !$new_query ) {
299               PTDEBUG && _d("Query on cxn", $curr->[ID], "hasn't changed");
300               $self->_update_profile($prev, $curr, $time);
301            }
302            else {
303               PTDEBUG && _d('Saving new query, state', $curr->[STATE]);
304               push @new_cxn, [
305                  @{$curr}[0..7],           # proc info
306                  int($query_start),        # START
307                  $etime,                   # ETIME
308                  $time,                    # FSEEN
309                  { ($curr->[STATE] || "") => 0 }, # PROFILE
310               ];
311            }
312         }
313      }
314      else {
315         PTDEBUG && _d('New cxn', $curr->[ID]);
316         if ( $curr->[INFO] && defined $curr->[TIME] ) {
317            # But only save the new cxn if it's executing.
318            PTDEBUG && _d('Saving query of new cxn, state', $curr->[STATE]);
319            push @new_cxn, [
320               @{$curr}[0..7],           # proc info
321               int($query_start),        # START
322               $etime,                   # ETIME
323               $time,                    # FSEEN
324               { ($curr->[STATE] || "") => 0 }, # PROFILE
325            ];
326         }
327      }
328   }  # CURRENTLY_ACTIVE_CXN
329
330   # Look at the cxn that we think are active.  From these we can
331   # determine:
332   #   3. If any of them ended.
333   # For the moment, "ended" means "not executing a query".  Later
334   # we may track a cxn in its entirety for quasi-profiling.
335   PREVIOUSLY_ACTIVE_CXN:
336   foreach my $prev ( values %$active_cxn ) {
337      if ( !$curr_cxn->{$prev->[ID]} ) {
338         PTDEBUG && _d('cxn', $prev->[ID], 'ended');
339         push @{$self->{event_cache}},
340            $self->make_event($prev, $time);
341         delete $active_cxn->{$prev->[ID]};
342      }
343      elsif (   ($curr_cxn->{$prev->[ID]}->[COMMAND] || "") eq 'Sleep'
344             || !$curr_cxn->{$prev->[ID]}->[STATE]
345             || !$curr_cxn->{$prev->[ID]}->[INFO] ) {
346         PTDEBUG && _d('cxn', $prev->[ID], 'became idle');
347         # We do not make an event in this case because it will have
348         # already been made above because of the INFO change.  But
349         # until we begin tracking cxn in their entirety, we do not
350         # to save idle cxn to save memory.
351         delete $active_cxn->{$prev->[ID]};
352      }
353   }
354
355   # Finally, merge new cxn into our hashref of active cxn.
356   # This is done here and not when the new cnx are discovered
357   # so that the PREVIOUSLY_ACTIVE_CXN doesn't look at them.
358   map { $active_cxn->{$_->[ID]} = $_; } @new_cxn;
359
360   $self->{last_poll} = $time;
361
362   # Return the first event in our cache, if any.  It may be an event
363   # we just made, or an event from a previous call.
364   my $event = shift @{$self->{event_cache}};
365   PTDEBUG && _d(scalar @{$self->{event_cache}}, "events in cache");
366   return $event;
367}
368
369# The exec time of the query is the max of the time from the processlist, or the
370# time during which we've actually observed the query running.  In case two
371# back-to-back queries executed as the same one and we weren't able to tell them
372# apart, their time will add up, which is kind of what we want.
373sub make_event {
374   my ( $self, $row, $time ) = @_;
375
376   my $observed_time = $time - $row->[FSEEN];
377   my $Query_time    = max($row->[TIME], $observed_time);
378
379   # An alternative to the above.
380   # my $observed_time = $self->{last_poll} - $row->[FSEEN];
381   # my $Query_time    = max($row->[TIME], $observed_time);
382
383   # Another alternative for this issue:
384   # http://code.google.com/p/maatkit/issues/detail?id=1246
385   # my $interval      = $time - $self->{last_poll};
386   # my $observed_time = ($self->{last_poll} + ($interval/2)) - $row->[FSEEN];
387   # my $Query_time    = max($row->[TIME], $observed_time);
388
389   # Slowlog Query_time includes Lock_time and we emulate this, too, but
390   # *not* by adding $row->[PROFILE]->{Locked} to $Query_time because
391   # our query time is already inclusive since we track query time based on
392   # INFO not STATE.  So our query time might be too inclusive since it
393   # includes any and all states of the query during its execution.
394
395   my $event = {
396      id         => $row->[ID],
397      db         => $row->[DB],
398      user       => $row->[USER],
399      host       => $row->[HOST],
400      arg        => $row->[INFO],
401      bytes      => length($row->[INFO]),
402      ts         => Transformers::ts($row->[START] + $row->[TIME]), # Query END time
403      Query_time => $Query_time,
404      Lock_time  => $row->[PROFILE]->{Locked} || 0,
405   };
406   PTDEBUG && _d('Properties of event:', Dumper($event));
407   return $event;
408}
409
410sub _get_active_cxn {
411   my ( $self ) = @_;
412   PTDEBUG && _d("Active cxn:", Dumper($self->{active_cxn}));
413   return $self->{active_cxn};
414}
415
416# Sub: _update_profile
417#   Update a query's PROFILE of STATE times.  The given cxn arrayrefs
418#   ($prev and $curr) should be the same cxn and same query.  If the
419#   query' state hasn't changed, the current state's time is incremented
420#   by time elapsed between the last poll and now now ($time).  Else,
421#   half the elapsed time is added to the previous state and half to the
422#   current state (re issue 1246).
423#
424#   We cannot calculate a START for any state because the query's TIME
425#   covers all states, so there's no way a posteriori to know how much
426#   of TIME was spent in any given state.  The best we can do is count
427#   how long we see the query in each state where ETIME (poll time)
428#   defines our resolution.
429#
430# Parameters:
431#   $prev - Arrayref of cxn's previous info
432#   $curr - Arrayref of cxn's current info
433#   $time - Current time (taken after poll)
434sub _update_profile {
435   my ( $self, $prev, $curr, $time ) = @_;
436   return unless $prev && $curr;
437
438   my $time_elapsed = $time - $self->{last_poll};
439
440   # Update only $prev because the caller should only be saving that arrayref.
441
442   if ( ($prev->[STATE] || "") eq ($curr->[STATE] || "") ) {
443      PTDEBUG && _d("Query is still in", $curr->[STATE], "state");
444      $prev->[PROFILE]->{$prev->[STATE] || ""} += $time_elapsed;
445   }
446   else {
447      # XXX The State of this cxn changed between polls.  How long
448      # was it in its previous state, and how long has it been in
449      # its current state?  We can't tell, so this is a compromise
450      # re http://code.google.com/p/maatkit/issues/detail?id=1246
451      PTDEBUG && _d("Query changed from state", $prev->[STATE],
452         "to", $curr->[STATE]);
453      my $half_time = ($time_elapsed || 0) / 2;
454
455      # Previous state ends.
456      $prev->[PROFILE]->{$prev->[STATE] || ""} += $half_time;
457
458      # Query assumes new state and we presume that the query has been
459      # in that state for half the poll time.
460      $prev->[STATE] = $curr->[STATE];
461      $prev->[PROFILE]->{$curr->[STATE] || ""}  = $half_time;
462   }
463
464   return;
465}
466
467# Accepts a PROCESSLIST and a specification of filters to use against it.
468# Returns queries that match the filters.  The standard process properties
469# are: Id, User, Host, db, Command, Time, State, Info.  These are used for
470# ignore and match.
471#
472# Possible find_spec are:
473#   * all            Match all not-ignored queries
474#   * busy_time      Match queries that have been Command=Query for longer than
475#                    this time
476#   * idle_time      Match queries that have been Command=Sleep for longer than
477#                    this time
478#   * ignore         A hashref of properties => regex patterns to ignore
479#   * match          A hashref of properties => regex patterns to match
480#
481sub find {
482   my ( $self, $proclist, %find_spec ) = @_;
483   PTDEBUG && _d('find specs:', Dumper(\%find_spec));
484   my $ms  = $self->{MasterSlave};
485
486   my @matches;
487   $self->{_reasons_for_matching} = undef;
488   QUERY:
489   foreach my $query ( @$proclist ) {
490      PTDEBUG && _d('Checking query', Dumper($query));
491      my $matched = 0;
492
493      # Don't allow matching replication threads.
494      if (    !$find_spec{replication_threads}
495           && $ms->is_replication_thread($query) ) {
496         PTDEBUG && _d('Skipping replication thread');
497         next QUERY;
498      }
499
500      # Match special busy_time.
501      #if ( $find_spec{busy_time} && ($query->{Command} || '') eq 'Query' ) {
502      if ( $find_spec{busy_time} && exists($self->{kill_busy_commands}->{$query->{Command} || ''}) ) {
503         next QUERY unless defined($query->{Time});
504         if ( $query->{Time} < $find_spec{busy_time} ) {
505            PTDEBUG && _d("Query isn't running long enough");
506            next QUERY;
507         }
508         my $reason = 'Exceeds busy time';
509         PTDEBUG && _d($reason);
510         # Saving the reasons for each query in the objct is a bit nasty,
511         # but the alternatives are worse:
512         # - Saving internal data in the query
513         # - Instead of using the stringified hashref as a key, using
514         #   a checksum of the hashes' contents. Which could occasionally
515         #   fail miserably due to timing-related issues.
516         push @{$self->{_reasons_for_matching}->{$query} ||= []}, $reason;
517         $matched++;
518      }
519
520      # Match special idle_time.
521      if ( $find_spec{idle_time} && ($query->{Command} || '') eq 'Sleep' ) {
522         next QUERY unless defined($query->{Time});
523         if ( $query->{Time} < $find_spec{idle_time} ) {
524            PTDEBUG && _d("Query isn't idle long enough");
525            next QUERY;
526         }
527         my $reason = 'Exceeds idle time';
528         PTDEBUG && _d($reason);
529         push @{$self->{_reasons_for_matching}->{$query} ||= []}, $reason;
530         $matched++;
531      }
532
533      PROPERTY:
534      foreach my $property ( qw(Id User Host db State Command Info) ) {
535         my $filter = "_find_match_$property";
536         # Check ignored properties first.  If the proc has at least one
537         # property that matches an ignore value, then it is totally ignored.
538         # and we can skip to the next proc (query).
539         if ( defined $find_spec{ignore}->{$property}
540              && $self->$filter($query, $find_spec{ignore}->{$property}) ) {
541            PTDEBUG && _d('Query matches ignore', $property, 'spec');
542            next QUERY;
543         }
544         # If the proc's property value isn't ignored, then check if it matches.
545         if ( defined $find_spec{match}->{$property} ) {
546            if ( !$self->$filter($query, $find_spec{match}->{$property}) ) {
547               PTDEBUG && _d('Query does not match', $property, 'spec');
548               next QUERY;
549            }
550            my $reason = 'Query matches ' . $property . ' spec';
551            PTDEBUG && _d($reason);
552            push @{$self->{_reasons_for_matching}->{$query} ||= []}, $reason;
553            $matched++;
554         }
555      }
556      if ( $matched || $find_spec{all} ) {
557         PTDEBUG && _d("Query matched one or more specs, adding");
558         push @matches, $query;
559         next QUERY;
560      }
561      PTDEBUG && _d('Query does not match any specs, ignoring');
562   } # QUERY
563
564   return @matches;
565}
566
567sub _find_match_Id {
568   my ( $self, $query, $property ) = @_;
569   return defined $property && defined $query->{Id} && $query->{Id} == $property;
570}
571
572sub _find_match_User {
573   my ( $self, $query, $property ) = @_;
574   return defined $property && defined $query->{User}
575      && $query->{User} =~ m/$property/;
576}
577
578sub _find_match_Host {
579   my ( $self, $query, $property ) = @_;
580   return defined $property && defined $query->{Host}
581      && $query->{Host} =~ m/$property/;
582}
583
584sub _find_match_db {
585   my ( $self, $query, $property ) = @_;
586   return defined $property && defined $query->{db}
587      && $query->{db} =~ m/$property/;
588}
589
590sub _find_match_State {
591   my ( $self, $query, $property ) = @_;
592   return defined $property && defined $query->{State}
593      && $query->{State} =~ m/$property/;
594}
595
596sub _find_match_Command {
597   my ( $self, $query, $property ) = @_;
598   return defined $property && defined $query->{Command}
599      && $query->{Command} =~ m/$property/;
600}
601
602sub _find_match_Info {
603   my ( $self, $query, $property ) = @_;
604   return defined $property && defined $query->{Info}
605      && $query->{Info} =~ m/$property/;
606}
607
608sub _d {
609   my ($package, undef, $line) = caller 0;
610   @_ = map { (my $temp = $_) =~ s/\n/\n# /g; $temp; }
611        map { defined $_ ? $_ : 'undef' }
612        @_;
613   print STDERR "# $package:$line $PID ", join(' ', @_), "\n";
614}
615
6161;
617}
618# ###########################################################################
619# End Processlist package
620# ###########################################################################
621