API: staging through /bulk-requests fails when authenticating with macaroons (master snapshot)

[onnozweers]

On our test server running a very recent master snapshot, we (@natalieda, @hailihu and I) have noticed a problem with staging with the API's bulk-requests. But only when using macaroons to authenticate through the API. And only when the file is nearline: when the file already is online, a pin is added to it. When using X509 or Basic auth, it just works normally.

Authentication	File is online	File is nearline
X509	Pinning works	Staging works
Basic (password)	Pinning works	Staging works
OIDC token	Pinning works	Staging works
Macaroon	Pinning works	"File not online. Staging not allowed"

In production, running 9.2.20, this problem doesn't exist.

Below is how we can reproduce it.

Version:

[root@hedgehog14 ~]# rpm -q dcache
dcache-10.2.0.d4c2c75-1.noarch

Getting a macaroon (with my username & password):

[onno@ui ~]# get-macaroon --url https://dcachetest.grid.surfsara.nl/users/onno --permissions LIST,DOWNLOAD,MANAGE,READ_METADATA,UPDATE_METADATA --user onno --output macaroon  --duration PT1H
Loading /etc/get-macaroon.conf
Loading /home/onno/.get-macaroon.conf
Enter host password for user 'onno':
Macaroon viewer: /usr/local/bin/view-macaroon

=== View deserialized macaroon ===
location Optional.empty
identifier Bi1fG95Y
cid iid:isWhga6T
cid id:31029;31040,40304,44436,47798,41385,30013,30014;onno
cid before:2024-09-11T15:23:26.446028014Z
cid home:/users/onno
cid path:/users/onno
cid activity:LIST,DOWNLOAD,MANAGE,READ_METADATA,UPDATE_METADATA
cid ip:145.38.0.0/16,145.100.5.0/27,145.100.5.210/26,145.100.32.0/22,145.100.48.0/23,145.100.50.0/23,145.100.200.0/21,145.100.9.64/29,145.101.32.0/21,145.100.56.0/22,2001:610:108::/48
signature ***********************************
=== End deserialized macaroon ===

MDAxY2xv********************************

Putting the token in the variable BEARER_TOKEN:

[onno@ui ~]# export BEARER_TOKEN='MDAxY2xv********************************'

Submit a stage (pin) request:

[onno@ui ~]# curl -X POST "https://dcachetest.grid.surfsara.nl:20443/api/v1/bulk-requests" -H "Authorization: Bearer $BEARER_TOKEN" --fail -H "accept: application/json" -H "content-type: application/json" -d '{ "activity": "PIN", "arguments": {"lifetime": "300"}, "target": ["/users/onno/tape/test"]}' --dump-header - | grep request-url
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100    91    0     0  100    91      0    408 --:--:-- --:--:-- --:--:--   409
request-url: https://dcachetest.grid.surfsara.nl:20443/api/v1/bulk-requests/0b881a6f-5f3b-4e45-89ee-2ff52f46e03e

Checking the result:

[onno@ui ~]# curl -X GET "https://dcachetest.grid.surfsara.nl:20443/api/v1/bulk-requests/0b881a6f-5f3b-4e45-89ee-2ff52f46e03e" -H "Authorization: Bearer $BEARER_TOKEN"
{
  "nextId" : -1,
  "uid" : "0b881a6f-5f3b-4e45-89ee-2ff52f46e03e",
  "arrivedAt" : 1726064763702,
  "startedAt" : 1726064763721,
  "lastModified" : 1726064763797,
  "status" : "COMPLETED",
  "targetPrefix" : "/",
  "targets" : [ {
    "target" : "/users/onno/tape/test",
    "state" : "FAILED",
    "submittedAt" : 1726064763709,
    "startedAt" : 1726064763709,
    "finishedAt" : 1726064763790,
    "errorType" : "java.lang.Throwable",
    "errorMessage" : "File not online. Staging not allowed.",
    "id" : 34594
  } ]
}

"Staging not allowed."

However, when we try this not with macaroons, but with another authentication method, like Basic (username/password) or X509, it just works. Here an example with Basic auth:

[onno@ui ~]# curl -X POST "https://dcachetest.grid.surfsara.nl:20443/api/v1/bulk-requests" --user onno --fail -H "accept: application/json" -H "content-type: application/json" -d '{ "activity": "PIN", "arguments": {"lifetime": "300"}, "target": ["/users/onno/tape/test"]}' --dump-header - | grep request-url
Enter host password for user 'onno':
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100    91    0     0  100    91      0    300 --:--:-- --:--:-- --:--:--   301
request-url: https://dcachetest.grid.surfsara.nl:20443/api/v1/bulk-requests/77eba525-6bee-4e12-bff3-4e93705801b4

[onno@ui ~]# curl -X GET "https://dcachetest.grid.surfsara.nl:20443/api/v1/bulk-requests/77eba525-6bee-4e12-bff3-4e93705801b4" --user onno
Enter host password for user 'onno':
{
  "nextId" : -1,
  "uid" : "77eba525-6bee-4e12-bff3-4e93705801b4",
  "arrivedAt" : 1726067208718,
  "startedAt" : 1726067208736,
  "lastModified" : 1726067218601,
  "status" : "COMPLETED",
  "targetPrefix" : "/",
  "targets" : [ {
    "target" : "/users/onno/tape/test",
    "state" : "COMPLETED",
    "submittedAt" : 1726067208724,
    "startedAt" : 1726067208724,
    "finishedAt" : 1726067218593,
    "id" : 34596
  } ]
}

I looked up the error message in the source:

dcache/modules/dcache/src/main/java/diskCacheV111/poolManager/RequestContainerV5.java

Line 1383 in f19e1c6

_currentRm = "File not online. Staging not allowed.";

But my knowledge of Java is insufficient to understand what goes wrong.

Is it a bug, or are we doing something wrong?

Kind regards,
Onno

[onnozweers]

I found this issue: #7654
I wasn't sure if it was related, so I upgraded our test server to the latest snapshot c165794. But this macaroon issue still exists.

[paulmillar]

Just to confirm #7654 is unrelated.

[onnozweers]

Tested with OIDC token. This works as expected. I updated the table above.