I recently switched from the Postgresql JPA ticket registry to MongoDB and am having a strange issue. The authentication succeeds, but then it fails to add the ticket to the mongo database, causing the process to fail and return to the login screen.
-- cas.properties -- cas.ticket.registry.mongo.host=localhost cas.ticket.registry.mongo.userId=<redacted> cas.ticket.registry.mongo.password=<redacted> cas.ticket.registry.mongo.databaseName=casdb cas.ticket.registry.mongo.collectionName=cas-ticket-registry cas.ticket.registry.mongo.dropCollection=false cas.ticket.registry.mongo.timeout=5000 cas.ticket.registry.mongo.writeConcern=NORMAL cas.ticket.mongo.conns.lifetime=60000 cas.ticket.mongo.conns.perHost=10 cas.ticket.registry.mongo.idleTimeout=30000 CAS connects to the database with the specified user, makes all the tables and seems like everything should be good. Then it encodes the TGT, but fails to add it. 2018-02-07 00:46:30,024 DEBUG [org.apereo.cas.ticket.factory.DefaultTicketGrantingTicketFactory] - <Encoded ticket-granting ticket id [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu]> 2018-02-07 00:46:30,025 DEBUG [org.apereo.cas.ticket.registry.MongoDbTicketRegistry] - <Adding ticket [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu]> 2018-02-07 00:46:30,118 ERROR [org.apereo.cas.ticket.registry.MongoDbTicketRegistry] - <Failed adding [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu]: [java.lang.NullPointerException]> 2018-02-07 00:46:30,118 DEBUG [org.apereo.cas.AbstractCentralAuthenticationService] - <Publishing [org.apereo.cas.support.events.ticket.CasTicketGrantingTicketCreatedEvent@2c84b7f8[ticketGrantingTicket=TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu]]> Has anyone else ran into this? --Mike K -- - Website: https://apereo.github.io/cas - Gitter Chatroom: https://gitter.im/apereo/cas - List Guidelines: https://goo.gl/1VRrw7 - Contributions: https://goo.gl/mh7qDG --- You received this message because you are subscribed to the Google Groups "CAS Community" group. To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+unsubscr...@apereo.org. To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/051a23e8-bb02-48a3-ab26-86b9a2fa3c40%40apereo.org.
2018-02-07 00:46:30,024 DEBUG [org.apereo.cas.ticket.factory.DefaultTicketGrantingTicketFactory] - <Attempting to encode ticket-granting ticket [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu]> 2018-02-07 00:46:30,024 DEBUG [org.apereo.cas.ticket.factory.DefaultTicketGrantingTicketFactory] - <Encoded ticket-granting ticket id [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu]> 2018-02-07 00:46:30,025 DEBUG [org.apereo.cas.ticket.registry.MongoDbTicketRegistry] - <Adding ticket [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu]> 2018-02-07 00:46:30,118 ERROR [org.apereo.cas.ticket.registry.MongoDbTicketRegistry] - <Failed adding [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu]: [java.lang.NullPointerException]> 2018-02-07 00:46:30,118 DEBUG [org.apereo.cas.AbstractCentralAuthenticationService] - <Publishing [org.apereo.cas.support.events.ticket.CasTicketGrantingTicketCreatedEvent@2c84b7f8[ticketGrantingTicket=TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu]]> 2018-02-07 00:46:30,122 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN ============================================================= WHO: MKromarek WHAT: TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu ACTION: TICKET_GRANTING_TICKET_CREATED APPLICATION: CAS WHEN: Wed Feb 07 00:46:30 PST 2018 CLIENT IP ADDRESS: 168.156.66.179 SERVER IP ADDRESS: 127.0.0.1 ============================================================= > 2018-02-07 00:46:30,122 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Initiating transaction commit> 2018-02-07 00:46:30,123 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Resuming suspended transaction after completion of inner transaction> 2018-02-07 00:46:30,123 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Initiating transaction commit> 2018-02-07 00:46:30,125 DEBUG [org.apereo.cas.web.support.DefaultCasCookieValueManager] - <Encoding cookie value [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu@168.156.66.179@Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:58.0) Gecko/20100101 Firefox/58.0]> 2018-02-07 00:46:30,125 DEBUG [org.apereo.cas.util.EncodingUtils] - <Encrypting via [A128CBC-HS256]> 2018-02-07 00:46:30,127 DEBUG [org.apereo.cas.web.support.CookieRetrievingCookieGenerator] - <Creating cookie [TGC]> 2018-02-07 00:46:30,128 DEBUG [org.apereo.cas.web.support.TGCCookieRetrievingCookieGenerator] - <Added cookie with name [TGC] and value [eyJhbGciOiJIUzUxMiJ9.WlhsS05tRllRV2xQYVVwRlVsVlphVXhEU21oaVIyTnBUMmxLYTJGWVNXbE1RMHBzWW0xTmFVOXBTa0pOVkVrMFVUQktSRXhWYUZSTmFsVXlTVzR3TGk1MlZVTXdZbVF0ZGxCUlJGQm5VWEJJTFVSbmVGTjNMamxyVkRKcFdEQlJSMUZKZFRoU1VFMXRRa1JuY3paaVpIZFBVMnQ2VTE5aGFEZEVUWFpGZG5KRmVGbE9NVWg1U0UxR1dIQTJZV3BsYjJ0alNYaFZOa1pVZUZWdUxXMTNkbFJvV2w5WUxYSlhOVzlFVld4VmRtdE9Tell0TlU4emFrcFlUMEpVVUVKUFlqTlBWbVpuY1RCU2NtMVBha2s1UVZCMkxYSnlhelE1YTJGWlVXNWlVM1p4YTNZMU5qRlBkM3BYVWs1TmFIUTFTRGhqUWtwd05rNVBSWEJLTTJJeldqRlNia3Q1V2kxdGFWZGxiRWxyTlVoQmVsQlZXRXh1U3pKMVlsRlRjekZuTVcxTVUxVjRPVnB6WmxKd0xXNDJaV2QzZDE5NFFVNXdWVWhLTWxONWFEaG9kbGt1VjA1a1F6UTFaemhJV0dZMU5GUkVka1pqT0cxQmR3PT0.QaCGgL80duqO2gtTdqzT6l0W1symhl314P-0JLXXge9RGQJTGV-EN08npycvJapnexM_Tv2UgzYccZdREn7mmA]> 2018-02-07 00:46:30,129 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Creating new transaction with name [org.apereo.cas.ticket.registry.DefaultTicketRegistrySupport.getAuthenticationFrom]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'ticketTransactionManager'> 2018-02-07 00:46:30,130 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Creating new transaction with name [org.apereo.cas.ticket.registry.DefaultTicketRegistrySupport.getAuthenticationFrom]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'ticketTransactionManager'> 2018-02-07 00:46:30,130 DEBUG [org.apereo.cas.ticket.registry.MongoDbTicketRegistry] - <Locating ticket ticketId [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu]> 2018-02-07 00:46:30,131 DEBUG [org.apereo.cas.ticket.registry.MongoDbTicketRegistry] - <Locating collection name [ticketGrantingTicketsCollection] for ticket definition [org.apereo.cas.ticket.DefaultTicketDefinition@28556a8b[implementationClass=class org.apereo.cas.ticket.TicketGrantingTicketImpl,prefix=TGT]]> 2018-02-07 00:46:30,131 DEBUG [org.apereo.cas.ticket.registry.MongoDbTicketRegistry] - <Located MongoDb collection instance [ticketGrantingTicketsCollection]> 2018-02-07 00:46:30,132 INFO [org.mongodb.driver.connection] - <Closed connection [connectionId{localValue:5, serverValue:67}] to localhost:27017 because it is past its maximum allowed life time.> 2018-02-07 00:46:30,132 DEBUG [org.mongodb.driver.connection] - <Closing connection connectionId{localValue:5, serverValue:67}> 2018-02-07 00:46:30,152 INFO [org.mongodb.driver.connection] - <Opened connection [connectionId{localValue:6, serverValue:68}] to localhost:27017> 2018-02-07 00:46:30,153 DEBUG [org.mongodb.driver.protocol.command] - <Sending command {find : BsonString{value='ticketGrantingTicketsCollection'}} to database casdb on connection [connectionId{localValue:6, serverValue:68}] to server localhost:27017> 2018-02-07 00:46:30,154 DEBUG [org.mongodb.driver.protocol.command] - <Command execution completed> 2018-02-07 00:46:30,154 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Initiating transaction commit> 2018-02-07 00:46:30,155 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Resuming suspended transaction after completion of inner transaction> 2018-02-07 00:46:30,155 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Initiating transaction commit> 2018-02-07 00:46:30,156 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Creating new transaction with name [org.apereo.cas.DefaultCentralAuthenticationService.destroyTicketGrantingTicket]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'ticketTransactionManager'> 2018-02-07 00:46:30,156 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Creating new transaction with name [org.apereo.cas.DefaultCentralAuthenticationService.destroyTicketGrantingTicket]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'ticketTransactionManager'> 2018-02-07 00:46:30,158 DEBUG [org.apereo.cas.DefaultCentralAuthenticationService] - <Removing ticket [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu] from registry...> 2018-02-07 00:46:30,158 DEBUG [org.apereo.cas.ticket.registry.MongoDbTicketRegistry] - <Locating ticket ticketId [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu]> 2018-02-07 00:46:30,159 DEBUG [org.apereo.cas.ticket.registry.MongoDbTicketRegistry] - <Locating collection name [ticketGrantingTicketsCollection] for ticket definition [org.apereo.cas.ticket.DefaultTicketDefinition@28556a8b[implementationClass=class org.apereo.cas.ticket.TicketGrantingTicketImpl,prefix=TGT]]> 2018-02-07 00:46:30,159 DEBUG [org.apereo.cas.ticket.registry.MongoDbTicketRegistry] - <Located MongoDb collection instance [ticketGrantingTicketsCollection]> 2018-02-07 00:46:30,160 DEBUG [org.mongodb.driver.protocol.command] - <Sending command {find : BsonString{value='ticketGrantingTicketsCollection'}} to database casdb on connection [connectionId{localValue:6, serverValue:68}] to server localhost:27017> 2018-02-07 00:46:30,161 DEBUG [org.mongodb.driver.protocol.command] - <Command execution completed> 2018-02-07 00:46:30,161 DEBUG [org.apereo.cas.AbstractCentralAuthenticationService] - <Ticket [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu] by type [TicketGrantingTicket] cannot be found in the ticket registry.> 2018-02-07 00:46:30,161 DEBUG [org.apereo.cas.DefaultCentralAuthenticationService] - <TicketGrantingTicket [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu] cannot be found in the ticket registry.> 2018-02-07 00:46:30,162 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN ============================================================= WHO: MKromarek WHAT: TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu ACTION: TICKET_GRANTING_TICKET_DESTROYED APPLICATION: CAS WHEN: Wed Feb 07 00:46:30 PST 2018 CLIENT IP ADDRESS: 168.156.66.179 SERVER IP ADDRESS: 127.0.0.1 ============================================================= > 2018-02-07 00:46:30,162 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Initiating transaction commit> 2018-02-07 00:46:30,163 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Resuming suspended transaction after completion of inner transaction> 2018-02-07 00:46:30,163 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Initiating transaction commit> 2018-02-07 00:46:30,164 WARN [org.apereo.cas.web.flow.GenerateServiceTicketAction] - <Could not grant service ticket [TGT-******************************************3wOfaglzGL-JNpegctV--qfA0S5-xCE-aws-stage-cas.highline.edu]. Routing to [authenticationFailure]>
2018-02-07T00:22:18.917-0800 W COMMAND [conn52] the autoIndexId option is deprecated and will be removed in a future release 2018-02-07T00:22:18.954-0800 I INDEX [conn52] build index on: casdb.serviceTicketsCollection properties: { v: 1, key: { expireAt: 1 }, name: "expireAt_1", ns: "casdb.serviceTicketsCollection", expireAfterSeconds: 10 } 2018-02-07T00:22:18.954-0800 I INDEX [conn52] building index using bulk method; build may temporarily use up to 500 megabytes of RAM 2018-02-07T00:22:18.954-0800 I INDEX [conn52] build index done. scanned 0 total records. 0 secs 2018-02-07T00:22:18.962-0800 W COMMAND [conn52] the autoIndexId option is deprecated and will be removed in a future release 2018-02-07T00:22:18.980-0800 I INDEX [conn52] build index on: casdb.proxyTicketsCollection properties: { v: 1, key: { expireAt: 1 }, name: "expireAt_1", ns: "casdb.proxyTicketsCollection", expireAfterSeconds: 10 } 2018-02-07T00:22:18.980-0800 I INDEX [conn52] building index using bulk method; build may temporarily use up to 500 megabytes of RAM 2018-02-07T00:22:18.980-0800 I INDEX [conn52] build index done. scanned 0 total records. 0 secs 2018-02-07T00:22:18.987-0800 W COMMAND [conn52] the autoIndexId option is deprecated and will be removed in a future release 2018-02-07T00:22:19.006-0800 I INDEX [conn52] build index on: casdb.ticketGrantingTicketsCollection properties: { v: 1, key: { expireAt: 1 }, name: "expireAt_1", ns: "casdb.ticketGrantingTicketsCollection", expireAfterSeconds: 28800 } 2018-02-07T00:22:19.006-0800 I INDEX [conn52] building index using bulk method; build may temporarily use up to 500 megabytes of RAM 2018-02-07T00:22:19.006-0800 I INDEX [conn52] build index done. scanned 0 total records. 0 secs 2018-02-07T00:22:19.015-0800 W COMMAND [conn52] the autoIndexId option is deprecated and will be removed in a future release 2018-02-07T00:22:19.034-0800 I INDEX [conn52] build index on: casdb.samlArtifactsCache properties: { v: 1, key: { expireAt: 1 }, name: "expireAt_1", ns: "casdb.samlArtifactsCache", expireAfterSeconds: 10 } 2018-02-07T00:22:19.034-0800 I INDEX [conn52] building index using bulk method; build may temporarily use up to 500 megabytes of RAM 2018-02-07T00:22:19.034-0800 I INDEX [conn52] build index done. scanned 0 total records. 0 secs 2018-02-07T00:22:19.039-0800 W COMMAND [conn52] the autoIndexId option is deprecated and will be removed in a future release 2018-02-07T00:22:19.058-0800 I INDEX [conn52] build index on: casdb.proxyGrantingTicketsCollection properties: { v: 1, key: { expireAt: 1 }, name: "expireAt_1", ns: "casdb.proxyGrantingTicketsCollection", expireAfterSeconds: 28800 } 2018-02-07T00:22:19.058-0800 I INDEX [conn52] building index using bulk method; build may temporarily use up to 500 megabytes of RAM 2018-02-07T00:22:19.059-0800 I INDEX [conn52] build index done. scanned 0 total records. 0 secs 2018-02-07T00:22:19.065-0800 W COMMAND [conn52] the autoIndexId option is deprecated and will be removed in a future release 2018-02-07T00:22:19.083-0800 I INDEX [conn52] build index on: casdb.samlAttributeQueryCache properties: { v: 1, key: { expireAt: 1 }, name: "expireAt_1", ns: "casdb.samlAttributeQueryCache", expireAfterSeconds: 10 } 2018-02-07T00:22:19.083-0800 I INDEX [conn52] building index using bulk method; build may temporarily use up to 500 megabytes of RAM 2018-02-07T00:22:19.084-0800 I INDEX [conn52] build index done. scanned 0 total records. 0 secs