Invidious: accept: Too many open files (Errno)

[tmiland]

Hi, have had some downtime recently (connection timeout), get this error:

accept: Too many open files (Errno) Jun 06 22:12:45 debian invidious[18277]: from /usr/share/crystal/src/thread.cr:69:3 in 'accept?' Jun 06 22:12:45 debian invidious[18277]: from /usr/share/crystal/src/http/server.cr:419:13 in '-> Jun 06 22:12:45 debian invidious[18277]: from /usr/share/crystal/src/fiber.cr:255:3 in '???' Jun 06 22:12:45 debian invidious[18277]: from ??? Jun 06 22:12:45 debian invidious[18277]: accept: Too many open files (Errno) Jun 06 22:12:45 debian invidious[18277]: from /usr/share/crystal/src/thread.cr:69:3 in 'accept?' Jun 06 22:12:45 debian invidious[18277]: from /usr/share/crystal/src/http/server.cr:419:13 in '-> Jun 06 22:12:45 debian invidious[18277]: from /usr/share/crystal/src/fiber.cr:255:3 in '???' Jun 06 22:12:45 debian invidious[18277]: from ???

When this happens, the invidious log-file is filled with info from the system-log.

Never seen this before... What gives?

[omarroth]

I've encounter this as well, generally it's because of a high request for static files (/js/watch.js, /css/default.css, etc.), but haven't found it to be a serious issue. Log for me looks like:

Exception: Error opening file '/css/default.css' with mode 'r': Too many open files (Errno)
   from ...

This may also be crystal-lang/crystal#7843 since from the above log it doesn't appear any files are being opened.

[tmiland]

Thanks!

Weird stuff.

The instance comes back online after a restart. Not sure if this is nginx, openssl or crystal, but there might be a setting somewhere to increase the amount of open files limit probably (idk.), that i forgot to change after migrating the instance... Hard to remember everything 😂

I'll look more into it later. 👍

[tmiland]

Suspect: proxy_read_timeout 90; in nginx reverse proxy

Increased to proxy_read_timeout 3600; to see if it makes any difference.

Also added:

nginx       soft    nofile  10000
nginx       hard    nofile  30000

to /etc/security/limits.conf

[tmiland]

Woke up to this today:

Log file is flooded with:

Jun 22 13:38:52 debian invidious[8325]: accept: Too many open files (Errno)
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/thread.cr:69:3 in 'accept?'
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/http/server.cr:419:13 in '->'
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/fiber.cr:255:3 in '???'
Jun 22 13:38:52 debian invidious[8325]:   from ???
Jun 22 13:38:52 debian invidious[8325]: accept: Too many open files (Errno)
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/thread.cr:69:3 in 'accept?'
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/http/server.cr:419:13 in '->'
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/fiber.cr:255:3 in '???'
Jun 22 13:38:52 debian invidious[8325]:   from ???
Jun 22 13:38:52 debian invidious[8325]: accept: Too many open files (Errno)
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/thread.cr:69:3 in 'accept?'
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/http/server.cr:419:13 in '->'
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/fiber.cr:255:3 in '???'
Jun 22 13:38:52 debian invidious[8325]:   from ???
Jun 22 13:38:52 debian invidious[8325]: accept: Too many open files (Errno)
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/thread.cr:69:3 in 'accept?'
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/http/server.cr:419:13 in '->'
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/fiber.cr:255:3 in '???'
Jun 22 13:38:52 debian invidious[8325]:   from ???
Jun 22 13:38:52 debian invidious[8325]: accept: Too many open files (Errno)
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/thread.cr:69:3 in 'accept?'
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/http/server.cr:419:13 in '->'
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/fiber.cr:255:3 in '???'
Jun 22 13:38:52 debian invidious[8325]:   from ???
Jun 22 13:38:52 debian invidious[8325]: accept: Too many open files (Errno)
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/thread.cr:69:3 in 'accept?'
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/http/server.cr:419:13 in '->'
Jun 22 13:38:52 debian invidious[8325]:   from /usr/share/crystal/src/fiber.cr:255:3 in '???'
Jun 22 13:38:52 debian invidious[8325]:   from ???

[tmiland]

Currently trying:

In invidious.service;

LimitNOFILE=infinity

pgrep -f "/home/invidious/invidious/invidious" 
17666

cat /proc/17666/limits
Limit                     Soft Limit           Hard Limit           Units     
Max cpu time              unlimited            unlimited            seconds   
Max file size             unlimited            unlimited            bytes     
Max data size             unlimited            unlimited            bytes     
Max stack size            8388608              unlimited            bytes     
Max core file size        0                    unlimited            bytes     
Max resident set          unlimited            unlimited            bytes     
Max processes             15318                15318                processes 
Max open files            1048576              1048576              files     
Max locked memory         65536                65536                bytes     
Max address space         unlimited            unlimited            bytes     
Max file locks            unlimited            unlimited            locks     
Max pending signals       15318                15318                signals   
Max msgqueue size         819200               819200               bytes     
Max nice priority         0                    0                    
Max realtime priority     0                    0                    
Max realtime timeout      unlimited            unlimited            us        

Previous max open files;

Max open files            1024                 4096                 files

[tmiland]

Trying with the potential fix now, still getting:

Jun 27 11:15:48 debian invidious[14372]: accept: Too many open files (Errno)
Jun 27 11:15:48 debian invidious[14372]:   from /usr/share/crystal/src/thread.cr:69:3 in 'accept?'
Jun 27 11:15:48 debian invidious[14372]:   from /usr/share/crystal/src/http/server.cr:419:13 in '->'
Jun 27 11:15:48 debian invidious[14372]:   from /usr/share/crystal/src/fiber.cr:255:3 in '???'
Jun 27 11:15:48 debian invidious[14372]:   from ???

Though after disabling https://github.com/omarroth/invidious/issues/578#issuecomment-505644782

Invidious service is also going down more frequently with the above fix disabled.

[tmiland]

Activated https://github.com/omarroth/invidious/issues/578#issuecomment-505644782 again.

See this in the log now:

Exception:  (DB::PoolRetryAttemptsExceeded)
  from lib/db/src/db/result_set.cr:28:5 in 'query'
  from lib/db/src/db/query_methods.cr:134:9 in 'query_one?:as'
  from src/invidious/videos.cr:873:15 in 'get_video'
  from src/invidious/videos.cr:872:1 in '->'
  from lib/kemal/src/kemal/route.cr:255:3 in '->'
  from src/invidious/helpers/handlers.cr:255:3 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call_next'
  from lib/kemal/src/kemal/filter_handler.cr:21:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call_next'
  from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call_next'
  from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call_next'
  from /usr/share/crystal/src/http/server/handler.cr:26:7 in '???'
  from /usr/share/crystal/src/http/server/handler.cr:26:7 in '???'
  from src/invidious/helpers/static_file_handler.cr:189:11 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call'
  from /usr/share/crystal/src/http/server/request_processor.cr:39:11 in 'process'
  from /usr/share/crystal/src/fiber.cr:255:3 in '???'
  from ???

Edit: Both instances is down. 500 Internal Server Error

Edit2: Reverting the latest commit.

[pbbob]

A temporary solution until this gets fixed would be to use a CDN like cloudflare.

[T0MuX]

Exactly the same issue for me. Check the #1281 for a piece of error log :)
My Invidious crashes after ~4h

[T0MuX]

@tmiland Hi, I don't understand why this issue is closed, what was your fix ?? I'm still having this issue

[zimhat]

I am having the same issue too. Anyone managed to find a fix ?

[vinyll]

Hey all!
Also having this issue repeatedly. Some of you could get it working properly?

[zimhat]

@vinyll not really a solution but a workaround : I restart invidious every 3 hours via systemd. I see that people are working on this issue : this pull request looks promising.

[vinyll]

@zimhat It's actually fixed in https://github.com/iv-org/lsquic.cr/pull/2. https://tube.connect.cafe has been running on it for the past few days with no tweaking :+1:
This issue can now officially close :)

[T0MuX]

Oh... maybe I will setup it again so... :)