Mails are not sending from UserApp after IDM46 Upgrade

Hi,

We have upgraded our production environment with IDM 4.6 from IDM 4.5.5. After this from any workflow mails are triggering we could see the below error from catalina.out



2017-07-31 14:52:52,737 [DEBUG] EngineImpl [RBPM] startProcess() process id =cn=Reset password - NEW,cn=RequestDefs,cn=AppConfig,cn=UserApplication,cn=driverset1,o=system
2017-07-31 14:52:52,737 [TRACE] ProcessImpl [RBPM] start() requestId=58b394f3024b4c0c888a212c7697c409, type=cn=Reset password - NEW,cn=RequestDefs,cn=AppConfig,cn=UserApplication,cn=driverset1,o=system
2017-07-31 14:52:52,737 [TRACE] Link [RBPM] Link() FORWARD[start, Activity]
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/txtMobile").setValue("")
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/comments").setValue("test")
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/txtRecipient").setValue("Z8MST")
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/txtuserdn").setValue("Z8MST")
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/txtEmail").setValue("zrm@BMK.dk")
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/txtInitiator").setValue("uaadmin")
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/recipientinitials").setValue("MST")
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/radiochoice").setValue("")
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/txtpassword").setValue("Z844v8wC")
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/initiatepassword").setValue("")
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/txtfieldLocale").setValue("EN")
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/txtOther").setValue("st00374756@techmahindra.com")
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,752 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/pwdpolicy").setValue("CN=BMK_PWD_Users,CN=Password Policies,CN=Security")
2017-07-31 14:52:52,768 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,768 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/cprnumber").setValue("1911709991")
2017-07-31 14:52:52,768 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,768 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/txtUser").setValue("cn=Z8MST,ou=contractors,ou=users,o=BMK")
2017-07-31 14:52:52,768 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,768 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/IDM_COMPLETED_APPROVAL_STATUS").setValue("denied")
2017-07-31 14:52:52,768 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,768 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/txtLastName").setValue("SAPIPV003")
2017-07-31 14:52:52,768 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,768 [DEBUG] DataItemEvaluator [RBPM] evaluating target expression: wi.createXPath("flow-data/start/request_form/txtFirstName").setValue("Test MST IPV 003")
2017-07-31 14:52:52,768 [DEBUG] DataItemEvaluator [RBPM] result: com.novell.soa.script.mozilla.javascript.Undefined@3c0cce2e
2017-07-31 14:52:52,768 [TRACE] ActivityNode [RBPM] persistStatus() activity=Reset password[start], newStatus=Arriving
2017-07-31 14:52:52,768 [TRACE] ProcessImpl [RBPM] startActivity() activity=Reset password[start], newThread=true, pooled = true
2017-07-31 14:52:52,768 [TRACE] ActivityNode [RBPM] notifyArrive(), activity=Reset password[start]
2017-07-31 14:52:52,768 [TRACE] ActivityNode [RBPM] process(), activity=Reset password[start]
2017-07-31 14:52:52,768 [TRACE] ActivityNode [RBPM] persistStatus() activity=Reset password[start], newStatus=Running
2017-07-31 14:52:52,783 [INFO] LogEvent [RBPM] [Workflow_Started] Initiated by cn=uaadmin,ou=sa,o=BMK, Process ID: 58b394f3024b4c0c888a212c7697c409, Process Name: cn=Reset password - NEW,cn=RequestDefs,cn=AppConfig,cn=UserApplication,cn=driverset1,o=system:199, Activity: start, Recipient: cn=uaadmin,ou=sa,o=BMK, Secondary User: null
2017-07-31 14:52:52,783 [TRACE] ActivityNode [RBPM] forward(), activity=Reset password[start], link=FORWARD[start, Activity]
2017-07-31 14:52:52,783 [TRACE] Link [RBPM] Link() FORWARD[Activity, Activity2]
2017-07-31 14:52:52,783 [TRACE] ProcessImpl [RBPM] forward() current=Reset password[start], next=E-Mail[Activity]
2017-07-31 14:52:52,799 [TRACE] ActivityNode [RBPM] persistStatus() activity=Reset password[start], newStatus=Departing
2017-07-31 14:52:52,799 [TRACE] ActivityNode [RBPM] notifyDepart(), activity=Reset password[start]
2017-07-31 14:52:52,799 [TRACE] ActivityNode [RBPM] applyChanges() activity=Reset password[start]
2017-07-31 14:52:52,799 [TRACE] ActivityNode [RBPM] persistStatus() activity=Reset password[start], newStatus=Idle
2017-07-31 14:52:52,799 [TRACE] ActivityNode [RBPM] persistStatus() activity=E-Mail[Activity], newStatus=Arriving
2017-07-31 14:52:52,799 [INFO] LogEvent [RBPM] [Workflow_Forwarded] Initiated by System, Process ID: 58b394f3024b4c0c888a212c7697c409, Process Name: cn=Reset password - NEW,cn=RequestDefs,cn=AppConfig,cn=UserApplication,cn=driverset1,o=system:199, Activity: start, Recipient: cn=uaadmin,ou=sa,o=BMK
2017-07-31 14:52:52,799 [TRACE] ProcessImpl [RBPM] startActivity() activity=E-Mail[Activity], newThread=false, pooled = false
2017-07-31 14:52:52,799 [TRACE] ActivityNode [RBPM] notifyArrive(), activity=E-Mail[Activity]
2017-07-31 14:52:52,799 [TRACE] ActivityNode [RBPM] process(), activity=E-Mail[Activity]
2017-07-31 14:52:52,799 [TRACE] ActivityNode [RBPM] persistStatus() activity=E-Mail[Activity], newStatus=Running
2017-07-31 14:52:52,815 [TRACE] DataItemEvaluator [RBPM] registerNrfRequest - Started
2017-07-31 14:52:52,815 [TRACE] DataItemEvaluator [RBPM] registerNrfRequest - Done
2017-07-31 14:52:52,815 [TRACE] DataItemEvaluator [RBPM] registerNrfResourceRequest - Started
2017-07-31 14:52:52,815 [TRACE] DataItemEvaluator [RBPM] registerNrfResourceRequest - Done
2017-07-31 14:52:52,815 [TRACE] DataItemEvaluator [RBPM] registerAttestation - Started
2017-07-31 14:52:52,815 [TRACE] DataItemEvaluator [RBPM] registerAttestation - Done
2017-07-31 14:52:52,815 [TRACE] WorkflowNotification [RBPM] Trying to evaluate mapping target:[TASK_DETAILS]
2017-07-31 14:52:52,815 [DEBUG] DataItemEvaluator [RBPM] evaluating to string: 'IDMProv/approvalForm.do?weId=58b394f3024b4c0c888a212c7697c409
  • The root cause for the issue is that <mapping resource="com/novell/soa/af/impl/persist/Configuration.hbm.xml"/> was missing from the hibernate.cfg.xml

    Regards,

    Gerard.
  • Thank you Gerard. For your quick help.

    Regards
    Siva ram T
  • On 8/1/2017 7:54 AM, gerardma wrote:
    >
    > The root cause for the issue is that <mapping
    > resource="com/novell/soa/af/impl/persist/Configuration.hbm.xml"/> was
    > missing from the hibernate.cfg.xml


    How did you figure that one out?
  • geoffc;2463170 wrote:
    On 8/1/2017 7:54 AM, gerardma wrote:
    >
    > The root cause for the issue is that <mapping
    > resource="com/novell/soa/af/impl/persist/Configuration.hbm.xml"/> was
    > missing from the hibernate.cfg.xml


    How did you figure that one out?


    Dear Geoffrey,

    We could infer from debug/trace logs of appropriate api calls, provide additional details.

    In my view: We suspect with below NPE(snippet from original post), seems unable to look from hibernate.cfg.xml:

    Caused by: java.lang.NullPointerException
    at com.novell.soa.af.impl.core.WorkflowNotification.s end(WorkflowNotification.java:313)
    ... 12 more
  • On 8/1/2017 10:24 AM, SPSivasubramanian wrote:
    >
    > geoffc;2463170 Wrote:
    >> On 8/1/2017 7:54 AM, gerardma wrote:
    >>>
    >>> The root cause for the issue is that <mapping
    >>> resource="com/novell/soa/af/impl/persist/Configuration.hbm.xml"/> was
    >>> missing from the hibernate.cfg.xml

    >>
    >> How did you figure that one out?

    >
    > Dear Geoffrey,
    >
    > We could infer from debug/trace logs of appropriate api calls, provide
    > additional details.
    >
    > In my view: We suspect with below NPE(snippet from original post), seems
    > unable to look from hibernate.cfg.xml:
    >
    > Caused by: java.lang.NullPointerException
    > at com.novell.soa.af.impl.core.WorkflowNotification.s
    > end(WorkflowNotification.java:313)
    > ... 12 more


    I see what you are saying. I suppose the correct config of
    hibernate.cfg.xml is documented somewhere? Seems like knowing what a
    properly working one SHOULD Look like would make noticing a incorrect
    one more obvious.

    I.e. I wish the config files were documented with examples of working
    configurations. Especially if they called out elements that if missing
    break the config.



  • On 8/1/2017 10:24 AM, SPSivasubramanian wrote:
    >
    > geoffc;2463170 Wrote:
    >> On 8/1/2017 7:54 AM, gerardma wrote:
    >>>
    >>> The root cause for the issue is that <mapping
    >>> resource="com/novell/soa/af/impl/persist/Configuration.hbm.xml"/> was
    >>> missing from the hibernate.cfg.xml

    >>
    >> How did you figure that one out?

    >
    > Dear Geoffrey,
    >
    > We could infer from debug/trace logs of appropriate api calls, provide
    > additional details.
    >
    > In my view: We suspect with below NPE(snippet from original post), seems
    > unable to look from hibernate.cfg.xml:
    >
    > Caused by: java.lang.NullPointerException
    > at com.novell.soa.af.impl.core.WorkflowNotification.s
    > end(WorkflowNotification.java:313)
    > ... 12 more


    I see what you are saying. I suppose the correct config of
    hibernate.cfg.xml is documented somewhere? Seems like knowing what a
    properly working one SHOULD Look like would make noticing a incorrect
    one more obvious.

    I.e. I wish the config files were documented with examples of working
    configurations. Especially if they called out elements that if missing
    break the config.



  • geoffc;2463177 wrote:
    On 8/1/2017 10:24 AM, SPSivasubramanian wrote:
    >
    > geoffc;2463170 Wrote:
    >> On 8/1/2017 7:54 AM, gerardma wrote:
    >>>
    >>> The root cause for the issue is that <mapping
    >>> resource="com/novell/soa/af/impl/persist/Configuration.hbm.xml"/> was
    >>> missing from the hibernate.cfg.xml

    >>
    >> How did you figure that one out?

    >
    > Dear Geoffrey,
    >
    > We could infer from debug/trace logs of appropriate api calls, provide
    > additional details.
    >
    > In my view: We suspect with below NPE(snippet from original post), seems
    > unable to look from hibernate.cfg.xml:
    >
    > Caused by: java.lang.NullPointerException
    > at com.novell.soa.af.impl.core.WorkflowNotification.s
    > end(WorkflowNotification.java:313)
    > ... 12 more


    I see what you are saying. I suppose the correct config of
    hibernate.cfg.xml is documented somewhere? Seems like knowing what a
    properly working one SHOULD Look like would make noticing a incorrect
    one more obvious.

    I.e. I wish the config files were documented with examples of working
    configurations. Especially if they called out elements that if missing
    break the config.


    Thank you Geoffrey. Hope our Documentation team keeping eye on Forum threads, also we have requested to take this input as well to capture in troubleshooting section and other pointers. Similarly we may think of other areas such as client settings and Localization mapping from hibernate.cfg.xml if somebody sees odd behavior from UI.
  • >> I.e. I wish the config files were documented with examples of working
    >> configurations. Especially if they called out elements that if missing
    >> break the config.

    >
    > Thank you Geoffrey. Hope our Documentation team keeping eye on Forum
    > threads, also we have requested to take this input as well to capture in
    > troubleshooting section and other pointers. Similarly we may think of
    > other areas such as client settings and Localization mapping from
    > hibernate.cfg.xml if somebody sees odd behavior from UI.


    There are many config files, whose contents are not discussed in the
    docs at all. Thus no clue what they do, officially, and how do we find
    out?

    Be nice to see docs or TID's or Cool Solutions on these items. I am
    glad to write what I can, but I need to learn some info about them somehow.