forcedotcom / sfdx-scanner

MIT License
217 stars 49 forks source link

[BUG] Dereferencing SObjectDescribe from Map using unknown key causes ambiguous `NoSuchElementException` #1209

Open thesunlover opened 1 year ago

thesunlover commented 1 year ago

Describe the bug Unknown error logged into DFA report. DFA file is located here: https://gist.github.com/thesunlover/6cf1e5bab1acc98b8c1777fcc9cab031

There are 2 similar logs in the sfge.log file:

2023-10-03 10:03:17  INFO  ThreadableRuleExecutor:51 - Beginning wait #13
2023-10-03 10:03:17  ERROR ThreadableRuleExecutor:208 - Internal Error executing rule. submission=RuleRunnerSubmission{pathEntry=Method{properties={FirstChild=false, BeginLine=79, DefiningType_CaseSafe=adaptercontroller, LastChild=false, DefiningType=AdapterController, Constructor=false, EndLine=79, Name_CaseSafe=createrecord, childIdx=7, ReturnType=Object, Name=createRecord, Arity=1, ReturnType_CaseSafe=object, BeginColumn=26}}, rules=[com.salesforce.rules.AvoidMultipleMassSchemaLookups@27c9e6a7, com.salesforce.rules.ApexFlsViolationRule@203b76dc, com.salesforce.rules.ApexNullPointerExceptionRule@50864985]}
java.util.NoSuchElementException: No value present

    at java.util.Optional.get(Optional.java:148) ~[?:?]
    at com.salesforce.rules.fls.apex.operations.ObjectBasedCheckUtil.isCrudCheckExpected(ObjectBasedCheckUtil.java:67) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.fls.apex.operations.SchemaBasedValidationAnalyzer.isCheckLevelValid(SchemaBasedValidationAnalyzer.java:199) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.fls.apex.operations.SchemaBasedValidationAnalyzer.convert(SchemaBasedValidationAnalyzer.java:174) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.fls.apex.operations.SchemaBasedValidationAnalyzer.checkForValidation(SchemaBasedValidationAnalyzer.java:77) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.fls.apex.operations.FlsValidationCentral.checkSchemaBasedFlsValidation(FlsValidationCentral.java:69) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.fls.apex.AbstractFlsVisitor.afterVisit(AbstractFlsVisitor.java:67) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.vertex.StandardConditionVertex$Negative.afterVisit(StandardConditionVertex.java:82) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:273) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:189) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:184) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:264) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:231) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:189) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:184) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:264) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:231) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:231) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:189) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:184) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:264) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:231) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:231) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:189) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:184) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:264) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:231) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:189) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.visit(ApexPathWalker.java:184) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.walk(ApexPathWalker.java:172) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.walkPath(ApexPathWalker.java:124) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.walkPath(ApexPathWalker.java:105) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.graph.visitor.ApexPathWalker.walkPath(ApexPathWalker.java:88) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.ApexFlsWriteRuleHandler.detectViolations(ApexFlsWriteRuleHandler.java:79) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.ApexFlsViolationRule.lambda$_run$0(ApexFlsViolationRule.java:90) ~[sfge-1.0.1-pilot.jar:?]
    at com.google.common.collect.ImmutableList.forEach(ImmutableList.java:405) ~[guava-28.0-jre.jar:?]
    at com.salesforce.rules.ApexFlsViolationRule._run(ApexFlsViolationRule.java:87) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.AbstractPathTraversalRule.run(AbstractPathTraversalRule.java:15) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.PathBasedRuleRunner.executeRulesOnPaths(PathBasedRuleRunner.java:144) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.PathBasedRuleRunner.runRules(PathBasedRuleRunner.java:81) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.ThreadableRuleExecutor$CallableExecutor.runRules(ThreadableRuleExecutor.java:230) ~[sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.ThreadableRuleExecutor$CallableExecutor.call(ThreadableRuleExecutor.java:167) [sfge-1.0.1-pilot.jar:?]
    at com.salesforce.rules.ThreadableRuleExecutor$CallableExecutor.call(ThreadableRuleExecutor.java:127) [sfge-1.0.1-pilot.jar:?]
    at java.util.concurrent.ForkJoinTask$AdaptedCallable.exec(ForkJoinTask.java:1448) [?:?]
    at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
    at java.util.concurrent.ForkJoinTask.doInvoke(ForkJoinTask.java:408) [?:?]
    at java.util.concurrent.ForkJoinTask.invoke(ForkJoinTask.java:736) [?:?]
    at java.util.concurrent.ForkJoinTask$AdaptedCallable.run(ForkJoinTask.java:1456) [?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
    at java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1426) [?:?]
    at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
    at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020) [?:?]
    at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656) [?:?]
    at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594) [?:?]
    at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183) [?:?]
2023-10-03 10:03:17  INFO  ThreadableRuleExecutor:216 - Finished. method=AdapterController:createRecord:79
2023-10-03 10:03:17  INFO  ThreadableRuleExecutor:119 - Future returned after 199 ms
2023-10-03 10:03:17  INFO  ThreadableRuleExecutor:58 - Wait #13 finished, adding 1 new entries

To Reproduce unknown

Expected behavior A clear log file or explanation about the issue that was found.

Screenshots N/A

Desktop (please complete the following information):

Additional context N/A

"Workaround": N/A

"Urgency": N/A

jfeingold35 commented 1 year ago

@thesunlover , it's unfortunate that this error message is so uninformative. I'll see if I can follow that stack trace and reveal anything that might shed some light on this. Hopefully, I can do that on my end. I may end up asking you to do some debugging on your end if need be.

jfeingold35 commented 1 year ago

@thesunlover , okay, so I've done some chasing here.

Basically, the problem with this specific log seems to be:

And that's about as far as I can get without looking at the code. If you can provide access to your codebase, I can try to crawl through it and see if I can locate the problematic if. Otherwise, I can attempt to walk you through the process of how I'd do that debugging. It's up to you.

thesunlover commented 1 year ago

@jfeingold35 could you please elaborate on the sentence: "The attempt to do this causes an empty Optional to be dereferenced". Looks like I could change the condition from read to write rule by switching the place of the CRUD operation to be inside the block of the if. image

jfeingold35 commented 1 year ago

@thesunlover , An Optional is just a Java construct that encloses another type and can either contain an instance of that type or just be empty. They simplify null checks and prevent null pointer exceptions. The error here is that an Optional is unexpectedly empty and we're failing to properly account for that. The operation specifically being a write operation is unlikely to be directly relevant to the cause of the bug. It's only worth mentioning because it might help you identify which specific if expression is causing the bug. Once we know what that expression is, we can figure out why the Optional is empty and how to properly handle that. Make sense?

thesunlover commented 1 year ago

Hey @jfeingold35, thank you again for the feedback and information you provided.

I see what you are saying. I'm falling into a loop from fixing one and getting the next error. IMO, we have all the required CRUD/FLS checks for the endpoints we are getting the errors, however, I would like to pass the security review from the 1st attempt.

Our company has agreed to share credentials to the repository, could you please contact me at salesforce-dev@interop.io?

thesunlover commented 1 year ago

Hey @jfeingold35,

could you please send me the details to (salesforce-dev@interop.io) on where to send you access to our repository?

I have created a case just in case you need to log your time. The case number in the partner's portal is 45574530

jfeingold35 commented 1 year ago

We haven't identified the root cause of the bug, but we've at least identified where the error is coming from. In code such as that attached, where you have a Map<String, Scheam.DescribeSObjectResult> that you reference using a string of indeterminate value, then doing a CRUD/FLS check (e.g. isAccessible()) using the associated DescribeSObjectResult will cause a NoSuchElementException as an empty optional is being dereferenced.

EntryPoint.cls

global with sharing class EntryPoint {
    global static SObject entryPointMethod(String type) {
        Schema.DescribeSObjectResult cDescribe = Constants.SUPPORTED_DESCRIBE_MAP.get(type);
        if (!cDescribe.isAccessible()) { // This line causes the indicated error.
            throw new PermissionsException('no perm');
        }
        SObject o = Database.query('SELECT Name FROM ' + type + ' LIMIT 1');
        return o;
    }

    public class PermissionsException extends Exception {}
}

Constants.cls

public class Constants {
    public static final List<String> SUPPORTED_SOBJECTS = new List<String> {
        'account', 'contact'
    };
    public static final Map<String, SObjectType> GLOBAL_DESCRIBE = Schema.getGlobalDescribe();
    public static final Map<String, Schema.DescribeSObjectResult> SUPPORTED_DESCRIBE_MAP = new Map<String,Schema.DescribeSObjectResult>();

    static {
        for (String sObjectName : SUPPORTED_SOBJECTS) {
            Schema.SObjectType objType = GLOBAL_DESCRIBE.get(sObjectName);
            if (objType != null) {
                Schema.DescribeSObjectResult objDescription = objType.getDescribe();
                SUPPORTED_DESCRIBE_MAP.put(sObjectName, objDescription);
            }
        }
    }
}
git2gus[bot] commented 1 year ago

This issue has been linked to a new work item: W-14463051