Dear Gurus,
I'd like to report another potential bug.
Environment as follows:
Release Version: 16.11.04 (I have tested it and it's ok in 16.11.03)
Work Steps:
1. In the login page: https://www.myowndomain.com/webtools/control/main, then click
login, then click "forget your passwords".
2. Then fill in the User Name that I have already created before, which is
associated with a primary email address.
3. Then click "continue" and then hit "email password";
4. As I have set the fields correctly in the file general.properties and also in database table ofbiz.system_property, I receive a system
email telling me to "click here to reset password" with a link.
Then click the link and following the instructions to fill in the new passwords and then the following error messages pop up. Generally speaking,
the error is about java.lang.NullPointerException.
(BTW, I tried it a couple of times with different locales like en and zh_CN but
all failed.)
Here below I highlighted somethings strange, where I have added some debugging
texts (in yellow background) to see what's going on.
Obviously, in my debugging text Tag ---801--- the keyValue is missing (null).
Maybe that's why it throws a java.lang.NullPointerException.
However, when I compare the codes (where it concerns) of EntityCrypto.java and LoginWorker.java between 11.04 and 11.03, I could not find the
difference So I do NOT understand why it works in my 11.03 but not 11.04.
2018-03-28 10:00:59,870 |http-nio-443-exec-4 |ServerHitBin |I|
Visit delegatorName=default, ServerHitBin delegatorName=default
2018-03-28 10:00:59,878 |http-nio-443-exec-4 |ControlServlet |T| [[[forgotPassword_step2(Domain:https://www.myowndomain.com)]
Request Done- total:0.146,since last([forgotPassword_s...):0.146]]
2018-03-28 10:01:02,961 |http-nio-443-exec-1 |ControlServlet |T| [[[forgotPassword_step3(Domain:https://www.myowndomain.com)]
Request Begun, encoding=[UTF-8]- total:0.0,since last(Begin):0.0]]
2018-03-28 10:01:02,988 |http-nio-443-exec-1 |EntityCrypto |I|
---804---originalKeyName---is---loginSecretKeyString
2018-03-28 10:01:02,988 |http-nio-443-exec-1 |EntityCrypto |I|
---805---originalKeyName---is---loginSecretKeyString
2018-03-28 10:01:02,988 |http-nio-443-exec-1 |EntityCrypto |I|
---806---hashRequest---is---org.apache.shiro.crypto.hash.SimpleHashRequest@327dc55e
2018-03-28 10:01:03,066 |http-nio-443-exec-1 |ServiceDispatcher |I| Service auth failed for userLoginId [MyCreatedUser] because
UserLogin record currentPassword fields did not match; note that the UserLogin object passed into a service may need to have the currentPassword
encrypted.
2018-03-28 10:01:03,067 |http-nio-443-exec-1 |ServiceDispatcher |T| Sync service [order/getUserPreferenceGroup] finished in [2]
milliseconds
2018-03-28 10:01:03,076 |http-nio-443-exec-1 |ScreenFactory |I| Got 1 screens in 0.009s from:
file:/D:/apache-ofbiz-16.11.04/applications/securityext/widget/EmailSecurityScreens.xml
2018-03-28 10:01:03,137 |http-nio-443-exec-1 |UtilProperties |I| ResourceBundle EmailPasswordUiLabels (en) created in 0.061s with 6
properties
2018-03-28 10:01:03,217 |http-nio-443-exec-1 |UtilProperties |I| ResourceBundle SecurityUiLabels (en) created in 0.08s with 58
properties
2018-03-28 10:01:03,238 |http-nio-443-exec-1 |EmailServices |I|
Expanded email subject to: New Password Sent (MyCreatedUser)
2018-03-28 10:01:07,710 |http-nio-443-exec-1 |ServiceDispatcher |T| Sync service [order/sendMailHiddenInLog] finished in [4471]
milliseconds
2018-03-28 10:01:07,711 |http-nio-443-exec-1 |ServiceDispatcher |T| Sync service [order/sendMailHiddenInLogFromScreen] finished in
[4678] milliseconds
2018-03-28 10:01:07,722 |http-nio-443-exec-1 |RequestHandler |I| Ran Event
[java:org.apache.ofbiz.securityext.login.LoginEvents#forgotPassword] from [request], result is [success]
2018-03-28 10:01:07,738 |http-nio-443-exec-1 |ConfigXMLReader |I| controller loaded: 0.001s, 16 requests, 14 views in
file:/D:/apache-ofbiz-16.11.04/specialpurpose/birt/webapp/ordermgr/WEB-INF/controller.xml
2018-03-28 10:01:07,763 |http-nio-443-exec-1 |ConfigXMLReader |I| controller loaded: 0.006s, 367 requests, 147 views in
file:/D:/apache-ofbiz-16.11.04/applications/order/webapp/ordermgr/WEB-INF/controller.xml
2018-03-28 10:01:07,794 |http-nio-443-exec-1 |ConfigXMLReader |I| controller loaded: 0.001s, 45 requests, 22 views in
file:/D:/apache-ofbiz-16.11.04/framework/common/webcommon/WEB-INF/common-controller.xml
2018-03-28 10:01:07,808 |http-nio-443-exec-1 |ConfigXMLReader |I| controller loaded: 0.0s, 0 requests, 0 views in
file:/D:/apache-ofbiz-16.11.04/framework/common/webcommon/WEB-INF/handlers-controller.xml
2018-03-28 10:01:07,837 |http-nio-443-exec-1 |ConfigXMLReader |I| controller loaded: 0.0s, 4 requests, 0 views in
file:/D:/apache-ofbiz-16.11.04/applications/commonext/webapp/WEB-INF/controller.xml
2018-03-28 10:01:07,860 |http-nio-443-exec-1 |ConfigXMLReader |I| controller loaded: 0.005s, 379 requests, 154 views in
file:/D:/apache-ofbiz-16.11.04/applications/content/webapp/content/WEB-INF/controller.xml
2018-03-28 10:01:07,911 |http-nio-443-exec-1 |RequestHandler |I|
Rendering View [login]. Hidden sessionId by default.
2018-03-28 10:01:07,933 |http-nio-443-exec-1 |ServiceDispatcher |T| Sync service [order/getVisualThemeResources] finished in [19]
milliseconds
2018-03-28 10:01:07,949 |http-nio-443-exec-1 |ScreenFactory |I| Got 26 screens in 0.014s from:
file:/D:/apache-ofbiz-16.11.04/framework/common/widget/CommonScreens.xml
2018-03-28 10:01:07,957 |http-nio-443-exec-1 |ScreenFactory |I| Got 4 screens in 0.007s from:
file:/D:/apache-ofbiz-16.11.04/applications/order/widget/ordermgr/CommonScreens.xml
2018-03-28 10:01:07,966 |http-nio-443-exec-1 |ScreenFactory |I| Got 1 screens in 0.008s from:
file:/D:/apache-ofbiz-16.11.04/applications/commonext/widget/CommonScreens.xml
2018-03-28 10:01:07,967 |http-nio-443-exec-1 |PrimaryKeyFinder |I| Returning null because found incomplete primary key in find:
[GenericEntity:PartyNameView][partyId,null()]
2018-03-28 10:01:08,066 |http-nio-443-exec-1 |ServiceDispatcher |T| Sync service [order/getLastSystemInfoNote] finished in [21]
milliseconds
2018-03-28 10:01:08,106 |http-nio-443-exec-1 |ServiceDispatcher |T| Sync service [order/getVisualThemeResources] finished in [31]
milliseconds
2018-03-28 10:01:08,398 |http-nio-443-exec-1 |ServerHitBin |I|
Visit delegatorName=default, ServerHitBin delegatorName=default
2018-03-28 10:01:08,411 |http-nio-443-exec-1 |ControlServlet |T| [[[forgotPassword_step3(Domain:https://www.myowndomain.com)]
Request Done- total:5.45,since last([forgotPassword_s...):5.45]]
2018-03-28 10:01:43,926 |http-nio-443-exec-10 |ControlEventListener
|I| Creating session: hidden sessionId by default.
2018-03-28 10:01:43,927 |http-nio-443-exec-10 |ControlServlet |T| [[[passwordChange(Domain:https://www.myowndomain.com)] Request
Begun, encoding=[UTF-8]- total:0.0,since last(Begin):0.0]]
2018-03-28 10:01:43,930 |http-nio-443-exec-10 |VisitHandler
|I| Found visitorId [10200] in cookie
2018-03-28 10:01:43,967 |http-nio-443-exec-10 |ConfigXMLReader |I| controller loaded: 0.004s, 258 requests, 105 views in
file:/D:/apache-ofbiz-16.11.04/applications/party/webapp/partymgr/WEB-INF/controller.xml
2018-03-28 10:01:43,983 |http-nio-443-exec-10 |ConfigXMLReader |I| controller loaded: 0.001s, 45 requests, 22 views in
file:/D:/apache-ofbiz-16.11.04/framework/common/webcommon/WEB-INF/common-controller.xml
2018-03-28 10:01:43,997 |http-nio-443-exec-10 |ConfigXMLReader |I| controller loaded: 0.0s, 0 requests, 0 views in
file:/D:/apache-ofbiz-16.11.04/framework/common/webcommon/WEB-INF/handlers-controller.xml
2018-03-28 10:01:44,013 |http-nio-443-exec-10 |ConfigXMLReader |I| controller loaded: 0.0s, 30 requests, 13 views in
file:/D:/apache-ofbiz-16.11.04/framework/common/webcommon/WEB-INF/security-controller.xml
2018-03-28 10:01:44,027 |http-nio-443-exec-10 |ConfigXMLReader |I| controller loaded: 0.0s, 4 requests, 0 views in
file:/D:/apache-ofbiz-16.11.04/applications/commonext/webapp/WEB-INF/controller.xml
2018-03-28 10:01:44,051 |http-nio-443-exec-10 |ConfigXMLReader |I| controller loaded: 0.006s, 379 requests, 154 views in
file:/D:/apache-ofbiz-16.11.04/applications/content/webapp/content/WEB-INF/controller.xml
2018-03-28 10:01:44,052 |http-nio-443-exec-10 |RequestHandler
|I| This is the first request in this visit. Hidden sessionId by default.
2018-03-28 10:01:44,056 |http-nio-443-exec-10 |RequestHandler
|I| Rendering View [requirePasswordChange]. Hidden sessionId by default.
2018-03-28 10:01:44,061 |http-nio-443-exec-10 |ServiceDispatcher |T| Sync service [partymgr/getUserPreferenceGroup] finished in [1]
milliseconds
2018-03-28 10:01:44,084 |http-nio-443-exec-10 |ServiceDispatcher |T| Sync service [partymgr/getVisualThemeResources] finished in [22]
milliseconds
2018-03-28 10:01:44,121 |http-nio-443-exec-10 |ScreenFactory |I| Got 26 screens in 0.019s from:
file:/D:/apache-ofbiz-16.11.04/framework/common/widget/CommonScreens.xml
2018-03-28 10:01:44,123 |http-nio-443-exec-10 |PrimaryKeyFinder |I| Returning null because found incomplete primary key in find:
[GenericEntity:Enumeration][enumId,null()]
2018-03-28 10:01:44,136 |http-nio-443-exec-10 |ScreenFactory |I| Got 4 screens in 0.012s from:
file:/D:/apache-ofbiz-16.11.04/applications/party/widget/partymgr/CommonScreens.xml
2018-03-28 10:01:44,316 |http-nio-443-exec-10 |UtilProperties |I| ResourceBundle PartyUiLabels (zh_CN_#Hans) created in 0.18s with 0
properties
2018-03-28 10:01:44,476 |http-nio-443-exec-10 |UtilProperties |I| ResourceBundle MarketingUiLabels (zh_CN_#Hans) created in 0.16s
with 281 properties
2018-03-28 10:01:44,800 |http-nio-443-exec-10 |UtilProperties |I| ResourceBundle AccountingUiLabels (zh_CN_#Hans) created in 0.261s
with 0 properties
2018-03-28 10:01:44,924 |http-nio-443-exec-10 |UtilProperties |I| ResourceBundle WorkEffortUiLabels (zh_CN_#Hans) created in 0.123s
with 0 properties
2018-03-28 10:01:45,030 |http-nio-443-exec-10 |UtilProperties |I| ResourceBundle ContentUiLabels (zh_CN_#Hans) created in 0.103s
with 0 properties
2018-03-28 10:01:45,085 |http-nio-443-exec-10 |UtilProperties |I| ResourceBundle SecurityUiLabels (zh_CN_#Hans) created in 0.05s
with 0 properties
2018-03-28 10:01:45,251 |http-nio-443-exec-10 |UtilProperties |I| ResourceBundle CommonUiLabels (zh_CN_#Hans) created in 0.165s with
0 properties
2018-03-28 10:01:45,413 |http-nio-443-exec-10 |UtilProperties |I| ResourceBundle OrderUiLabels (zh_CN_#Hans) created in 0.162s with
0 properties
2018-03-28 10:01:46,189 |http-nio-443-exec-10 |UtilProperties |I| ResourceBundle ProductUiLabels (zh_CN_#Hans) created in 0.775s
with 0 properties
2018-03-28 10:01:46,307 |http-nio-443-exec-10 |UtilProperties |I| ResourceBundle HumanResUiLabels (zh_CN_#Hans) created in 0.117s
with 319 properties
2018-03-28 10:01:46,316 |http-nio-443-exec-10 |ScreenFactory |I| Got 1 screens in 0.008s from:
file:/D:/apache-ofbiz-16.11.04/applications/commonext/widget/CommonScreens.xml
2018-03-28 10:01:46,384 |http-nio-443-exec-10 |UtilProperties |I| ResourceBundle CommonExtUiLabels (zh_CN_#Hans) created in 0.068s
with 0 properties
2018-03-28 10:01:46,385 |http-nio-443-exec-10 |PrimaryKeyFinder |I| Returning null because found incomplete primary key in find:
[GenericEntity:PartyNameView][partyId,null()]
2018-03-28 10:01:46,471 |http-nio-443-exec-10 |ServiceDispatcher |T| Sync service [partymgr/getLastSystemInfoNote] finished in [14]
milliseconds
2018-03-28 10:01:46,695 |http-nio-443-exec-10 |ServiceDispatcher |T| Sync service [partymgr/getVisualThemeResources] finished in [1]
milliseconds
2018-03-28 10:01:47,791 |http-nio-443-exec-10 |ServerHitBin
|I| Visit delegatorName=default, ServerHitBin delegatorName=default
2018-03-28 10:01:47,795 |http-nio-443-exec-10 |ControlServlet |T| [[[passwordChange(Domain:https://www.myowndomain.com)] Request
Done- total:3.868,since last([passwordChange(D...):3.868]]
2018-03-28 10:02:01,101 |http-nio-443-exec-2 |ControlServlet |T| [[[login(Domain:https://www. myowndomain.com)] Request Begun,
encoding=[UTF-8]- total:0.0,since last(Begin):0.0]]
2018-03-28 10:02:01,131 |http-nio-443-exec-2 |ConfigXMLReader |I| controller loaded: 0.006s, 258 requests, 105 views in
file:/D:/apache-ofbiz-16.11.04/applications/party/webapp/partymgr/WEB-INF/controller.xml
2018-03-28 10:02:01,150 |http-nio-443-exec-2 |ConfigXMLReader |I| controller loaded: 0.0s, 45 requests, 22 views in
file:/D:/apache-ofbiz-16.11.04/framework/common/webcommon/WEB-INF/common-controller.xml
2018-03-28 10:02:01,166 |http-nio-443-exec-2 |ConfigXMLReader |I| controller loaded: 0.0s, 0 requests, 0 views in
file:/D:/apache-ofbiz-16.11.04/framework/common/webcommon/WEB-INF/handlers-controller.xml
2018-03-28 10:02:01,181 |http-nio-443-exec-2 |ConfigXMLReader |I| controller loaded: 0.0s, 30 requests, 13 views in
file:/D:/apache-ofbiz-16.11.04/framework/common/webcommon/WEB-INF/security-controller.xml
2018-03-28 10:02:01,195 |http-nio-443-exec-2 |ConfigXMLReader |I| controller loaded: 0.0s, 4 requests, 0 views in
file:/D:/apache-ofbiz-16.11.04/applications/commonext/webapp/WEB-INF/controller.xml
2018-03-28 10:02:01,235 |http-nio-443-exec-2 |ConfigXMLReader |I| controller loaded: 0.021s, 379 requests, 154 views in
file:/D:/apache-ofbiz-16.11.04/applications/content/webapp/content/WEB-INF/controller.xml
2018-03-28 10:02:01,249 |http-nio-443-exec-2 |LoginWorker |I|
---801---KeyValue---is---
2018-03-28 10:02:01,249 |http-nio-443-exec-2 |EntityCrypto |I| ---803---KeyName and encryptMethod and encryptedString---are--- -
TRUE - aJ2+NE8uB+1IAeKogPERRw==
2018-03-28 10:02:01,249 |http-nio-443-exec-2 |EntityCrypto |I|
---804---originalKeyName---is---
2018-03-28 10:02:01,249 |http-nio-443-exec-2 |EntityCrypto |I|
---805---originalKeyName---is---
2018-03-28 10:02:01,249 |http-nio-443-exec-2 |EntityCrypto |I|
---806---hashRequest---is---org.apache.shiro.crypto.hash.SimpleHashRequest@39915efb
2018-03-28 10:02:01,249 |http-nio-443-exec-2 |JavaEventHandler |E|
Problems Processing Event
java.lang.NullPointerException
at
org.apache.ofbiz.entity.util.EntityCrypto$ShiroStorageHandler.getHashedKeyName(EntityCrypto.java:253)
~[ofbiz.jar:?]
at
org.apache.ofbiz.entity.util.EntityCrypto.findKey(EntityCrypto.java:160)
~[ofbiz.jar:?]
at
org.apache.ofbiz.entity.util.EntityCrypto.doDecrypt(EntityCrypto.java:144)
~[ofbiz.jar:?]
at
org.apache.ofbiz.entity.util.EntityCrypto.decrypt(EntityCrypto.java:127)
~[ofbiz.jar:?]
at
org.apache.ofbiz.webapp.control.LoginWorker.login(LoginWorker.java:391)
~[ofbiz.jar:?]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
~[?:1.8.0_131]
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
~[?:1.8.0_131]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
~[?:1.8.0_131]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_131]
at
org.apache.ofbiz.webapp.event.JavaEventHandler.invoke(JavaEventHandler.java:100)
[ofbiz.jar:?]
at
org.apache.ofbiz.webapp.event.JavaEventHandler.invoke(JavaEventHandler.java:80)
[ofbiz.jar:?]
at
org.apache.ofbiz.webapp.control.RequestHandler.runEvent(RequestHandler.java:732)
[ofbiz.jar:?]
at
org.apache.ofbiz.webapp.control.RequestHandler.doRequest(RequestHandler.java:453)
[ofbiz.jar:?]
at
org.apache.ofbiz.webapp.control.ControlServlet.doGet(ControlServlet.java:210)
[ofbiz.jar:?]
at
org.apache.ofbiz.webapp.control.ControlServlet.doPost(ControlServlet.java:85)
[ofbiz.jar:?]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
[javax.servlet-api-3.1.0.jar:3.1.0]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
[javax.servlet-api-3.1.0.jar:3.1.0]
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
[tomcat-embed-websocket-8.0.39.jar:8.0.39]
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.ofbiz.webapp.control.ContextFilter.doFilter(ContextFilter.java:196)
[ofbiz.jar:?]
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.ofbiz.webapp.control.ControlFilter.doFilter(ControlFilter.java:156)
[ofbiz.jar:?]
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:212)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:94)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:504)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:620)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:502)
[tomcat-catalina-8.0.42.jar:8.0.42]
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1104)
[tomcat-coyote-8.0.42.jar:8.0.42]
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:684)
[tomcat-coyote-8.0.42.jar:8.0.42]
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1519)
[tomcat-coyote-8.0.42.jar:8.0.42]
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1475)
[tomcat-coyote-8.0.42.jar:8.0.42]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[?:1.8.0_131]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[?:1.8.0_131]
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
[tomcat-util-8.0.42.jar:8.0.42]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]
Thanks for your help!
Best Regards
Schumann
