Uploaded image for project: 'OpenAM'
  1. OpenAM
  2. OPENAM-16007

NPE when stopping running troubleshooting recorder in 7.0 (and prevents further AM starts)

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Cannot Reproduce
    • Affects Version/s: 7.0.0
    • Fix Version/s: None
    • Component/s: debug logging
    • Target Version/s:
    • Rank:
      1|i00io5:

      Description

      Bug description

      When testing the recorder functionality documented here: https://backstage.forgerock.com/knowledge/kb/article/a31521479

      ...it's possible to activate the tool as expected in 7.0, however when sending the REST request to stop logging it reports a 500 response and a NPE is logged.

      How to reproduce the issue

      1). Install a 7.0 build (9th March 2020 14:35 build tested here) on Tomcat 8.5 with JDK 11.

      2). Get a valid token:

      curl -v -X POST -H "X-OpenAM-Username: amadmin" -H "X-OpenAM-Password: cangetinam" -H "Content-Type: application/json" -H "Accept-API-Version: resource=2.1"  http://openam.example.com:8080/AM7/json/realms/root/authenticate
      
      {"tokenId":"-f-gqfyDLPJ5A1yGJ760E1h7UeA.*AAJTSQACMDEAAlNLABxIMU1nMjNnb25TaXZPSEFBWVNkUnd2bW9uZGc9AAR0eXBlAANDVFMAAlMxAAA.*","successUrl":"/AM7/console","realm":"/"} 

      3). Start the recorder:

      curl -v -X POST -H "iPlanetDirectoryPro: -f-gqfyDLPJ5A1yGJ760E1h7UeA.*AAJTSQACMDEAAlNLABxIMU1nMjNnb25TaXZPSEFBWVNkUnd2bW9uZGc9AAR0eXBlAANDVFMAAlMxAAA.*" -H "Content-Type: application/json" -H "Accept-API-Version: resource=1.0" -d ' {
        "issueID": 12345,
        "referenceID": "test",
        "description": "Troubleshooting artifacts in support of case 12345",
        "zipEnable": true,
        "configExport": {
         "enable": true,
         "password": "5x2RR70",
         "sharePassword": false
        },
        "debugLogs": {
         "debugLevel": "MESSAGE"
        },
        "threadDump" : {
          "enable": false
        }
       }' http://openam.example.com:8080/AM7/json/realms/root/records?_action=start 

      4). Stop the recorder:

      curl -v -X POST -H "iPlanetDirectoryPro: -f-gqfyDLPJ5A1yGJ760E1h7UeA.*AAJTSQACMDEAAlNLABxIMU1nMjNnb25TaXZPSEFBWVNkUnd2bW9uZGc9AAR0eXBlAANDVFMAAlMxAAA.*" -H "Content-Type: application/json" -H "Accept-API-Version: resource=1.0" http://openam.example.com:8080/AM7/json/realms/root/records?_action=stop 

      ...this returns:

      < HTTP/1.1 500 
      < X-Frame-Options: SAMEORIGIN
      < X-Content-Type-Options: nosniff
      < Cache-Control: private
      < Content-Length: 0
      < Date: Tue, 10 Mar 2020 09:24:52 GMT
      < Connection: close 

      ...with the following in CoreSystem:

      ERROR: A runtime exception occurred during the CREST request handling
      java.lang.IllegalStateException: Exception from invocation expected to be handled by promise
              at org.forgerock.json.resource.AnnotatedMethod.invoke(AnnotatedMethod.java:100)
      <SNIP>
      
      Caused by: java.lang.reflect.InvocationTargetException: null
              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.forgerock.json.resource.AnnotatedMethod.invoke(AnnotatedMethod.java:96)
              ... 131 common frames omitted
      Caused by: java.lang.NullPointerException: null
              at org.forgerock.openam.core.rest.record.DefaultDebugRecorder.stopRecording(DefaultDebugRecorder.java:206)
              at org.forgerock.openam.core.rest.record.RecordResource.actionStop(RecordResource.java:130)
              ... 136 common frames omitted
       

      Note: when the recording has been stopped, it's then not possible to start another recording.  That request now returns a 500 response.

      After this then starting up AM (after a clean shutdown) looks to fail where it appears to loop on sending these types of messages to catalina.out:

      10:12:20.194 [Worker Thread 0] DEBUG org.forgerock.audit.AuditServiceImpl - Cascading the event of topic ldap-access to the handlers : [org.forgerock.audit.handlers.json.JsonAuditEventHandler@21b737e0]
      10:12:20.195 [Worker Thread 3] DEBUG org.forgerock.audit.AuditServiceImpl - Audit create id dc10d0c2-d80f-4087-bf08-4871839dac4a-155694
      10:12:20.195 [Worker Thread 3] DEBUG org.forgerock.audit.AuditServiceImpl - Cascading the event of topic ldap-access to the handlers : [org.forgerock.audit.handlers.json.JsonAuditEventHandler@21b737e0] 
      ..
      Expected behaviour
      Recording should stop and return a 200 response
      
      Current behaviour
      Recording stops but returns a 500 response and a NPE in the logs.  It should be possible to start up AM as well after stopping the recorder.

        Attachments

          Activity

            People

            Assignee:
            kajetan.hemzaczek Kajetan Hemzaczek
            Reporter:
            andy.itter Andy Itter
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: