From bb3889c1d4930e2ca96b47aea10ce5e803737043 Mon Sep 17 00:00:00 2001 From: Dirk Koopman Date: Fri, 13 Jan 2023 18:57:12 +0000 Subject: [PATCH] pc11 -> pc61 upgrade work This includes: rewriting the exist pc11->pc61 to be more understandable (and may be work better). Add stats to this process and provide show/spotstats to enquire how it's all going. Dump the routing table to /spider/local_data (in json) every 10 minutes and on exit. Read the routing table back in on start up so that all that IP address info isn't lost over software updates or other routine restarts. --- Changes | 16 ++++++-- cmd/Commands_en.hlp | 12 ++++++ cmd/show/spotstats.pl | 23 +++++++++++ perl/DXProtHandle.pm | 95 ++++++++++++++++++++++++++++++++++--------- perl/Route.pm | 12 ++++++ perl/Route/Node.pm | 31 ++++++++++---- perl/Route/User.pm | 32 +++++++++++---- perl/cluster.pl | 8 +++- 8 files changed, 189 insertions(+), 40 deletions(-) create mode 100644 cmd/show/spotstats.pl diff --git a/Changes b/Changes index 3a74ec81..902e0707 100644 --- a/Changes +++ b/Changes @@ -1,3 +1,13 @@ +13Jan23======================================================================= +1. Periodically store Routing tables and, if they are young enough (def: 3hrs) + autotically restore them on restart of the node. This will short circuit + the need to rebuild the routing tables from scratch on every restart - + which is normally for something like software update. +2. Fix pc11 debugging stats with the correct figures. Sigh... Also move some + of the totals to a different place. +3. Add show/spotstats command which gives the current spot statistics shown + during pc11 debugging (which means you don't need to set/deb pc11 unless + you really want that extra noise). 12Jan23======================================================================= 1. Regularise 'set/debug pc11' output to track all the routes through PC11 and PC61 processing and statistics. @@ -14,9 +24,9 @@ http://www.dxspider.net/download/badip.global. I have added the following lines to my /spider/local_cmd/crontab: -24 * * * * spawn('cd /spider/local_data; wget http://www.dxspider.net/download/badip.torexit') -24 * * * * spawn('cd /spider/local_data; wget http://www.dxspider.net/download/badip.torrelay') -24 * * * * spawn('cd /spider/local_data; wget http://www.dxspider.net/download/badip.global') +24 * * * * spawn('cd /spider/local_data; wget -qN http://www.dxspider.net/download/badip.torexit') +24 * * * * spawn('cd /spider/local_data; wget -qN http://www.dxspider.net/download/badip.torrelay') +24 * * * * spawn('cd /spider/local_data; wget -qN http://www.dxspider.net/download/badip.global') 25 * * * * run_cmd('load/badip') The tor files are downloaded from https://lists.fissionrelays.net/tor/ at diff --git a/cmd/Commands_en.hlp b/cmd/Commands_en.hlp index 5320002a..909c3b7d 100644 --- a/cmd/Commands_en.hlp +++ b/cmd/Commands_en.hlp @@ -2797,6 +2797,18 @@ So for example:- SH/SAT AO-10 SH/SAT FENGYUN1 12 2 +=== 1^SHOW/SPOTSTATS^Show the current Spot statistics +View the current unique spot sentences seen since the last restart. + +It shows the number of PC11 and PC61 sentences and the percentage +of PC11s received of the total of both. It also shows the number +of PC11s that have been promoted to PC61 before being passed on +plus a total percentage of incoming PC11 that have been promoted. + +A PC11 can be promoted to PC61 by a stored IP address in the routing +table or it can be promoted by being delayed to a short for any +passing PC61 from another node. + === 6^SHOW/STARTUP ^View a user startup script === 0^SHOW/STARTUP^View your own startup script View the contents of a startup script created with SET/STARTUP. diff --git a/cmd/show/spotstats.pl b/cmd/show/spotstats.pl new file mode 100644 index 00000000..5c20a338 --- /dev/null +++ b/cmd/show/spotstats.pl @@ -0,0 +1,23 @@ +# show the current received spot stats including +# pc11s +# pc61s +# percentage of pc11s in the total no of (unique) pc11+pc61 spots +# no of pc11s promoted to pc61 by stored ip address +# no of pc11s promoted to pc61 because a pc61 with the same data came in just after the pc11 +# no of pc11 promoted to pc61 by any means +# percentage of pc11 promoted to pc61s + +my $self = shift; +return (1, $self->msg('e5')) unless $self->priv >= 1; +my @out; + +my $r = DXProt::get_pc11_61_stats(); +#$DB::single = 1; +if ($r) { + my $spots = $r->{pc61_rx} + $r->{pc11_rx}; + my $stats = sprintf "spots pc61: $r->{pc61_rx} pc11: $r->{pc11_rx}(%0.1f%%) total: $spots - promotions - by pc61: $r->{pc11_to_61} by route: $r->{rpc11_to_61} total: $r->{promotions}(%0.1f%%)", $r->{pc11_percent}, $r->{promotions_percent}; + push @out, $stats; +} else { + push @out, qq{pc11 stats not available}; +} +return (1, @out); diff --git a/perl/DXProtHandle.pm b/perl/DXProtHandle.pm index 256f2967..22c82ea4 100644 --- a/perl/DXProtHandle.pm +++ b/perl/DXProtHandle.pm @@ -49,7 +49,7 @@ use vars qw($pc11_max_age $pc23_max_age $last_pc50 $eph_restime $eph_info_restim $eph_pc15_restime $pc9x_past_age $pc9x_dupe_age $pc10_dupe_age $pc92_slug_changes $last_pc92_slug $pc92Ain $pc92Cin $pc92Din $pc92Kin $pc9x_time_tolerance - $pc92filterdef $senderverify $pc11_dwell_time + $pc92filterdef $senderverify $pc11_dwell_time $pc11_extract_route ); $pc9x_dupe_age = 60; # catch loops of circular (usually) D records @@ -63,6 +63,7 @@ $pc9x_time_tolerance; # thing a node might send - once an hour and we $senderverify = 0; # 1 - check for forged PC11 or PC61. # 2 - if forged, dump them. $pc11_dwell_time = 2; # number of seconds to wait for a PC61 to come to substitute the PC11 +$pc11_extract_route = 1; # generate missing user route entry and IP address from passing PC61s $pc92filterdef = bless ([ @@ -167,9 +168,7 @@ sub handle_11 } } - my $type = - - dbg("INPUT $self->{call} -> $line origin $origin recurse: $recurse") if isdbg("pc11") || isdbg("pc61"); + dbg("INPUT $self->{call}: $line origin $origin recurse: $recurse") if isdbg("pc11") || isdbg("pc61"); # my ($hops) = $pc->[8] =~ /^H(\d+)/; @@ -265,23 +264,46 @@ sub handle_11 unless ($recurse) { if ($pcno == 61) { if (Spot::dup_find(@spot[0..4,7])) { - dbg("DUPE $pc->[0] $self->{call} -> key: $key dumped") if isdbg('pc11'); + dbg("DUPE $pc->[0] $self->{call}: key: $key dumped") if isdbg('pc11'); return; } else { ++$pc61_rx; } + # as we have a route to a user, if it does not exist, create and link if (and only if) the node exists as well + if ($pc->[8]) { + my $new = $pc->[8]; + # $new =~ s/,/:/g; + my $r = Route::User::get($pc->[6]); + unless ($r) { + my $rn = Route::Node::get($pc->[7]) || Route::Node->new($pc->[7]); + $rn->add_user($pc->[6], 0, $pc->[8]); + $r = Route::User::get($pc->[6]); + } + if ($r) { + if ($r->ip ne $pc->[8]) { + my $old = $r->ip; + $r->ip($new); + dbg("ROUTE ALTER IP node: $pc->[7] user: $pc->[6] old IP: '$old'-> new IP: '$new'") if isdbg('pc11'); + } else { + dbg("ROUTE NEW IP node: $pc->[7] user: $pc->[6] IP: '$new'") if isdbg('pc11'); + } + } else { + dbg("ROUTE ADD Failed for node $pc->[7] user $pc->[6]") if isdbg('pc11'); + } + } + if ($pc11_saved{$key}) { ++$pc11_to_61; my $percent = $pc11_rx ? $pc11_to_61 * 100 / $pc11_rx : 0; - dbg(sprintf("PROMOTED BETTER $self->{call} -> $pc->[0] $key, using PC61, saved PC11 DUMPED: $pc61_rx pc11: $pc11_rx better pc61: $pc11_to_61 (%0.1f%%)", $percent)) if isdbg("pc11"); + dbg(sprintf("PROMOTED BETTER $self->{call}: $pc->[0] $key, using pc61, WAITING pc11 DUMPED: $pc61_rx pc11: $pc11_rx better pc61: $pc11_to_61 (%0.1f%%)", $percent)) if isdbg("pc11"); delete $pc11_saved{$key}; } } if ($pcno == 11) { if (Spot::dup_find(@spot[0..4,7])) { - dbg("DUPE $pc->[0] $self->{call} -> key: $key dumped") if isdbg('pc11'); + dbg("DUPE $pc->[0] $self->{call}: key: $key dumped") if isdbg('pc11'); return; } else { ++$pc11_rx; @@ -294,13 +316,14 @@ sub handle_11 # can we promote this to a PC61? my $r = Route::User::get($spot[4]); # find spotter + if ($r && $r->ip) { # do we have an ip addres $pcno = 61; $pc->[0] = 'PC61'; $pc->[7] = $spot[14] = $r->ip; ++$rpc11_to_61; my $percent = $pc11_rx ? $rpc11_to_61 * 100 / $pc11_rx : 0; - dbg(sprintf("PROMOTED ROUTE $self->{call} -> PC11 $key PROMOTED to PC61 with IP $spot[14] pc61: $pc61_rx pc11: $pc11_rx route->pc61 $rpc11_to_61 (%0.1f%%)", $percent)) if isdbg("pc11"); + dbg(sprintf("PROMOTED ROUTE $self->{call}: pc11 $key PROMOTED to pc61 with IP $spot[14] pc61: $pc61_rx pc11: $pc11_rx route->pc61 $rpc11_to_61 (%0.1f%%)", $percent)) if isdbg("pc11"); delete $pc11_saved{$key}; } @@ -308,27 +331,23 @@ sub handle_11 # save it and wait - it will be called from pc11_process if ($pcno == 11) { $pc11_saved{$key} = [$main::systime, $self, $pcno, $line, $origin, $pc]; - dbg("SAVED $self->{call} -> NEW $pc->[0] spot $key waiting for a better offer") if isdbg("pc11"); + dbg("WAITING $self->{call}: NEW $pc->[0] spot $key waiting for a better offer") if isdbg("pc11"); return; } } } - my $count = $pc11_to_61+$rpc11_to_61; - my $percent = $pc11_rx ? $count*100 / $pc11_rx : 0; - my $pc11_61 = $pc61_rx ? $pc11_rx*100 / $pc61_rx : 0; - dbg(sprintf("PASSED $self->{call} -> $pc->[0] spot $key, pc11: $pc11_rx pc61: $pc61_rx PC11/PC61 ratio: %0.1f%% total pc11->pc61: $count (%0.1f%%) ", $pc11_61, $percent)) if isdbg("pc11"); # this goes after the input filtering, but before the add # so that if it is input filtered, it isn't added to the dup # list. This allows it to come in from a "legitimate" source if (Spot::dup(@spot[0..4,7])) { - dbg("PCPROT: Duplicate Spot $self->{call} -> $pc->[0] $key ignored\n") if isdbg('chanerr') || isdbg('dupespot') || isdbg('pc11'); + dbg("PCPROT: Duplicate Spot $self->{call}: $pc->[0] $key ignored\n") if isdbg('chanerr') || isdbg('dupespot') || isdbg('pc11'); return; } - dbg("PROCESSING $self->{call} -> $pc->[0] key: $key") if isdbg('pc11'); + dbg("PROCESSING $self->{call}: $pc->[0] key: $key") if isdbg('pc11'); # we check IP addresses for PC61 - this will also dedupe PC11 copies if (@$pc > 8 && is_ipaddr($pc->[8])) { @@ -467,16 +486,21 @@ sub handle_11 send_dx_spot($self, $line, @spot) if @spot; # cancel any recursion as we have now processed it + my $count = $pc11_to_61+$rpc11_to_61; + my $percent = ($pc11_rx + $pc61_rx) ? ($pc11_rx * 100) / ($pc11_rx + $pc61_rx) : 0; + my $pc11_61 = $pc11_rx ? ($count * 100) / $pc11_rx : 0; + my $data = "$self->{call} $pc->[0] key: $key"; + my $stats = sprintf "pc11: $pc11_rx pc61: $pc61_rx pc11%%: %0.1f%% pc11->pc61: $count(%0.1f%%)", $percent, $pc11_61; if ($recurse) { if ($pc11_saved{$key}) { - dbg("END RECURSED $self->{call} $pc->[0] key: $key removed and finished") if isdbg('pc11'); + dbg("END RECURSED $data removed and finished $stats") if isdbg('pc11'); delete $pc11_saved{$key}; } else { - dbg("END RECURSED $self->{call} $pc->[0] key: $key finished") if isdbg('pc11'); + dbg("END RECURSED $data finished $stats") if isdbg('pc11'); } $recurse = 0; } else { - dbg("END NORMAL $self->{call} $pc->[0] key: $key finished") if isdbg('pc11'); + dbg("END NORMAL $data finished $stats") if isdbg('pc11'); } } @@ -486,7 +510,7 @@ sub pc11_process foreach my $key (keys %pc11_saved) { my $r = $pc11_saved{$key}; if ($main::systime > $r->[0] + $pc11_dwell_time) { - dbg("SAVED PC11 spot $key timed out waiting, recursing") if isdbg("pc11"); + dbg("RECURSE PC11 spot $key timed out waiting, resend") if isdbg("pc11"); my $self = $r->[1]; delete $pc11_saved{$key}; $self->handle_11(@$r[2..5], 1); @@ -494,6 +518,23 @@ sub pc11_process } } +# return the pc11 / pc61 / promotions data +sub get_pc11_61_stats +{ + my $promotions = $pc11_to_61+$rpc11_to_61; + my $percent = ($pc11_rx + $pc61_rx) ? ($pc11_rx * 100) / ($pc11_rx + $pc61_rx) : 0; + my $pc11_61p = $pc11_rx ? ($promotions * 100) / $pc11_rx : 0; + return { + pc11_rx => $pc11_rx+0, + pc61_rx => $pc61_rx+0, + pc11_to_61 => $pc11_to_61+0, + rpc11_to_61 => $rpc11_to_61+0, + promotions => $promotions+0, + pc11_percent => $percent+0, + promotions_percent => $pc11_61p+0, + }; +} + # announces sub handle_12 { @@ -807,7 +848,7 @@ sub handle_18 $self->state('init'); my $parent = Route::Node::get($self->{call}); - + # record the type and version offered if (my ($software, $version) = $pc->[1] =~ /(DXSpider|CC\s*Cluster)\s+Version: (\d+(?:\.\d+)?)/i) { $version += 0; @@ -828,6 +869,20 @@ sub handle_18 $self->sort('S'); } # $self->{handle_xml}++ if DXXml::available() && $pc->[1] =~ /\bxml/; + } elsif (my ($software, $version, $build) = $pc->[1] =~ /(AR-Cluster)\s+Version:\s+(\d+\.\d+).?(\d+\.\d+)?/) { + dbg("$self->{call} = $software version $version build $build"); + $self->{version} = $version; + $self->user->version($version); + $parent->version($version); + $self->{build} = $build; + $self->user->build($build); + $parent->build($build); + unless ($self->is_arcluster) { + dbg("Change U " . $self->user->sort . " C $self->{sort} -> R"); + $self->user->sort('R'); + $self->user->put; + $self->sort('R'); + } } else { dbg("$self->{call} = Unknown software ($pc->[1] $pc->[2])"); $self->version(50.0); diff --git a/perl/Route.pm b/perl/Route.pm index a8820ea4..99b4b2b1 100644 --- a/perl/Route.pm +++ b/perl/Route.pm @@ -423,6 +423,18 @@ sub field_prompt return $val->{$ele} || $valid{$ele}; } +sub write_cache +{ + Route::Node::write_cache(); + Route::User::write_cache(); +} + +sub read_cache +{ + Route::Node::read_cache(); + Route::User::read_cache(); +} + # # generic AUTOLOAD for accessors # diff --git a/perl/Route/Node.pm b/perl/Route/Node.pm index 348bb5b1..baa862ae 100644 --- a/perl/Route/Node.pm +++ b/perl/Route/Node.pm @@ -412,22 +412,37 @@ sub write_cache }; if (!$@ && @s) { my $fh = IO::File->new(">$cachefn") or confess("writing $cachefn $!"); - if (isdbg("routecache")) { - $fh->print(sort @s); - } - else { - $fh->print(@s); - } + print $fh "$_" for (sort @s); $fh->close; } else { - dbg("Route::Node:Write_cache error '$@'"); + dbg("Route::Node::write_cache error '$@'"); return; } $json->indent(0)->canonical(0); my $diff = _diffms($ta); - dbg("Route::Node:WRITE_CACHE time to write: $diff mS"); + dbg("Route::Node::write_cache time to write: $diff mS"); } +sub read_cache +{ + my $json = DXJSON->new; + $json->canonical(isdbg('routecache')); + + my $ta = [ gettimeofday ]; + my $count; + + my $fh = IO::File->new("$cachefn") or confess("reading $cachefn $!"); + while (my $l = <$fh>) { + chomp $l; + my ($k, $v) = split /:/, $l, 2; + $list{$k} = bless $json->decode($v) or confess("json error decoding '$v'"); + ++$count; + } + $fh->close; + + my $diff = _diffms($ta); + dbg("Route::Node::read_cache time to read $count records from $cachefn : $diff mS"); +} sub DESTROY { diff --git a/perl/Route/User.pm b/perl/Route/User.pm index bbd289d2..3a6f4f32 100644 --- a/perl/Route/User.pm +++ b/perl/Route/User.pm @@ -114,19 +114,35 @@ sub write_cache }; if (!$@ && @s) { my $fh = IO::File->new(">$cachefn") or confess("writing $cachefn $!"); - if (isdbg("routecache")) { - $fh->print(sort @s); - } - else { - $fh->print(@s); - } + print $fh $_ for (sort @s); $fh->close; } else { - dbg("Route::User:Write_cache error '$@'"); + dbg("Route::User::write_cache error '$@'"); return; } my $diff = _diffms($ta); - dbg("Route::User:WRITE_CACHE time to write: $diff mS"); + dbg("Route::User::write_cache time to write: $diff mS"); +} + +sub read_cache +{ + my $json = DXJSON->new; + $json->canonical(isdbg('routecache')); + + my $ta = [ gettimeofday ]; + my $count; + + my $fh = IO::File->new("$cachefn") or confess("reading $cachefn $!"); + while (my $l = <$fh>) { + chomp $l; + my ($k, $v) = split /:/, $l, 2; + $list{$k} = bless $json->decode($v) or confess("json error decoding '$v'"); + ++$count; + } + $fh->close; + + my $diff = _diffms($ta); + dbg("Route::User::read_cache time to read $count records from $cachefn : $diff mS"); } # diff --git a/perl/cluster.pl b/perl/cluster.pl index 2cbdee68..177009ea 100755 --- a/perl/cluster.pl +++ b/perl/cluster.pl @@ -464,6 +464,9 @@ sub cease # close all databases DXDb::closeall; + # Write route cache + Route::write_cache(); + # close all listeners foreach my $l (@listeners) { $l->close_server; @@ -646,7 +649,9 @@ sub setup_start } } - + # read any route cache there might be + Route::read_cache(); + # start listening for incoming messages/connects dbg("starting listeners ..."); my $conn = IntMsg->new_server($clusteraddr, $clusterport, \&login); @@ -860,6 +865,7 @@ sub per_minute sub per_10_minute { RBN::per_10_minute(); + Route::write_cache(); } sub per_hour -- 2.34.1