Hi,

> I will continue to investigate, but wondered if anyone else out there had hit 
> this and, if so, how did you work around it

Just for the record, and in the absence of any better suggestions, I've worked 
around this by commenting out the following block in 
[dspace-src]/dspace-api/src/main/java/org/dspace/core/Context.java (around line 
303):


/*

if (log.isDebugEnabled())

{

      Thread currThread = Thread.currentThread();

      StackTraceElement[] stackTrace = currThread.getStackTrace();

      String caller = stackTrace[stackTrace.length - 1].getClassName();



      String previousCaller = (String) authStateClassCallHistory.pop();



      // if previousCaller is not the current caller *only* log a warning

      if (!previousCaller.equals(caller))

      {

            log

                  .warn(LogManager

                        .getHeader(

                              this,

                              "restore_auth_sys_state",

                              "Class: "

                                    + caller

                                    + " call restore but previous state change 
made by "

                                    + previousCaller));

      }

}

*/

- and I'm now able to create a new user when logging on via LDAP with the log 
level set to DEBUG.

Of course, if anyone has any better suggestions, I'm all ears :)

Cheers,

Mike

Michael White
Senior Developer
Business Applications and Integrations

T: (01786) 466877
E: michael.wh...@stir.ac.uk<mailto:michael.wh...@stir.ac.uk>
A: G5, Airthrey Castle, University of Stirling, Stirling, FK9 4LA

From: Michael White
Sent: 14 November 2017 13:41
To: dspace-tech@googlegroups.com
Subject: LDAPAuthentication - can't create ePerson at DEBUG

Hi,

DSpace v6.2, JSPUI . . .

I've been working to set up (hierarchical) LDAP based authentication on my 
DSpace v6.2 DEV system but I'm having problems getting the system to 
auto-create an ePerson record for new users when the log level is set to DEBUG. 
In this case, the authentication/creation of the new ePerson fails, and an 
"EmptyStackException" is thrown when (as far as I can tell) the system attempts 
to restore the Authorisation state.

With the log level set at INFO, it all works as expected - the new user is 
authenticated and then the ePerson record is created and the user is logged in 
- here is a log snippet showing this working as expected at INFO:

2017-11-14 13:20:22,462 INFO  org.dspace.authenticate.LDAPAuthentication @ 
anonymous:session_id=AEFB43EF410423BD73812BA53CFDC825:ip_addr=139.153.86.2:auth:attempting
 trivial auth of user=mmw2
2017-11-14 13:20:22,584 INFO  org.dspace.authenticate.LDAPAuthentication @ 
anonymous:session_id=AEFB43EF410423BD73812BA53CFDC825:ip_addr=139.153.86.2:autoregister:netid=mmw2
2017-11-14 13:20:22,597 INFO  org.dspace.eperson.EPersonServiceImpl @ 
anonymous:session_id=AEFB43EF410423BD73812BA53CFDC825:ip_addr=139.153.86.2:create_eperson:eperson_id=5955e86d-726f-4ea2-a28d-df92d73aaf15
2017-11-14 13:20:22,680 INFO  org.dspace.eperson.EPersonServiceImpl @ 
anonymous:session_id=AEFB43EF410423BD73812BA53CFDC825:ip_addr=139.153.86.2:update_eperson:eperson_id=5955e86d-726f-4ea2-a28d-df92d73aaf15
2017-11-14 13:20:22,750 INFO  org.dspace.authenticate.LDAPAuthentication @ 
mike.wh...@stir.ac.uk:session_id=AEFB43EF410423BD73812BA53CFDC825:ip_addr=139.153.86.2:authenticate:type=ldap-login<mailto:mike.wh...@stir.ac.uk:session_id=AEFB43EF410423BD73812BA53CFDC825:ip_addr=139.153.86.2:authenticate:type=ldap-login>,
 created ePerson
2017-11-14 13:20:22,751 WARN  org.dspace.core.Context @ 
mike.wh...@stir.ac.uk:session_id=AEFB43EF410423BD73812BA53CFDC825:ip_addr=139.153.86.2:restore_auth_sys_state:not<mailto:mike.wh...@stir.ac.uk:session_id=AEFB43EF410423BD73812BA53CFDC825:ip_addr=139.153.86.2:restore_auth_sys_state:not>
 previous state info available null
2017-11-14 13:20:22,752 INFO  org.dspace.eperson.EPersonServiceImpl @ 
mike.wh...@stir.ac.uk:session_id=AEFB43EF410423BD73812BA53CFDC825:ip_addr=139.153.86.2:update_eperson:eperson_id=5955e86d-726f-4ea2-a28d-df92d73aaf15<mailto:mike.wh...@stir.ac.uk:session_id=AEFB43EF410423BD73812BA53CFDC825:ip_addr=139.153.86.2:update_eperson:eperson_id=5955e86d-726f-4ea2-a28d-df92d73aaf15>
2017-11-14 13:20:22,855 ERROR org.dspace.core.I18nUtil @ No language specified 
for EPerson 5955e86d-726f-4ea2-a28d-df92d73aaf15
2017-11-14 13:20:22,856 INFO  org.dspace.app.webui.servlet.LDAPServlet @ 
mike.wh...@stir.ac.uk:session_id=AEFB43EF410423BD73812BA53CFDC825:ip_addr=139.153.86.2:login:type=explicit<mailto:mike.wh...@stir.ac.uk:session_id=AEFB43EF410423BD73812BA53CFDC825:ip_addr=139.153.86.2:login:type=explicit>
2017-11-14 13:20:22,991 INFO  org.dspace.app.webui.servlet.MyDSpaceServlet @ 
mike.wh...@stir.ac.uk:session_id=923FB17CB27F83101481AD719C33997B:ip_addr=139.153.86.2:view_mydspace<mailto:mike.wh...@stir.ac.uk:session_id=923FB17CB27F83101481AD719C33997B:ip_addr=139.153.86.2:view_mydspace>:


However, with the log level at DEBUG, this fails with the reported Exception:

2017-11-14 13:14:43,178 DEBUG org.dspace.app.webui.servlet.DSpaceServlet @ 
anonymous:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:http_request:--
 URL Was\colon; http\colon;//dspace6dev.stir.ac.uk\colon;8080/jspui/ldap-login
-- Method\colon; POST
-- Parameters were\colon;
-- login_netid\colon; "mmw2"
-- login_password\colon; *not logged*
-- login_submit\colon; "Log In"

2017-11-14 13:14:43,178 DEBUG org.dspace.core.LegacyPluginServiceImpl @ Adding 
Sequence plugin for interface= org.dspace.authenticate.AuthenticationMethod, 
class=org.dspace.authenticate.LDAPAuthentication
2017-11-14 13:14:43,178 DEBUG org.dspace.core.LegacyPluginServiceImpl @ Adding 
Sequence plugin for interface= org.dspace.authenticate.AuthenticationMethod, 
class=org.dspace.authenticate.PasswordAuthentication
2017-11-14 13:14:43,179 INFO  org.dspace.authenticate.LDAPAuthentication @ 
anonymous:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:auth:attempting
 trivial auth of user=mmw2
2017-11-14 13:14:43,283 DEBUG org.dspace.authenticate.LDAPAuthentication @ 
anonymous:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:got 
DN:CN=mmw2,OU=Enabled,OU=Staff,dc=ad,dc=stir,dc=ac,dc=uk
2017-11-14 13:14:43,292 INFO  org.dspace.authenticate.LDAPAuthentication @ 
anonymous:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:autoregister:netid=mmw2
2017-11-14 13:14:43,310 INFO  org.dspace.eperson.EPersonServiceImpl @ 
anonymous:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:create_eperson:eperson_id=b4a43809-a530-4f26-b300-7910e13ad76e
2017-11-14 13:14:43,351 DEBUG org.dspace.identifier.IdentifierServiceImpl @ 
Found identifiers: []
2017-11-14 13:14:43,352 DEBUG org.dspace.content.DSpaceObjectServiceImpl @ .
2017-11-14 13:14:43,370 DEBUG org.dspace.core.LegacyPluginServiceImpl @ Adding 
Sequence plugin for interface= org.dspace.authenticate.AuthenticationMethod, 
class=org.dspace.authenticate.LDAPAuthentication
2017-11-14 13:14:43,371 DEBUG org.dspace.core.LegacyPluginServiceImpl @ Adding 
Sequence plugin for interface= org.dspace.authenticate.AuthenticationMethod, 
class=org.dspace.authenticate.PasswordAuthentication
2017-11-14 13:14:43,371 INFO  org.dspace.eperson.EPersonServiceImpl @ 
anonymous:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:update_eperson:eperson_id=b4a43809-a530-4f26-b300-7910e13ad76e
2017-11-14 13:14:43,406 DEBUG org.dspace.identifier.IdentifierServiceImpl @ 
Found identifiers: []
2017-11-14 13:14:43,407 DEBUG org.dspace.content.DSpaceObjectServiceImpl @ .
2017-11-14 13:14:43,409 DEBUG org.dspace.event.BasicDispatcher @ Processing 
queue of 2 events.
2017-11-14 13:14:43,411 DEBUG org.dspace.event.BasicDispatcher @ Iterating over 
3 consumers...
2017-11-14 13:14:43,411 DEBUG org.dspace.event.Event @ Filtering event: 
eventType=1, subjectType=128, result=false
2017-11-14 13:14:43,412 DEBUG org.dspace.event.Event @ Filtering event: 
eventType=1, subjectType=128, result=false
2017-11-14 13:14:43,413 DEBUG org.dspace.event.Event @ Filtering event: 
eventType=1, subjectType=128, result=true
2017-11-14 13:14:43,413 DEBUG org.dspace.event.BasicDispatcher @ Sending event 
to "eperson": org.dspace.event.Event(eventType=CREATE, SubjectType=EPERSON, 
SubjectID=b4a43809-a530-4f26-b300-7910e13ad76e, ObjectType=(Unknown), 
ObjectID=null, TimeStamp=1510665283352, dispatcher=1544803905, detail=[null], 
transactionID="TX5984711716153792285911977537842347528")
2017-11-14 13:14:43,414 DEBUG org.dspace.event.BasicDispatcher @ Iterating over 
3 consumers...
2017-11-14 13:14:43,414 DEBUG org.dspace.event.Event @ Filtering event: 
eventType=2, subjectType=128, result=false
2017-11-14 13:14:43,414 DEBUG org.dspace.event.Event @ Filtering event: 
eventType=2, subjectType=128, result=false
2017-11-14 13:14:43,414 DEBUG org.dspace.event.Event @ Filtering event: 
eventType=2, subjectType=128, result=false
2017-11-14 13:14:43,414 DEBUG org.dspace.event.BasicDispatcher @ Calling end 
for consumer "versioning"
2017-11-14 13:14:43,415 DEBUG org.dspace.event.BasicDispatcher @ Calling end 
for consumer "discovery"
2017-11-14 13:14:43,415 DEBUG org.dspace.event.BasicDispatcher @ Calling end 
for consumer "eperson"
2017-11-14 13:14:43,417 INFO  org.dspace.authenticate.LDAPAuthentication @ 
mike.wh...@stir.ac.uk:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:authenticate:type=ldap-login<mailto:mike.wh...@stir.ac.uk:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:authenticate:type=ldap-login>,
 created ePerson
2017-11-14 13:14:43,419 WARN  org.dspace.core.Context @ 
mike.wh...@stir.ac.uk:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:restore_auth_sys_state:not<mailto:mike.wh...@stir.ac.uk:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:restore_auth_sys_state:not>
 previous state info available null
2017-11-14 13:14:43,420 WARN  org.dspace.app.webui.servlet.DSpaceServlet @ 
mike.wh...@stir.ac.uk:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:general_jspui_error:java.util.EmptyStackException<mailto:mike.wh...@stir.ac.uk:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:general_jspui_error:java.util.EmptyStackException>
java.util.EmptyStackException
        at java.util.Stack.peek(Stack.java:102)
        at java.util.Stack.pop(Stack.java:84)
        at org.dspace.core.Context.restoreAuthSystemState(Context.java:309)
        at 
org.dspace.authenticate.LDAPAuthentication.authenticate(LDAPAuthentication.java:387)
        at 
org.dspace.authenticate.AuthenticationServiceImpl.authenticateInternal(AuthenticationServiceImpl.java:111)
        at 
org.dspace.authenticate.AuthenticationServiceImpl.authenticate(AuthenticationServiceImpl.java:81)
        at 
org.dspace.app.webui.servlet.LDAPServlet.doDSPost(LDAPServlet.java:78)
        at 
org.dspace.app.webui.servlet.DSpaceServlet.processRequest(DSpaceServlet.java:122)
        at 
org.dspace.app.webui.servlet.DSpaceServlet.doPost(DSpaceServlet.java:80)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:661)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
        at 
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
        at 
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at 
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
        at 
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at 
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at 
org.dspace.utils.servlet.DSpaceWebappServletFilter.doFilter(DSpaceWebappServletFilter.java:78)
        at 
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at 
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at 
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
        at 
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
        at 
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478)
        at 
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
        at 
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
        at 
org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:624)
        at 
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
        at 
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
        at 
org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799)
        at 
org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
        at 
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
        at 
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455)
        at 
org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at 
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.lang.Thread.run(Thread.java:748)
2017-11-14 13:14:43,427 DEBUG org.dspace.app.webui.util.JSPManager @ 
mike.wh...@stir.ac.uk:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:view_jsp:/error/internal.jsp<mailto:mike.wh...@stir.ac.uk:session_id=FD5A8F4BFB2A5A8B1EC70A560831F10A:ip_addr=139.153.86.2:view_jsp:/error/internal.jsp>


This is obviously rather bizarre behaviour (why should the log level affect 
this?), but I note (from a search of the DSpace archives) it was also reported 
around a year ago in relation to DSpace v6.0 
(https://jira.duraspace.org/browse/DS-3428), but the last comment is from 
February 2017 and the issue is not marked as resolved.

I will continue to investigate, but wondered if anyone else out there had hit 
this and, if so, how did you work around it (aside from setting the log level 
at INFO - I'm still in development, so I really need logging at DEBUG!)?

Cheers,

Mike

Michael White
Senior Developer
Business Applications and Integrations

T: (01786) 466877
E: michael.wh...@stir.ac.uk<mailto:michael.wh...@stir.ac.uk>
A: G5, Airthrey Castle, University of Stirling, Stirling, FK9 4LA


-- 
The University achieved an overall 5 stars in the QS World University Rankings 
2016/17
The University of Stirling is a charity registered in Scotland, 
 number SC 011159.

-- 
You received this message because you are subscribed to the Google Groups 
"DSpace Technical Support" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to dspace-tech+unsubscr...@googlegroups.com.
To post to this group, send email to dspace-tech@googlegroups.com.
Visit this group at https://groups.google.com/group/dspace-tech.
For more options, visit https://groups.google.com/d/optout.

Reply via email to