Too Many Open Files


#1

Hello:

Ok - I’m still debugging the system I described in Files Transferred Multiple Times? - here’s a copy of the system summary for reference:

I’m running Syncthing on two locally-network Synology NAS units in order to reconcile a large data set (~4.6 million files at ~37TB) between the units, prior to moving one of the NAS units off-site. Both units have nearly the same data set (unfortunately not quite the same - probably 99% identical), and the data is not being touched, to allow the sync to complete. Only these two units are signed into the cluster, and they each only have one Shared Folder.

I’m aware that the NAS units won’t give very high performance, and that I’m using a large data set - so have set my expectations accordingly. However, I’m getting much slower sync than I would expect; the rate of transfer seems to vary considerably, but I’m typically getting ~100GB reconciled per day - and it’s been going on for months now!

I’m digging around in the log files, and have found a lot of ‘too many open files’ entries in the log for the NAS units. The sync appears to start off normally - but after >24hrs we get the ‘too many open files’ errors appearing, sometimes interrupted by Puller/finisher versions of the same file.

When the log entries are really going for it, we’re seeing about 45k entries per second of the form:

WARNING: Accepting connection (BEP/tcp): accept tcp [::]:22000: accept4: too many open files

Due to the massive log size, here are some extracts showing NAS02:

  • (13:45:35) Syncthing being started, and starting a scan of the shared folder;
  • (10:26:10) Receiving an index update from NAS01;
  • (10:46:18) File syncing happening;
  • (01:22:12) Syncing continuing to happen - then the first ‘too many open files’ error;
  • (01:22:31) The ‘normal’ too many open files error interrupted by a Puller/finisher version of the same message;
  • (22:01:55) The errors finishing in a panic, and syncthing restarting itself.
[OVPYX] 13:45:35 INFO: My ID: OVPYXBH-******-******-******-******-******-******-******
[OVPYX] 13:45:36 INFO: Single thread SHA256 performance is 92 MB/s using minio/sha256-simd (66 MB/s using crypto/sha256).
[OVPYX] 13:45:36 VERBOSE: Starting up (/usr/local/syncthing/var)
[OVPYX] 13:45:38 INFO: Hashing performance with weak hash is 80.84 MB/s
[OVPYX] 13:45:39 INFO: Hashing performance without weak hash is 91.25 MB/s
[OVPYX] 13:45:39 INFO: Weak hash enabled, as it has an acceptable performance impact.
[OVPYX] 14:16:56 INFO: Ready to synchronize "NAS" (bvkmk-wxrz3) (readwrite)
[OVPYX] 14:16:56 INFO: Send rate is unlimited, receive rate is unlimited
[OVPYX] 14:16:56 INFO: Rate limits do not apply to LAN connections
[OVPYX] 14:16:56 INFO: Using discovery server https://discovery-v4-2.syncthing.net/v2/?id=DVU36WY-H3LVZHW-E6LLFRE-YAFN5EL-HILWRYP-OC2M47J-Z4PE62Y-ADIBDQC
[OVPYX] 14:16:56 INFO: Using discovery server https://discovery-v4-3.syncthing.net/v2/?id=VK6HNJ3-VVMM66S-HRVWSCR-IXEHL2H-U4AQ4MW-UCPQBWX-J2L2UBK-NVZRDQZ
[OVPYX] 14:16:56 INFO: Using discovery server https://discovery-v4-4.syncthing.net/v2/?id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
[OVPYX] 14:16:56 INFO: Using discovery server https://discovery-v6-2.syncthing.net/v2/?id=DVU36WY-H3LVZHW-E6LLFRE-YAFN5EL-HILWRYP-OC2M47J-Z4PE62Y-ADIBDQC
[OVPYX] 14:16:56 INFO: TCP listener ([::]:22000) starting
[OVPYX] 14:16:56 INFO: KCP listener ([::]:22020) starting
[OVPYX] 14:16:56 VERBOSE: Folder "bvkmk-*****" is now scanning
[OVPYX] 14:16:58 INFO: Using discovery server https://discovery-v6-3.syncthing.net/v2/?id=VK6HNJ3-VVMM66S-HRVWSCR-IXEHL2H-U4AQ4MW-UCPQBWX-J2L2UBK-NVZRDQZ
[OVPYX] 14:16:58 INFO: Using discovery server https://discovery-v6-4.syncthing.net/v2/?id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
[OVPYX] 14:16:58 INFO: Device GSXHK4J-******-******-******-******-******-******-****** is "NAS1" at [dynamic]
[OVPYX] 14:16:58 INFO: Device OVPYXBH-******-******-******-******-******-******-****** is "NAS02" at [dynamic]
[OVPYX] 14:16:58 VERBOSE: Startup complete
[OVPYX] 14:16:58 INFO: GUI and API listening on [::]:7070
[OVPYX] 14:16:58 INFO: Access the GUI via the following URL: http://127.0.0.1:7070/
[OVPYX] 14:17:01 VERBOSE: Local change detected in folder "bvkmk-*****": added dir subfolder/path1/here
...
[OVPYX] 10:26:10 VERBOSE: Device GSXHK4J-******-******-******-******-******-******-****** sent an index update for "bvkmk-*****" with 131 items
[OVPYX] 10:37:12 INFO: Completed initial scan of readwrite folder "NAS" (bvkmk-*****)
[OVPYX] 10:37:12 VERBOSE: Folder "bvkmk-*****" is now idle
[OVPYX] 10:37:12 VERBOSE: Folder "bvkmk-*****" is now syncing
[OVPYX] 10:39:26 VERBOSE: Device GSXHK4J-******-******-******-******-******-******-****** sent an index update for "bvkmk-*****" with 178 items
...
[OVPYX] 10:46:18 VERBOSE: Started syncing "bvkmk-*****" / "subfolder/path2/here" (update dir)
[OVPYX] 10:46:18 VERBOSE: Finished syncing "bvkmk-*****" / "subfolder/path2/here" (update dir): Success
[OVPYX] 10:46:18 VERBOSE: Started syncing "bvkmk-*****" / "subfolder/path3/here" (update dir)
[OVPYX] 10:46:18 VERBOSE: Finished syncing "bvkmk-*****" / "subfolder/path3/here" (update dir): Success
[OVPYX] 10:46:18 VERBOSE: Started syncing "bvkmk-*****" / "subfolder/path4/here" (update dir)
[OVPYX] 10:46:18 VERBOSE: Finished syncing "bvkmk-*****" / "subfolder/path5/here" (update dir): Success
...
[OVPYX] 01:22:12 VERBOSE: Started syncing "bvkmk-*****" / "file/path1/here" (update file)
[OVPYX] 01:22:14 VERBOSE: Started syncing "bvkmk-*****" / "file/path2/here" (update file)
[OVPYX] 01:22:16 WARNING: Accepting connection (BEP/tcp): accept tcp [::]:22000: accept4: too many open files
...
[OVPYX] 01:22:31 WARNING: Accepting connection (BEP/tcp): accept tcp [::]:22000: accept4: too many open files
[OVPYX] 01:22:31 INFO: Puller (folder "\"NAS\" (bvkmk-*****)", file "file/path3/here"): finisher: dst create: open /volume1/NAS/file/path4/here: too many open files
[OVPYX] 01:22:31 WARNING: Accepting connection (BEP/tcp): accept tcp [::]:22000: accept4: too many open files
...
[OVPYX] 22:01:55 WARNING: Accepting connection (BEP/tcp): accept tcp [::]:22000: accept4: too many open files
panic: open /usr/local/syncthing/var/index-v0.14.0.db/10492564.ldb: too many open files
[OVPYX] 22:01:57 INFO: syncthing v0.14.40 "Dysprosium Dragonfly" (go1.9.2 linux-amd64) teamcity@build.syncthing.net 2017-10-28 19:15:32 UTC
[OVPYX] 22:01:57 INFO: My ID: OVPYXBH-******-******-******-******-******-******-******
[OVPYX] 22:01:58 INFO: Single thread SHA256 performance is 93 MB/s using minio/sha256-simd (68 MB/s using crypto/sha256).
[OVPYX] 22:01:58 VERBOSE: Starting up (/usr/local/syncthing/var)
...

I’ve attached a redacted copy of the NAS02 panic log referenced here, plus screenshots of Syncthing from both NAS01 and NAS02.

I hope this is all of some use - please let me know if I can provide any further information to help diagnose this.

Many thanks,

Pants.

panic-20171126-220155_redacted.log (55.1 KB)


(Jakob Borg) #2

Most likely your NAS allows very few open files, including network connections, which is a problem for Syncthing and results in the panic when it can’t open database files.

Try ulimit-n in a shell, similar to where you start Syncthing from, and see what it says. Less than 1024 or so is wrong.


#3

Hi Jakob:

Thanks for coming back so quickly. I’ve just run the command you suggested, and it returned 1024.

Best wishes,

Pants.


(Audrius Butkevicius) #4

For this many files you will definately need to increase that, as I suspect even the database can create this many files in between compactions.


(Jakob Borg) #5

I think it should work with 1024, but either it clearly doesn’t or Syncthing gets a lower value courtesy of whoever starts it.


#6

Hello both:

Many thanks for your input on this. I shall have to dig harder into the Synology setup then - the methods I’ve found for increasing the limit seem not to work, and it’s possible that the Synology has a hard-coded limit… :frowning:

Pants.


(Audrius Butkevicius) #7

Can you provide ls -lah /proc/<pid of syncthing that uses more memory>/fd* output?


(Jakob Borg) #8

And on that note, cat /proc/$thePid/limits (with the Syncthing PID, again)


#9

Hello:

Thanks for following this up. I’ve been looking into raising the ulimit, but I’m banging my head against a brick wall - Synology seems to make this more difficult than is ideal…

Anyhoo, here’s the output you requested. It looks like there was another panic a couple of hours ago, so things are unlikely to have reached critical mass yet:

root@NAS02:/usr/syno/etc# ps -u syncthing
  PID TTY          TIME CMD
13857 ?        01:16:41 syncthing
14184 ?        00:23:06 syncthing
root@NAS02:/usr/syno/etc# cat /proc/13857/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        unlimited            unlimited            bytes     
Max resident set          unlimited            unlimited            bytes     
Max processes             63944                63944                processes 
Max open files            4096                 4096                 files     
Max locked memory         65536                65536                bytes     
Max address space         unlimited            unlimited            bytes     
Max file locks            unlimited            unlimited            locks     
Max pending signals       63944                63944                signals   
Max msgqueue size         819200               819200               bytes     
Max nice priority         0                    0                    
Max realtime priority     0                    0                    
Max realtime timeout      unlimited            unlimited            us        
root@NAS02:/usr/syno/etc# cat /proc/14184/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        unlimited            unlimited            bytes     
Max resident set          unlimited            unlimited            bytes     
Max processes             63944                63944                processes 
Max open files            1024                 4096                 files     
Max locked memory         65536                65536                bytes     
Max address space         unlimited            unlimited            bytes     
Max file locks            unlimited            unlimited            locks     
Max pending signals       63944                63944                signals   
Max msgqueue size         819200               819200               bytes     
Max nice priority         0                    0                    
Max realtime priority     0                    0                    
Max realtime timeout      unlimited            unlimited            us        
root@NAS02:/usr/syno/etc# ls -lah /proc/13857/fd*
/proc/13857/fd:
total 0
dr-x------ 2 syncthing users  0 Nov 29 08:39 .
dr-xr-xr-x 8 syncthing users  0 Nov 29 06:02 ..
lr-x------ 1 syncthing users 64 Nov 29 08:39 0 -> /dev/null
l-wx------ 1 syncthing users 64 Nov 29 08:39 1 -> pipe:[60052884]
lr-x------ 1 syncthing users 64 Nov 29 08:39 10 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762813.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 100 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762667.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 101 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761791.ldb
l-wx------ 1 syncthing users 64 Nov 29 08:39 102 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762962.log
lrwx------ 1 syncthing users 64 Nov 29 08:39 103 -> socket:[60113935]
lrwx------ 1 syncthing users 64 Nov 29 08:39 104 -> socket:[60106174]
lr-x------ 1 syncthing users 64 Nov 29 08:39 105 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762904.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 106 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762915.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 107 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761780.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 108 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762675.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 109 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762683.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 11 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762688.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 110 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761166.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 111 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761175.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 113 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762809.ldb
lrwx------ 1 syncthing users 64 Nov 29 08:39 114 -> socket:[60285002]
lr-x------ 1 syncthing users 64 Nov 29 08:39 115 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762685.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 116 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762924.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 12 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762922.ldb
lrwx------ 1 syncthing users 64 Nov 29 08:39 128 -> socket:[60113398]
lrwx------ 1 syncthing users 64 Nov 29 08:39 129 -> socket:[60113397]
lr-x------ 1 syncthing users 64 Nov 29 08:39 13 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761158.ldb
lrwx------ 1 syncthing users 64 Nov 29 08:39 130 -> socket:[60106218]
lrwx------ 1 syncthing users 64 Nov 29 08:39 131 -> socket:[60106216]
lr-x------ 1 syncthing users 64 Nov 29 08:39 14 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762666.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 15 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762905.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 16 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761779.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 17 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762808.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 18 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761157.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 19 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762914.ldb
l-wx------ 1 syncthing users 64 Nov 29 08:39 2 -> pipe:[60052883]
lr-x------ 1 syncthing users 64 Nov 29 08:39 20 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762907.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 21 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762926.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 22 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761156.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 23 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762811.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 24 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762679.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 25 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762668.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 26 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762909.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 27 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762927.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 28 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762698.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 29 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762697.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 3 -> /dev/urandom
lr-x------ 1 syncthing users 64 Nov 29 08:39 30 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761787.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 31 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762677.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 32 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761792.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 33 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762906.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 34 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762690.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 35 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762920.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 36 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762921.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 37 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762908.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 38 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762671.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 39 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762717.ldb
lrwx------ 1 syncthing users 64 Nov 29 08:39 4 -> anon_inode:[eventpoll]
lr-x------ 1 syncthing users 64 Nov 29 08:39 40 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762856.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 41 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762673.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 42 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762919.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 43 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761776.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 44 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762700.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 45 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762710.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 46 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762702.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 47 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761785.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 48 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762928.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 49 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762910.ldb
lrwx------ 1 syncthing users 64 Nov 29 08:39 5 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/LOCK
lr-x------ 1 syncthing users 64 Nov 29 08:39 50 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762699.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 51 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761772.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 52 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762695.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 53 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762925.ldb
lrwx------ 1 syncthing users 64 Nov 29 08:39 54 -> socket:[60106172]
lr-x------ 1 syncthing users 64 Nov 29 08:39 55 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761154.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 56 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762911.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 57 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761176.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 58 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762684.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 59 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761155.ldb
l-wx------ 1 syncthing users 64 Nov 29 08:39 6 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/LOG
lr-x------ 1 syncthing users 64 Nov 29 08:39 60 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10763079.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 61 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761165.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 62 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762669.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 63 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762713.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 64 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762665.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 65 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762912.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 66 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762929.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 67 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762689.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 68 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762686.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 69 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762701.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 7 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762709.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 70 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762687.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 71 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762691.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 72 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762916.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 73 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762692.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 74 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762693.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 75 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762703.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 76 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762705.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 77 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762714.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 78 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761786.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 79 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762923.ldb
l-wx------ 1 syncthing users 64 Nov 29 08:39 8 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/MANIFEST-10759286
lr-x------ 1 syncthing users 64 Nov 29 08:39 80 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761778.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 81 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762694.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 82 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762696.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 83 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762810.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 84 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762706.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 85 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762707.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 87 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762672.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 88 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761168.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 89 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762676.ldb
lrwx------ 1 syncthing users 64 Nov 29 08:39 9 -> socket:[60106279]
lr-x------ 1 syncthing users 64 Nov 29 08:39 90 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761177.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 91 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761167.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 92 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762704.ldb
lrwx------ 1 syncthing users 64 Nov 29 08:39 93 -> socket:[60106213]
lr-x------ 1 syncthing users 64 Nov 29 08:39 94 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761774.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 95 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762670.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 96 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762674.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 97 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10761178.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 98 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762708.ldb
lr-x------ 1 syncthing users 64 Nov 29 08:39 99 -> /volume1/@appstore/syncthing/var/index-v0.14.0.db/10762711.ldb

/proc/13857/fdinfo:
total 0
dr-x------ 2 syncthing users 0 Nov 29 08:39 .
dr-xr-xr-x 8 syncthing users 0 Nov 29 06:02 ..
-r-------- 1 syncthing users 0 Nov 29 08:39 0
-r-------- 1 syncthing users 0 Nov 29 08:39 1
-r-------- 1 syncthing users 0 Nov 29 08:39 10
-r-------- 1 syncthing users 0 Nov 29 08:39 100
-r-------- 1 syncthing users 0 Nov 29 08:39 101
-r-------- 1 syncthing users 0 Nov 29 08:39 102
-r-------- 1 syncthing users 0 Nov 29 08:39 103
-r-------- 1 syncthing users 0 Nov 29 08:39 104
-r-------- 1 syncthing users 0 Nov 29 08:39 105
-r-------- 1 syncthing users 0 Nov 29 08:39 106
-r-------- 1 syncthing users 0 Nov 29 08:39 107
-r-------- 1 syncthing users 0 Nov 29 08:39 108
-r-------- 1 syncthing users 0 Nov 29 08:39 109
-r-------- 1 syncthing users 0 Nov 29 08:39 11
-r-------- 1 syncthing users 0 Nov 29 08:39 110
-r-------- 1 syncthing users 0 Nov 29 08:39 111
-r-------- 1 syncthing users 0 Nov 29 08:39 113
-r-------- 1 syncthing users 0 Nov 29 08:39 114
-r-------- 1 syncthing users 0 Nov 29 08:39 115
-r-------- 1 syncthing users 0 Nov 29 08:39 116
-r-------- 1 syncthing users 0 Nov 29 08:39 12
-r-------- 1 syncthing users 0 Nov 29 08:39 128
-r-------- 1 syncthing users 0 Nov 29 08:39 129
-r-------- 1 syncthing users 0 Nov 29 08:39 13
-r-------- 1 syncthing users 0 Nov 29 08:39 130
-r-------- 1 syncthing users 0 Nov 29 08:39 131
-r-------- 1 syncthing users 0 Nov 29 08:39 14
-r-------- 1 syncthing users 0 Nov 29 08:39 15
-r-------- 1 syncthing users 0 Nov 29 08:39 16
-r-------- 1 syncthing users 0 Nov 29 08:39 17
-r-------- 1 syncthing users 0 Nov 29 08:39 18
-r-------- 1 syncthing users 0 Nov 29 08:39 19
-r-------- 1 syncthing users 0 Nov 29 08:39 2
-r-------- 1 syncthing users 0 Nov 29 08:39 20
-r-------- 1 syncthing users 0 Nov 29 08:39 21
-r-------- 1 syncthing users 0 Nov 29 08:39 22
-r-------- 1 syncthing users 0 Nov 29 08:39 23
-r-------- 1 syncthing users 0 Nov 29 08:39 24
-r-------- 1 syncthing users 0 Nov 29 08:39 25
-r-------- 1 syncthing users 0 Nov 29 08:39 26
-r-------- 1 syncthing users 0 Nov 29 08:39 27
-r-------- 1 syncthing users 0 Nov 29 08:39 28
-r-------- 1 syncthing users 0 Nov 29 08:39 29
-r-------- 1 syncthing users 0 Nov 29 08:39 3
-r-------- 1 syncthing users 0 Nov 29 08:39 30
-r-------- 1 syncthing users 0 Nov 29 08:39 31
-r-------- 1 syncthing users 0 Nov 29 08:39 32
-r-------- 1 syncthing users 0 Nov 29 08:39 33
-r-------- 1 syncthing users 0 Nov 29 08:39 34
-r-------- 1 syncthing users 0 Nov 29 08:39 35
-r-------- 1 syncthing users 0 Nov 29 08:39 36
-r-------- 1 syncthing users 0 Nov 29 08:39 37
-r-------- 1 syncthing users 0 Nov 29 08:39 38
-r-------- 1 syncthing users 0 Nov 29 08:39 39
-r-------- 1 syncthing users 0 Nov 29 08:39 4
-r-------- 1 syncthing users 0 Nov 29 08:39 40
-r-------- 1 syncthing users 0 Nov 29 08:39 41
-r-------- 1 syncthing users 0 Nov 29 08:39 42
-r-------- 1 syncthing users 0 Nov 29 08:39 43
-r-------- 1 syncthing users 0 Nov 29 08:39 44
-r-------- 1 syncthing users 0 Nov 29 08:39 45
-r-------- 1 syncthing users 0 Nov 29 08:39 46
-r-------- 1 syncthing users 0 Nov 29 08:39 47
-r-------- 1 syncthing users 0 Nov 29 08:39 48
-r-------- 1 syncthing users 0 Nov 29 08:39 49
-r-------- 1 syncthing users 0 Nov 29 08:39 5
-r-------- 1 syncthing users 0 Nov 29 08:39 50
-r-------- 1 syncthing users 0 Nov 29 08:39 51
-r-------- 1 syncthing users 0 Nov 29 08:39 52
-r-------- 1 syncthing users 0 Nov 29 08:39 53
-r-------- 1 syncthing users 0 Nov 29 08:39 54
-r-------- 1 syncthing users 0 Nov 29 08:39 55
-r-------- 1 syncthing users 0 Nov 29 08:39 56
-r-------- 1 syncthing users 0 Nov 29 08:39 57
-r-------- 1 syncthing users 0 Nov 29 08:39 58
-r-------- 1 syncthing users 0 Nov 29 08:39 59
-r-------- 1 syncthing users 0 Nov 29 08:39 6
-r-------- 1 syncthing users 0 Nov 29 08:39 60
-r-------- 1 syncthing users 0 Nov 29 08:39 61
-r-------- 1 syncthing users 0 Nov 29 08:39 62
-r-------- 1 syncthing users 0 Nov 29 08:39 63
-r-------- 1 syncthing users 0 Nov 29 08:39 64
-r-------- 1 syncthing users 0 Nov 29 08:39 65
-r-------- 1 syncthing users 0 Nov 29 08:39 66
-r-------- 1 syncthing users 0 Nov 29 08:39 67
-r-------- 1 syncthing users 0 Nov 29 08:39 68
-r-------- 1 syncthing users 0 Nov 29 08:39 69
-r-------- 1 syncthing users 0 Nov 29 08:39 7
-r-------- 1 syncthing users 0 Nov 29 08:39 70
-r-------- 1 syncthing users 0 Nov 29 08:39 71
-r-------- 1 syncthing users 0 Nov 29 08:39 72
-r-------- 1 syncthing users 0 Nov 29 08:39 73
-r-------- 1 syncthing users 0 Nov 29 08:39 74
-r-------- 1 syncthing users 0 Nov 29 08:39 75
-r-------- 1 syncthing users 0 Nov 29 08:39 76
-r-------- 1 syncthing users 0 Nov 29 08:39 77
-r-------- 1 syncthing users 0 Nov 29 08:39 78
-r-------- 1 syncthing users 0 Nov 29 08:39 79
-r-------- 1 syncthing users 0 Nov 29 08:39 8
-r-------- 1 syncthing users 0 Nov 29 08:39 80
-r-------- 1 syncthing users 0 Nov 29 08:39 81
-r-------- 1 syncthing users 0 Nov 29 08:39 82
-r-------- 1 syncthing users 0 Nov 29 08:39 83
-r-------- 1 syncthing users 0 Nov 29 08:39 84
-r-------- 1 syncthing users 0 Nov 29 08:39 85
-r-------- 1 syncthing users 0 Nov 29 08:39 87
-r-------- 1 syncthing users 0 Nov 29 08:39 88
-r-------- 1 syncthing users 0 Nov 29 08:39 89
-r-------- 1 syncthing users 0 Nov 29 08:39 9
-r-------- 1 syncthing users 0 Nov 29 08:39 90
-r-------- 1 syncthing users 0 Nov 29 08:39 91
-r-------- 1 syncthing users 0 Nov 29 08:39 92
-r-------- 1 syncthing users 0 Nov 29 08:39 93
-r-------- 1 syncthing users 0 Nov 29 08:39 94
-r-------- 1 syncthing users 0 Nov 29 08:39 95
-r-------- 1 syncthing users 0 Nov 29 08:39 96
-r-------- 1 syncthing users 0 Nov 29 08:39 97
-r-------- 1 syncthing users 0 Nov 29 08:39 98
-r-------- 1 syncthing users 0 Nov 29 08:39 99
root@NAS02:/usr/syno/etc# ls -lah /proc/14184/fd*
/proc/14184/fd:
total 0
dr-x------ 2 syncthing users  0 Nov 29 08:39 .
dr-xr-xr-x 8 syncthing users  0 Nov 28 08:03 ..
lrwx------ 1 syncthing users 64 Nov 29 08:39 0 -> /dev/null
lrwx------ 1 syncthing users 64 Nov 29 08:39 1 -> /dev/null
lrwx------ 1 syncthing users 64 Nov 29 08:39 2 -> /dev/null
lr-x------ 1 syncthing users 64 Nov 29 08:39 3 -> pipe:[60052883]
lrwx------ 1 syncthing users 64 Nov 29 08:39 4 -> anon_inode:[eventpoll]
lr-x------ 1 syncthing users 64 Nov 29 08:39 8 -> pipe:[60052884]

/proc/14184/fdinfo:
total 0
dr-x------ 2 syncthing users 0 Nov 29 08:39 .
dr-xr-xr-x 8 syncthing users 0 Nov 28 08:03 ..
-r-------- 1 syncthing users 0 Nov 29 08:39 0
-r-------- 1 syncthing users 0 Nov 29 08:39 1
-r-------- 1 syncthing users 0 Nov 29 08:39 2
-r-------- 1 syncthing users 0 Nov 29 08:39 3
-r-------- 1 syncthing users 0 Nov 29 08:39 4
-r-------- 1 syncthing users 0 Nov 29 08:39 8
root@NAS02:/usr/syno/etc# 

Many thanks,

Pants.


(Audrius Butkevicius) #10

So at the point you took a sample of this info it feels syncthing was just started, even tho at that point, most of the FDs are consumed by the database, which partially confirms my theory. You’ll have to raise limits I suspect.


#11

Hi Audrius:

I suspect you’re right. I’m keeping an eye on the FDs, and will post again when they increase.

I’ve also put in a support request with Synology - though I don’t hold my breath that they’ll be very helpful.

It looks like there are ~22000 files in my index-v0.14.0.db folder - I guess there’s a good chance that >1024 of them might be open at any one time… I presume there’s no switch in Syncthing to limit that?! :wink:

Best wishes,

Pants.


(Jakob Borg) #12

There is no flag, but the database layer is limited to 100 open files. I don’t see how we would open 900 other files to exhaust the 1024 fd limit, to be honest.

Perhaps something with the new fs watcher, if you’ve enabled it?


#13

Thanks Jakob.

Perhaps something with the new fs watcher, if you’ve enabled it?

No - still running on a scheduled scan basis.

Syncthing has now started actually transferring now - and yet the FD listing is still only showing 132 files open (at the time of reading, 6 files for syncing, and the rest are mainly database files). Perhaps something is going haywire further down the road - I’ll continue to keep an eye on it.


#14

…And, incase anyone else is interested, Synology have responded quickly - but unhelpfully:

Unfortunately, we are unable to support or provide terminal level Linux commands directly to users (regardless of proficiency with SSH). … But a limit will exist for a reason and I cannot recommend altering any configurations on your NAS, for performance and stability concerns going forward.

Thanks Synology. :frowning:


#15

Hello again:

So it’s about 15 hours since syncthing panicked and restarted. Now the list of open files is rather substantial:

root@NAS02:~# ls -lah /proc/13857/fd*
/proc/13857/fd:
total 0
dr-x------  2 syncthing users  0 Nov 29 08:39 .
dr-xr-xr-x  8 syncthing users  0 Nov 29 06:02 ..
lr-x------  1 syncthing users 64 Nov 29 08:39 0 -> /dev/null
l-wx------  1 syncthing users 64 Nov 29 08:39 1 -> pipe:[60052884]
lrwx------+ 1 syncthing users 64 Nov 29 08:39 10 -> /file/path1/.syncthing.file1.tmp
lrwx------+ 1 syncthing users 64 Nov 29 08:39 100 -> /file/path2/.syncthing.file2.tmp
lrwx------+ 1 syncthing users 64 Nov 29 21:39 1000 -> /file/path3/.syncthing.file3.tmp
...

/proc/13857/fdinfo:
ls: cannot access /proc/13857/fdinfo/2465: No such file or directory
total 0
dr-x------ 2 syncthing users 0 Nov 29 08:39 .
dr-xr-xr-x 8 syncthing users 0 Nov 29 06:02 ..
-r-------- 1 syncthing users 0 Nov 29 08:39 0
-r-------- 1 syncthing users 0 Nov 29 08:39 1
-r-------- 1 syncthing users 0 Nov 29 08:39 10
-r-------- 1 syncthing users 0 Nov 29 08:39 100
-r-------- 1 syncthing users 0 Nov 29 21:39 1000
-r-------- 1 syncthing users 0 Nov 29 21:39 1001
-r-------- 1 syncthing users 0 Nov 29 21:39 1002
-r-------- 1 syncthing users 0 Nov 29 21:39 1003
-r-------- 1 syncthing users 0 Nov 29 21:39 1004
-r-------- 1 syncthing users 0 Nov 29 21:39 1005
-r-------- 1 syncthing users 0 Nov 29 21:39 1006
-r-------- 1 syncthing users 0 Nov 29 21:39 1007
-r-------- 1 syncthing users 0 Nov 29 21:39 1008
-r-------- 1 syncthing users 0 Nov 29 21:39 1009
-r-------- 1 syncthing users 0 Nov 29 08:39 101
...
-r-------- 1 syncthing users 0 Nov 29 21:39 245
-r-------- 1 syncthing users 0 Nov 29 21:39 2450
-r-------- 1 syncthing users 0 Nov 29 21:39 2451
-r-------- 1 syncthing users 0 Nov 29 21:39 2452
-r-------- 1 syncthing users 0 Nov 29 21:39 2453
-r-------- 1 syncthing users 0 Nov 29 21:39 2454
-r-------- 1 syncthing users 0 Nov 29 21:39 2455
-r-------- 1 syncthing users 0 Nov 29 21:39 2456
-r-------- 1 syncthing users 0 Nov 29 21:39 2457
-r-------- 1 syncthing users 0 Nov 29 21:39 2458
-r-------- 1 syncthing users 0 Nov 29 21:39 2459
-r-------- 1 syncthing users 0 Nov 29 21:39 246
-r-------- 1 syncthing users 0 Nov 29 21:39 2460
-r-------- 1 syncthing users 0 Nov 29 21:39 2461
-r-------- 1 syncthing users 0 Nov 29 21:39 2463
-r-------- 1 syncthing users 0 Nov 29 21:39 2464
-????????? ? ?         ?     ?            ? 2465
-r-------- 1 syncthing users 0 Nov 29 21:39 2466
-r-------- 1 syncthing users 0 Nov 29 21:39 2467
-r-------- 1 syncthing users 0 Nov 29 21:39 2468
-r-------- 1 syncthing users 0 Nov 29 21:39 2469
-r-------- 1 syncthing users 0 Nov 29 21:39 247
-r-------- 1 syncthing users 0 Nov 29 21:39 2470
-r-------- 1 syncthing users 0 Nov 29 21:39 2471
-r-------- 1 syncthing users 0 Nov 29 21:39 2472
-r-------- 1 syncthing users 0 Nov 29 21:39 2473
-r-------- 1 syncthing users 0 Nov 29 21:39 2474
-r-------- 1 syncthing users 0 Nov 29 21:39 2475
-r-------- 1 syncthing users 0 Nov 29 21:39 2476
-r-------- 1 syncthing users 0 Nov 29 21:39 2477
-r-------- 1 syncthing users 0 Nov 29 21:39 2478
-r-------- 1 syncthing users 0 Nov 29 21:41 2479
-r-------- 1 syncthing users 0 Nov 29 21:39 248
-r-------- 1 syncthing users 0 Nov 29 21:41 2480
-r-------- 1 syncthing users 0 Nov 29 21:39 2481
...
-r-------- 1 syncthing users 0 Nov 29 08:39 99
-r-------- 1 syncthing users 0 Nov 29 21:39 990
-r-------- 1 syncthing users 0 Nov 29 21:39 991
-r-------- 1 syncthing users 0 Nov 29 21:39 992
-r-------- 1 syncthing users 0 Nov 29 21:39 993
-r-------- 1 syncthing users 0 Nov 29 21:39 994
-r-------- 1 syncthing users 0 Nov 29 21:39 995
-r-------- 1 syncthing users 0 Nov 29 21:39 996
-r-------- 1 syncthing users 0 Nov 29 21:39 997
-r-------- 1 syncthing users 0 Nov 29 21:39 998
-r-------- 1 syncthing users 0 Nov 29 21:39 999

Is there anything I should look for in the verbose log which might help show what’s going on?

Thanks.


(Jakob Borg) #16

No, but the first section that you dot-dot-dotted that shows what the open files are


#17

Hi Jakob:

Indeed - the vast majority of these files are .syncthing.xyz.tmp files. There are a few database and socket files scattered here and there - but is it to be expected that there should be >2000 user data file chunks open during the transfer? Wouldn’t a chunk get opened, written, and then closed again?

When I looked earlier in the day, I saw ~10 such files open whilst the transfer was taking place - which seems much more reasonable…

Thanks,

Pants.


(Audrius Butkevicius) #18

It should only have 2, unless you tweaked puller settings and such.


#19

Hello Audrius:

Nope - I’ve not changed any such settings…


(Audrius Butkevicius) #20

Can you post the output from /fd directory (fdinfo bears no purpose).