Bug#682798: ERROR: Node N cannot be found in the node store M (too many open files)
same problem here with Debian Jessie on amd64 with python-larch 1.20131130-1 and obnam 1.8-1. Did anyone found an alternative? I just need: * backup over sftp * gpg encryption support (signature using different key would be nice too) * automatic checkpoints * should be in Debian Jessie * old backups should be possible to get removed * incremental backup
Bug#682798: ERROR: Node N cannot be found in the node store M (too many open files)
On Fri, Aug 21, 2015 at 12:30:31PM +, Franz Schrober wrote: same problem here with Debian Jessie on amd64 with python-larch 1.20131130-1 and obnam 1.8-1. Do you get an error message saying there are too many open files, or just an error message that a node is missing? -- sic transit disci mundi, ergo obnam
Bug#682798: ERROR: Node N cannot be found in the node store M (too many open files)
Package: obnam Followup-For: Bug #682798 There seems to be a problem with how obnam deals with ENOMEM conditions, causing it to leak pipes. Yet another trial run failed. This time I ran a lsof process periodically in another screen window: % (export LC_ALL=C ; while :; do date; really lsof -c obnam | grep -c pipe$; sleep 20; done) | tee obnam-lsof.txt The data are interesting: [... several hours of low counts deleted ...] Fri Jul 27 06:50:14 EEST 2012 2 Fri Jul 27 06:50:34 EEST 2012 2 Fri Jul 27 06:50:54 EEST 2012 2 Fri Jul 27 06:51:14 EEST 2012 2 Fri Jul 27 06:51:34 EEST 2012 2 Fri Jul 27 06:51:54 EEST 2012 2 Fri Jul 27 06:52:14 EEST 2012 2 Fri Jul 27 06:52:34 EEST 2012 11 Fri Jul 27 06:52:55 EEST 2012 9 Fri Jul 27 06:53:15 EEST 2012 2 Fri Jul 27 06:53:35 EEST 2012 9 Fri Jul 27 06:53:55 EEST 2012 2 Fri Jul 27 06:54:15 EEST 2012 2 Fri Jul 27 06:54:35 EEST 2012 2 Fri Jul 27 06:54:55 EEST 2012 2 Fri Jul 27 06:55:15 EEST 2012 2 Fri Jul 27 06:55:35 EEST 2012 23 Fri Jul 27 06:55:55 EEST 2012 33 Fri Jul 27 06:56:15 EEST 2012 33 Fri Jul 27 06:56:35 EEST 2012 30 Fri Jul 27 06:56:55 EEST 2012 30 Fri Jul 27 06:57:15 EEST 2012 49 Fri Jul 27 06:57:35 EEST 2012 44 Fri Jul 27 06:57:55 EEST 2012 44 Fri Jul 27 06:58:15 EEST 2012 44 Fri Jul 27 06:58:36 EEST 2012 49 Fri Jul 27 06:58:56 EEST 2012 44 Fri Jul 27 06:59:16 EEST 2012 44 Fri Jul 27 06:59:36 EEST 2012 49 Fri Jul 27 06:59:56 EEST 2012 398 Fri Jul 27 07:00:16 EEST 2012 1605 Fri Jul 27 07:00:36 EEST 2012 3222 Fri Jul 27 07:00:57 EEST 2012 5994 Fri Jul 27 07:01:18 EEST 2012 5994 Fri Jul 27 07:01:40 EEST 2012 5994 Fri Jul 27 07:02:01 EEST 2012 5994 Fri Jul 27 07:02:23 EEST 2012 5994 Fri Jul 27 07:02:44 EEST 2012 5994 Fri Jul 27 07:03:05 EEST 2012 5994 Fri Jul 27 07:03:27 EEST 2012 5994 Fri Jul 27 07:03:48 EEST 2012 5994 Fri Jul 27 07:04:09 EEST 2012 5994 Fri Jul 27 07:04:30 EEST 2012 5994 Fri Jul 27 07:04:52 EEST 2012 5994 Fri Jul 27 07:05:13 EEST 2012 5994 Fri Jul 27 07:05:34 EEST 2012 5994 Fri Jul 27 07:05:55 EEST 2012 5994 Fri Jul 27 07:06:15 EEST 2012 5994 Fri Jul 27 07:06:37 EEST 2012 5994 Fri Jul 27 07:06:58 EEST 2012 5994 Fri Jul 27 07:07:19 EEST 2012 5994 Fri Jul 27 07:07:40 EEST 2012 5994 Fri Jul 27 07:08:00 EEST 2012 5994 Fri Jul 27 07:08:22 EEST 2012 5994 Fri Jul 27 07:08:43 EEST 2012 5994 Fri Jul 27 07:09:03 EEST 2012 5994 Fri Jul 27 07:09:25 EEST 2012 5994 Fri Jul 27 07:09:46 EEST 2012 5994 Fri Jul 27 07:10:07 EEST 2012 5994 Fri Jul 27 07:10:29 EEST 2012 5994 Fri Jul 27 07:10:50 EEST 2012 5994 Fri Jul 27 07:11:11 EEST 2012 5994 Fri Jul 27 07:11:33 EEST 2012 5994 Fri Jul 27 07:11:54 EEST 2012 5994 Fri Jul 27 07:12:15 EEST 2012 5994 Fri Jul 27 07:12:37 EEST 2012 5994 Fri Jul 27 07:12:58 EEST 2012 5994 Fri Jul 27 07:13:19 EEST 2012 5994 Fri Jul 27 07:13:41 EEST 2012 5994 Fri Jul 27 07:14:02 EEST 2012 5994 Fri Jul 27 07:14:23 EEST 2012 5994 Fri Jul 27 07:14:45 EEST 2012 5994 Fri Jul 27 07:15:07 EEST 2012 5994 Fri Jul 27 07:15:28 EEST 2012 5994 Fri Jul 27 07:15:49 EEST 2012 5994 Fri Jul 27 07:16:11 EEST 2012 5994 Fri Jul 27 07:16:32 EEST 2012 5994 Fri Jul 27 07:16:54 EEST 2012 5994 Fri Jul 27 07:17:15 EEST 2012 5994 Fri Jul 27 07:17:37 EEST 2012 5994 Fri Jul 27 07:17:58 EEST 2012 5994 Fri Jul 27 07:18:20 EEST 2012 5994 Fri Jul 27 07:18:42 EEST 2012 5994 Fri Jul 27 07:19:03 EEST 2012 5994 Fri Jul 27 07:19:25 EEST 2012 5994 Fri Jul 27 07:19:45 EEST 2012 5994 Fri Jul 27 07:20:06 EEST 2012 5994 Fri Jul 27 07:20:26 EEST 2012 5994 Fri Jul 27 07:20:47 EEST 2012 5994 Fri Jul 27 07:21:08 EEST 2012 5994 Fri Jul 27 07:21:29 EEST 2012 5994 Fri Jul 27 07:21:49 EEST 2012 5994 Fri Jul 27 07:22:10 EEST 2012 5994 Fri Jul 27 07:22:32 EEST 2012 5994 Fri Jul 27 07:22:52 EEST 2012 5994 Fri Jul 27 07:23:14 EEST 2012 5994 Fri Jul 27 07:23:35 EEST 2012 5994 Fri Jul 27 07:23:55 EEST 2012 5994 Fri Jul 27 07:24:16 EEST 2012 5994 Fri Jul 27 07:24:37 EEST 2012 5994 Fri Jul 27 07:24:58 EEST 2012 5994 Fri Jul 27 07:25:19 EEST 2012 5994 Fri Jul 27 07:25:40 EEST 2012 5994 Fri Jul 27 07:26:02 EEST 2012 5994 Fri Jul 27 07:26:23 EEST 2012 5994 Fri Jul 27 07:26:44 EEST 2012 5994 Fri Jul 27 07:27:04 EEST 2012 5994 Fri Jul 27 07:27:26 EEST 2012 5994 Fri Jul 27 07:27:46 EEST 2012 5994 Fri Jul 27 07:28:07 EEST 2012 5994 Fri Jul 27 07:28:28 EEST 2012 5994 Fri Jul 27 07:28:49 EEST 2012 5994 Fri Jul 27 07:29:10 EEST 2012 5994 Fri Jul 27 07:29:32 EEST 2012 5994 Fri Jul 27 07:29:54 EEST 2012 5994 Fri Jul 27 07:30:15 EEST 2012 5994 Fri Jul 27 07:30:36 EEST 2012 5994 Fri Jul 27 07:30:57 EEST 2012 5994 Fri Jul 27 07:31:18 EEST 2012 5994 Fri Jul 27 07:31:38 EEST 2012 5994 Fri Jul 27 07:31:59 EEST 2012 5994 Fri Jul 27 07:32:20 EEST 2012 5994 Fri Jul 27 07:32:41 EEST 2012 5994 Fri Jul 27 07:33:03 EEST 2012 5994 Fri Jul 27 07:33:24 EEST 2012 5994 Fri Jul 27 07:33:45 EEST 2012 5994 Fri Jul 27 07:34:07 EEST 2012 5994 Fri Jul 27 07:34:29 EEST 2012 5994 Fri Jul 27 07:34:51 EEST 2012 5994 Fri Jul 27 07:35:12 EEST 2012 5994 Fri Jul 27 07:35:34 EEST 2012 5994 Fri Jul 27 07:35:55 EEST 2012 5994 Fri Jul 27
Bug#682798: ERROR: Node N cannot be found in the node store M (too many open files)
Package: obnam
Followup-For: Bug #682798
I tried to continue the backup with a raised open file limit, similar failure.
(The backup disk is mounted over NFS, which may complicate things.)
[... lots of too many open files errors deleted ...]
2012-07-26 17:58:21 ERROR Can't back up /home/ajk/.gnupg: Too many open files
2012-07-26 17:58:21 DEBUG OSError(24, 'Too many open files')
2012-07-26 17:58:22 DEBUG Backing up
/home/ajk/wp-2.0.6/wp-admin/images/box-butt-left.gif
2012-07-26 17:58:22 ERROR Error reading node: 2: No such file or directory:
/mnt/backup/1566508680438567912/nodes/0/0/0/646
2012-07-26 17:58:22 DEBUG Handling exception Node 1606 cannot be found in the
node store 1566508680438567912
2012-07-26 17:58:22 DEBUG Traceback (most recent call last):
File /usr/lib/python2.7/dist-packages/obnamlib/plugins/backup_plugin.py,
line 258, in backup
self.backup_roots(roots)
File /usr/lib/python2.7/dist-packages/obnamlib/plugins/backup_plugin.py,
line 357, in backup_roots
metadata)
File /usr/lib/python2.7/dist-packages/obnamlib/plugins/backup_plugin.py,
line 564, in backup_file_contents
self.repo.append_file_chunks(filename, chunkids)
File /usr/lib/python2.7/dist-packages/obnamlib/repo.py, line 750, in
append_file_chunks
self.client.append_file_chunks(filename, chunkids)
File /usr/lib/python2.7/dist-packages/obnamlib/clientmetadatatree.py, line
507, in append_file_chunks
self.tree.insert(self.chunk_key(chunkid, file_id), '')
File /usr/lib/python2.7/dist-packages/larch/tree.py, line 281, in insert
kids = self._insert_into_index(self.root, key, value)
File /usr/lib/python2.7/dist-packages/larch/tree.py, line 317, in
_insert_into_index
child = self._get_node(new_index[child_key])
File /usr/lib/python2.7/dist-packages/larch/tree.py, line 111, in _get_node
return self.node_store.get_node(node_id)
File /usr/lib/python2.7/dist-packages/larch/nodestore_disk.py, line 237, in
get_node
raise larch.NodeMissing(self.dirname, node_id)
NodeMissing: Node 1606 cannot be found in the node store 1566508680438567912
2012-07-26 17:58:22 INFO Unlocking client because of error
2012-07-26 17:58:22 DEBUG Got second exception while unlocking: have not got
lock on shared B-trees
2012-07-26 17:58:22 DEBUG Traceback (most recent call last):
File /usr/lib/python2.7/dist-packages/obnamlib/plugins/backup_plugin.py,
line 285, in unlock_when_error
self.repo.unlock_client()
File /usr/lib/python2.7/dist-packages/obnamlib/repo.py, line 455, in
unlock_client
self._really_remove_generations(self.added_generations)
File /usr/lib/python2.7/dist-packages/obnamlib/repo.py, line 566, in
_really_remove_generations
self.require_shared_lock()
File /usr/lib/python2.7/dist-packages/obnamlib/repo.py, line 221, in
require_shared_lock
raise LockFail('have not got lock on shared B-trees')
LockFail: have not got lock on shared B-trees
2012-07-26 17:58:22 CRITICAL Node 1606 cannot be found in the node store
1566508680438567912
-- System Information:
Debian Release: wheezy/sid
APT prefers testing
APT policy: (990, 'testing')
Architecture: i386 (i686)
Kernel: Linux 2.6.32.33-kvm-i386-2028-dirty (SMP w/1 CPU core)
Locale: LANG=fi_FI.UTF-8, LC_CTYPE=fi_FI.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/bash
Versions of packages obnam depends on:
ii libc6 2.13-33
ii python2.7.3~rc2-1
ii python-cliapp 1.20120630-1
ii python-larch 1.20120527-1
ii python-paramiko 1.7.7.1-3
ii python-tracing0.6-2
ii python-ttystatus 0.19-1
obnam recommends no packages.
obnam suggests no packages.
-- no debconf information
--
To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org
with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#682798: ERROR: Node N cannot be found in the node store M (too many open files)
Package: obnam Followup-For: Bug #682798 I have another attempt running so far for 4½ hours; lsof shows obnam has a lot of pipes open! # lsof -c obnam | grep -c pipe$ 2042 # lsof -c obnam | grep pipe$ | head obnam 21834 root1w FIFO0,7 0t0 10250227 pipe obnam 21834 root2w FIFO0,7 0t0 10250227 pipe obnam 21834 root6r FIFO0,7 0t0 10732079 pipe obnam 21834 root7r FIFO0,7 0t0 10732080 pipe obnam 21834 root8w FIFO0,7 0t0 10732080 pipe obnam 21834 root 10r FIFO0,7 0t0 10732081 pipe obnam 21834 root 11w FIFO0,7 0t0 10732081 pipe obnam 21834 root 12r FIFO0,7 0t0 10732082 pipe obnam 21834 root 13w FIFO0,7 0t0 10732082 pipe obnam 21834 root 15r FIFO0,7 0t0 10732142 pipe What's happening here? -- System Information: Debian Release: wheezy/sid APT prefers testing APT policy: (990, 'testing') Architecture: i386 (i686) Kernel: Linux 2.6.32.33-kvm-i386-2028-dirty (SMP w/1 CPU core) Locale: LANG=fi_FI.UTF-8, LC_CTYPE=fi_FI.UTF-8 (charmap=UTF-8) Shell: /bin/sh linked to /bin/bash Versions of packages obnam depends on: ii libc6 2.13-33 ii python2.7.3~rc2-1 ii python-cliapp 1.20120630-1 ii python-larch 1.20120527-1 ii python-paramiko 1.7.7.1-3 ii python-tracing0.6-2 ii python-ttystatus 0.19-1 obnam recommends no packages. obnam suggests no packages. -- no debconf information -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#682798: ERROR: Node N cannot be found in the node store M (too many open files)
Package: obnam
Version: 1.1-1
I've been trying to do an initial full backup of my server using obnam, but it
reliably fails with the error message
ERROR: Node 1598 cannot be found in the node store 1566508680438567912
(the numbers change between attempts) about 12 hours into the backup run. I
unfortunately did not have logging enabled in any of these attempts.
After the last full backup attempt I've tried restarting the backup; it failed
eventually with the following (trimmed) log:
2012-07-25 13:05:15 DEBUG Current configuration:
[config]
output =
log = /var/tmp/backup-local/obnam-log
log-level = debug
log-max = 0
log-keep = 10
log-mode = 0600
dump-memory-profile = simple
repository = /mnt/backup
client-name = flowerpot.kaijanaho.info
node-size = 262144
chunk-size = 1048576
upload-queue-size = 1024
lru-size = 500
trace =
idpath-depth = 3
idpath-bits = 12
idpath-skip = 13
quiet = False
pretend = False
pretend-time =
lock-timeout = 60
crash-limit = 0
compress-with = deflate
root =
exclude =
exclude-caches = False
one-file-system = False
checkpoint = 1073741824
chunkids-per-group = 1024
deduplicate = fatalist
leave-checkpoints = False
small-files-in-btree = False
warn-age = 27h
critical-age = 27h
sftp-delay = 0
ssh-key =
strict-ssh-host-keys = False
ssh-known-hosts = /root/.ssh/known_hosts
pure-paramiko = False
to =
generation = latest
keep =
fsck-fix = False
2012-07-25 13:05:15 INFO Backup starts
[ ... ]
2012-07-25 18:22:49 DEBUG Backing up
/home/ajk/wp-2.0.6/wp-admin/import/livejournal.php
2012-07-25 18:22:50 ERROR Error reading node: 24: Too many open files:
1566508680438567912/nodes/0/0/0/314
2012-07-25 18:22:50 DEBUG Handling exception Node 788 cannot be found in the
node store 1566508680438567912
2012-07-25 18:22:51 DEBUG Traceback (most recent call last):
File /usr/lib/python2.7/dist-packages/obnamlib/plugins/backup_plugin.py,
line 258, in backup
self.backup_roots(roots)
File /usr/lib/python2.7/dist-packages/obnamlib/plugins/backup_plugin.py,
line 357, in backup_roots
metadata)
File /usr/lib/python2.7/dist-packages/obnamlib/plugins/backup_plugin.py,
line 564, in backup_file_contents
self.repo.append_file_chunks(filename, chunkids)
File /usr/lib/python2.7/dist-packages/obnamlib/repo.py, line 750, in
append_file_chunks
self.client.append_file_chunks(filename, chunkids)
File /usr/lib/python2.7/dist-packages/obnamlib/clientmetadatatree.py, line
507, in append_file_chunks
self.tree.insert(self.chunk_key(chunkid, file_id), '')
File /usr/lib/python2.7/dist-packages/larch/tree.py, line 281, in insert
kids = self._insert_into_index(self.root, key, value)
File /usr/lib/python2.7/dist-packages/larch/tree.py, line 317, in
_insert_into_index
child = self._get_node(new_index[child_key])
File /usr/lib/python2.7/dist-packages/larch/tree.py, line 111, in _get_node
return self.node_store.get_node(node_id)
File /usr/lib/python2.7/dist-packages/larch/nodestore_disk.py, line 237, in
get_node
raise larch.NodeMissing(self.dirname, node_id)
NodeMissing: Node 788 cannot be found in the node store 1566508680438567912
2012-07-25 18:22:51 INFO Unlocking client because of error
2012-07-25 18:22:51 DEBUG Got second exception while unlocking: have not got
lock on shared B-trees
2012-07-25 18:22:51 DEBUG Traceback (most recent call last):
File /usr/lib/python2.7/dist-packages/obnamlib/plugins/backup_plugin.py,
line 285, in unlock_when_error
self.repo.unlock_client()
File /usr/lib/python2.7/dist-packages/obnamlib/repo.py, line 455, in
unlock_client
self._really_remove_generations(self.added_generations)
File /usr/lib/python2.7/dist-packages/obnamlib/repo.py, line 566, in
_really_remove_generations
self.require_shared_lock()
File /usr/lib/python2.7/dist-packages/obnamlib/repo.py, line 221, in
require_shared_lock
raise LockFail('have not got lock on shared B-trees')
LockFail: have not got lock on shared B-trees
2012-07-25 18:22:51 CRITICAL Node 788 cannot be found in the node store
1566508680438567912
I'm now running another attempt to continue the backup. (Maybe I should try
raise the limits, but whyever for does obnam need a lot of open files? Even if
it does, that error message should be given in stderr, not buried in the logs.)
-- System Information:
Debian Release: wheezy/sid
APT prefers testing
APT policy: (990, 'testing')
Architecture: i386 (i686)
Kernel: Linux 2.6.32.33-kvm-i386-2028-dirty (SMP w/1 CPU core)
Locale: LANG=fi_FI.UTF-8, LC_CTYPE=fi_FI.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/bash
Versions of packages obnam depends on:
ii libc6 2.13-33
ii python2.7.3~rc2-1
ii python-cliapp 1.20120630-1
ii python-larch 1.20120527-1
ii python-paramiko 1.7.7.1-3
ii python-tracing0.6-2
ii python-ttystatus 0.19-1
obnam recommends no packages.
obnam suggests no packages.
-- no debconf information
--
To UNSUBSCRIBE, email to
