Beefy Boxes and Bandwidth Generously Provided by pair Networks
more useful options
 
PerlMonks  

Re: FD leaks while interacting with DB

by roboticus (Chancellor)
on Apr 13, 2020 at 16:47 UTC ( #11115472=note: print w/replies, xml ) Need Help??


in reply to FD leaks while interacting with DB

prabakar.bhatt:

I don't know how you're expecting us to help without better information. You give us the source code to a tiny script that you say doesn't give any problems, so there's no real need to look at that. You next give us a debug log from DBI for an unrelated program that obviously does more and different things. While debug logs are nice, there are no references to file opens/closes, so I don't see how it's useful to help you track down an FD leak. It's kind of like you asking "Hey, I'm trying to figure out why my hard drive got filled up by my program. Here's the source code to a totally different program, and I have an NVidia GTX970 video card. So how do I fix it?"

What I would want to see would be the source code to the app that is failing along with the DBI log. But I wouldn't want to wade through hundreds of lines of irrelevent code. So I'd suggest making a copy of your application, and then start chopping out pieces that aren't interesting, testing each version of the code to make sure that the file descriptor leak is still happening.

Frequently during this process, you'll chop out a chunk of code and the problem will go away. When this happens, take a look at what you chopped out to see what bearing it may have on the problem, alternately, you'll get a small enough program for people to look at that you can post and ask qustions about.

Anyway, when I looked at your debug log, I notice a couple things:

  • The log contains references DBI in an unusual-looking path: /usr/opt/temip/alarm_beautifier/perl/lib/site_perl/x86.../DBI.pm: Do you possibly have a hacked up version of DBI? You might want to compare it to the original distribution version to see if there is anything suspicious in there.
  • It looks like there are multiple DB handles in your log (I don't have an active DB right now, so I can't confirm), perhaps you're leaking DB handles which are causing your problem?
  • At the end of your log, I see some "DESTROY(..) ignored for outer handle (inner DBI::st=... has ref cnt 1)", so it looks like something is holding a handle to a statement, so your attempt to close the database may be failing because you still have statement handles lying around.

Since perl tries to delete things when they're no longer accessible, I'd look for places where you store database handles, statement handles, etc. Not only can you store them in a hash or array, you can also have accidental references to them with closures, so be sure to look for those, too.

...roboticus

When your only tool is a hammer, all problems look like your thumb.

Replies are listed 'Best First'.
Re^2: FD leaks while interacting with DB
by prabakar.bhatt (Initiate) on May 04, 2020 at 10:46 UTC
    Thanks for your help.

    We tried few things to give the exact reproducer. What we figured is , Issue is reproducible when application is multi threaded.

    In Multi threaded application , even after exiting the thread FDs are not freed.

    Please find the reproducer scripts and steps below.

    File1 : Sample.pm

    package sample; use strict; use DBI; my $count = 0; sub showtime () { print "Starting loop \n"; #while ( $count < 50 ) { $count++; print ("Connecting to DB \n"); # Modify sid, user, password values. my $dbh = DBI->connect("DBI:Oracle:host=localhost;port=1521;sid= +syno",'temipsyno','temipsyno',{PrintError => 1, RaiseError => 1, ora_ +envhp => 0}); #my $cmd = "grep VmRSS /proc/$$/status"; # Check no. of fd's after connection to db. #my $cmd = "ls -l /proc/$$/fd | grep ocius"; #print `$cmd`; sleep(1); print ("Disconnecting from DB \n"); $dbh->disconnect or warn "Disconnection failed: $DBI::errstr\n"; #} print "Ending script \n"; } 1;
    Source file2 : scr1
    #!/usr/local/bin/perl use threads; use sample; $ENV{'ORACLE_HOME'} = '/usr/opt/oracle'; sub worker() { my $count = 0; # Make it do some work (open and close DB 10 times). while ( $count < 2 ) { sample::showtime(); $count = $count + 1 ; #my $cmd = "ls -l /proc/$$/fd | grep ocius"; #print threads -> self() -> tid() . " : " . `$cmd` ; sleep 3 } } my $nthreads = 5; for ( 1..$nthreads ) { threads->create(\&worker); } foreach my $thr (threads->list() ) { $thr->join(); } print ("Check no. of fd's for ocius.msb using lsof -p $$. Sleeping 30s + \n"); print ("If no. of fd's > 0, then why there is still fd's not closed ev +en after" . " threads have exited \n"); sleep(30);
    How to execute the script:
    ./scr1
    Sample o/p:
    Starting loop Connecting to DB Starting loop Connecting to DB Starting loop Connecting to DB Starting loop Connecting to DB Starting loop Connecting to DB Disconnecting from DB Ending script Disconnecting from DB Ending script Disconnecting from DB Ending script Disconnecting from DB Ending script Disconnecting from DB Ending script Starting loop Connecting to DB Starting loop Connecting to DB Starting loop Connecting to DB Starting loop Connecting to DB Starting loop Connecting to DB Disconnecting from DB Ending script Disconnecting from DB Ending script Disconnecting from DB Ending script Disconnecting from DB Ending script Disconnecting from DB Ending script Check no. of fd's for ocius.msb using lsof -p 9940. Sleeping 30s
    If no. of fd's > 0, then why there is still fd's not closed even after threads have exited

      I changed the DSN to Postgres and tested locally. I added another sleep before the loop and ran lsof there as well, then compared the outputs. There were many files open at the end of the program not present in the first list, but none of them seem to be a leaked database handle:
      11116432.pl 17198 choroba mem REG 254,0 118512 6711636 /usr +/lib64/libsasl2.so.3.0.0 11116432.pl 17198 choroba mem REG 254,0 14648 6711746 /usr +/lib64/libkeyutils.so.1.6 11116432.pl 17198 choroba mem REG 254,0 14720 6719925 /usr +/lib64/libcom_err.so.2.1 11116432.pl 17198 choroba mem REG 254,0 159456 5909809 /lib +64/libselinux.so.1 11116432.pl 17198 choroba mem REG 254,0 199576 6714342 /usr +/lib64/libk5crypto.so.3.1 11116432.pl 17198 choroba mem REG 254,0 217032 264891 /var +/lib/nscd/passwd 11116432.pl 17198 choroba mem REG 254,0 2681240 6719579 /usr +/lib64/libcrypto.so.1.1 11116432.pl 17198 choroba mem REG 254,0 299128 6729817 /usr +/lib64/libpq.so.5.10 11116432.pl 17198 choroba mem REG 254,0 309784 6714338 /usr +/lib64/libgssapi_krb5.so.2.2 11116432.pl 17198 choroba mem REG 254,0 335416 6715270 /usr +/lib64/libldap_r-2.4.so.2.10.9 11116432.pl 17198 choroba mem REG 254,0 442648 6730433 /usr +/lib64/libssl.so.1.1 11116432.pl 17198 choroba mem REG 254,0 52440 6714354 /usr +/lib64/libkrb5support.so.0.1 11116432.pl 17198 choroba mem REG 254,0 575808 6711541 /usr +/lib64/libpcre.so.1.2.9 11116432.pl 17198 choroba mem REG 254,0 60472 6715268 /usr +/lib64/liblber-2.4.so.2.10.9 11116432.pl 17198 choroba mem REG 254,0 900864 6714352 /usr +/lib64/libkrb5.so.3.3 11116432.pl 17198 choroba mem REG 254,0 92216 5909835 /lib +64/libz.so.1.2.11 11116432.pl 17198 choroba mem REG 254,0 96624 5909861 /lib +64/libresolv-2.26.so 11116432.pl 17198 choroba mem REG 254,2 844776 14710922 /hom +e/choroba/perl5/lib/perl5/x86_64-linux-thread-multi/auto/DBD/Pg/Pg.so

      It seems to be an Oracle issue, see File Handles Staying Open on ocius.msb (they're using C++, so it doesn't seem to be Perl related).

      map{substr$_->[0],$_->[1]||0,1}[\*||{},3],[[]],[ref qr-1,-,-1],[{}],[sub{}^*ARGV,3]
      Does the problem persist when you remove use DBI, change it to require DBI, and move it inside the showtime sub?
      map{substr$_->[0],$_->[1]||0,1}[\*||{},3],[[]],[ref qr-1,-,-1],[{}],[sub{}^*ARGV,3]

        Yes , We tried. Still FD's are leaking

Log In?
Username:
Password:

What's my password?
Create A New User
Node Status?
node history
Node Type: note [id://11115472]
help
Chatterbox?
and the web crawler heard nothing...

How do I use this? | Other CB clients
Other Users?
Others exploiting the Monastery: (8)
As of 2020-09-28 22:40 GMT
Sections?
Information?
Find Nodes?
Leftovers?
    Voting Booth?
    If at first I donít succeed, I Ö










    Results (144 votes). Check out past polls.

    Notices?