Bug 982833 - Dangling files (anon_inodes) after creating, syncing, and deleting repos
Summary: Dangling files (anon_inodes) after creating, syncing, and deleting repos
Keywords:
Status: CLOSED DUPLICATE of bug 976561
Alias: None
Product: Pulp
Classification: Retired
Component: API/integration
Version: 2.2 Beta
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: ---
: ---
Assignee: Jason Connor
QA Contact: Preethi Thomas
URL:
Whiteboard:
Depends On:
Blocks: 950743
TreeView+ depends on / blocked
 
Reported: 2013-07-10 01:47 UTC by Justin Sherrill
Modified: 2014-03-31 01:40 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2013-07-10 13:25:04 UTC
Embargoed:


Attachments (Terms of Use)
Script to reproduce the issue (615 bytes, application/x-sh)
2013-07-10 01:49 UTC, Justin Sherrill
no flags Details
Log of too many of open files (52.87 KB, text/x-log)
2013-07-10 02:02 UTC, Justin Sherrill
no flags Details
NEW script to reproduce the issue that runs 1000 times (649 bytes, application/x-sh)
2013-07-10 13:11 UTC, Justin Sherrill
no flags Details

Description Justin Sherrill 2013-07-10 01:47:24 UTC
Description of problem:

When creating, syncing, and deleting yum repos with pulp, it seems that pulp is leaking file descriptors.


Version-Release number of selected component (if applicable):
pulp-server-2.2.0-0.19.beta.el6.noarch

How reproducible:
Always

Steps to Reproduce:
1. run  pulp-admin  login -u admin -p admin
2. Run the included script which creates, syncs and deletes repos 1000 times

Actual results:
The open file counts continue to increase, repo create will eventually fail with OSError: [Errno 24] Too many open files in  /var/log/pulp/pulp.log

Expected results:
Command can run forever with no issue. 

Additional info:

The script prints two numbers prior to create, delete, and sync.  the total number of open files under the apache user, and the total number of anon_inodes under the apache user.  These seem to be the file type that is growing.   It seems to grown around: 

 1586 - 570

for me.

Comment 1 Justin Sherrill 2013-07-10 01:49:03 UTC
Created attachment 771319 [details]
Script to reproduce the issue

Comment 2 Justin Sherrill 2013-07-10 01:49:33 UTC
Note that this was seen on RHEL 6 (not sure about f18).

Comment 3 Justin Sherrill 2013-07-10 02:01:41 UTC
Example output of script:

                                           [  OK  ]
[jlsherri@abed runcible]$ ./test.sh 
create: 1035 - 20
Successfully created repository [FOO-16440-1]

sync: 1037 - 22
delete: 1041 - 25
create: 1042 - 26
Successfully created repository [FOO-16440-2]

sync: 1043 - 27
delete: 1045 - 29
create: 1046 - 30
Successfully created repository [FOO-16440-3]

sync: 1047 - 31
delete: 1049 - 33
create: 1050 - 34
Successfully created repository [FOO-16440-4]

sync: 1051 - 35
delete: 1053 - 37
create: 1054 - 38
Successfully created repository [FOO-16440-5]

sync: 1055 - 39
<SNIP>


After about ~140 repo creates/sync/deletes:


sync: 1588 - 572
delete: 1590 - 574
create: 1591 - 575
Successfully created repository [FOO-16440-139]

sync: 1592 - 576
delete: 1594 - 578
create: 1595 - 579
Successfully created repository [FOO-16440-140]

sync: 1596 - 580
delete: 1598 - 582
create: 1599 - 583
An internal error occurred on the Pulp server. More information can be found in
the client log file ~/.pulp/admin.log.


Uploading last ~500 lines of pulp.log

Comment 4 Justin Sherrill 2013-07-10 02:02:47 UTC
Created attachment 771330 [details]
Log of too many of open files

Comment 5 Justin Sherrill 2013-07-10 02:08:33 UTC
Example output from pulp-server-2.1.2-0.3.beta.el6.noarch where problem is NOT seen:

[jlsherri@abed runcible]$ ./test.sh 
create: 1028 - 19
Successfully created repository [FOO-3507-1]

sync: 1028 - 19
delete: 1029 - 19
create: 1029 - 19
Successfully created repository [FOO-3507-2]

sync: 1029 - 19
delete: 1029 - 19
create: 1029 - 19
Successfully created repository [FOO-3507-3]

sync: 1029 - 19
delete: 1029 - 19
create: 1029 - 19
Successfully created repository [FOO-3507-4]

sync: 1029 - 19
delete: 1029 - 19
create: 1029 - 19
Successfully created repository [FOO-3507-5]

sync: 1029 - 19
delete: 1029 - 19
create: 1029 - 19
Successfully created repository [FOO-3507-6]

sync: 1029 - 19
delete: 1029 - 19
create: 1029 - 19
Successfully created repository [FOO-3507-7]

<SNIP>

Comment 6 David Davis 2013-07-10 13:05:58 UTC
I'm getting some different behavior on Fedora 18. Running the script as is on Fedora 18 didn't reproduce it at all but I noticed the script is only doing 100 iterations. I changed it to 1000 iterations and after about 10 minutes, it began throwing the "Too many files" error. However, after about 5-10 iterations, it resumed working. Moreover, the number for $ANON doesn't increase on F18.

Comment 7 Justin Sherrill 2013-07-10 13:10:48 UTC
Ack sorry yeah, i accidentally uploaded an older script that only did 100 iterations.  Uploading  anew version that also exists as soon as the first failed command occurs.

Comment 8 Justin Sherrill 2013-07-10 13:11:29 UTC
Created attachment 771590 [details]
NEW script to reproduce the issue that runs 1000 times

Comment 9 Michael Hrivnak 2013-07-10 13:25:04 UTC
Thanks for the detailed report. We're tracking this bug already, but your additional diagnosis will certainly help.

*** This bug has been marked as a duplicate of bug 976561 ***


Note You need to log in before you can comment on or make changes to this bug.