Requests not selecting Entity from the eHcache hitting the DB instead

[Tony Evans]

I am new to EhCache, so not to sure what the problem is, but I have set up log for debug and stats on both eHcache and Hibernate. Sorry if there is to much logs I have broken it down.

What I did was a select on a Bank Entity that brought back a collection of Accounts, which brought back a collection of funds. This is the logging for the initial request

1-16 11:33:32 [http-nio-8080-exec-1] INFO  c.c.s.s.b.c.BankServiceController - Find Banks
2019-01-16 11:33:32 [http-nio-8080-exec-1] DEBUG o.s.d.r.c.s.TransactionalRepositoryProxyPostProcessor$CustomAnnotationTransactionAttributeSource - Adding transactional method 'findAll' with attribute: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly; ''
2019-01-16 11:33:32 [http-nio-8080-exec-1] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'transactionManager'
2019-01-16 11:33:32 [http-nio-8080-exec-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.jpa.internal.EntityManagerImpl@2e558c32] for JPA transaction
2019-01-16 11:33:32 [http-nio-8080-exec-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findAll]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly; ''
2019-01-16 11:33:32 [http-nio-8080-exec-1] DEBUG o.s.jdbc.datasource.DataSourceUtils - Setting JDBC Connection [ProxyConnection[PooledConnection[com.mysql.cj.jdbc.ConnectionImpl@75efa37b]]] read-only
2019-01-16 11:33:32 [http-nio-8080-exec-1] DEBUG o.h.e.t.internal.TransactionImpl - begin
2019-01-16 11:33:32 [http-nio-8080-exec-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@70d43d98]
2019-01-16 11:33:32 [http-nio-8080-exec-1] DEBUG o.h.jpa.criteria.CriteriaQueryImpl - Rendered criteria query -> select generatedAlias0 from Bank as generatedAlias0 where generatedAlias0.bankId in (:param0)
2019-01-16 11:33:32 [http-nio-8080-exec-1] DEBUG o.h.h.i.QueryTranslatorFactoryInitiator - QueryTranslatorFactory : org.hibernate.hql.internal.ast.ASTQueryTranslatorFactory@587eb709
2019-01-16 11:33:32 [http-nio-8080-exec-1] INFO  o.h.h.i.QueryTranslatorFactoryInitiator - HHH000397: Using ASTQueryTranslatorFactory
2019-01-16 11:33:32 [http-nio-8080-exec-1] DEBUG o.h.h.i.ast.QueryTranslatorImpl - parse() - HQL: select generatedAlias0 from com.cav.spring.service.bank.entity.Bank as generatedAlias0 where generatedAlias0.bankId in (:param0)
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.h.i.ast.QueryTranslatorImpl - --- HQL AST ---
 \-[QUERY] Node: 'query'
    +-[SELECT_FROM] Node: 'SELECT_FROM'
    |  +-[FROM] Node: 'from'
    |  |  \-[RANGE] Node: 'RANGE'
    |  |     +-[DOT] Node: '.'
    |  |     |  +-[DOT] Node: '.'
    |  |     |  |  +-[DOT] Node: '.'
    |  |     |  |  |  +-[DOT] Node: '.'
    |  |     |  |  |  |  +-[DOT] Node: '.'
    |  |     |  |  |  |  |  +-[DOT] Node: '.'
    |  |     |  |  |  |  |  |  +-[IDENT] Node: 'com'
    |  |     |  |  |  |  |  |  \-[IDENT] Node: 'cav'
    |  |     |  |  |  |  |  \-[IDENT] Node: 'spring'
    |  |     |  |  |  |  \-[IDENT] Node: 'service'
    |  |     |  |  |  \-[IDENT] Node: 'bank'
    |  |     |  |  \-[IDENT] Node: 'entity'
    |  |     |  \-[IDENT] Node: 'Bank'
    |  |     \-[ALIAS] Node: 'generatedAlias0'
    |  \-[SELECT] Node: 'select'
    |     \-[IDENT] Node: 'generatedAlias0'
    \-[WHERE] Node: 'where'
       \-[IN] Node: 'in'
          +-[DOT] Node: '.'
          |  +-[IDENT] Node: 'generatedAlias0'
          |  \-[IDENT] Node: 'bankId'
          \-[IN_LIST] Node: 'inList'
             \-[COLON] Node: ':'
                \-[IDENT] Node: 'param0'

2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.hql.internal.ast.ErrorCounter - throwQueryException() : no errors
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.h.i.antlr.HqlSqlBaseWalker - select << begin [level=1, statement=select]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.h.internal.ast.tree.FromElement - FromClause{level=1} : com.cav.spring.service.bank.entity.Bank (generatedAlias0) -> bank0_
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.h.i.ast.tree.FromReferenceNode - Resolved : generatedAlias0 -> bank0_.bank_id
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.h.i.ast.tree.FromReferenceNode - Resolved : generatedAlias0 -> bank0_.bank_id
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.hql.internal.ast.tree.DotNode - getDataType() : bankId -> org.hibernate.type.LongType@1fe4a710
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.h.i.ast.tree.FromReferenceNode - Resolved : generatedAlias0.bankId -> bank0_.bank_id
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.h.i.antlr.HqlSqlBaseWalker - select : finishing up [level=1, statement=select]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.hql.internal.ast.HqlSqlWalker - processQuery() :  ( SELECT ( {select clause} bank0_.bank_id ) ( FromClause{level=1} bank bank0_ ) ( where ( in ( bank0_.bank_id bank0_.bank_id bankId ) ( inList ? ) ) ) )
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.h.i.ast.util.JoinProcessor - Using FROM fragment [bank bank0_]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.h.i.antlr.HqlSqlBaseWalker - select >> end [level=1, statement=select]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.h.i.ast.QueryTranslatorImpl - --- SQL AST ---
 \-[SELECT] QueryNode: 'SELECT'  querySpaces (bank)
    +-[SELECT_CLAUSE] SelectClause: '{select clause}'
    |  +-[ALIAS_REF] IdentNode: 'bank0_.bank_id as bank_id1_2_' {alias=generatedAlias0, className=com.cav.spring.service.bank.entity.Bank, tableAlias=bank0_}
    |  \-[SQL_TOKEN] SqlFragment: 'bank0_.bank_active as bank_act2_2_, bank0_.bank_code as bank_cod3_2_, bank0_.bank_name as bank_nam4_2_, bank0_.contact_details_code as contact_5_2_, bank0_.effective_date as effectiv6_2_'
    +-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[generatedAlias0], fromElementByTableAlias=[bank0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
    |  \-[FROM_FRAGMENT] FromElement: 'bank bank0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=generatedAlias0,role=null,tableName=bank,tableAlias=bank0_,origin=null,columns={,className=com.cav.spring.service.bank.entity.Bank}}
    \-[WHERE] SqlNode: 'where'
       \-[IN] InLogicOperatorNode: 'in'
          +-[DOT] DotNode: 'bank0_.bank_id' {propertyName=bankId,dereferenceType=PRIMITIVE,getPropertyPath=bankId,path=generatedAlias0.bankId,tableAlias=bank0_,className=com.cav.spring.service.bank.entity.Bank,classAlias=generatedAlias0}
          |  +-[ALIAS_REF] IdentNode: 'bank0_.bank_id' {alias=generatedAlias0, className=com.cav.spring.service.bank.entity.Bank, tableAlias=bank0_}
          |  \-[IDENT] IdentNode: 'bankId' {originalText=bankId}
          \-[IN_LIST] SqlNode: 'inList'
             \-[NAMED_PARAM] ParameterNode: '?' {name=param0, expectedType=org.hibernate.type.LongType@1fe4a710}

2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.hql.internal.ast.ErrorCounter - throwQueryException() : no errors
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.h.i.ast.QueryTranslatorImpl - HQL: select generatedAlias0 from com.cav.spring.service.bank.entity.Bank as generatedAlias0 where generatedAlias0.bankId in (:param0)
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.h.i.ast.QueryTranslatorImpl - SQL: select bank0_.bank_id as bank_id1_2_, bank0_.bank_active as bank_act2_2_, bank0_.bank_code as bank_cod3_2_, bank0_.bank_name as bank_nam4_2_, bank0_.contact_details_code as contact_5_2_, bank0_.effective_date as effectiv6_2_ from bank bank0_ where bank0_.bank_id in (?)
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.hql.internal.ast.ErrorCounter - throwQueryException() : no errors
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG org.hibernate.SQL - 
    select
        bank0_.bank_id as bank_id1_2_,
        bank0_.bank_active as bank_act2_2_,
        bank0_.bank_code as bank_cod3_2_,
        bank0_.bank_name as bank_nam4_2_,
        bank0_.contact_details_code as contact_5_2_,
        bank0_.effective_date as effectiv6_2_ 
    from
        bank bank0_ 
    where
        bank0_.bank_id in (
            ?
        )
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - [1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG org.hibernate.loader.Loader - Result set row: 0
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([bank_id1_2_] : [BIGINT]) - [1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG org.hibernate.loader.Loader - Result row: EntityKey[com.cav.spring.service.bank.entity.Bank#1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([bank_act2_2_] : [VARCHAR]) - [Y]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([bank_cod3_2_] : [VARCHAR]) - [NW100]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([bank_nam4_2_] : [VARCHAR]) - [Natwest]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([contact_5_2_] : [INTEGER]) - [1000]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([effectiv6_2_] : [TIMESTAMP]) - [2014-01-11 00:00:00.0]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [com.cav.spring.service.bank.entity.Bank#1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE org.hibernate.type.CollectionType - Created collection wrapper: [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.engine.internal.TwoPhaseLoad - Adding entity to second-level cache: [com.cav.spring.service.bank.entity.Bank#1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [com.cav.spring.service.bank.entity.Bank#1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.jpa.internal.EntityManagerImpl@2e558c32]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.e.t.internal.TransactionImpl - committing
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.s.jdbc.datasource.DataSourceUtils - Resetting read-only flag of JDBC Connection [ProxyConnection[PooledConnection[com.mysql.cj.jdbc.ConnectionImpl@75efa37b]]]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.c.p.AbstractLoadPlanBasedCollectionInitializer - Loading collection: [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG org.hibernate.SQL - 
    select
        accounts0_.bank_id as bank_id1_3_0_,
        accounts0_.account_id as account_2_3_0_,
        account1_.account_id as account_1_0_1_,
        account1_.account_active as account_2_0_1_,
        account1_.account_name as account_3_0_1_,
        account1_.effective_date as effectiv4_0_1_ 
    from
        bank_account accounts0_ 
    inner join
        account account1_ 
            on accounts0_.account_id=account1_.account_id 
    where
        accounts0_.bank_id=?
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - [1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.p.e.p.i.ResultSetProcessorImpl - Preparing collection intializer : [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.p.e.p.i.ResultSetProcessorImpl - Starting ResultSet row #0
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_1_0_1_] : [BIGINT]) - [12341]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_2_0_1_] : [VARCHAR]) - [null]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_3_0_1_] : [VARCHAR]) - [BlackRock]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([effectiv4_0_1_] : [TIMESTAMP]) - [2014-01-11 00:00:00.0]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([bank_id1_3_0_] : [BIGINT]) - [1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.p.e.p.i.CollectionReferenceInitializerImpl - Found row of collection: [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_2_3_0_] : [BIGINT]) - [12341]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.p.e.p.i.ResultSetProcessorImpl - Starting ResultSet row #1
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_1_0_1_] : [BIGINT]) - [12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_2_0_1_] : [VARCHAR]) - [null]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_3_0_1_] : [VARCHAR]) - [BlackRock]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([effectiv4_0_1_] : [TIMESTAMP]) - [2014-01-11 00:00:00.0]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([bank_id1_3_0_] : [BIGINT]) - [1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.p.e.p.i.CollectionReferenceInitializerImpl - Found row of collection: [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_2_3_0_] : [BIGINT]) - [12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [com.cav.spring.service.bank.entity.Account#12341]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE org.hibernate.type.CollectionType - Created collection wrapper: [com.cav.spring.service.bank.entity.Account.banks#12341]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE org.hibernate.type.CollectionType - Created collection wrapper: [com.cav.spring.service.bank.entity.Account.funds#12341]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.engine.internal.TwoPhaseLoad - Adding entity to second-level cache: [com.cav.spring.service.bank.entity.Account#12341]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [com.cav.spring.service.bank.entity.Account#12341]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [com.cav.spring.service.bank.entity.Account#12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE org.hibernate.type.CollectionType - Created collection wrapper: [com.cav.spring.service.bank.entity.Account.banks#12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE org.hibernate.type.CollectionType - Created collection wrapper: [com.cav.spring.service.bank.entity.Account.funds#12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.engine.internal.TwoPhaseLoad - Adding entity to second-level cache: [com.cav.spring.service.bank.entity.Account#12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [com.cav.spring.service.bank.entity.Account#12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.e.l.i.CollectionLoadContext - 1 collections were found in result set for role: com.cav.spring.service.bank.entity.Bank.accounts
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.e.l.i.CollectionLoadContext - Caching collection: [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.e.l.i.CollectionLoadContext - Collection fully initialized: [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.e.l.i.CollectionLoadContext - 1 collections initialized for role: com.cav.spring.service.bank.entity.Bank.accounts
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.r.j.i.ResourceRegistryStandardImpl - HHH000387: ResultSet's statement was not registered
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.c.p.AbstractLoadPlanBasedCollectionInitializer - Done loading collection
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.c.p.AbstractLoadPlanBasedCollectionInitializer - Loading collection: [com.cav.spring.service.bank.entity.Account.funds#12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG org.hibernate.SQL - 
    select
        funds0_.account_id as account_1_1_0_,
        funds0_.fund_id as fund_id2_1_0_,
        fund1_.fund_id as fund_id1_4_1_,
        fund1_.buy as buy2_4_1_,
        fund1_.effective_date as effectiv3_4_1_,
        fund1_.fund_name as fund_nam4_4_1_,
        fund1_.fund_time_stamp as fund_tim5_4_1_,
        fund1_.sell as sell6_4_1_,
        fund1_.yeild as yeild7_4_1_ 
    from
        account_fund funds0_ 
    inner join
        fund fund1_ 
            on funds0_.fund_id=fund1_.fund_id 
    where
        funds0_.account_id=?
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - [12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.p.e.p.i.ResultSetProcessorImpl - Preparing collection intializer : [com.cav.spring.service.bank.entity.Account.funds#12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.p.e.p.i.ResultSetProcessorImpl - Starting ResultSet row #0
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([fund_id1_4_1_] : [BIGINT]) - [123421]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([buy2_4_1_] : [NUMERIC]) - [10.2000]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([effectiv3_4_1_] : [TIMESTAMP]) - [2014-01-11 00:00:00.0]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([fund_nam4_4_1_] : [VARCHAR]) - [Imp]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([fund_tim5_4_1_] : [TIMESTAMP]) - [2019-01-14 14:35:29.0]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([sell6_4_1_] : [NUMERIC]) - [10.1000]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([yeild7_4_1_] : [FLOAT]) - [5.0]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_1_1_0_] : [BIGINT]) - [12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.p.e.p.i.CollectionReferenceInitializerImpl - Found row of collection: [com.cav.spring.service.bank.entity.Account.funds#12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([fund_id2_1_0_] : [BIGINT]) - [123421]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [com.cav.spring.service.bank.entity.Fund#123421]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE org.hibernate.type.CollectionType - Created collection wrapper: [com.cav.spring.service.bank.entity.Fund.accounts#123421]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.engine.internal.TwoPhaseLoad - Adding entity to second-level cache: [com.cav.spring.service.bank.entity.Fund#123421]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [com.cav.spring.service.bank.entity.Fund#123421]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.e.l.i.CollectionLoadContext - 1 collections were found in result set for role: com.cav.spring.service.bank.entity.Account.funds
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.e.l.i.CollectionLoadContext - Caching collection: [com.cav.spring.service.bank.entity.Account.funds#12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.e.l.i.CollectionLoadContext - Collection fully initialized: [com.cav.spring.service.bank.entity.Account.funds#12342]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.e.l.i.CollectionLoadContext - 1 collections initialized for role: com.cav.spring.service.bank.entity.Account.funds
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.r.j.i.ResourceRegistryStandardImpl - HHH000387: ResultSet's statement was not registered
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.c.p.AbstractLoadPlanBasedCollectionInitializer - Done loading collection
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.c.p.AbstractLoadPlanBasedCollectionInitializer - Loading collection: [com.cav.spring.service.bank.entity.Account.funds#12341]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG org.hibernate.SQL - 
    select
        funds0_.account_id as account_1_1_0_,
        funds0_.fund_id as fund_id2_1_0_,
        fund1_.fund_id as fund_id1_4_1_,
        fund1_.buy as buy2_4_1_,
        fund1_.effective_date as effectiv3_4_1_,
        fund1_.fund_name as fund_nam4_4_1_,
        fund1_.fund_time_stamp as fund_tim5_4_1_,
        fund1_.sell as sell6_4_1_,
        fund1_.yeild as yeild7_4_1_ 
    from
        account_fund funds0_ 
    inner join
        fund fund1_ 
            on funds0_.fund_id=fund1_.fund_id 
    where
        funds0_.account_id=?
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - [12341]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.p.e.p.i.ResultSetProcessorImpl - Preparing collection intializer : [com.cav.spring.service.bank.entity.Account.funds#12341]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.p.e.p.i.ResultSetProcessorImpl - Starting ResultSet row #0
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([fund_id1_4_1_] : [BIGINT]) - [123411]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([buy2_4_1_] : [NUMERIC]) - [10.2000]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([effectiv3_4_1_] : [TIMESTAMP]) - [2014-01-11 00:00:00.0]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([fund_nam4_4_1_] : [VARCHAR]) - [Imp]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([fund_tim5_4_1_] : [TIMESTAMP]) - [2019-01-14 09:42:46.0]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([sell6_4_1_] : [NUMERIC]) - [10.1000]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([yeild7_4_1_] : [FLOAT]) - [5.0]
2019-01-16 11:33:33 [http-nio-8080-exec-1] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_1_1_0_] : [BIGINT]) - [12341]
2019-01-16 11:33:33 [http-nio-8080-exec-1] DEBUG o.h.l.p.e.p.i.CollectionReferenceInitializerImpl - Found row of collection: [com.cav.spring.service.bank.entity.Account.funds#12341]

[Tony Evans]

This is the same request again for the same bank object, from reading the logs it doesnt look to me that its calling into eHcache, that its just running a staticSQL into the DB

2019-01-16 11:36:00 [http-nio-8080-exec-5] INFO  c.c.s.s.b.c.BankServiceController - Find Banks
2019-01-16 11:36:00 [http-nio-8080-exec-5] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.jpa.internal.EntityManagerImpl@1518374e] for JPA transaction
2019-01-16 11:36:00 [http-nio-8080-exec-5] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findAll]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly; ''
2019-01-16 11:36:00 [http-nio-8080-exec-5] DEBUG o.s.jdbc.datasource.DataSourceUtils - Setting JDBC Connection [ProxyConnection[PooledConnection[com.mysql.cj.jdbc.ConnectionImpl@75efa37b]]] read-only
2019-01-16 11:36:00 [http-nio-8080-exec-5] DEBUG o.h.e.t.internal.TransactionImpl - begin
2019-01-16 11:36:00 [http-nio-8080-exec-5] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@54253d75]
2019-01-16 11:36:00 [http-nio-8080-exec-5] DEBUG o.h.jpa.criteria.CriteriaQueryImpl - Rendered criteria query -> select generatedAlias0 from Bank as generatedAlias0 where generatedAlias0.bankId in (:param0)
2019-01-16 11:36:00 [http-nio-8080-exec-5] DEBUG org.hibernate.SQL - 
    select
        bank0_.bank_id as bank_id1_2_,
        bank0_.bank_active as bank_act2_2_,
        bank0_.bank_code as bank_cod3_2_,
        bank0_.bank_name as bank_nam4_2_,
        bank0_.contact_details_code as contact_5_2_,
        bank0_.effective_date as effectiv6_2_ 
    from
        bank bank0_ 
    where
        bank0_.bank_id in (
            ?
        )
2019-01-16 11:36:00 [http-nio-8080-exec-5] TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - [1234]
2019-01-16 11:36:00 [http-nio-8080-exec-5] DEBUG org.hibernate.loader.Loader - Result set row: 0
2019-01-16 11:36:00 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([bank_id1_2_] : [BIGINT]) - [1234]
2019-01-16 11:36:00 [http-nio-8080-exec-5] DEBUG org.hibernate.loader.Loader - Result row: EntityKey[com.cav.spring.service.bank.entity.Bank#1234]
2019-01-16 11:36:00 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([bank_act2_2_] : [VARCHAR]) - [Y]
2019-01-16 11:36:00 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([bank_cod3_2_] : [VARCHAR]) - [NW100]
2019-01-16 11:36:00 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([bank_nam4_2_] : [VARCHAR]) - [Natwest]
2019-01-16 11:36:00 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([contact_5_2_] : [INTEGER]) - [1000]
2019-01-16 11:36:00 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([effectiv6_2_] : [TIMESTAMP]) - [2014-01-11 00:00:00.0]
2019-01-16 11:36:00 [http-nio-8080-exec-5] DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [com.cav.spring.service.bank.entity.Bank#1234]
2019-01-16 11:36:00 [http-nio-8080-exec-5] TRACE org.hibernate.type.CollectionType - Created collection wrapper: [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.engine.internal.TwoPhaseLoad - Adding entity to second-level cache: [com.cav.spring.service.bank.entity.Bank#1234]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [com.cav.spring.service.bank.entity.Bank#1234]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.jpa.internal.EntityManagerImpl@1518374e]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.e.t.internal.TransactionImpl - committing
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.s.jdbc.datasource.DataSourceUtils - Resetting read-only flag of JDBC Connection [ProxyConnection[PooledConnection[com.mysql.cj.jdbc.ConnectionImpl@75efa37b]]]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.l.c.p.AbstractLoadPlanBasedCollectionInitializer - Loading collection: [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG org.hibernate.SQL - 
    select
        accounts0_.bank_id as bank_id1_3_0_,
        accounts0_.account_id as account_2_3_0_,
        account1_.account_id as account_1_0_1_,
        account1_.account_active as account_2_0_1_,
        account1_.account_name as account_3_0_1_,
        account1_.effective_date as effectiv4_0_1_ 
    from
        bank_account accounts0_ 
    inner join
        account account1_ 
            on accounts0_.account_id=account1_.account_id 
    where
        accounts0_.bank_id=?
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - [1234]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.l.p.e.p.i.ResultSetProcessorImpl - Preparing collection intializer : [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.l.p.e.p.i.ResultSetProcessorImpl - Starting ResultSet row #0
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_1_0_1_] : [BIGINT]) - [12341]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_2_0_1_] : [VARCHAR]) - [null]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_3_0_1_] : [VARCHAR]) - [BlackRock]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([effectiv4_0_1_] : [TIMESTAMP]) - [2014-01-11 00:00:00.0]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([bank_id1_3_0_] : [BIGINT]) - [1234]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.l.p.e.p.i.CollectionReferenceInitializerImpl - Found row of collection: [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_2_3_0_] : [BIGINT]) - [12341]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.l.p.e.p.i.ResultSetProcessorImpl - Starting ResultSet row #1
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_1_0_1_] : [BIGINT]) - [12342]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_2_0_1_] : [VARCHAR]) - [null]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_3_0_1_] : [VARCHAR]) - [BlackRock]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([effectiv4_0_1_] : [TIMESTAMP]) - [2014-01-11 00:00:00.0]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([bank_id1_3_0_] : [BIGINT]) - [1234]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.l.p.e.p.i.CollectionReferenceInitializerImpl - Found row of collection: [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_2_3_0_] : [BIGINT]) - [12342]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [com.cav.spring.service.bank.entity.Account#12341]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE org.hibernate.type.CollectionType - Created collection wrapper: [com.cav.spring.service.bank.entity.Account.banks#12341]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE org.hibernate.type.CollectionType - Created collection wrapper: [com.cav.spring.service.bank.entity.Account.funds#12341]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.engine.internal.TwoPhaseLoad - Adding entity to second-level cache: [com.cav.spring.service.bank.entity.Account#12341]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [com.cav.spring.service.bank.entity.Account#12341]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.engine.internal.TwoPhaseLoad - Resolving associations for [com.cav.spring.service.bank.entity.Account#12342]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE org.hibernate.type.CollectionType - Created collection wrapper: [com.cav.spring.service.bank.entity.Account.banks#12342]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE org.hibernate.type.CollectionType - Created collection wrapper: [com.cav.spring.service.bank.entity.Account.funds#12342]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.engine.internal.TwoPhaseLoad - Adding entity to second-level cache: [com.cav.spring.service.bank.entity.Account#12342]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.engine.internal.TwoPhaseLoad - Done materializing entity [com.cav.spring.service.bank.entity.Account#12342]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.e.l.i.CollectionLoadContext - 1 collections were found in result set for role: com.cav.spring.service.bank.entity.Bank.accounts
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.e.l.i.CollectionLoadContext - Caching collection: [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.e.l.i.CollectionLoadContext - Collection fully initialized: [com.cav.spring.service.bank.entity.Bank.accounts#1234]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.e.l.i.CollectionLoadContext - 1 collections initialized for role: com.cav.spring.service.bank.entity.Bank.accounts
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.r.j.i.ResourceRegistryStandardImpl - HHH000387: ResultSet's statement was not registered
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.l.c.p.AbstractLoadPlanBasedCollectionInitializer - Done loading collection
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.l.c.p.AbstractLoadPlanBasedCollectionInitializer - Loading collection: [com.cav.spring.service.bank.entity.Account.funds#12342]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG org.hibernate.SQL - 
    select
        funds0_.account_id as account_1_1_0_,
        funds0_.fund_id as fund_id2_1_0_,
        fund1_.fund_id as fund_id1_4_1_,
        fund1_.buy as buy2_4_1_,
        fund1_.effective_date as effectiv3_4_1_,
        fund1_.fund_name as fund_nam4_4_1_,
        fund1_.fund_time_stamp as fund_tim5_4_1_,
        fund1_.sell as sell6_4_1_,
        fund1_.yeild as yeild7_4_1_ 
    from
        account_fund funds0_ 
    inner join
        fund fund1_ 
            on funds0_.fund_id=fund1_.fund_id 
    where
        funds0_.account_id=?
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - [12342]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.l.p.e.p.i.ResultSetProcessorImpl - Preparing collection intializer : [com.cav.spring.service.bank.entity.Account.funds#12342]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.l.p.e.p.i.ResultSetProcessorImpl - Starting ResultSet row #0
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([fund_id1_4_1_] : [BIGINT]) - [123421]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([buy2_4_1_] : [NUMERIC]) - [10.2000]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([effectiv3_4_1_] : [TIMESTAMP]) - [2014-01-11 00:00:00.0]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([fund_nam4_4_1_] : [VARCHAR]) - [Imp]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([fund_tim5_4_1_] : [TIMESTAMP]) - [2019-01-14 14:35:29.0]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([sell6_4_1_] : [NUMERIC]) - [10.1000]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([yeild7_4_1_] : [FLOAT]) - [5.0]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([account_1_1_0_] : [BIGINT]) - [12342]
2019-01-16 11:36:01 [http-nio-8080-exec-5] DEBUG o.h.l.p.e.p.i.CollectionReferenceInitializerImpl - Found row of collection: [com.cav.spring.service.bank.entity.Account.funds#12342]
2019-01-16 11:36:01 [http-nio-8080-exec-5] TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([fund_id2_1_0_] : [BIGINT]) - [123421]

[Tony Evans]

I have set the ehcache.xml and it is being loaded. I just used a default one

@EnableCaching
@Configuration
public class EHCacheConfig {

	@Bean
    public EhCacheCacheManager ehCacheCacheManager() {
        EhCacheCacheManager cacheManager = new EhCacheCacheManager();
        cacheManager.setCacheManager(ehCacheManagerFactory().getObject());
        cacheManager.setTransactionAware(true);
        return cacheManager;
    }

    @Bean
    public EhCacheManagerFactoryBean ehCacheManagerFactory(){
        EhCacheManagerFactoryBean ehCacheBean = new EhCacheManagerFactoryBean();
        ehCacheBean.setConfigLocation(new ClassPathResource("ehcache.xml"));
        ehCacheBean.setShared(true);
        return ehCacheBean;
    }
}

<ehcache xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:noNameSpaceSchemaLocation="ehcache.xsd"
         updateCheck="true"
         monitoring="autodetect"
         dynamicConfig="true">

    <diskStore path="java.io.tmpdir"/>

   <defaultCache maxElementsInMemory="10000" eternal="false"
		timeToIdleSeconds="120" timeToLiveSeconds="120" overflowToDisk="false"
		maxElementsOnDisk="10000000" diskPersistent="false"
		diskExpiryThreadIntervalSeconds="120" memoryStoreEvictionPolicy="LRU" />
</ehcache>

n.s.e.config.ConfigurationFactory - Configuring ehcache from ehcache.xml found in the classpath: file:/C:/Users/user/workdev/SpringProj/SpringBootWebService/BankEhCacheJPAWebbService/target/classes/ehcache.xml
n.s.e.config.ConfigurationFactory - Configuring ehcache from URL: file:/C:/Users/user/workdev/SpringProj/SpringBootWebService/BankEhCacheJPAWebbService/target/classes/ehcache.xml
n.s.e.config.ConfigurationFactory - Configuring ehcache from InputStream
net.sf.ehcache.config.BeanHandler - Ignoring ehcache attribute xmlns:xsi
net.sf.ehcache.config.BeanHandler - Ignoring ehcache attribute xsi:noNameSpaceSchemaLocation
n.s.e.config.DiskStoreConfiguration - Disk Store Path: C:\Users\user\AppData\Local\Temp\
net.sf.ehcache.util.PropertyUtil - propertiesString is null.
n.s.e.config.ConfigurationHelper - No CacheManagerEventListenerFactory class specified. Skipping...
net.sf.ehcache.Cache - No BootstrapCacheLoaderFactory class specified. Skipping...
net.sf.ehcache.Cache - CacheWriter factory not configured. Skipping...
n.s.e.config.ConfigurationHelper - No CacheExceptionHandlerFactory class specified. Skipping...

I am not going to go through every Entity as it will overload the logging, but its the same for each one, so taking Bank

@Entity
@Cache(usage=CacheConcurrencyStrategy.READ_WRITE, region="bank")
@Table(name="Bank")
public class Bank {
	
	@Id
	@Column(name="BANK_ID")
	private long bankId;
	
	@Column(name="BANK_CODE")
	private String bankCode;
	
	@Column(name="BANK_NAME")
	private String bankName;
	
	@Column(name="CONTACT_DETAILS_CODE")
	private int contactDetailsCode;
	
	@Column(name="EFFECTIVE_DATE")
	private Date effectiveDate;
	
	@Column(name="BANK_ACTIVE")
	private String active;
	
	@org.hibernate.annotations.Cache(usage = CacheConcurrencyStrategy.READ_WRITE)
	@ManyToMany(cascade = { 
	        CascadeType.PERSIST, 
	        CascadeType.MERGE
	    })
	    @JoinTable(name = "BANK_ACCOUNT",
	        joinColumns = @JoinColumn(name = "BANK_ID"),
	        inverseJoinColumns = @JoinColumn(name = "ACCOUNT_ID")
	    )
	private Set<Account> accounts = new HashSet<Account>();

	public long getBankId() {
		return bankId;
	}

	public void setBankId(long bankId) {
		this.bankId = bankId;
	}

	public String getBankCode() {
		return bankCode;
	}

	public void setBankCode(String bankCode) {
		this.bankCode = bankCode;
	}

	public String getBankName() {
		return bankName;
	}

	public void setBankName(String bankName) {
		this.bankName = bankName;
	}

	public int getContactDetailsCode() {
		return contactDetailsCode;
	}

	public void setContactDetailsCode(int contactDetailsCode) {
		this.contactDetailsCode = contactDetailsCode;
	}
	
	

	public Date getEffectiveDate() {
		return effectiveDate;
	}

	public void setEffectiveDate(Date effectiveDate) {
		this.effectiveDate = effectiveDate;
	}

	public void setAccounts(Set<Account> accounts) {
		this.accounts = accounts;
	}

	public String getActive() {
		return active;
	}

	public void setActive(String active) {
		this.active = active;
	}

	public Set<Account> getAccounts() {
		return accounts;
	}

	public void setAccounts(Account account) {
		accounts.add(account);
		account.getBanks().add(this);
	}
	
	public void removeAccounts(Account account){
		accounts.remove(account);
		account.getBanks().remove(this);
    }

	@Override
	public int hashCode() {
		final int prime = 31;
		int result = 1;
		result = prime * result + ((active == null) ? 0 : active.hashCode());
		result = prime * result + ((bankCode == null) ? 0 : bankCode.hashCode());
		result = prime * result + (int) (bankId ^ (bankId >>> 32));
		result = prime * result + ((bankName == null) ? 0 : bankName.hashCode());
		result = prime * result + contactDetailsCode;
		result = prime * result + ((effectiveDate == null) ? 0 : effectiveDate.hashCode());
		return result;
	}

	@Override
	public boolean equals(Object obj) {
		if (this == obj)
			return true;
		if (obj == null)
			return false;
		if (getClass() != obj.getClass())
			return false;
		Bank other = (Bank) obj;
		if (active == null) {
			if (other.active != null)
				return false;
		} else if (!active.equals(other.active))
			return false;
		if (bankCode == null) {
			if (other.bankCode != null)
				return false;
		} else if (!bankCode.equals(other.bankCode))
			return false;
		if (bankId != other.bankId)
			return false;
		if (bankName == null) {
			if (other.bankName != null)
				return false;
		} else if (!bankName.equals(other.bankName))
			return false;
		if (contactDetailsCode != other.contactDetailsCode)
			return false;
		if (effectiveDate == null) {
			if (other.effectiveDate != null)
				return false;
		} else if (!effectiveDate.equals(other.effectiveDate))
			return false;
		return true;
	}

	@Override
	public String toString() {
		return "BankEntity [bankId=" + bankId + ", bankCode=" + bankCode + ", bankName=" + bankName
				+ ", contactDetailsCode=" + contactDetailsCode + ", effectiveDate=" + effectiveDate + ", active="
				+ active + "]";
	}
}

logging for setting it up in ehCache

2 WARN  o.h.c.e.AbstractEhcacheRegionFactory - HHH020003: Could not find a specific ehcache configuration for cache named [bank]; using defaults.
2 net.sf.ehcache.store.MemoryStore - Initialized net.sf.ehcache.store.MemoryStore for bank

1-16 11:32:39 [main] DEBUG net.sf.ehcache.Cache - Initialised cache: bank
2 n.s.e.config.ConfigurationHelper - CacheDecoratorFactory not configured for defaultCache. Skipping for 'bank'.
2 o.h.c.e.AbstractEhcacheRegionFactory - started EHCache region: bank
2 o.h.b.internal.ClassLoaderAccessImpl - Not known whether passed class name [com.cav.spring.service.bank.entity.Bank] is safe
2 o.h.b.internal.ClassLoaderAccessImpl - No temp ClassLoader provided; using live ClassLoader for loading potentially unsafe class : com.cav.spring.service.bank.entity.Bank
2 o.h.b.internal.ClassLoaderAccessImpl - Not known whether passed class name [com.cav.spring.service.bank.entity.Bank] is safe

2 o.h.b.internal.ClassLoaderAccessImpl - No temp ClassLoader provided; using live ClassLoader for loading potentially unsafe class : com.cav.spring.service.bank.entity.Bank

[Tim Holloway]

1-16 11:32:39 [main] DEBUG net.sf.ehcache.Cache - Initialised cache: bank
2 n.s.e.config.ConfigurationHelper - CacheDecoratorFactory 
  not configured for defaultCache. Skipping for 'bank'.

I believe this is your answer. You need to configure your defaultCache.

[Tony Evans]

Thanks, that might be the problem. Its funny none of the examples use CacheDecoratorFactory, as I understand it you set the Enity as a Cache, and its just supposed to create that in the cache, well thats the easy bit. There are also plenty of examples of using defaultcache, aagin none with a CacheDecoratorFactory set up. I will read up and see why I need to create a concrete object that extends CacheDecoratorFactory, and what its supposed to do. But this might be a red herring. But will close down each route,