Opened 8 years ago

Closed 8 years ago

#2889 closed bug (Fixed)

"Too many files open" error and losing all torrents

Reported by: MaycneSonahoz Owned by:
Priority: major Milestone: 1.3.14
Component: Core Version: 1.3.13
Keywords: Cc:

Description

Hi,

A few weeks ago i got an important issue: Deluge lost all my torrents. More precisely, the torrent list got empty, though the files and torrent files were still there.

After a small investigation, i found out that the ~/.conf/deluge/state/torrents.state and torrents.state.bak files had been deleted. After opening Deluge again, from the terminal, after some time i got errors of the following kind:

[ERROR ] 19:43:26 torrentmanager:833 Unable to save /home/maycne/.config/deluge/state/torrents.fastresume: [Errno 24] Trop de fichiers ouverts: '/home/maycne/.config/deluge/state/torrents.fastresume.tmp'
[ERROR ] 19:43:32 core:248 There was an error adding the torrent file ed965dd1d26331357302f877482526e90c0d0515.torrent
[ERROR ] 19:43:32 core:249 local variable 'ex' referenced before assignment
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/deluge/core/core.py", line 246, in add_torrent_file
File "/usr/lib/python2.7/site-packages/deluge/core/torrentmanager.py", line 534, in add
File "/usr/lib/python2.7/site-packages/deluge/core/torrentmanager.py", line 744, in save_state
UnboundLocalError: local variable 'ex' referenced before assignment
[ERROR ] 19:43:33 torrentmanager:833 Unable to save /home/maycne/.config/deluge/state/torrents.fastresume: [Errno 24] Trop de fichiers ouverts: '/home/maycne/.config/deluge/state/torrents.fastresume.tmp'
[ERROR ] 19:43:46 torrentmanager:734 Unable to backup /home/maycne/.config/deluge/state/torrents.state to /home/maycne/.config/deluge/state/torrents.state.bak: [Errno 2] Aucun fichier ou dossier de ce type

For those who don't read French, "Trop de fichiers ouverts" means "too many files open".

I saw some posts about this error here, either with no solution, or with a solution of "don't use so many torrents" or "increase the limit of files your system can open". Those were also the solutions suggested on Manjaro's forum at first.

But after digging a bit, i found that Deluge opens a lot more files than any other programs, including other torrent clients. Long story short, i found and used the following command in order to look how many files were open.

lsof | awk '{ print $2 " " $1; }' | sort -rn | uniq -c | sort -rn | head -20

Using this with Deluge and Qbittorrent open, both with the exact same list of 83 torrents (all completed), i saw that after around 45min of activity, Deluge had 7 times more open files than Qbittorrent (14880 and 2037 respectively), which might not be normal.

I found this issue with:

I might have had this issue for longer, but i only found it after losing the torrent list.

You can find more details on Manjaro's forum (https://forum.manjaro.org/t/deluge-repeatedly-crashes-over-too-many-files-open/7566) and i'll gladly provide more intel if needed.

Maycne.

Attachments (2)

lsof-20161012.tar.gz (22.8 KB ) - added by MaycneSonahoz 8 years ago.
lsof output (2016-10-12)
lsof-deluge-classic-20161013.txt (29.4 KB ) - added by MaycneSonahoz 8 years ago.
lsof output 2016-10-13

Download all attachments as: .zip

Change History (13)

comment:1 by qk4lka, 8 years ago

I also lost all torrents. =(

comment:2 by Calum, 8 years ago

Component: UnknownCore
Milestone: needs verified1.3.14
Version: other (please specify)1.3.13

The UnboundLocalError is a bug that needs fixing.

I am not sure why there would be so many more open files, afaik the Deluge code is closing file handles...

comment:3 by Calum, 8 years ago

Actually I think all the instances for 2.0 code were converted to use with statement so there are still missing file close statements in 1.3 code.

These are the most likely culprits I have found with a quick search and some have the potential to add up if not garbage collected:

./config.py:359
./config.py:407
./core/daemon.py:55
./core/authmanager.py:121
./ui/web/server.py:237
./ui/common.py:69

comment:4 by Calum, 8 years ago

So I went through the code and changed as many instances as I could find with missing close statements.

If you could test with the PR I have posted on github that would be very helpful: https://github.com/deluge-torrent/deluge/pull/110

comment:5 by MaycneSonahoz, 8 years ago

@Cas

Sadly it didn't improve much: the number of open files still rises to 14k, and i still have the "too many files open" error. I also had an error during install in the web module (which didn't hinder me since i used the gtk client).

[maycne@CManj-maycne deluge]$ sudo python2 setup.py install > install.log
/home/maycne/Projects/github/deluge/deluge/_libtorrent.py:59: RuntimeWarning: to-Python converter for boost::shared_ptr<libtorrent::alert> already registered; second conversion method ignored.
  import libtorrent as lt
warning: no previously-included files matching '*.egg-link' found under directory 'deluge'
warning: no previously-included files found matching 'deluge/ui/web/js/build.sh'
warning: no previously-included files found matching 'deluge/ui/web/js/Deluge*.js'
  File "build/bdist.linux-x86_64/egg/deluge/ui/web/server.py", line 392
    with open(order_file, 'rb') as _file
                                       ^
SyntaxError: invalid syntax

zip_safe flag not set; analyzing archive contents...
deluge.pluginmanagerbase: module references __file__
deluge.ui.ui: module references __file__
deluge.ui.console.__init__: module references __path__
  File "/usr/lib/python2.7/site-packages/deluge-1.3.13.dev0-py2.7.egg/deluge/ui/web/server.py", line 392
    with open(order_file, 'rb') as _file
                                       ^
SyntaxError: invalid syntax

[maycne@CManj-maycne deluge]$ deluge
/usr/lib/python2.7/site-packages/deluge-1.3.13.dev0-py2.7.egg/deluge/_libtorrent.py:59: RuntimeWarning: to-Python converter for boost::shared_ptr<libtorrent::alert> already registered; second conversion method ignored.
  import libtorrent as lt
/usr/lib/python2.7/site-packages/twisted/internet/_glibbase.py:301: GtkWarning: Attempting to read the recently used resources file at `/home/maycne/.local/share/recently-used.xbel', but the parser failed: L'ouverture du fichier « /home/maycne/.local/share/recently-used.xbel » a échoué : Trop de fichiers ouverts.
[ERROR   ] 22:27:59 torrentmanager:744 Unable to save /home/maycne/.config/deluge/state/torrents.state: [Errno 24] Trop de fichiers ouverts: '/home/maycne/.config/deluge/state/torrents.state.tmp'
[ERROR   ] 22:30:50 torrentmanager:833 Unable to save /home/maycne/.config/deluge/state/torrents.fastresume: [Errno 24] Trop de fichiers ouverts: '/home/maycne/.config/deluge/state/torrents.fastresume.tmp'

Last edited 8 years ago by MaycneSonahoz (previous) (diff)

comment:6 by Calum, 8 years ago

I have applied a fix to the PR for webui code.

Can you try running deluge in thinclient mode and paste the output of lsof for deluge and deluged processes.

by MaycneSonahoz, 8 years ago

Attachment: lsof-20161012.tar.gz added

lsof output (2016-10-12)

comment:7 by MaycneSonahoz, 8 years ago

This is interesting.

I first ran deluge in thin client mode as you asked. The lsof output for this was rather small, which i found disturbing. So i ran deluge again, in classic mode. And then the lsof output grew quite big.

[maycne@CManj-maycne ~]$ ps aux | grep deluge
maycne    1356  3.4  0.6 552028 51456 pts/0    Sl+  20:56   1:46 /usr/bin/python2 /usr/bin/deluged -d
maycne    1375  0.9  1.2 1228792 98500 pts/1   Sl+  20:56   0:28 /usr/bin/python2 /usr/bin/deluge
[maycne@CManj-maycne ~]$ lsof -p 1356 > lsof-deluged.txt
[maycne@CManj-maycne ~]$ lsof -p 1375 > lsof-deluge.txt
[maycne@CManj-maycne ~]$ ps aux | grep deluge
maycne    2172  5.5  1.5 1570808 124624 pts/1  Sl+  21:51   1:09 /usr/bin/python2 /usr/bin/deluge
maycne    2415  0.0  0.0  10780  2184 pts/2    S+   22:12   0:00 grep deluge
[maycne@CManj-maycne ~]$ lsof -p 2172 > lsof-deluge-classic.txt

I put the output files in lsof-20161012.tar.gz.

comment:8 by andar, 8 years ago

All the temp files look pretty small, I wonder if they are tracker icons.. Do you have a lot of torrents in your session and from a lot of different trackers?

Any chance you could patch your Deluge to add a suffix to the temp files created by the tracker icons code? https://github.com/deluge-torrent/deluge/blob/9c27ed29ae6faaa7d3de1a53dea02c4ed527e218/deluge/ui/tracker_icons.py#L238

Just add an argument to mkstemp like: mkstemp('tracker-icon')

This way we could see if that's where the files are being created. You could also inspect some of the tmp files to see if you can discern what they are.. Maybe try running the file command against some of them.

comment:9 by Calum, 8 years ago

Well spotted andar :)

I have pushed a new update to the PR including modifying the prefix to help identify tmp files from tracker_icon code and close the file descriptor.

comment:10 by MaycneSonahoz, 8 years ago

Yep, you nailed it! Open files went down to 3k.

[maycne@CManj-maycne ~]$ ps aux | grep deluge
maycne   14396  7.6  2.0 1531272 164332 pts/1  Sl+  19:34   2:17 /usr/bin/python2 /usr/bin/deluge
[maycne@CManj-maycne ~]$ lsof | awk '{ print $2 " " $1; }' | sort -rn | uniq -c | sort -rn | head -20
   3228 14396 /usr/bin/
    516 14386 pool
   2824 1131 mozStorag
   2824 1131 JS\x20Hel
    269 14396 gmain
    269 14396 gdbus
    253 14800 pidgin
   2310 1107 qbittorre
   2128 1121 JS\x20Hel
   1596 1121 mozStorag
    129 14386 tumblerd
    129 14386 gmain
    129 14386 gdbus
   1059 1131 ImgDecode
   1059 1131 DOM\x20Wo
    940 1077 threaded-
    798 1121 ImgDecode
    532 1121 thunderbi
    532 1121 DOM\x20Wo
    353 1131 URL\x20Cl
[maycne@CManj-maycne ~]$ lsof -p 14396 > lsof-deluge-classic-20161013.txt

Thanks a lot! \o/

by MaycneSonahoz, 8 years ago

lsof output 2016-10-13

comment:11 by Calum, 8 years ago

Resolution: Fixed
Status: newclosed

Fixed in develop [9dd3b1617d44d71] and 1.3-stable [a7fe4d45107b4], [798f5e2deb10e]

Note: See TracTickets for help on using tickets.