dcache gPlazma NPE in RecordFailedLogins

13 Jan 2023 15:31:41 (gPlazma) [door:xrootd-1094-fndcatemp2@xrootd-1094-fndcatemp2Domain:AAXyK/Wd+oA xrootd-1094-fndcatemp2 Login] Login operation failed
java.lang.NullPointerException: null
        at org.dcache.gplazma.RecordFailedLogins$KnownFailedLogins.storageSubjectFor(RecordFailedLogins.java:88)
        at org.dcache.gplazma.RecordFailedLogins$KnownFailedLogins.has(RecordFailedLogins.java:98)
        at org.dcache.gplazma.RecordFailedLogins.accept(RecordFailedLogins.java:124)
        at org.dcache.gplazma.RecordFailedLogins.accept(RecordFailedLogins.java:36)
        at org.dcache.gplazma.GPlazma.lambda$login$1(GPlazma.java:142)
        at java.base/java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:807)
        at org.dcache.gplazma.GPlazma.login(GPlazma.java:142)
        at org.dcache.auth.Gplazma2LoginStrategy.login(Gplazma2LoginStrategy.java:145)
        at org.dcache.services.login.MessageHandler.messageArrived(MessageHandler.java:58)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at org.dcache.cells.CellMessageDispatcher$LongReceiver.deliver(CellMessageDispatcher.java:286)
        at org.dcache.cells.CellMessageDispatcher.call(CellMessageDispatcher.java:188)
        at org.dcache.cells.AbstractCell.messageArrived(AbstractCell.java:302)
        at dmg.cells.nucleus.CellAdapter.messageArrived(CellAdapter.java:856)
        at dmg.cells.nucleus.CellNucleus$DeliverMessageTask.run(CellNucleus.java:1274)
        at org.dcache.util.BoundedExecutor$Worker.run(BoundedExecutor.java:247)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at dmg.cells.nucleus.CellNucleus.lambda$wrapLoggingContext$2(CellNucleus.java:727)
        at java.base/java.lang.Thread.run(Thread.java:834)

Jan 13 '23 21:01 alrossi

Reproducer unit test:

   @Test
    public void testNullPrinsipals() {
        var failedLogins = new RecordFailedLogins();

        var loginResult = new LoginResult();
        failedLogins.accept(loginResult);
    }

Jan 18 '23 17:01 kofemann

Did you run this, or is this a suggestion?

Jan 18 '23 17:01 alrossi

I did. The question is why we get an empty Result? gPlazma with an empty config?

Jan 18 '23 17:01 kofemann

Let me see if I can reconstruct how this happened. It looks like missing subject, no?

Jan 18 '23 17:01 alrossi

Steps to reproduce:

Create a faulty scitoken plugin (incomplete) in dcache.conf or layout:

gplazma.scitoken.issuer!fermilab=https://cilogon.org/fermilab
gplazma.scitoken.audience-targets=https://wlcg.cern.ch/jwt/v1/any https://cilogon.org/fermilab https://demo.scitokens.org

(issuer is missing root, user / group specifications). This was an oversight.

Get a token and try to read a file:

 xrdcp5x -f roots://fndcatemp2.fnal.gov:1095//pnfs/fs/usr/fermilab/users/arossi/volatile/data_1b /dev/null

depending on whether you can read anonymously or not, it will either fail or succeed. But the login fails in any case. gPlazma cannot report it because the scitoken plugin is broken. Full log:

19 Jan 2023 07:43:02 (gPlazma) [] failed to create scitoken: null
19 Jan 2023 07:44:09 (gPlazma) [door:xrootd-1095-fndcatemp2@xrootd-1095-fndcatemp2Domain:AAXyniCcTLA xrootd-1095-fndcatemp2 Login] Login operation failed
java.lang.NullPointerException: null
        at org.dcache.gplazma.RecordFailedLogins$KnownFailedLogins.storageSubjectFor(RecordFailedLogins.java:88)
        at org.dcache.gplazma.RecordFailedLogins$KnownFailedLogins.has(RecordFailedLogins.java:98)
        at org.dcache.gplazma.RecordFailedLogins.accept(RecordFailedLogins.java:124)
        at org.dcache.gplazma.RecordFailedLogins.accept(RecordFailedLogins.java:36)
        at org.dcache.gplazma.GPlazma.lambda$login$1(GPlazma.java:142)
        at java.base/java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:807)
        at org.dcache.gplazma.GPlazma.login(GPlazma.java:142)
        at org.dcache.auth.Gplazma2LoginStrategy.login(Gplazma2LoginStrategy.java:145)
        at org.dcache.services.login.MessageHandler.messageArrived(MessageHandler.java:58)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at org.dcache.cells.CellMessageDispatcher$LongReceiver.deliver(CellMessageDispatcher.java:286)
        at org.dcache.cells.CellMessageDispatcher.call(CellMessageDispatcher.java:188)
        at org.dcache.cells.AbstractCell.messageArrived(AbstractCell.java:302)
        at dmg.cells.nucleus.CellAdapter.messageArrived(CellAdapter.java:856)
        at dmg.cells.nucleus.CellNucleus$DeliverMessageTask.run(CellNucleus.java:1274)
        at org.dcache.util.BoundedExecutor$Worker.run(BoundedExecutor.java:247)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at dmg.cells.nucleus.CellNucleus.lambda$wrapLoggingContext$2(CellNucleus.java:727)
        at java.base/java.lang.Thread.run(Thread.java:834)

Jan 19 '23 13:01 alrossi