gPlazma NPE in RecordFailedLogins

alrossi commented 1 year ago

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)

kofemann commented 1 year ago

Reproducer unit test:

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

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

alrossi commented 1 year ago

Did you run this, or is this a suggestion?

kofemann commented 1 year ago

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

alrossi commented 1 year ago

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

alrossi commented 1 year ago

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)

dCache / dcache

gPlazma NPE in RecordFailedLogins #6953