Error on publisher

Hi,

We have an error on a publisher node when trying to publish a transaction :

cvmfs_server publish repo
Using auto tag 'generic-2023-02-20T12:24:03Z'
Processing changes...
..............................................................................................................................................................................................................................................................
Waiting for upload of files before committing...
Committing file catalogs...
Wait for all uploads to finish
Exporting repository manifest
Lease end request - error reply: {"reason":"could not obtain statistics counters: no statistics counters for lease repo/","status":"error"}
SessionContext: could not commit session. Aborting.
[ERROR] Failed to commit transaction.
Statistics stored at: /var/spool/cvmfs/repo/stats.db
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 080236f170f456c5d452fa2009b786cc80fc5d51 -r gw,/srv/cvmfs/repo/data/txn,http://stm0.in2p3.fr:4929/api/v1 -w http://stm0.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/repo.pub -L -D generic-2023-02-20T12:24:03Z -H /etc/cvmfs/keys/repo.gw -P /var/spool/cvmfs/repo/session_token -f overlayfs -p -l 4194304 -a 8388608 -h 16777216 -i

When trying to abort :

cvmfs_server abort repo
You are about to DISCARD ALL CHANGES OF THE CURRENT TRANSACTION for repo!  Are you sure (y/N)? y
Error: 'no statistics counters for lease repo/'

Publisher node and stratum 0 node are two separated server with cvmfs 2.10 : have you some ideas to help us ?

Thanks

Debug logs :

CVMFS_SERVER_DEBUG=3 cvmfs_server abort repo
(cvmfs) Parsing config file /etc/cvmfs/server.local    [02-20-2023 13:55:07 CET]
(cvmfs) Parsing config file /etc/cvmfs/repositories.d/repo/server.conf    [02-20-2023 13:55:07 CET]
(cvmfs) execve'd /bin/sh (PID: 31867)    [02-20-2023 13:55:07 CET]
(cvmfs) Parsing config file /etc/cvmfs/repositories.d/repo/replica.conf    [02-20-2023 13:55:07 CET]
(cvmfs) current credentials uid 501 gid 100 euid 501 egid 100, switching to 501 100 (temp: 0)    [02-20-2023 13:55:07 CET]
(cvmfs) switch credentials result 0 (0)    [02-20-2023 13:55:07 CET]
You are about to DISCARD ALL CHANGES OF THE CURRENT TRANSACTION for repo!  Are you sure (y/N)? y
(download) escaped http://stm0.fr/cvmfs/repo/.cvmfswhitelist to http://stm0.fr/cvmfs/repo/.cvmfswhitelist    [02-20-2023 13:55:10 CET]
(download) Verify downloaded url http://stm0.fr/cvmfs/repo/.cvmfswhitelist, proxy DIRECT (curl error 0)    [02-20-2023 13:55:10 CET]
(signature) whitelist UTC expiry timestamp in localtime: 22 Mar 2023 03:00:00    [02-20-2023 13:55:10 CET]
(signature) local time: 20 Feb 2023 13:55:10    [02-20-2023 13:55:10 CET]
(download) escaped http://stm0.fr/cvmfs/repo/.cvmfspublished to http://stm0.fr/cvmfs/repo/.cvmfspublished    [02-20-2023 13:55:10 CET]
(download) Verify downloaded url http://stm0.fr/cvmfs/repo/.cvmfspublished, proxy DIRECT (curl error 0)    [02-20-2023 13:55:10 CET]
(download) escaped http://stm0.fr/cvmfs/repo/data/66/b2c6e3e1954bc809e673e8d4c1a7640f60d80eX to http://stm0.fr/cvmfs/repo/data/66/b2c6e3e1954bc809e673e8d4c1a7640f60d80eX    [02-20-2023 13:55:10 CET]
(download) Verify downloaded url http://stm0.fr/cvmfs/repo/data/66/b2c6e3e1954bc809e673e8d4c1a7640f60d80eX, proxy DIRECT (curl error 0)    [02-20-2023 13:55:10 CET]
(download) escaped http://stm0.fr/cvmfs/repo/.cvmfswhitelist to http://stm0.fr/cvmfs/repo/.cvmfswhitelist    [02-20-2023 13:55:10 CET]
(download) Verify downloaded url http://stm0.fr/cvmfs/repo/.cvmfswhitelist, proxy DIRECT (curl error 0)    [02-20-2023 13:55:10 CET]
(signature) whitelist UTC expiry timestamp in localtime: 22 Mar 2023 03:00:00    [02-20-2023 13:55:10 CET]
(signature) local time: 20 Feb 2023 13:55:10    [02-20-2023 13:55:10 CET]
(download) escaped http://stm0.fr/cvmfs/repo/.cvmfsreflog to http://stm0.fr/cvmfs/repo/.cvmfsreflog    [02-20-2023 13:55:10 CET]
(download) http status error code: HTTP/1.1 404 Not Found
 [404]    [02-20-2023 13:55:10 CET]
(download) Verify downloaded url http://stm0.fr/cvmfs/repo/.cvmfsreflog, proxy DIRECT (curl error 23)    [02-20-2023 13:55:10 CET]
(download) download failed (error 9 - host returned HTTP error)    [02-20-2023 13:55:10 CET]
(download) escaped http://stm0.fr/cvmfs/repo/data/2d/978cdf4775b0f53404c2c159692a590e1819d0H to http://stm0.fr/cvmfs/repo/data/2d/978cdf4775b0f53404c2c159692a590e1819d0H    [02-20-2023 13:55:10 CET]
(download) Verify downloaded url http://stm0.fr/cvmfs/repo/data/2d/978cdf4775b0f53404c2c159692a590e1819d0H, proxy DIRECT (curl error 0)    [02-20-2023 13:55:10 CET]
(sql) opening database file /var/spool/cvmfs/repo/tmp/tags.gHB8Jw    [02-20-2023 13:55:10 CET]
(sql) failed to read-ahead /var/spool/cvmfs/repo/tmp/tags.gHB8Jw (22)    [02-20-2023 13:55:10 CET]
(sql) successfully prepared statement 'BEGIN;'    [02-20-2023 13:55:10 CET]
(sql) successfully prepared statement 'COMMIT;'    [02-20-2023 13:55:10 CET]
(sql) successfully prepared statement 'SELECT count(*) FROM properties WHERE key = :key;'    [02-20-2023 13:55:10 CET]
(sql) successfully prepared statement 'SELECT value FROM properties WHERE key = :key;'    [02-20-2023 13:55:10 CET]
(sql) successfully prepared statement 'INSERT OR REPLACE INTO properties (key, value) VALUES (:key, :value);'    [02-20-2023 13:55:10 CET]
(sql) opened database with schema version 1.000000 and revision 3    [02-20-2023 13:55:10 CET]
(sql) successfully prepared statement 'PRAGMA foreign_keys = ON;'    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(history) opened history database '/var/spool/cvmfs/repo/tmp/tags.gHB8Jw' for repository 'repo' (writable)    [02-20-2023 13:55:10 CET]
(sql) Database object took ownership of '/var/spool/cvmfs/repo/tmp/tags.gHB8Jw'    [02-20-2023 13:55:10 CET]
(download) escaped http://stm0.fr/cvmfs/repo/data/de/cf358874358c4f313db997d36a3b8e3d62622eM to http://stm0.fr/cvmfs/repo/data/de/cf358874358c4f313db997d36a3b8e3d62622eM    [02-20-2023 13:55:10 CET]
(download) Verify downloaded url http://stm0.fr/cvmfs/repo/data/de/cf358874358c4f313db997d36a3b8e3d62622eM, proxy DIRECT (curl error 0)    [02-20-2023 13:55:10 CET]
(cvmfs) pipeline memory thresholds 682/1024 M    [02-20-2023 13:55:10 CET]
(cvmfs) pipeline memory thresholds 682/1024 M    [02-20-2023 13:55:10 CET]
Error: 'no statistics counters for lease repo/'
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) successfully finalized statement    [02-20-2023 13:55:10 CET]
(sql) closing SQLite database '/var/spool/cvmfs/repo/tmp/tags.gHB8Jw' (unlink: yes)    [02-20-2023 13:55:10 CET]

Hi,
Just a bit more of context, as our production platform is blocked due to this issue, we don’t have much time before deciding to do a full rollback.
This happen while trying to activate cvfsm gateway functionality. This errors pop only on one out of the 2 CVMFS repos we have. The other is working fine.
We see two errors in the logs that we are unable to debug:
1/ HTTP 404 on .cvmfsreflog : the file is indeed missing on the filesystem (while it is present on the repository that is working)
2/ (sql) opening database file /var/spool/cvmfs/repo/tmp/tags.gHB8Jw [02-20-2023 13:55:10 CET]
(sql) failed to read-ahead /var/spool/cvmfs/repo/tmp/tags.gHB8Jw (22) [02-20-2023 13:55:10 CET]
No idea what this means

Thanks in advance for your help

Pierre

Hi Martin, Pierre,

could you also check the stratum0 logs for errors? (Should be journalctl -u cvmfs-gateway)
Cheers,
Valentin

Those two warnings/errors should not be fatal.

Are all software components (cvmfs-server, cvmfs-gateway, cvmfs) on publisher & gateway updated to 2.10? Unfortunately, there has been a bug in the 2.10 release that made it necessary to update the components in lockstep.

Yes all software components are in 2.10. There is no error in stratum0 logs :

e4d-0357-42ed-a3a9-b9b91f68ae5b","req_dt":0.074389,"method":"DELETE","url":"/api/v1/leases/2453EDVNLJCRAODX5XFJHF
URVJA6BWWWOFYQD4DXK6POVVRCIVFQ====","t0":"2023-02-20T15:19:27+01:00","message":"request received"}
Feb 20 15:19:27 stm0.fr cvmfs_gateway[19645]: {"level":"info","component":"actions","req_id":"3d
789e4d-0357-42ed-a3a9-b9b91f68ae5b","req_dt":447.658246,"action":"cancel_lease","outcome":"no statistics counters
 for lease repo/","action_dt":447.108266,"message":"action complete"}
Feb 20 15:19:27 stm0.fr cvmfs_gateway[19645]: {"level":"info","component":"http","req_id":"3d789
e4d-0357-42ed-a3a9-b9b91f68ae5b","req_dt":510.859008,"message":"request processed"}

Can you explain how to update in lockstep ?

While no transactions are running, you’d update all packages on gateway and publishers. But that apparently took place, so it’s a different problem.

publisher node is a fresh install with 2.10, but stratum0 was updated from 2.9, when there were no transactions.

So do I understand correctly that at the moment you can neither publish nor abort the transaction?

You can try a manual reset of the gateway and the publisher. On the publisher, remove /var/spool/cvmfs/$reponame/in_transaction and /var/spool/cvmfs/$reponame/session_token and everything under /var/spool/cvmfs/$reponame/scratch/current/.

On the gateway, stop the cvmfs gateway service and remove the lease database in /var/lib/cvmfs-gateway/gw.db (Note: if the gateway is used for multiple repositories, this will remove the lease database for all of them).

Then restart the gateway and try to publishing again.

Ok, done that, new error on publish :

cvmfs_server publish repo
Using auto tag 'generic-2023-02-20T14:37:10Z'
Processing changes...
Waiting for upload of files before committing...
Committing file catalogs...
Wait for all uploads to finish
Exporting repository manifest
Lease end request - error reply: {"reason":"missing_reflog","status":"error"}
SessionContext: could not commit session. Aborting.
[ERROR] Failed to commit transaction.
Statistics stored at: /var/spool/cvmfs/repo/stats.db
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 59e2124ec59b724312526b18b2040140e04cac37 -r gw,/srv/cvmfs/repo/data/txn,http://stm0:4929/api/v1 -w http://stm0/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/repo.pub -L -D generic-2023-02-20T14:37:10Z -H /etc/cvmfs/keys/repo.gw -P /var/spool/cvmfs/repo/session_token -f overlayfs -p -l 4194304 -a 8388608 -h 16777216 -i

We have this in the logs:

Feb 20 15:35:54 apceuclidccstm0.in2p3.fr cvmfs_receiver[22088]: CommitProcessor - error: missing reflog.chksum

I see, so actually the missing reflog is a fatal error in this case. So the original repository must have been created a while ago? Reflogs were added in version 2.3 and, unfortunately, there is currently no good command support to update older repositories to the gateway deployment.

A reflog is automatically created during garbage collection, but I assume garbage collection is not used with this repository.

We can create the reflog from the existing repository using the (internal) cvmfs_swissknife command on the gateway. To use it with the correct options, we’d need to know the repository configuration (/etc/cvmfs/repositories.d/$reponame/server.conf, you can send it in a private message if you prefer).

How complicated is your rollback procedure? It may be a good idea not to recreate the reflog under time pressure today.

Yes, it’s a very old repository with no gc. I’ve sent you the conf.

Solved for the time being in private thread. Related GitHub issues:

Hi, We encounter the error message again when publishing:

cvmfs_server publish repo
Using auto tag 'generic-2023-03-02T09:29:42Z'
Processing changes...
Waiting for upload of files before committing...
Committing file catalogs...
Wait for all uploads to finish
Exporting repository manifest
Lease end request - error reply: {"reason":"could not obtain statistics counters: no statistics counters for lease repo/","status":"error"}
SessionContext: could not commit session. Aborting.
[ERROR] Failed to commit transaction.
Statistics stored at: /var/spool/cvmfs/repo/stats.db
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 ccc324ab89bc04ca5852bf68b5b1c79422d3bf37 -r gw,/srv/cvmfs/repo/data/txn,http://stm0:4929/api/v1 -w http://stm0/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/repo.pub -L -D generic-2023-03-02T09:29:42Z -H /etc/cvmfs/keys/repo.gw -P /var/spool/cvmfs/repo/session_token -f overlayfs -p -l 4194304 -a 8388608 -h 16777216 -i

gateway logs

Mar 02 10:28:29 stm0 cvmfs_receiver[23573]: CVMFS receiver started
Mar 02 10:28:29 stm0 cvmfs_receiver[23573]: PayloadProcessor - lease_path: repo/, header digest: d6d9422b97a7a097906c8606eae6b273703f6a8a, header size: 228
Mar 02 10:28:30 stm0 cvmfs_receiver[23573]: CVMFS receiver finished
Mar 02 10:28:30 stm0 cvmfs_gateway[27260]: {"level":"info","component":"actions","req_id":"936fdbc5-5f12-4369-bac0-a11c775dbb0d","req_dt":1230.336283,"action":"submit_payload","outcome":"success","action_dt":1229.55744,"message":"action complete"}
Mar 02 10:28:30 stm0 cvmfs_gateway[27260]: {"level":"info","component":"http","req_id":"936fdbc5-5f12-4369-bac0-a11c775dbb0d","req_dt":1230.375706,"message":"request_processed"}
Mar 02 10:28:30 stm0 cvmfs_gateway[27260]: {"level":"info","component":"http","req_id":"a105ae5a-1933-4993-a048-6de1d22cd66d","req_dt":0.005968,"method":"POST","url":"/api/v1/leases/LBDLB46GXMK5UVY5THNV3P22VMD4X2DZLTBF6PW7REQG5KY7RBHA====","t0":"2023-03-02T10:28:30+01:00","message":"request received"}
Mar 02 10:28:30 stm0 cvmfs_gateway[27260]: {"level":"info","component":"actions","req_id":"a105ae5a-1933-4993-a048-6de1d22cd66d","req_dt":6.968333,"action":"commit_lease","outcome":"could not obtain statistics counters: no statistics counters for lease repo/","action_dt":6.842967,"message":"action complete"}
Mar 02 10:28:30 stm0 cvmfs_gateway[27260]: {"level":"info","component":"http","req_id":"a105ae5a-1933-4993-a048-6de1d22cd66d","req_dt":7.020004,"message":"request processed"}
Mar 02 10:28:30 stm0 cvmfs_receiver[23580]: CVMFS receiver started
Mar 02 10:28:30 stm0 cvmfs_receiver[23580]: CVMFS receiver finished

Thanks for your help !

Apologies, I missed that message. In general, it is easier to handle delayed follow-ups with a new topic.

With the just released cvmfs 2.10.1 we have added some fixes to bring back the repository in a working state. You can try (after updating) to use cvmfs_server abort -f.