Having some trouble when a user tries logging in using both Shib AND OAuth...I think...

[laulandn]

Hey all, I have a user reportably having trouble logging in...I don't have the exact order of what she tried. All I know is she tried both Shib and OAUTH and is now unable to log in at all.
I've verified that she is a legit user of her University's Shibboleth and the correct attributes are coming across with good values.
One possible scenario is this:

1. Used her University ID and it worked.
2. Tried her Google ID (OAUTH) and it didn't (duplicate name/etc already there?).
3. Tried to use her University ID again, and it now fails.
   The order may have been OAUTH->Shib->OAUTH.
   Have you guys seen anything like that?
   Thanks!

[laulandn]

Forgot to mention. The URL is: https://dataverse.tdl.org and the version is 4.8.4 build 128-ef7dce7

[laulandn]

Let me know if you think an upgrade would fix this.

[pdurbin]

@laulandn Dataverse 4.4 (pull request #3025) is when we made a big effort to improve Shibboleth support so I don't think an upgrade would help, but you should, of course, always be thinking about staying up to date with releases. 😄 Maybe there was a more recent bug fix or two I'm forgetting.

The best thing would probably be to email server.log to support@dataverse.org (on the day when the failure occurred) so that we can see if there were any exceptions thrown.

[laulandn]

Phil, I'm seeing this every time she tries to log in using her Shib account. She was reported as using her Google ID also, but shouldn't that have had her gmail address? Maybe not!

[2018-06-20T16:28:58.389-0500] [glassfish 4.1] [WARNING] [AS-EJB-00056] [javax.enterprise.ejb.container] [tid: _ThreadID=49 _ThreadName=jk-connector(2)] [timeMillis: 1529530138389] [levelValue: 900] [[
A system exception occurred during an invocation on EJB AuthenticationServiceBean, method: public edu.harvard.iq.dataverse.authorization.users.AuthenticatedUser edu.harvard.iq.dataverse.authorization.AuthenticationServiceBean.createAuthenticatedUser(edu.harvard.iq.dataverse.authorization.UserRecordIdentifier,java.lang.String,edu.harvard.iq.dataverse.authorization.AuthenticatedUserDisplayInfo,boolean)]]

[2018-06-20T16:28:58.390-0500] [glassfish 4.1] [WARNING] [] [javax.enterprise.ejb.container] [tid: _ThreadID=49 _ThreadName=jk-connector(2)] [timeMillis: 1529530138390] [levelValue: 900] [[

javax.ejb.EJBException
at com.sun.ejb.containers.EJBContainerTransactionManager.processSystemException(EJBContainerTransactionManager.java:748)
at com.sun.ejb.containers.EJBContainerTransactionManager.completeNewTx(EJBContainerTransactionManager.java:698)
at com.sun.ejb.containers.EJBContainerTransactionManager.postInvokeTx(EJBContainerTransactionManager.java:503)
at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4566)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2074)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2044)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:220)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88)
at com.sun.proxy.$Proxy351.createAuthenticatedUser(Unknown Source)
at edu.harvard.iq.dataverse.authorization.EJB31_Generated__AuthenticationServiceBean__Intf____Bean.createAuthenticatedUser(Unknown Source)
at edu.harvard.iq.dataverse.Shib.confirmAndCreateAccount(Shib.java:288)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at javax.el.ELUtil.invokeMethod(ELUtil.java:332)
at javax.el.BeanELResolver.invoke(BeanELResolver.java:537)
at javax.el.CompositeELResolver.invoke(CompositeELResolver.java:256)
at com.sun.el.parser.AstValue.invoke(AstValue.java:283)
at com.sun.el.MethodExpressionImpl.invoke(MethodExpressionImpl.java:304)
at org.jboss.weld.util.el.ForwardingMethodExpression.invoke(ForwardingMethodExpression.java:40)
at org.jboss.weld.el.WeldMethodExpression.invoke(WeldMethodExpression.java:50)
at com.sun.faces.facelets.el.TagMethodExpression.invoke(TagMethodExpression.java:105)
at javax.faces.component.MethodBindingMethodExpressionAdapter.invoke(MethodBindingMethodExpressionAdapter.java:87)
at com.sun.faces.application.ActionListenerImpl.processAction(ActionListenerImpl.java:102)
at javax.faces.component.UICommand.broadcast(UICommand.java:315)
at javax.faces.component.UIViewRoot.broadcastEvents(UIViewRoot.java:790)
at javax.faces.component.UIViewRoot.processApplication(UIViewRoot.java:1282)
at com.sun.faces.lifecycle.InvokeApplicationPhase.execute(InvokeApplicationPhase.java:81)
at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101)
at com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:198)
at javax.faces.webapp.FacesServlet.service(FacesServlet.java:646)
at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1682)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:344)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
at org.glassfish.tyrus.servlet.TyrusServletFilter.doFilter(TyrusServletFilter.java:295)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
at org.ocpsoft.rewrite.servlet.RewriteFilter.doFilter(RewriteFilter.java:205)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:316)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:160)
at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673)
at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:174)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:415)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:282)
at com.sun.enterprise.v3.services.impl.ContainerMapper$HttpHandlerCallable.call(ContainerMapper.java:459)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:167)
at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:201)
at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:175)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:235)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:284)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:201)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:133)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:112)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:561)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:112)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:117)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:56)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:137)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:565)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:545)
at java.lang.Thread.run(Thread.java:748)
Caused by: javax.persistence.PersistenceException: Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "authenticateduser_email_key"
Detail: Key (email)=(rachel.letteri@tamu.edu) already exists.
Error Code: 0
Call: INSERT INTO AUTHENTICATEDUSER (AFFILIATION, CREATEDTIME, EMAIL, EMAILCONFIRMED, FIRSTNAME, LASTAPIUSETIME, LASTLOGINTIME, LASTNAME, POSITION, SUPERUSER, USERIDENTIFIER) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
bind => [11 parameters bound]
Query: InsertObjectQuery([AuthenticatedUser identifier:@rachel.letteri1])
at org.eclipse.persistence.internal.jpa.EntityManagerImpl.flush(EntityManagerImpl.java:868)
at com.sun.enterprise.container.common.impl.EntityManagerWrapper.flush(EntityManagerWrapper.java:437)
at edu.harvard.iq.dataverse.authorization.AuthenticationServiceBean.save(AuthenticationServiceBean.java:467)
at edu.harvard.iq.dataverse.authorization.AuthenticationServiceBean.createAuthenticatedUser(AuthenticationServiceBean.java:554)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1081)
at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1153)
at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4786)
at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:656)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:64)
at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
at sun.reflect.GeneratedMethodAccessor100.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:883)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doCall(SystemInterceptorProxy.java:163)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:140)
at sun.reflect.GeneratedMethodAccessor99.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:883)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:369)
at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:4758)
at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4746)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:212)
... 61 more
Caused by: Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "authenticateduser_email_key"
Detail: Key (email)=(rachel.letteri@tamu.edu) already exists.
Error Code: 0
Call: INSERT INTO AUTHENTICATEDUSER (AFFILIATION, CREATEDTIME, EMAIL, EMAILCONFIRMED, FIRSTNAME, LASTAPIUSETIME, LASTLOGINTIME, LASTNAME, POSITION, SUPERUSER, USERIDENTIFIER) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
bind => [11 parameters bound]
Query: InsertObjectQuery([AuthenticatedUser identifier:@rachel.letteri1])
at org.eclipse.persistence.exceptions.DatabaseException.sqlException(DatabaseException.java:340)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.processExceptionForCommError(DatabaseAccessor.java:1611)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeDirectNoSelect(DatabaseAccessor.java:898)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeNoSelect(DatabaseAccessor.java:962)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:631)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:558)
at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:2002)
at org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:298)
at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:242)
at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:228)
at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.insertObject(DatasourceCallQueryMechanism.java:377)
at org.eclipse.persistence.internal.queries.StatementQueryMechanism.insertObject(StatementQueryMechanism.java:165)
at org.eclipse.persistence.internal.queries.StatementQueryMechanism.insertObject(StatementQueryMechanism.java:180)
at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.insertObjectForWrite(DatabaseQueryMechanism.java:489)
at org.eclipse.persistence.queries.InsertObjectQuery.executeCommit(InsertObjectQuery.java:80)
at org.eclipse.persistence.queries.InsertObjectQuery.executeCommitWithChangeSet(InsertObjectQuery.java:90)
at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.executeWriteWithChangeSet(DatabaseQueryMechanism.java:301)
at org.eclipse.persistence.queries.WriteObjectQuery.executeDatabaseQuery(WriteObjectQuery.java:58)
at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:899)
at org.eclipse.persistence.queries.DatabaseQuery.executeInUnitOfWork(DatabaseQuery.java:798)
at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWorkObjectLevelModifyQuery(ObjectLevelModifyQuery.java:108)
at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWork(ObjectLevelModifyQuery.java:85)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2896)
at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1804)
at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1786)
at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1737)
at org.eclipse.persistence.internal.sessions.CommitManager.commitNewObjectsForClassWithChangeSet(CommitManager.java:226)
at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsWithChangeSet(CommitManager.java:125)
at org.eclipse.persistence.internal.sessions.AbstractSession.writeAllObjectsWithChangeSet(AbstractSession.java:4207)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabase(UnitOfWorkImpl.java:1441)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabaseWithPreBuiltChangeSet(UnitOfWorkImpl.java:1587)
at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.writeChanges(RepeatableWriteUnitOfWork.java:452)
at org.eclipse.persistence.internal.jpa.EntityManagerImpl.flush(EntityManagerImpl.java:863)
... 93 more
Caused by: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "authenticateduser_email_key"
Detail: Key (email)=(rachel.letteri@tamu.edu) already exists.
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2198)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1927)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255)
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:562)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:420)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:366)
at sun.reflect.GeneratedMethodAccessor724.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.postgresql.ds.jdbc23.AbstractJdbc23PooledConnection$StatementHandler.invoke(AbstractJdbc23PooledConnection.java:456)
at com.sun.proxy.$Proxy242.executeUpdate(Unknown Source)
at com.sun.gjc.spi.base.PreparedStatementWrapper.executeUpdate(PreparedStatementWrapper.java:125)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeDirectNoSelect(DatabaseAccessor.java:890)
... 123 more
]]

[2018-06-20T16:28:58.391-0500] [glassfish 4.1] [INFO] [] [edu.harvard.iq.dataverse.Shib] [tid: _ThreadID=49 _ThreadName=jk-connector(2)] [timeMillis: 1529530138391] [levelValue: 800] [[
Couldn't create user urn:mace:tamu.edu:shibboleth:idp:tamu:administrative:cscn:idp.tamu.edu|rachel.letteri@tamu.edu due to exception: javax.persistence.PersistenceException: Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "authenticateduser_email_key"
Detail: Key (email)=(rachel.letteri@tamu.edu) already exists.
Error Code: 0
Call: INSERT INTO AUTHENTICATEDUSER (AFFILIATION, CREATEDTIME, EMAIL, EMAILCONFIRMED, FIRSTNAME, LASTAPIUSETIME, LASTLOGINTIME, LASTNAME, POSITION, SUPERUSER, USERIDENTIFIER) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
bind => [11 parameters bound]
Query: InsertObjectQuery([AuthenticatedUser identifier:@rachel.letteri1])]]

[laulandn]

FYI, You can have any email you want for you Google ID. I'm betting she has her set to her tamu.edu one and she's trying to log in with both accounts for some reason.

[pdurbin]

@laulandn the uniqueness constraint violation is happening for the "email" field in the "authenticateduser" table: http://phoenix.dataverse.org/schemaspy/latest/tables/authenticateduser.html

To figure out which user it is, you'll need to take the "useridentifier" string from the "authenticateduser" table and find it in the "authenticateduserlookup" table: http://phoenix.dataverse.org/schemaspy/latest/tables/authenticateduserlookup.html

The new-user Manage Users dashboard might help you troubleshoot: http://guides.dataverse.org/en/4.9/admin/user-administration.html

There are also some API endpoints that might help you troubleshoot:

• http://guides.dataverse.org/en/4.9/api/native-api.html#list-single-user
• http://guides.dataverse.org/en/4.9/api/native-api.html#list-users

[laulandn]

So it boils down to: user emails MUST be unique, and a user may never use multiple logins (shib, oauth, builtin) that have the same email address. Correct? Makes sense.

[pdurbin]

@laulandn yes. That's right. Please see also #3704

[pdurbin]

@laulandn is there something you'd like us to fix in the code? Should this issue remain open? Were you able to figure out a workaround?

[laulandn]

I think ulitmately I really need a good way for the admin to delete "extra" users (or ones that used an undesired auth method) from the user management dashboard. This is #4475

The problem is that I've had to use the api call to remove the "extra" oauth user (so they can then log in using shibboleth). It will fail if items are owned, so I then have to delete those, etc etc.

I've run up against database contraints...or maybe a missing contraint...where things like a password reset token won't allow me to get rid of the user without database careful editing.

So an official way to not just remove the user, but everything associated with them...maybe reassigning ownership of item to the admin user, or the creator of the dataverse where the items are located.

Thanks!

[pdurbin]

Yeah, #4475 is about wanting a way to delete users, I think, but the title is off at the moment.

#1929 is about the database constraints you can hit while trying to delete users.

[pdurbin]

We discussed #4430 today in sprint planning and it's related in some ways. It's somewhat difficult to support users with auth problems, especially when they try logging in with more than one method.

[djbrooke]

@laulandn hope you're well! I'm going to close this one as we are tracking delete in a separate issue.