Hi,
We have mounted the version of cmvfs-server on one of our publishing nodes to 2.10 and since then it is impossible to publish a transaction. It worked in 2.9.
Here are the logs :
$ cvmfs_server publish
Using auto tag 'generic-2022-12-08T14:04:10Z'
Processing changes...
Waiting for upload of files before committing...
Committing file catalogs...
Wait for all uploads to finish
Exporting repository manifest
/usr/bin/cvmfs_server: line 4105: 4418 Killed $user_shell "$sync_command"
Synchronization failed
Executed Command:
cvmfs_swissknife sync -u /cvmfs/repo -s /var/spool/cvmfs/repo/scratch/current -c /var/spool/cvmfs/repo/rdonly -t /var/spool/cvmfs/repo/tmp -b 3add0f8d322dacd6b34d8e9d7d918ca727e1f3c2 -r gw,/srv/cvmfs/repo/data/txn,http://stm0-pp.in2p3.fr:4929/api/v1 -w http://stm0-pp.in2p3.fr/cvmfs/repo -o /var/spool/cvmfs/repo/tmp/manifest -e sha1 -Z default -C /etc/cvmfs/repositories.d/repo/trusted_certs -N repo -K /etc/cvmfs/keys/repopub -L -D generic-2022-12-08T14:04:10Z -H /etc/cvmfs/keys/repogw -P /var/spool/cvmfs/repo/session_token -f overlayfs -p -l 4194304 -a 8388608 -h 16777216 -i
In syslog :
failed to read-ahead /var/spool/cvmfs/repo/stats.db (22)
Dec 08 15:04:10 node.novalocal cvmfs_swissknife[4418]: failed to read-ahead /var/spool/cvmfs/repo/tmp/catalog.DFHS2Y (22)
Dec 08 15:04:12 node.novalocal cvmfs_swissknife[4422]: --
Signal: 11, errno: 0, version: 2.10.0, PID: 4418
Executable path: /usr/bin/cvmfs_swissknife
failed to re-gain root permissions... still give it a try
(gdb)
Error output:
ptrace: Operation not permitted.
Timestamp: Thu Dec 8 15:04:12 2022
Crash logged also on file: /tmp/cvmfs-swissknife-sync-stacktrace.2022.12.08-14.04.10.4418
Dec 08 15:04:12 node.novalocal cvmfs_server[4470]: (repo) failed to publish
Thanks for your help
jakob
December 8, 2022, 2:27pm
2
Was the gateway also upgraded to 2.10? There is unfortunately a bug in the 2.10 release that requires gateway and publishers to be updated in lockstep.
Yes, gateway is 2.10. How do we do if we did the update without lock?
On our 2.9 publisher we have an error too :
$ cvmfs_server transaction repo
Make lease acquire request failed: 7. Reply:
(unexpected termination) cannot acquire lease
Stacktrace:
/lib64/libcvmfs_server.so.2.9.4(+0x727e8) [0x7f6aab3ae7e8]
/lib64/libcvmfs_server.so.2.9.4(+0x7a6ad) [0x7f6aab3b66ad]
/lib64/libcvmfs_server.so.2.9.4(_ZN7publish9Publisher7Session7AcquireEv+0x3f9) [0x7f6aab3bd0dd]
/lib64/libcvmfs_server.so.2.9.4(_ZN7publish9Publisher15TransactionImplEv+0xcc) [0x7f6aab3be63a]
/lib64/libcvmfs_server.so.2.9.4(_ZN7publish9Publisher16TransactionRetryEv+0xe5) [0x7f6aab3bf07f]
/lib64/libcvmfs_server.so.2.9.4(_ZN7publish9Publisher11TransactionEv+0xe) [0x7f6aab3aeef6]
/usr/bin/cvmfs_publish() [0x4396eb]
/usr/bin/cvmfs_publish() [0x4107ad]
/lib64/libc.so.6(+0x3feb0) [0x7f6aaa978eb0]
/lib64/libc.so.6(__libc_start_main+0x80) [0x7f6aaa978f60]
/usr/bin/cvmfs_publish() [0x410955]
jakob
December 8, 2022, 7:57pm
5
You need to update this publisher to 2.10, too.
Ok, so if everything is on 2.10, then this hang is new. Can you reproduce it? If so, please run the publish in debug mode with
CVMFS_SERVER_DEBUG=3 cvmfs_server publish
That should give us more useful output.
Publisher updated to 2.10, and same problem when opening a transaction :
$ CVMFS_SERVER_DEBUG=3 cvmfs_server transaction repo
(cvmfs) Parsing config file /etc/cvmfs/server.local [12-09-2022 07:57:36 CET]
(cvmfs) Parsing config file /etc/cvmfs/repositories.d/repo/server.conf [12-09-2022 07:57:36 CET]
(cvmfs) execve'd /bin/sh (PID: 6189) [12-09-2022 07:57:36 CET]
(cvmfs) Parsing config file /etc/cvmfs/repositories.d/repo/replica.conf [12-09-2022 07:57:36 CET]
(cvmfs) current credentials uid 501 gid 100 euid 501 egid 100, switching to 501 100 (temp: 0) [12-09-2022 07:57:36 CET]
(cvmfs) switch credentials result 0 (0) [12-09-2022 07:57:36 CET]
(download) escaped http://stm0/cvmfs/repo/.cvmfswhitelist to http://stm0/cvmfs/repo/.cvmfswhitelist [12-09-2022 07:57:36 CET]
(download) Verify downloaded url http://stm0/cvmfs/repo/.cvmfswhitelist, proxy DIRECT (curl error 0) [12-09-2022 07:57:36 CET]
(signature) whitelist UTC expiry timestamp in localtime: 8 Jan 2023 02:00:00 [12-09-2022 07:57:36 CET]
(signature) local time: 9 Dec 2022 07:57:36 [12-09-2022 07:57:36 CET]
(download) escaped http://stm0/cvmfs/repo/.cvmfspublished to http://stm0/cvmfs/repo/.cvmfspublished [12-09-2022 07:57:36 CET]
(download) Verify downloaded url http://stm0/cvmfs/repo/.cvmfspublished, proxy DIRECT (curl error 0) [12-09-2022 07:57:36 CET]
(download) escaped http://stm0/cvmfs/repo/data/30/6fc0168d90196df9d65ca74ced5ac9c2bf71a1X to http://stm0/cvmfs/repo/data/30/6fc0168d90196df9d65ca74ced5ac9c2bf71a1X [12-09-2022 07:57:36 CET]
(download) Verify downloaded url http://stm0/cvmfs/repo/data/30/6fc0168d90196df9d65ca74ced5ac9c2bf71a1X, proxy DIRECT (curl error 0) [12-09-2022 07:57:36 CET]
(download) escaped http://stm0/cvmfs/repo/.cvmfswhitelist to http://stm0/cvmfs/repo/.cvmfswhitelist [12-09-2022 07:57:36 CET]
(download) Verify downloaded url http://stm0/cvmfs/repo/.cvmfswhitelist, proxy DIRECT (curl error 0) [12-09-2022 07:57:36 CET]
(signature) whitelist UTC expiry timestamp in localtime: 8 Jan 2023 02:00:00 [12-09-2022 07:57:36 CET]
(signature) local time: 9 Dec 2022 07:57:36 [12-09-2022 07:57:36 CET]
(download) escaped http://stm0/cvmfs/repo/.cvmfsreflog to http://stm0/cvmfs/repo/.cvmfsreflog [12-09-2022 07:57:36 CET]
(download) Verify downloaded url http://stm0/cvmfs/repo/.cvmfsreflog, proxy DIRECT (curl error 0) [12-09-2022 07:57:36 CET]
(sql) opening database file /var/spool/cvmfs/repo/tmp/reflog.PhuM2Y [12-09-2022 07:57:36 CET]
(sql) failed to read-ahead /var/spool/cvmfs/repo/tmp/reflog.PhuM2Y (22) [12-09-2022 07:57:36 CET]
(sql) successfully prepared statement 'BEGIN;' [12-09-2022 07:57:36 CET]
(sql) successfully prepared statement 'COMMIT;' [12-09-2022 07:57:36 CET]
(sql) successfully prepared statement 'SELECT count(*) FROM properties WHERE key = :key;' [12-09-2022 07:57:36 CET]
(sql) successfully prepared statement 'SELECT value FROM properties WHERE key = :key;' [12-09-2022 07:57:36 CET]
(sql) successfully prepared statement 'INSERT OR REPLACE INTO properties (key, value) VALUES (:key, :value);' [12-09-2022 07:57:36 CET]
(sql) opened database with schema version 1.000000 and revision 0 [12-09-2022 07:57:36 CET]
(reflog) opened Reflog database '/var/spool/cvmfs/repo/tmp/reflog.PhuM2Y' for repository 'repo' [12-09-2022 07:57:36 CET]
(sql) Database object took ownership of '/var/spool/cvmfs/repo/tmp/reflog.PhuM2Y' [12-09-2022 07:57:36 CET]
(download) escaped http://stm0/cvmfs/repo/data/01/af29b4b1eca5bdae1e865a6d50fdc24cece07fH to http://stm0/cvmfs/repo/data/01/af29b4b1eca5bdae1e865a6d50fdc24cece07fH [12-09-2022 07:57:36 CET]
(download) Verify downloaded url http://stm0/cvmfs/repo/data/01/af29b4b1eca5bdae1e865a6d50fdc24cece07fH, proxy DIRECT (curl error 0) [12-09-2022 07:57:36 CET]
(sql) opening database file /var/spool/cvmfs/repo/tmp/tags.UQlXkP [12-09-2022 07:57:36 CET]
(sql) failed to read-ahead /var/spool/cvmfs/repo/tmp/tags.UQlXkP (22) [12-09-2022 07:57:36 CET]
(sql) successfully prepared statement 'BEGIN;' [12-09-2022 07:57:36 CET]
(sql) successfully prepared statement 'COMMIT;' [12-09-2022 07:57:36 CET]
(sql) successfully prepared statement 'SELECT count(*) FROM properties WHERE key = :key;' [12-09-2022 07:57:36 CET]
(sql) successfully prepared statement 'SELECT value FROM properties WHERE key = :key;' [12-09-2022 07:57:36 CET]
(sql) successfully prepared statement 'INSERT OR REPLACE INTO properties (key, value) VALUES (:key, :value);' [12-09-2022 07:57:36 CET]
(sql) opened database with schema version 1.000000 and revision 3 [12-09-2022 07:57:36 CET]
(sql) successfully prepared statement 'PRAGMA foreign_keys = ON;' [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(history) opened history database '/var/spool/cvmfs/repo/tmp/tags.UQlXkP' for repository 'repo' (writable) [12-09-2022 07:57:36 CET]
(sql) Database object took ownership of '/var/spool/cvmfs/repo/tmp/tags.UQlXkP' [12-09-2022 07:57:36 CET]
(download) escaped http://stm0/cvmfs/repo/data/85/e4f386da0d5d77c7f66cf2f58e10951f24b653M to http://stm0/cvmfs/repo/data/85/e4f386da0d5d77c7f66cf2f58e10951f24b653M [12-09-2022 07:57:36 CET]
(download) Verify downloaded url http://stm0/cvmfs/repo/data/85/e4f386da0d5d77c7f66cf2f58e10951f24b653M, proxy DIRECT (curl error 0) [12-09-2022 07:57:36 CET]
Make lease acquire request failed: 7. Reply:
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) closing SQLite database '/var/spool/cvmfs/repo/tmp/tags.UQlXkP' (unlink: yes) [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) successfully finalized statement [12-09-2022 07:57:36 CET]
(sql) closing SQLite database '/var/spool/cvmfs/repo/tmp/reflog.PhuM2Y' (unlink: yes) [12-09-2022 07:57:36 CET]
(unexpected termination) cannot acquire lease
Stacktrace:
/lib64/libcvmfs_server_debug.so.2.10.0(+0x12709a) [0x7f455ab7809a]
/lib64/libcvmfs_server_debug.so.2.10.0(+0x131ee8) [0x7f455ab82ee8]
/lib64/libcvmfs_server_debug.so.2.10.0(+0x13d768) [0x7f455ab8e768]
/lib64/libcvmfs_server_debug.so.2.10.0(_ZN7publish9Publisher7Session7AcquireEv+0x11a) [0x7f455ab8fd6a]
/lib64/libcvmfs_server_debug.so.2.10.0(_ZN7publish9Publisher15TransactionImplEv+0x100) [0x7f455ab921c6]
/lib64/libcvmfs_server_debug.so.2.10.0(_ZN7publish9Publisher16TransactionRetryEv+0x15b) [0x7f455ab91f39]
/lib64/libcvmfs_server_debug.so.2.10.0(_ZN7publish9Publisher11TransactionEv+0x18) [0x7f455ab8169c]
/usr/bin/cvmfs_publish_debug() [0x49439b]
/usr/bin/cvmfs_publish_debug() [0x49bbb6]
/lib64/libc.so.6(+0x3feb0) [0x7f4559e8eeb0]
/lib64/libc.so.6(__libc_start_main+0x80) [0x7f4559e8ef60]
/usr/bin/cvmfs_publish_debug() [0x439025]
jakob
December 9, 2022, 9:47am
7
Oh, turns out even the non-debug output contained a clue:
Error code 7 comes from libcurl and it means “cannot connect to host”. Is the gateway reachable from the publisher? You can test from the publisher with
curl http://<gateway endpoint>/api/v1/leases
Indeed the cvmfs-gateway service crashed during the update. After a restart of the service everything seems to work again.
Can you confirm me the proper way to do a gateway and publisher update ?
Thanks for your help.
jakob
December 12, 2022, 11:12am
9
The recommended way is to first finish all active transactions on all the remote publishers. Then to update the cvmfs, cvmfs-server, and cvmfs-gateway packages both on the publishers and the gateway. And lastly to run an empty test transaction on one of the publishers.