Random warnings in duplicate fixup in Net::SIP::Dispatcher

[intellasoft]

Inside this sub __resolve_uri_final in Net/SIP/Dispatcher.pm

This call causes random warnings:

    @$resp =
        sort { $a->{prio} <=> $b->{prio} }
        grep { !$dup{$_->{host}}{$_->{family}}{$_->{proto}}{$_->{addr}}{$_->{port}}++ }
        @$resp;

Use of uninitialized value in hash element at /usr/local/library/perl/lib/perl5/Net/SIP/Dispatcher.pm line 889.

I added a dumper for $resp to see what it's working on:

$VAR1 = [ { 'prio' => 65536, 'host' => 'sip.clearip.com', 'family' => 2, 'proto' => 'udp', 'addr' => '35.175.114.72', 'port' => 5060 }, { 'port' => 5060, 'prio' => 65536, 'host' => 'sip.clearip.com', 'family' => 2, 'proto' => 'udp', 'addr' => '35.175.114.73' }, { 'proto' => 'udp', 'family' => 2, 'addr' => '35.175.114.71', 'prio' => 65536, 'host' => 'sip.clearip.com', 'port' => 5060 }, { 'port' => 5060, 'prio' => 65536, 'host' => 'sip.clearip.com', 'proto' => 'udp', 'family' => 2, 'addr' => '35.175.114.74' }, { 'port' => 5060, 'addr' => '35.175.114.72', 'family' => 2, 'proto' => 'tcp', 'host' => 'sip.clearip.com', 'prio' => 65536 }, { 'proto' => 'tcp', 'family' => 2, 'addr' => '35.175.114.73', 'prio' => 65536, 'host' => 'sip.clearip.com', 'port' => 5060 }, { 'addr' => '35.175.114.71', 'proto' => 'tcp', 'family' => 2, 'host' => 'sip.clearip.com', 'prio' => 65536, 'port' => 5060 }, { 'port' => 5060, 'host' => 'sip.clearip.com', 'prio' => 65536, 'addr' => '35.175.114.74', 'proto' => 'tcp', 'family' => 2 } ];

[noxxi]

Unfortunately I don't get the warnings with the data you provided. Please create a minimal but reproducible example so that I can debug the problem.

[intellasoft]

It's very random. I'm having a hard time constructing a reproduction.

[kobaz]

Here's more information: See attached for full dump

I get this warning: Use of uninitialized value in hash element at /usr/local/library/perl/lib/perl5/Net/SIP/Dispatcher.pm line 889

uninitalized.log

[kobaz]

I am trying to narrow down the problem here.

I added debugs to try and find why under random situations that one of the values is undefined in the $resp list

sub __resolve_uri_final {
    my ($dst_addr,$legs,$allowed_legs,$force_port,$default_port,$callback,$resp) = @_;
    $DEBUG && DEBUG_DUMP( 100,$resp );

    return invoke_callback( $callback,EHOSTUNREACH )
        unless $resp && @$resp;

    # overwrite port if it was forced by user
    do { $_->{port} = $force_port for(@$resp) } if $force_port;

    # for A|AAAA records we got no port, use default_port
    $_->{port} ||= $default_port for(@$resp);

    # sort by prio and eliminate duplicates
    # FIXME: can contradict order in @proto
    if (@$resp>1) {
        my %dup;

+       my @undef;
+
+       foreach my $r (@$resp) {
+         push(@undef, $r) if (!defined($r->{prio}) || !defined($r->{host}) || !defined($r->{family}) || !defined($r->{addr}) || !defined($r->{port}));
+       }
+
+       if (scalar(@undef)) {
+         DEBUG(50,"__resolve_uri_final something undef");
+         DEBUG_DUMP(50, \@undef);
+       }
+
        @$resp =
            sort { $a->{prio} <=> $b->{prio} }
            grep { !$dup{$_->{host}}{$_->{family}}{$_->{proto}}{$_->{addr}}{$_->{port}}++ }
            @$resp;
    }

Something strange I've run into:

main::__ANON__('Attempt to access disallowed key \'prio\' in a restricted hash at /usr/local/library/perl/lib/perl5/Net/SIP/Dispatcher.pm line 889.^J') called at /usr/local/library/perl/lib/perl5/Net/SIP/Dispatcher.pm line 889
Net::SIP::Dispatcher::__resolve_uri_final('ARRAY(0x56135ef6e150)', 'ARRAY(0x56135ef6dbb0)', 'ARRAY(0x56135ef745b0)', undef, 5060, 'ARRAY(0x56135ef6c008)', 'ARRAY(0x56135ef6de20)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Util.pm line 484
Net::SIP::Util::invoke_callback('ARRAY(0x56135ef74490)', 'ARRAY(0x56135ef6de20)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Dispatcher.pm line 999
Net::SIP::Dispatcher::__ANON__('ARRAY(0x56135ef717f8)', 'ARRAY(0x56135ef74490)', 'ARRAY(0x56135ef6de20)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Util.pm line 484
Net::SIP::Util::invoke_callback('ARRAY(0x56135ef747a8)', 'ARRAY(0x56135ef6de20)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Dispatcher.pm line 1202
Net::SIP::Dispatcher::__generic_resolver('HASH(0x56135ef71330)', 'A:sip.clearip.com', 'ARRAY(0x56135ef74da8)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Util.pm line 484
Net::SIP::Util::invoke_callback('ARRAY(0x56135ef71e40)', 'ARRAY(0x56135ef74da8)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Dispatcher.pm line 1245
Net::SIP::Dispatcher::__ANON__('IO::Socket::IP=GLOB(0x56135ef716a8)', 'ARRAY(0x56135ef71e40)', 'IO::Socket::IP=GLOB(0x56135ef716a8)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Util.pm line 484
Net::SIP::Util::invoke_callback(undef, undef) called at /usr/local/library/perl/lib/perl5/Net/SIP/Dispatcher/Eventloop.pm line 242
Net::SIP::Dispatcher::Eventloop::loop('Net::SIP::Dispatcher::Eventloop=HASH(0x56135ef4d450)', 5, 'SCALAR(0x56135ef33f58)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Simple.pm line 268
Net::SIP::Simple::loop('Net::SIP::Simple=HASH(0x56135ef53458)', 5, 'SCALAR(0x56135ef33f58)') called at /intellasoft/Modules/Intellasoft/LIB/Intellasoft/Vendors/TransNexus.pm line 325

This doesn't always happen.... but: Any idea why this would be set randomly as a restricted hash? It's not normally restricted in 99.99% of my testing.

1 in 10000 sessions will throw this error. Still can't find the cause yet.

[kobaz]

I think I might have found one issue:

  my $ua = Net::SIP::Simple->new(
    legs           => [$leg_from, $leg_to],

I think Net::SIP will sometimes choose the wrong leg when replying to traffic.. because i also saw this:

main::__ANON__('target protocol  does not match leg tcp at /usr/local/library/perl/lib/perl5/Net/SIP/Leg.pm line 432.^J') called at /usr/local/library/perl/lib/perl5/CGI/Carp.pm line 361
CGI::Carp::realdie('target protocol  does not match leg tcp at /usr/local/library/perl/lib/perl5/Net/SIP/Leg.pm line 432.^J') called at /usr/local/library/perl/lib/perl5/CGI/Carp.pm line 453
CGI::Carp::die('target protocol  does not match leg tcp') called at /usr/local/library/perl/lib/perl5/Net/SIP/Leg.pm line 432
Net::SIP::Leg::deliver('Net::SIP::Leg=HASH(0x55e321fb1788)', 'Net::SIP::Request=HASH(0x55e32201e9c8)', 'HASH(0x55e321dc6298)', 'ARRAY(0x55e3220686f0)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Dispatcher.pm line 661
Net::SIP::Dispatcher::__deliver('Net::SIP::Dispatcher=HASH(0x55e31ba51490)', 'Net::SIP::Dispatcher::Packet=HASH(0x55e321d818e8)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Dispatcher.pm line 626
Net::SIP::Dispatcher::__ANON__('Net::SIP::Dispatcher=HASH(0x55e31ba51490)', 'Net::SIP::Dispatcher::Packet=HASH(0x55e321d818e8)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Util.pm line 484
Net::SIP::Util::invoke_callback('ARRAY(0x55e321faf6f8)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Dispatcher.pm line 928
Net::SIP::Dispatcher::__resolve_uri_final('ARRAY(0x55e321fb11e8)', 'ARRAY(0x55e321fb1830)', 'ARRAY(0x55e321d81408)', undef, 5060, 'ARRAY(0x55e321faf6f8)', 'ARRAY(0x55e321fb11b8)') called at /usr/local/library/perl/lib/perl5/Net/SIP/Uti\

The die message is:

    die "target protocol $dst->{proto} does not match leg $self->{proto}"
        if exists $dst->{proto} && $dst->{proto} ne $self->{proto};

with the message being: target protocol does not match leg tcp which means $dst->{proto} is undefined/empty

[kobaz]

I also tried getting rid of $leg_to

  my $ua = Net::SIP::Simple->new(
    legs           => [$leg_from],
    from           => $from_user,
    outgoing_proxy => 'sip.clearip.com',
    domain         => 'sip.clearip.com',
  );

same error:

Trace begun at (eval 231) line 1
main::__ANON__('target protocol  does not match leg tcp at /usr/local/library/perl/lib/perl5/Net/SIP/Leg.pm line 432.^J') called at /usr/local/library/perl/lib/perl5/CGI/Carp.pm line 361
CGI::Carp::realdie('target protocol  does not match leg tcp at /usr/local/library/perl/lib/perl5/Net/SIP/Leg.pm line 432.^J') called at /usr/local/library/perl/lib/perl5/CGI/Carp.pm line 453

I'm going to work on next trying to figure out exactly why it fails so randomly. It looks like it's related to an issue I mentioned in another thread regarding multiple A records for a sip destination