Uploaded image for project: 'Grouper'
  1. Grouper
  2. GRP-3965

null value in password recently used status

    XMLWordPrintable

Details

    • Improvement
    • Resolution: Fixed
    • Minor
    • 2.6.9
    • None
    • None
    • None

    Description

      When I try to use a local entity and a JWT bearer token to connect to the Grouper web service, I get a 500 error where it appears to try to insert the NUL ("0x00") character (different than a simple "null value" , and not allowed in Postgres) into the "status" field.
      grouper-ws;grouper_error.log;unt;${env:USERTOKEN};2022-03-29T14:33:17,229: [ajp-nio-0.0.0.0-8009-exec-6] ERROR SqlExceptionHelper.logExceptions(129) - [] - Batch entry 0 insert into grouper_password_recently_used (hibernate_version_number, grouper_password_id, jwt_jti, jwt_iat, attempt_millis, ip_address, status, id) values (0, 'db70355392b543b28131836fcba3c91f', NULL, NULL, 1648578797201, '140.182.88.49', ' ', 'af5959b38b464b339f1b71eaf1f9b4b0') was aborted: ERROR: invalid byte sequence for encoding "UTF8": 0x00 Call getNextException to see other errors in the batch.
      grouper-ws;grouper_error.log;unt;${env:USERTOKEN};2022-03-29T14:33:17,229: [ajp-nio-0.0.0.0-8009-exec-6] ERROR SqlExceptionHelper.logExceptions(129) - [] - ERROR: invalid byte sequence for encoding "UTF8": 0x00
      grouper-ws;grouper_error.log;unt;${env:USERTOKEN};2022-03-29T14:33:17,230: [ajp-nio-0.0.0.0-8009-exec-6] ERROR BatchingBatch.performExecution(124) - [] - HHH000315: Exception executing batch [could not execute batch]
      grouper-ws;grouper_error.log;unt;${env:USERTOKEN};2022-03-29T14:33:17,232: [ajp-nio-0.0.0.0-8009-exec-6] ERROR GrouperUtil.logErrorNextException(1244) - [] - Next exception
      org.postgresql.util.PSQLException: ERROR: invalid byte sequence for encoding "UTF8": 0x00
      at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2675) ~[postgresql-42.3.2.jar:42.3.2]
      at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2365) ~[postgresql-42.3.2.jar:42.3.2]
      at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:559) ~[postgresql-42.3.2.jar:42.3.2]
      at org.postgresql.jdbc.PgStatement.internalExecuteBatch(PgStatement.java:887) ~[postgresql-42.3.2.jar:42.3.2]
      at org.postgresql.jdbc.PgStatement.executeBatch(PgStatement.java:910) ~[postgresql-42.3.2.jar:42.3.2]
      at org.postgresql.jdbc.PgPreparedStatement.executeBatch(PgPreparedStatement.java:1638) ~[postgresql-42.3.2.jar:42.3.2]
      at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:2544) ~[c3p0-0.9.5.4.jar:0.9.5.4]
      at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:110) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:97) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      ....
      (edited)
      jwterr0.txt
      grouper-ws;grouper_error.log;unt;${env:USERTOKEN};2022-03-29T14:33:17,229: [ajp-nio-0.0.0.0-8009-exec-6] ERROR SqlExceptionHelper.logExceptions(129) - [] - Batch entry 0 insert into grouper_password_recently_used (hibernate_version_number, grouper_password_id, jwt_jti, jwt_iat, attempt_millis, ip_address, status, id) values (0, 'db70355392b543b28131836fcba3c91f', NULL, NULL, 1648578797201, '140.182.88.49', ' ', 'af5959b38b464b339f1b71eaf1f9b4b0') was aborted: ERROR: invalid byte sequence for encoding "UTF8": 0x00 Call getNextException to see other errors in the batch.
      grouper-ws;grouper_error.log;unt;${env:USERTOKEN};2022-03-29T14:33:17,229: [ajp-nio-0.0.0.0-8009-exec-6] ERROR SqlExceptionHelper.logExceptions(129) - [] - ERROR: invalid byte sequence for encoding "UTF8": 0x00
      grouper-ws;grouper_error.log;unt;${env:USERTOKEN};2022-03-29T14:33:17,230: [ajp-nio-0.0.0.0-8009-exec-6] ERROR BatchingBatch.performExecution(124) - [] - HHH000315: Exception executing batch [could not execute batch]
      grouper-ws;grouper_error.log;unt;${env:USERTOKEN};2022-03-29T14:33:17,232: [ajp-nio-0.0.0.0-8009-exec-6] ERROR GrouperUtil.logErrorNextException(1244) - [] - Next exception
      org.postgresql.util.PSQLException: ERROR: invalid byte sequence for encoding "UTF8": 0x00
      at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2675) ~[postgresql-42.3.2.jar:42.3.2]
      at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2365) ~[postgresql-42.3.2.jar:42.3.2]
      at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:559) ~[postgresql-42.3.2.jar:42.3.2]
      at org.postgresql.jdbc.PgStatement.internalExecuteBatch(PgStatement.java:887) ~[postgresql-42.3.2.jar:42.3.2]
      at org.postgresql.jdbc.PgStatement.executeBatch(PgStatement.java:910) ~[postgresql-42.3.2.jar:42.3.2]
      at org.postgresql.jdbc.PgPreparedStatement.executeBatch(PgPreparedStatement.java:1638) ~[postgresql-42.3.2.jar:42.3.2]
      at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:2544) ~[c3p0-0.9.5.4.jar:0.9.5.4]
      at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:110) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:97) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.execute(AbstractBatchImpl.java:147) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.executeBatch(JdbcCoordinatorImpl.java:214) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:611) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:456) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1282) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at edu.internet2.middleware.grouper.hibernate.ByObject.saveOrUpdate(ByObject.java:479) ~[grouper-2.6.8.jar:2.6.8]
      at edu.internet2.middleware.grouper.hibernate.ByObjectStatic$5.callback(ByObjectStatic.java:376) ~[grouper-2.6.8.jar:2.6.8]
      at edu.internet2.middleware.grouper.hibernate.HibernateSession.callbackHibernateSession(HibernateSession.java:700) [grouper-2.6.8.jar:2.6.8]
      at edu.internet2.middleware.grouper.hibernate.ByObjectStatic.saveOrUpdate(ByObjectStatic.java:363) [grouper-2.6.8.jar:2.6.8]
      at edu.internet2.middleware.grouper.internal.dao.hib3.Hib3GrouperPasswordRecentlyUsedDAO.saveOrUpdate(Hib3GrouperPasswordRecentlyUsedDAO.java:84) [grouper-2.6.8.jar:2.6.8]
      at edu.internet2.middleware.grouper.authentication.GrouperPublicPrivateKeyJwt.decode(GrouperPublicPrivateKeyJwt.java:222) [grouper-2.6.8.jar:2.6.8]
      at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.doFilter(GrouperServiceJ2ee.java:983) [grouper-ws-2.6.8.jar:2.6.8]
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:8.5.57]
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.57]
      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199) [catalina.jar:8.5.57]
      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [catalina.jar:8.5.57]
      at org.apache.tomee.catalina.OpenEJBValve.invoke(OpenEJBValve.java:44) [tomee-catalina-7.0.9.jar:7.0.9]
      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:543) [catalina.jar:8.5.57]
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) [catalina.jar:8.5.57]
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) [catalina.jar:8.5.57]
      at org.apache.tomee.catalina.OpenEJBSecurityListener$RequestCapturer.invoke(OpenEJBSecurityListener.java:97) [tomee-catalina-7.0.9.jar:7.0.9]
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [catalina.jar:8.5.57]
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) [catalina.jar:8.5.57]
      at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:524) [tomcat-coyote.jar:8.5.57]
      at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) [tomcat-coyote.jar:8.5.57]
      at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:818) [tomcat-coyote.jar:8.5.57]
      at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1626) [tomcat-coyote.jar:8.5.57]
      at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-coyote.jar:8.5.57]
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_322]
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_322]
      at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.5.57]
      at java.lang.Thread.run(Thread.java:750) [?:1.8.0_322]
      grouper-ws;grouper_error.log;unt;${env:USERTOKEN};2022-03-29T14:33:17,234: [ajp-nio-0.0.0.0-8009-exec-6] ERROR GrouperServiceJ2ee.handleExceptionHelper(1141) - [] - Error processing request
      edu.internet2.middleware.grouper.internal.dao.GrouperDAOException: Problem in HibernateSession: HibernateSession (2b94bc0e): new, notReadonly, READ_WRITE_NEW, notActiveTransaction, session (43daac9d),
      Exception in saveOrUpdate: edu.internet2.middleware.grouper.authentication.GrouperPasswordRecentlyUsed, ByObjectStatic, query: ', cacheable: null, cacheRegion: null, entityName: null, tx type: null
      at edu.internet2.middleware.grouper.hibernate.HibernateSession._internal_hibernateSessionCatch(HibernateSession.java:588) ~[grouper-2.6.8.jar:2.6.8]
      at edu.internet2.middleware.grouper.hibernate.HibernateSession.callbackHibernateSession(HibernateSession.java:710) ~[grouper-2.6.8.jar:2.6.8]
      at edu.internet2.middleware.grouper.hibernate.ByObjectStatic.saveOrUpdate(ByObjectStatic.java:363) ~[grouper-2.6.8.jar:2.6.8]
      at edu.internet2.middleware.grouper.internal.dao.hib3.Hib3GrouperPasswordRecentlyUsedDAO.saveOrUpdate(Hib3GrouperPasswordRecentlyUsedDAO.java:84) ~[grouper-2.6.8.jar:2.6.8]
      at edu.internet2.middleware.grouper.authentication.GrouperPublicPrivateKeyJwt.decode(GrouperPublicPrivateKeyJwt.java:222) ~[grouper-2.6.8.jar:2.6.8]
      at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.doFilter(GrouperServiceJ2ee.java:983) [grouper-ws-2.6.8.jar:2.6.8]
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:8.5.57]
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.57]
      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199) [catalina.jar:8.5.57]
      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [catalina.jar:8.5.57]
      at org.apache.tomee.catalina.OpenEJBValve.invoke(OpenEJBValve.java:44) [tomee-catalina-7.0.9.jar:7.0.9]
      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:543) [catalina.jar:8.5.57]
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) [catalina.jar:8.5.57]
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) [catalina.jar:8.5.57]
      at org.apache.tomee.catalina.OpenEJBSecurityListener$RequestCapturer.invoke(OpenEJBSecurityListener.java:97) [tomee-catalina-7.0.9.jar:7.0.9]
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [catalina.jar:8.5.57]
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) [catalina.jar:8.5.57]
      at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:524) [tomcat-coyote.jar:8.5.57]
      at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) [tomcat-coyote.jar:8.5.57]
      at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:818) [tomcat-coyote.jar:8.5.57]
      at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1626) [tomcat-coyote.jar:8.5.57]
      at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-coyote.jar:8.5.57]
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_322]
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_322]
      at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.5.57]
      at java.lang.Thread.run(Thread.java:750) [?:1.8.0_322]
      Caused by: org.hibernate.exception.DataException: could not execute batch,
      Exception in save: edu.internet2.middleware.grouper.authentication.GrouperPasswordRecentlyUsed, edu.internet2.middleware.grouper.hibernate.ByObject@5d16c16
      at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:118) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:109) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:119) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:97) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.execute(AbstractBatchImpl.java:147) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.executeBatch(JdbcCoordinatorImpl.java:214) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:611) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:456) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1282) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
      at edu.internet2.middleware.grouper.hibernate.ByObject.saveOrUpdate(ByObject.java:479) ~[grouper-2.6.8.jar:2.6.8]
      at edu....

      Attachments

        Activity

          People

            vivek.sachdeva@at.internet2.edu Vivek Sachdeva (google.com)
            chris.hyzer@at.internet2.edu Chris Hyzer (upenn.edu)
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: