Abysmal performance of Net::SFTP (and I have GMP & Pari)

Discussion in 'Perl Misc' started by usenet@DavidFilmer.com, Nov 1, 2006.

  1. Guest

    Greetings.

    I am having terrible problems with very poor performance when using
    Net::SFTP. Specifically, it takes about 10 seconds for a machine to
    transfer a 1 MB file to itself (localhost), and this is a brand new,
    very FAST, lightly loaded server (and I can replicate this problem on
    other machines as well). Using ordinary FTP takes 0.4 seconds, and
    doing the same thing with commandline sftp completes the task in the
    blink of an eye.

    I ***DO*** have Math::GMP::BigInt installed (as well as
    Math::pari::BigInt), and a diagnostic dump of %INC indicates these are
    being called (see below). Enabling SFTP debug mode shows that I am not
    experiencing any long pauses (ie, I get a handle in 0.8 seconds, and
    transfers occur at a steady - though slow - pace without any pauses).

    It is doubtful that I have the option to use Net::SSH2 (because the
    servers do not have libssh2 and I probably won't be able to do anything
    about that). I really need to figure out why Net::SFTP is behaving so
    poorly. I really appreciate any insight anyone can offer.

    Here is my test script:

    #!/usr/bin/perl
    use strict; use warnings;
    use Net::SFTP;

    #Create with: dd if=/dev/urandom of=/tmp/1mb.junk bs=1024 count=1024
    my $testfile = "/tmp/1mb.junk";

    my %comm = (
    user => 'myuserid',
    password => 'mypassword',
    ssh_args => [ cipher => 'blowfish-cbc' ],
    debug => 0,
    );

    my $sftp = Net::SFTP->new('localhost', %comm) or die "oops: $@";

    $sftp->put ($testfile, "$testfile.test")
    or die("ftp put failed ", $sftp->message);

    END{
    print map{"$_\n"} sort keys %INC; #check for GMP/Pari
    }

    __END__


    The blowfish cipher is indeed the "fastest" (as the docs indicate). I
    tried the other available ciphers with inferior results:
    arcfour 14 seconds
    3des-cbc 22 seconds


    The "interesting" parts of the %INC dump (in the END block of the test
    script) look like this (and validate that GMP/Pari are being called):

    Convert/ASN1 MIME/Base64
    Convert/ASN1/IO Math/BigInt
    Convert/ASN1/_decode Math/BigInt/GMP
    Convert/ASN1/_encode Math/GMP
    Convert/ASN1/parser Math/Pari
    Convert/PEM Net/SFTP
    Convert/PEM/CBC Net/SFTP/Attributes
    Convert/PEM/ErrorHandler Net/SFTP/Buffer
    Crypt/Blowfish Net/SFTP/Constants
    Crypt/DH Net/SFTP/Util
    Crypt/DSA Net/SSH/Perl
    Crypt/DSA/Key Net/SSH/Perl/Agent
    Crypt/DSA/Key/PEM Net/SSH/Perl/Auth
    Crypt/DSA/KeyChain Net/SSH/Perl/Auth/Password
    Crypt/DSA/Signature Net/SSH/Perl/Auth/PublicKey
    Crypt/DSA/Util Net/SSH/Perl/AuthMgr
    Crypt/Random Net/SSH/Perl/Buffer
    Crypt/Random/Generator Net/SSH/Perl/Channel
    Crypt/Random/Provider/File Net/SSH/Perl/ChannelMgr
    Crypt/Random/Provider/devurandom Net/SSH/Perl/Cipher
    Digest/HMAC Net/SSH/Perl/Cipher/Blowfish
    Digest/HMAC_MD5 Net/SSH/Perl/Cipher/CBC
    Digest/HMAC_SHA1 Net/SSH/Perl/Comp
    Digest/MD5 Net/SSH/Perl/Config
    Digest/SHA1 Net/SSH/Perl/Constants
    Digest/base Net/SSH/Perl/Kex
    Encode Net/SSH/Perl/Kex/DH1
    Encode/Alias Net/SSH/Perl/Key
    Encode/Config Net/SSH/Perl/Key/DSA
    Encode/Encoding Net/SSH/Perl/Mac
    Fcntl Net/SSH/Perl/Packet
    IO Net/SSH/Perl/SSH2
    IO/Handle Net/SSH/Perl/Util
    IO/Select Net/SSH/Perl/Util/Hosts
    IO/Socket Net/SSH/Perl/Util/SSH2MP
    IO/Socket/INET Net/SSH/Perl/Util/Term
    IO/Socket/UNIX


    I ran the script thorough Devel::profile (perl -d:profile test.pl); the
    top results (> 1.0%) are:

    time elapsed (wall): 12.8377
    time running program: 9.6744 (75.36%)
    time profiling (est.): 3.1633 (24.64%)
    number of calls: 361634
    number of exceptions: 11

    %Time Sec. #calls sec/call name
    28.05 2.714 131970 0.000021 Crypt::Blowfish::encrypt
    23.32 2.256 139 0.016228 Net::SSH::perl::Cipher::CBC::encrypt
    10.08 0.975 282 0.003458 IO::Select::select
    5.53 0.535 32 0.016733 IO::Select::can_read
    4.51 0.437 132840 0.000003 Crypt::Blowfish::crypt
    2.78 0.269 59 0.004553 Net::SSH::perl::Util::SSH2MP::bin2mp
    2.52 0.244 144 0.001693 Net::SSH::perl::Util::SSH2MP::mp2bin
    1.47 0.142 1035 0.000137 Net::SSH::perl::Buffer::new
    1.25 0.121 449 0.000269 Net::SSH::perl::packet::read_poll_ssh2
    1.12 0.109 1041 0.000104 Net::SSH::perl::Util::import

    So the machine is definitely spending most of its time with the crypto
    stuff (not I/O stuff), which is to be expected, but it is taking a LONG
    time to do the crypto stuff.

    I know that Math::BigInt::GMP (or Pari) is very important for SFTP
    performance. But I have both libraries and their BigInt modules
    installed. Is there ANOTHER math module that I need???

    I'm happy to entertain any "try this and see what happens" ideas.

    Thanks!

    --
    The best way to get a good answer is to ask a good question.
    David Filmer (http://DavidFilmer.com)
     
    , Nov 1, 2006
    #1
    1. Advertisements

  2. zentara Guest

    On 31 Oct 2006 17:30:40 -0800, wrote:


    >So the machine is definitely spending most of its time with the crypto
    >stuff (not I/O stuff), which is to be expected, but it is taking a LONG
    >time to do the crypto stuff.
    >
    >I know that Math::BigInt::GMP (or Pari) is very important for SFTP
    >performance. But I have both libraries and their BigInt modules
    >installed. Is there ANOTHER math module that I need???


    Did you rebuild the Net::SFTP and the Net::SSH::perl module
    after you installed the Math modules? And I mean rebuild them
    from scratch, not just install some premade package?

    When things don't work, usually the best bet is to upgrade to
    the latest versions of all modules, and Perl version, AND build
    them yourself so you can see any warnings.




    --
    I'm not really a human, but I play one on earth.
    http://zentara.net/japh.html
     
    zentara, Nov 1, 2006
    #2
    1. Advertisements

  3. Sisyphus Guest

    <> wrote in message
    news:...
    ..
    ..
    >
    > I ***DO*** have Math::GMP::BigInt installed (as well as
    > Math::pari::BigInt), and a diagnostic dump of %INC indicates these are
    > being called (see below).


    I would still entertain the possibility that Math::BigInt is being called
    somehow. To check that's *not* the case I would rename Math/BigInt.pm to
    (eg) Math/BigInt_hide.pm, re-run the script and see if performance improves.
    If it makes no difference then we can assume that Math::BigInt is *not* to
    blame - but if either the script croaks, or it runs significantly faster,
    then there's your culprit.

    I note that Math::BigInt *is* listed in %INC .... hence my suspicions about
    it.

    Cheers,
    Rob
     
    Sisyphus, Nov 2, 2006
    #3
  4. Guest

    Sisyphus wrote:
    > I would still entertain the possibility that Math::BigInt is being called
    > somehow. To check that's *not* the case I would rename Math/BigInt.pm to
    > (eg) Math/BigInt_hide.pm, re-run the script and see if performance improves.


    Thanks for the suggestion, Rob (I was hoping you would notice and reply
    to this thread; you've been very helpful to me on other SSH-ish issues,
    and I've been grateful for your help).

    I tried your suggestion and the test program blew up with:

    Can't locate Math/BigInt.pm in @INC ... Crypt/DH.pm line 6

    and further complained:

    Compilation failed in require .../Net/SSH/Perl/Kex/DH1.pm line 13.
    Compilation failed in require .../Net/SSH/Perl/Kex.pm line 6.
    Compilation failed in require .../Net/SSH/Perl/SSH2.pm line 6.
    Compilation failed in require .../Net/SSH/Perl.pm line 54.

    Line 6 of Crypt::DH (version 0.06) says:
    use Math::BigInt lib => "GMP,Pari";

    which looks OK to me and would seem to account for the Math::BigInt
    call in %INC (but, hey, what do I know?). FWIW, I tried to take GMP
    out (leaving only Pari) but it made no noticeable difference.


    --
    The best way to get a good answer is to ask a good question.
    David Filmer (http://DavidFilmer.com)
     
    , Nov 2, 2006
    #4
  5. Sisyphus Guest

    <> wrote in message
    news:...
    ..
    ..
    >> To check that's *not* the case I would rename Math/BigInt.pm to
    > > (eg) Math/BigInt_hide.pm, re-run the script and see if performance

    improves.
    >


    > I tried your suggestion and the test program blew up with:
    >
    > Can't locate Math/BigInt.pm in @INC ... Crypt/DH.pm line 6
    >


    Same culprit as last time.

    >
    > Line 6 of Crypt::DH (version 0.06) says:
    > use Math::BigInt lib => "GMP,Pari";
    >


    Yes ... that's what it says alright .... but I sort of expected it should
    be:

    use Math::BigInt lib => "GMP","Pari";

    I could be wrong about that.

    You have Math::BigInt::GMP, so just change the above line to:

    use Math::BigInt lib => "GMP";

    I'm assuming that Math::BigInt::GMP is fully functional ... ??

    Cheers,
    Rob
     
    Sisyphus, Nov 2, 2006
    #5
  6. salva Guest

    wrote:
    > Greetings.
    >
    > I am having terrible problems with very poor performance when using
    > Net::SFTP. Specifically, it takes about 10 seconds for a machine to
    > transfer a 1 MB file to itself (localhost), and this is a brand new,
    > very FAST, lightly loaded server (and I can replicate this problem on
    > other machines as well). Using ordinary FTP takes 0.4 seconds, and
    > doing the same thing with commandline sftp completes the task in the
    > blink of an eye.


    have you tried Net::SFTP::Foreign? it is much faster, similar to the
    sftp command.

    Cheers,

    - Salva
     
    salva, Nov 2, 2006
    #6
  7. Ben Morrow Guest

    Quoth "Sisyphus" <>:
    >
    > <> wrote in message
    > news:...
    > .
    > .
    > >> To check that's *not* the case I would rename Math/BigInt.pm to
    > > > (eg) Math/BigInt_hide.pm, re-run the script and see if performance

    > improves.
    >
    > > I tried your suggestion and the test program blew up with:
    > >
    > > Can't locate Math/BigInt.pm in @INC ... Crypt/DH.pm line 6
    > >

    >
    > Same culprit as last time.


    This I would not expect to work, as Math::BigInt loads the various
    libraries for you. You could try moving Math::BigInt::Calc out of the
    way, though.

    The next version of Math::BigInt is supposed to let you insist on
    loading a specific library (see
    http://groups.google.co.uk/group/perl.perl5.porters/browse_frm/
    thread/7eda1c02e4a92be/ee2a9bbb4e5a160d
    (URL broken)).

    Ben

    --
    If you put all the prophets, | You'd have so much more reason
    Mystics and saints | Than ever was born
    In one room together, | Out of all of the conflicts of time.
    The Levellers, 'Believers'
     
    Ben Morrow, Nov 2, 2006
    #7
  8. Sisyphus Guest

    "Ben Morrow" <> wrote in message
    news:...
    >
    > Quoth "Sisyphus" <>:
    > >
    > > <> wrote in message
    > > news:...
    > > .
    > > .
    > > >> To check that's *not* the case I would rename Math/BigInt.pm to
    > > > > (eg) Math/BigInt_hide.pm, re-run the script and see if performance

    > > improves.
    > >
    > > > I tried your suggestion and the test program blew up with:
    > > >
    > > > Can't locate Math/BigInt.pm in @INC ... Crypt/DH.pm line 6
    > > >

    > >
    > > Same culprit as last time.

    >
    > This I would not expect to work, as Math::BigInt loads the various
    > libraries for you.


    Doh ... you're right. Crypt/DH.pm will inevitably try to load Math::BigInt -
    which doesn't necessarily mean that the slow Math::BigInt pure perl routines
    will be used.

    > You could try moving Math::BigInt::Calc out of the
    > way, though.


    Much smarter idea .... might actually test out what I was intending to test
    :)

    The absence of Math::BigInt::Calc in the op's listing of %INC would suggest
    that the slow Math::BigInt pure perl routines are *not* to blame in this
    instance, after all.

    Cheers,
    Rob
     
    Sisyphus, Nov 2, 2006
    #8
  9. Guest

    wrote:
    ....
    >
    > Here is my test script:
    >
    > #!/usr/bin/perl
    > use strict; use warnings;
    > use Net::SFTP;
    >
    > #Create with: dd if=/dev/urandom of=/tmp/1mb.junk bs=1024 count=1024
    > my $testfile = "/tmp/1mb.junk";
    >
    > my %comm = (
    > user => 'myuserid',
    > password => 'mypassword',
    > ssh_args => [ cipher => 'blowfish-cbc' ],
    > debug => 0,
    > );
    >
    > my $sftp = Net::SFTP->new('localhost', %comm) or die "oops: $@";
    >
    > $sftp->put ($testfile, "$testfile.test")
    > or die("ftp put failed ", $sftp->message);
    >
    > END{
    > print map{"$_\n"} sort keys %INC; #check for GMP/Pari
    > }
    >
    > __END__
    >
    > The blowfish cipher is indeed the "fastest" (as the docs indicate). I
    > tried the other available ciphers with inferior results:
    > arcfour 14 seconds
    > 3des-cbc 22 seconds
    >
    > The "interesting" parts of the %INC dump (in the END block of the test
    > script) look like this (and validate that GMP/Pari are being called):


    So it appears that GMP/Pari are installed, but from the profile it appears
    they aren't doing anything.

    > I ran the script thorough Devel::profile (perl -d:profile test.pl); the
    > top results (> 1.0%) are:


    Can you get Profile to give you *all* of the subs and look through that
    for GMP/Pari calls?


    > %Time Sec. #calls sec/call name
    > 28.05 2.714 131970 0.000021 Crypt::Blowfish::encrypt
    > 23.32 2.256 139 0.016228 Net::SSH::perl::Cipher::CBC::encrypt
    > 10.08 0.975 282 0.003458 IO::Select::select
    > 5.53 0.535 32 0.016733 IO::Select::can_read
    > 4.51 0.437 132840 0.000003 Crypt::Blowfish::crypt


    Crypt::Blowfish::encrypt doesn't do anything other than rearrange
    it's args and pass them on to the XS code Crypt::Blowfish::crypt.
    Yet it takes over 6 times longer than the code that does the real
    work? My gut feeling is that the bottleneck here is simply the fact
    that you make 2 function calls for every 8 bytes to be encrypted.

    I don't see how this could be possibly be fast. Could someone who *does*
    find this to be fast on their machines please DProf this example and
    post the results?


    > I'm happy to entertain any "try this and see what happens" ideas.


    The first two things I'd try, would be to use DProf rather than Profile,
    and see if you get similar results. And to "strace" the run (I think you
    are on Linux, right?), and see if anything pops out that way.

    Xho

    --
    -------------------- http://NewsReader.Com/ --------------------
    Usenet Newsgroup Service $9.95/Month 30GB
     
    , Nov 2, 2006
    #9
    1. Advertisements

Want to reply to this thread or ask your own question?

It takes just 2 minutes to sign up (and it's free!). Just click the sign up button to choose a username and then you can ask your own questions on the forum.
Similar Threads
  1. Replies:
    4
    Views:
    1,151
  2. Allen Harkleroad
    Replies:
    0
    Views:
    498
    Allen Harkleroad
    Sep 5, 2007
  3. Rodd Snook
    Replies:
    8
    Views:
    374
    Rodd Snook
    May 28, 2004
  4. MaggotChild
    Replies:
    1
    Views:
    204
    MaggotChild
    Oct 28, 2009
  5. MaggotChild

    Net::SFTP Fails, sftp OK

    MaggotChild, Oct 28, 2009, in forum: Perl Misc
    Replies:
    2
    Views:
    1,067
    C.DeRykus
    Oct 29, 2009
Loading...

Share This Page