perl/DXDebug.pm

   1 #
   2 # The system variables - those indicated will need to be changed to suit your
   3 # circumstances (and callsign)
   4 #
   5 # Copyright (c) 1998-2019 - Dirk Koopman G1TLH
   6 #
   7 # Note: Everything is recorded into the ring buffer (in perl terms: a numerically max sized array).
   8 #       To allow debugging of a category (e.g. 'chan') but not onto disc (just into the ring buffer)
   9 #       do: set/debug chan nologchan
  10 #
  11 #       To print the current contents into the debug log: show/debug_ring
  12 #
  13 #       On exit or serious error the ring buffer is printed to the current debug log
  14 #
  15 # In Progress:
  16 #       Expose a localhost listener on port (default) 27755 to things like watchdbg so that they can carry on
  17 #       as normal, possibly with a "remember" button to permanently capture stuff observed.
  18 #
  19 # Future:
  20 #       This is likely to be some form of triggering or filtering controlling (some portion
  21 #       of) ring_buffer dumping.
  22 #
  23 #
  24
  25 package DXDebug;
  26
  27 use 5.10.1;
  28 use warnings;
  29
  30 require Exporter;
  31 @ISA = qw(Exporter);
  32 @EXPORT = qw(dbginit dbg dbgadd dbgsub dbglist dbgdump isdbg dbgclose dbgtrace dbgprintring dbgsetcat confess croak cluck carp);
  33
  34 use strict;
  35 use vars qw(%dbglevel $fp $callback $cleandays $keepdays $dbgringlth);
  36
  37 use DXUtil;
  38 use DXLog ();
  39 use Carp ();
  40 use POSIX qw(isatty);
  41
  42 %dbglevel = ();
  43 $fp = undef;
  44 $callback = undef;
  45 $keepdays = 10;
  46 $cleandays = 100;
  47 $dbgringlth = 500;
  48
  49 our $no_stdout;                                 # set if not running in a terminal
  50 our @dbgring;
  51
  52 # Avoid generating "subroutine redefined" warnings with the following
  53 # hack (from CGI::Carp):
  54 if (!defined $DB::VERSION) {
  55         local $^W=0;
  56         eval qq( sub confess {
  57             \$SIG{__DIE__} = 'DEFAULT';
  58         DXDebug::dbgprintring() if DXDebug::isdbg('nologchan');
  59         DXDebug::dbg(\$@);
  60 #               DXDebug::dbg(Carp::shortmess(\@_));
  61         DXDebug::longmess(\@_);
  62             exit(-1);
  63         }
  64         sub croak {
  65                 \$SIG{__DIE__} = 'DEFAULT';
  66         DXDebug::dbgprintring() if DXDebug::isdbg('nologchan');
  67         DXDebug::dbg(\$@);
  68 #               DXDebug::dbg(Carp::longmess(\@_));
  69         DXDebug::shortmess(\@_);
  70                 exit(-1);
  71         }
  72         sub carp {
  73         DXDebug::dbgprintring(5) if DXDebug::isdbg('nologchan');
  74 #        DXDebug::dbg(Carp::shortmess(\@_));
  75         DXDebug::longmess(\@_);
  76     }
  77         sub cluck {
  78         DXDebug::dbgprintring(5) if DXDebug::isdbg('nologchan');
  79 #        DXDebug::dbg(Carp::longmess(\@_));
  80         DXDebug::longmess(\@_);
  81     } );
  82
  83     CORE::die(Carp::shortmess($@)) if $@;
  84 } else {
  85     eval qq( sub confess { die Carp::longmess(\@_); };
  86                          sub croak { die Carp::shortmess(\@_); };
  87                          sub cluck { warn Carp::longmess(\@_); };
  88                          sub carp { warn Carp::shortmess(\@_); };
  89    );
  90 }
  91
  92
  93 my $_isdbg = '';                                                # current dbg level we are processing
  94
  95 # print stack trace
  96 sub dbgtrace
  97 {
  98 #       say "*** in dbgtrace";
  99         $_isdbg = 'trace';
 100         dbg(@_);
 101         for (my $i = 1; (my ($pkg, $fn, $l, $subr) = caller($i)); ++$i) {
 102 #               say "*** in dbgtrace $i";
 103                 next if $pkg eq 'DXDebug';
 104 #               say "*** in dbgtrace after package";
 105                 last if $pkg =~ /Mojo/;
 106 #               say "*** in dbgtrace $i after mojo";
 107                 $_isdbg = 'trace';
 108                 dbg("Stack ($i): ${pkg}::$subr in $fn line: $l");
 109         }
 110         $_isdbg = '';
 111 }
 112
 113 sub dbg
 114 {
 115 #       return unless $fp;
 116         my $t = time;
 117         for (@_) {
 118                 my $r = $_;
 119                 chomp $r;
 120                 my @l = split /\n/, $r;
 121                 foreach my $l (@l) {
 122                         $l =~ s/([\x00-\x08\x0B-\x1f\x7f-\xff])/sprintf("%%%02X",ord($1))/eg;
 123                         my $tag = $_isdbg ? "($_isdbg) " : '(*) ';
 124                         print "$tag$l\n" if defined \*STDOUT && !$no_stdout;
 125                         my $str = "$t^$tag$l";
 126                         &$callback($str) if $callback;
 127                         if ($dbgringlth) {
 128                                 shift @dbgring while (@dbgring > $dbgringlth);
 129                                 push @dbgring, $str;
 130                         }
 131                         $fp->writeunix($t, $str) unless !$fp || $dbglevel{"nolog$_isdbg"} ;
 132                 }
 133         }
 134         $_isdbg = '';
 135 }
 136
 137 sub dbginit
 138 {
 139         my $basename = shift || 'debug';
 140         $callback = shift;
 141
 142         # add sig{__DIE__} handling
 143         unless (defined $DB::VERSION) {
 144                 $SIG{__WARN__} = sub {
 145                         if ($_[0] =~ /Deep\s+recursion/i) {
 146                                 dbg($@);
 147                                 dbg(Carp::longmess(@_));
 148                                 CORE::die;
 149                         }
 150                         else {
 151                                 dbg($@);
 152                                 dbg(Carp::shortmess(@_));
 153                         }
 154                 };
 155
 156                 $SIG{__DIE__} = sub { dbg($@); dbg(Carp::longmess(@_)); };
 157
 158                 # switch off STDOUT printing if we are not talking to a TTY
 159                 unless ($^O =~ /^MS/ || $^O =~ /^OS-2/) {
 160                         unless (isatty(STDOUT->fileno)) {
 161                                 ++$no_stdout;
 162                         }
 163                 }
 164         }
 165
 166         $fp = DXLog::new($basename, 'dat', 'd');
 167         dbgclearring();
 168 }
 169
 170 sub dbgclose
 171 {
 172         $SIG{__DIE__} = $SIG{__WARN__} = 'DEFAULT';
 173         if ($fp) {
 174                 dbgprintring() if grep /nolog/, keys %dbglevel;
 175                 $fp->close();
 176         }
 177         dbgclearring();
 178         undef $fp;
 179 }
 180
 181 sub dbgdump
 182 {
 183         return unless $fp;
 184
 185         my $l = shift;
 186         my $m = shift;
 187         if ($dbglevel{$l} || $l eq 'err') {
 188                 my @out;
 189                 foreach my $l (@_) {
 190                         for (my $o = 0; $o < length $l; $o += 16) {
 191                                 my $c = substr $l, $o, 16;
 192                                 my $h = unpack "H*", $c;
 193                                 $c =~ s/[\x00-\x1f\x7f-\xff]/./g;
 194                                 my $left = 16 - length $c;
 195                                 $h .= ' ' x (2 * $left) if $left > 0;
 196                                 push @out, $m . sprintf("%4d:", $o) . "$h $c";
 197                                 $m = ' ' x (length $m);
 198                         }
 199                 }
 200                 dbg(@out) if isdbg($l); # yes, I know, I have my reasons;
 201         }
 202 }
 203
 204 sub dbgadd
 205 {
 206         my $entry;
 207
 208         foreach $entry (@_) {
 209                 $dbglevel{$entry} = 1;
 210         }
 211 }
 212
 213 sub dbgsub
 214 {
 215         my $entry;
 216
 217         foreach $entry (@_) {
 218                 delete $dbglevel{$entry};
 219         }
 220 }
 221
 222 sub dbglist
 223 {
 224         return keys (%dbglevel);
 225 }
 226
 227 sub isdbg($)
 228 {
 229         return unless $fp;
 230         if ($dbglevel{$_[0]}) {
 231                 $_isdbg = $_[0];
 232                 return 1;
 233     }
 234 }
 235
 236 sub shortmess
 237 {
 238         return dbgtrace(@_);
 239 }
 240
 241 sub longmess
 242 {
 243         return dbgtrace(@_);
 244 }
 245
 246 sub dbgprintring
 247 {
 248         return unless $fp;
 249         my $i = shift || 0;
 250         my $count = @dbgring;
 251         $i =  @dbgring-$i if $i;
 252         return 0 unless $i < $count;    # do nothing if there is nothing to print
 253
 254         my $first;
 255         my $l;
 256         for ( ; $i < $count; ++$i) {
 257                 my ($t, $str) = split /\^/, $dbgring[$i], 2;
 258                 next unless $t;
 259                 my $lt = time;
 260                 unless ($first) {
 261                         $fp->writeunix($lt, "$lt^###");
 262                         $fp->writeunix($lt, "$lt^### RINGBUFFER START at line $i (zero base)");
 263                         $fp->writeunix($lt, "$lt^###");
 264                         $first = $t;
 265                 }
 266                 my $buf = sprintf "%02d:%02d:%02d", (gmtime($t))[2,1,0];
 267                 $fp->writeunix($lt, "$lt^RING: $buf^$str");
 268                 ++$l;
 269         }
 270         my $et = time;
 271         $fp->writeunix($et, "$et^###");
 272         $fp->writeunix($et, "$et^### RINGBUFFER END $l debug lines written");
 273         $fp->writeunix($et, "$et^###");
 274         return $l;
 275 }
 276
 277 sub dbgclearring
 278 {
 279         @dbgring = ();
 280 }
 281
 282 # clean out old debug files, stop when you get a gap of more than a month
 283 sub dbgclean
 284 {
 285         my $date = $fp->unixtoj($main::systime)->sub($keepdays+1);
 286         my $i = 0;
 287
 288         while ($i < 31) {
 289                 my $fn = $fp->_genfn($date);
 290                 if (-e $fn) {
 291                         unlink $fn;
 292                         $i = 0;
 293                 }
 294                 else {
 295                         $i++;
 296                 }
 297                 $date = $date->sub(1);
 298         }
 299 }
 300
 301 # force a category for the next (unconditional) dbg message (replace (*) with (<something>))
 302 sub dbgsetcat
 303 {
 304         $_isdbg = shift;
 305 }
 306
 307 1;
 308 __END__
 309
 310
 311
 312
 313
 314
 315