SuccessConsole Output

Skipping 1,105 KB.. Full Log
pache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,269 WARN  [qtp307046058-2507][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,273 WARN  [qtp307046058-2495][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,287 WARN  [qtp307046058-2510][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,288 WARN  [qtp307046058-2499][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,291 WARN  [qtp307046058-2508][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,302 WARN  [qtp307046058-2472][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,304 WARN  [qtp307046058-2496][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,306 WARN  [qtp307046058-2476][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,306 WARN  [qtp307046058-2477][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,307 WARN  [qtp307046058-2475][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,312 WARN  [qtp307046058-2474][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,320 WARN  [qtp307046058-2498][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,323 WARN  [qtp307046058-2511][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,346 WARN  [qtp307046058-2507][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,347 WARN  [qtp307046058-2500][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,348 WARN  [qtp307046058-2495][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,351 WARN  [qtp307046058-2497][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,361 WARN  [qtp307046058-2499][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,365 WARN  [qtp307046058-2510][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,368 WARN  [qtp307046058-2474][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,377 WARN  [qtp307046058-2476][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,382 WARN  [qtp307046058-2498][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,384 WARN  [qtp307046058-2508][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,387 WARN  [qtp307046058-2475][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,389 WARN  [qtp307046058-2496][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,396 WARN  [qtp307046058-2472][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,406 WARN  [qtp307046058-2477][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,408 WARN  [qtp307046058-2507][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,419 WARN  [qtp307046058-2500][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,422 WARN  [qtp307046058-2497][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,423 WARN  [qtp307046058-2511][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,423 WARN  [qtp307046058-2510][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,439 WARN  [qtp307046058-2499][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,443 WARN  [qtp307046058-2495][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,445 WARN  [qtp307046058-2498][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,455 WARN  [qtp307046058-2508][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,458 WARN  [qtp307046058-2477][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,464 WARN  [qtp307046058-2472][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,466 WARN  [qtp307046058-2474][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,468 WARN  [qtp307046058-2476][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,475 WARN  [qtp307046058-2475][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,477 WARN  [qtp307046058-2496][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,478 WARN  [qtp307046058-2507][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,499 WARN  [qtp307046058-2510][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,506 WARN  [qtp307046058-2497][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,507 WARN  [qtp307046058-2500][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,514 WARN  [qtp307046058-2511][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,515 WARN  [qtp307046058-2499][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,521 WARN  [qtp307046058-2508][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,522 WARN  [qtp307046058-2495][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,537 WARN  [qtp307046058-2472][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,538 WARN  [qtp307046058-2475][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,545 WARN  [qtp307046058-2498][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,549 WARN  [qtp307046058-2477][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,557 WARN  [qtp307046058-2476][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,560 WARN  [qtp307046058-2496][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,561 WARN  [qtp307046058-2474][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,570 WARN  [qtp307046058-2511][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,573 WARN  [qtp307046058-2510][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,574 WARN  [qtp307046058-2507][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,581 WARN  [qtp307046058-2508][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,583 WARN  [qtp307046058-2500][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,587 WARN  [qtp307046058-2499][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,597 WARN  [qtp307046058-2472][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,598 WARN  [qtp307046058-2497][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,608 WARN  [qtp307046058-2495][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,609 WARN  [qtp307046058-2477][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,615 WARN  [qtp307046058-2475][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,630 WARN  [qtp307046058-2498][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,643 WARN  [qtp307046058-2507][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,644 WARN  [qtp307046058-2476][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,647 WARN  [qtp307046058-2496][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,651 WARN  [qtp307046058-2474][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,660 WARN  [qtp307046058-2508][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,662 WARN  [qtp307046058-2472][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,663 WARN  [qtp307046058-2499][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,669 WARN  [qtp307046058-2511][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,671 WARN  [qtp307046058-2500][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,673 WARN  [qtp307046058-2510][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,677 WARN  [qtp307046058-2495][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,683 WARN  [qtp307046058-2477][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,684 WARN  [qtp307046058-2475][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,688 WARN  [qtp307046058-2498][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,703 WARN  [qtp307046058-2497][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,704 WARN  [qtp307046058-2476][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,715 WARN  [qtp307046058-2508][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,716 WARN  [qtp307046058-2499][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,723 WARN  [qtp307046058-2472][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,725 WARN  [qtp307046058-2496][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,729 WARN  [qtp307046058-2500][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,732 WARN  [qtp307046058-2507][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,734 WARN  [qtp307046058-2495][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,743 WARN  [qtp307046058-2498][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,744 WARN  [qtp307046058-2475][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,744 WARN  [qtp307046058-2511][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,746 WARN  [qtp307046058-2474][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,752 WARN  [qtp307046058-2477][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,758 WARN  [qtp307046058-2510][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,765 WARN  [qtp307046058-2476][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,774 WARN  [qtp307046058-2499][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,775 WARN  [qtp307046058-2497][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,795 WARN  [qtp307046058-2508][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,796 WARN  [qtp307046058-2495][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,797 WARN  [qtp307046058-2472][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,801 WARN  [qtp307046058-2500][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,802 WARN  [qtp307046058-2475][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,809 WARN  [qtp307046058-2474][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,810 WARN  [qtp307046058-2511][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,812 WARN  [qtp307046058-2507][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,817 WARN  [qtp307046058-2498][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,820 WARN  [qtp307046058-2477][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,821 WARN  [qtp307046058-2496][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,826 WARN  [qtp307046058-2499][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,828 WARN  [qtp307046058-2497][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:45,828 DEBUG [CryptoCache][CryptoCache$CleanupTask] run: entered
10:06:45,828 INFO  [CryptoCache][CryptoCache$CleanupTask] run: CryptoCache was garbage-collected. Cancelling this TimerTask.
10:06:45,848 WARN  [qtp307046058-2510][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDODataStoreException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
NestedThrowables:
java.sql.SQLException: org.apache.derby.jdbc.EmbeddedDriver is not registered with the JDBC driver manager
10:06:46,283 DEBUG [qtp307046058-2475][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: Returning request: null
10:06:46,289 DEBUG [Thread-12][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:06:46,300 DEBUG [qtp307046058-2512][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:06:46,317 DEBUG [qtp307046058-2512][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: Entered.
10:06:46,565 DEBUG [KeyStore][KeyStore$ExipreCacheEntryTimerTask] run: 1 users left in cache.
10:06:46,701 DEBUG [KeyStore][KeyStore$ExipreCacheEntryTimerTask] run: 1 users left in cache.
10:06:46,748 DEBUG [SessionManager][SessionManager$ExpireSessionTimerTask] run: 1 sessions left.
10:06:48,995 DEBUG [qtp307046058-2472][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: Returning request: null
10:06:48,997 DEBUG [Thread-3][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:06:49,000 DEBUG [qtp307046058-2472][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:06:49,003 DEBUG [qtp307046058-2472][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: Entered.
10:06:49,039 DEBUG [qtp307046058-2499][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: Returning request: null
10:06:49,042 DEBUG [Thread-5][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:06:49,048 DEBUG [qtp307046058-2475][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:06:49,052 DEBUG [qtp307046058-2475][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: Entered.
10:06:49,110 DEBUG [qtp307046058-2496][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: Returning request: null
10:06:49,112 DEBUG [qtp307046058-2477][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: Returning request: null
10:06:49,114 DEBUG [qtp307046058-2495][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: Returning request: null
10:06:49,114 DEBUG [Thread-4][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:06:49,118 DEBUG [Thread-9][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:06:49,121 DEBUG [qtp307046058-2499][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:06:49,123 DEBUG [Thread-2][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:06:49,128 DEBUG [qtp307046058-2499][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: Entered.
10:06:49,131 DEBUG [qtp307046058-2495][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:06:49,134 DEBUG [qtp307046058-2496][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:06:49,139 DEBUG [qtp307046058-2496][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: Entered.
10:06:49,139 DEBUG [qtp307046058-2495][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: Entered.
10:06:49,157 DEBUG [qtp307046058-2500][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: Returning request: null
10:06:49,161 DEBUG [Thread-10][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:06:49,167 DEBUG [qtp307046058-2477][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:06:49,171 DEBUG [qtp307046058-2477][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: Entered.
10:06:59,561 DEBUG [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: entered
10:07:08,732 INFO  [qtp307046058-2509][Cumulus4jStoreManager] ====================== Cumulus4j ======================
10:07:08,732 INFO  [qtp307046058-2509][Cumulus4jStoreManager] Bundle: org.cumulus4j.store - Version: 1.2.1.SNAPSHOT
10:07:08,732 INFO  [qtp307046058-2509][Cumulus4jStoreManager] =======================================================
10:07:08,734 ERROR [qtp307046058-2509][Persistence] java.lang.reflect.InvocationTargetException
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
	at org.datanucleus.plugin.NonManagedPluginRegistry.createExecutableExtension(NonManagedPluginRegistry.java:631)
	at org.datanucleus.plugin.PluginManager.createExecutableExtension(PluginManager.java:301)
	at org.datanucleus.NucleusContext.initialiseAutoStart(NucleusContext.java:432)
	at org.datanucleus.NucleusContext.initialise(NucleusContext.java:384)
	at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:768)
	at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:326)
	at org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:195)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at javax.jdo.JDOHelper$16.run(JDOHelper.java:1970)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.jdo.JDOHelper.invoke(JDOHelper.java:1965)
	at javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1171)
	at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:813)
	at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
	at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManagerFactory(TestService.java:59)
	at org.cumulus4j.integrationtest.webapp.TestService.getPersistenceManager(TestService.java:72)
	at org.cumulus4j.integrationtest.webapp.TestService.testPost(TestService.java:93)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
	at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)
	at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
	at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:288)
	at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
	at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
	at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
	at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1469)
	at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1400)
	at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1349)
	at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1339)
	at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)
	at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:537)
	at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:699)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:546)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1283)
	at org.cumulus4j.keymanager.back.shared.AjaxHeadersFilter.doFilter(AjaxHeadersFilter.java:33)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1254)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:481)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:516)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:230)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:956)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:411)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:188)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:891)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:151)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:114)
	at org.eclipse.jetty.server.Server.handle(Server.java:353)
	at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:598)
	at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1059)
	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:590)
	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212)
	at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:427)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:510)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access$000(SelectChannelEndPoint.java:34)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:450)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.ClassCastException: org.cumulus4j.store.Cumulus4jStoreManager cannot be cast to org.datanucleus.store.rdbms.RDBMSStoreManager
	at org.datanucleus.store.rdbms.autostart.SchemaAutoStarter.<init>(SchemaAutoStarter.java:68)
	... 70 more

10:07:08,735 DEBUG [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: begin loading. class=org.cumulus4j.store.test.movie.Movie
10:07:08,737 INFO  [qtp307046058-2509][AbstractCryptoManager] getCryptoSessionExpiryTimerPeriod: Property 'cumulus4j.cryptoSessionExpiryTimer.period' is not set. Using default value 60000.
10:07:08,737 TRACE [qtp307046058-2509][AbstractCryptoSession] setCryptoSessionID: cryptoSessionID=test-8362680472692879091_k39lp45d*1*0q9pd0
10:07:08,737 INFO  [qtp307046058-2509][AbstractCryptoManager] getCryptoSessionExpiryAgeMSec: Property 'cumulus4j.cryptoSessionExpiryAge' is not set. Using default value 1800000.
10:07:09,329 INFO  [qtp307046058-2509][MinimumCumulus4jVersion] version=10100001
10:07:10,013 INFO  [qtp307046058-2509][MinimumCumulus4jVersion] version=10100001
10:07:10,014 DEBUG [qtp307046058-2509][RecreateIndex] deleteIndex: Entered.
10:07:10,221 DEBUG [qtp307046058-2509][RecreateIndex] deleteIndex: There are no IndexEntry instances in the database => quit.
10:07:10,221 DEBUG [qtp307046058-2509][RecreateIndex] deleteIndex: Leaving.
10:07:10,272 DEBUG [qtp307046058-2509][Cumulus4jStoreManager] registerClass: clazz=org.cumulus4j.store.test.movie.Movie
10:07:10,291 DEBUG [qtp307046058-2509][ClassMeta] jdoPreStore: org.cumulus4j.store.model.ClassMeta@60ac8a02[null,org.cumulus4j.store.test.movie.Movie]
10:07:10,300 DEBUG [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta == null => populating. this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,316 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@a53e0f9[null,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,326 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,326 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@a53e0f9[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,340 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@a53e0f9[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,340 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@a53e0f9[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,340 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@a53e0f9[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,341 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@32501c61[null,org.cumulus4j.store.test.movie.Movie#directedBy[collectionElement]]
10:07:10,343 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@32501c61[2,org.cumulus4j.store.test.movie.Movie#directedBy[collectionElement]]
10:07:10,344 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@a53e0f9[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,344 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,344 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@580afdbd[null,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,346 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,346 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@580afdbd[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,347 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@580afdbd[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,347 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@580afdbd[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,347 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@580afdbd[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,348 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@565e4c29[null,org.cumulus4j.store.test.movie.Movie#languages[collectionElement]]
10:07:10,350 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@565e4c29[4,org.cumulus4j.store.test.movie.Movie#languages[collectionElement]]
10:07:10,352 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@580afdbd[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,352 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,353 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@2c069986[null,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
10:07:10,355 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,355 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@2c069986[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
10:07:10,356 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2c069986[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
10:07:10,356 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,356 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@70aadb97[null,org.cumulus4j.store.test.movie.Movie#name[primary]]
10:07:10,359 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,359 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@70aadb97[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
10:07:10,360 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@70aadb97[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
10:07:10,360 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,360 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@2f36f01b[null,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,363 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,363 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@2f36f01b[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,364 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2f36f01b[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,364 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2f36f01b[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,364 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2f36f01b[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,365 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@691e343e[null,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
10:07:10,367 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@691e343e[8,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
10:07:10,368 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2f36f01b[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,368 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,369 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@708dd8f3[null,org.cumulus4j.store.test.movie.Movie#rating[primary]]
10:07:10,371 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,371 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@708dd8f3[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
10:07:10,372 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@708dd8f3[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
10:07:10,372 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,373 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@52a209ec[null,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,376 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,376 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@52a209ec[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,377 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@52a209ec[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,377 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@52a209ec[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,377 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@52a209ec[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,378 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@f53df2c[null,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
10:07:10,380 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@f53df2c[11,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
10:07:10,381 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@52a209ec[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,382 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,382 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@1f0d50ea[null,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
10:07:10,385 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,385 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@1f0d50ea[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
10:07:10,386 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1f0d50ea[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
10:07:10,386 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,387 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@6bd02d56[null,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,389 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,389 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@6bd02d56[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,390 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@6bd02d56[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,390 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@6bd02d56[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,390 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@6bd02d56[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,391 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@1a2541c3[null,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
10:07:10,393 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@1a2541c3[14,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
10:07:10,394 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@6bd02d56[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,394 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,395 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@a53e0f9[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,395 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@580afdbd[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,395 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2c069986[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
10:07:10,395 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@70aadb97[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
10:07:10,395 DEBUG [qtp307046058-2509][FieldMeta] getEmbeddedClassMeta: this.embeddedClassMetaLoaded == false => loading. this=org.cumulus4j.store.model.FieldMeta@70aadb97[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
10:07:10,417 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2f36f01b[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,417 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@708dd8f3[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
10:07:10,417 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@52a209ec[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,417 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1f0d50ea[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
10:07:10,417 DEBUG [qtp307046058-2509][FieldMeta] getEmbeddedClassMeta: this.embeddedClassMetaLoaded == false => loading. this=org.cumulus4j.store.model.FieldMeta@1f0d50ea[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
10:07:10,420 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@6bd02d56[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,420 DEBUG [qtp307046058-2509][ClassMeta] jdoPostDetach: attached=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,420 DEBUG [qtp307046058-2509][ClassMeta] jdoPostDetach: Detaching this.fieldName2FieldMeta: attached=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,421 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@60ac8a02[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,421 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@2c069986[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
10:07:10,421 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@2c069986[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
10:07:10,421 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2c069986[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
10:07:10,421 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@2c069986[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
10:07:10,421 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@1f0d50ea[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
10:07:10,422 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@1f0d50ea[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
10:07:10,422 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1f0d50ea[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
10:07:10,422 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@1f0d50ea[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
10:07:10,422 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@580afdbd[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,422 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@580afdbd[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,423 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@580afdbd[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,423 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@565e4c29[4,org.cumulus4j.store.test.movie.Movie#languages[collectionElement]]
10:07:10,423 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@565e4c29[4,org.cumulus4j.store.test.movie.Movie#languages[collectionElement]]
10:07:10,423 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@565e4c29[4,org.cumulus4j.store.test.movie.Movie#languages[collectionElement]]
10:07:10,423 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@565e4c29[4,org.cumulus4j.store.test.movie.Movie#languages[collectionElement]]
10:07:10,423 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@580afdbd[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,423 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@2f36f01b[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,424 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@2f36f01b[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,424 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2f36f01b[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,424 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@691e343e[8,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
10:07:10,424 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@691e343e[8,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
10:07:10,424 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@691e343e[8,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
10:07:10,424 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@691e343e[8,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
10:07:10,424 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@2f36f01b[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,424 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@70aadb97[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
10:07:10,424 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@70aadb97[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
10:07:10,425 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@70aadb97[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
10:07:10,425 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@70aadb97[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
10:07:10,425 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@a53e0f9[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,425 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@a53e0f9[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,425 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@a53e0f9[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,426 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@32501c61[2,org.cumulus4j.store.test.movie.Movie#directedBy[collectionElement]]
10:07:10,426 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@32501c61[2,org.cumulus4j.store.test.movie.Movie#directedBy[collectionElement]]
10:07:10,426 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@32501c61[2,org.cumulus4j.store.test.movie.Movie#directedBy[collectionElement]]
10:07:10,426 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@32501c61[2,org.cumulus4j.store.test.movie.Movie#directedBy[collectionElement]]
10:07:10,426 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@a53e0f9[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,426 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@708dd8f3[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
10:07:10,426 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@708dd8f3[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
10:07:10,426 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@708dd8f3[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
10:07:10,427 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@708dd8f3[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
10:07:10,427 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@52a209ec[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,427 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@52a209ec[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,427 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@52a209ec[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,427 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@f53df2c[11,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
10:07:10,427 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@f53df2c[11,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
10:07:10,427 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@f53df2c[11,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
10:07:10,427 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@f53df2c[11,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
10:07:10,427 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@52a209ec[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,428 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@6bd02d56[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,428 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@6bd02d56[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,428 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@6bd02d56[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,428 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@1a2541c3[14,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
10:07:10,428 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@1a2541c3[14,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
10:07:10,428 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1a2541c3[14,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
10:07:10,428 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@1a2541c3[14,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
10:07:10,428 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@6bd02d56[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,431 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,431 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@7273936a[5,org.cumulus4j.store.test.movie.Movie#movieID[primary]]
10:07:10,431 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1d34eda[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,431 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@57ddcb25[4,org.cumulus4j.store.test.movie.Movie#languages[collectionElement]]
10:07:10,431 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@244f687f[12,org.cumulus4j.store.test.movie.Movie#tagLine[primary]]
10:07:10,431 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@59557c78[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,433 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@3526e9ad[8,org.cumulus4j.store.test.movie.Movie#producedBy[collectionElement]]
10:07:10,433 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@45d0c44f[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,434 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@d084258[2,org.cumulus4j.store.test.movie.Movie#directedBy[collectionElement]]
10:07:10,434 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@193ba617[6,org.cumulus4j.store.test.movie.Movie#name[primary]]
10:07:10,434 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1b153cf2[9,org.cumulus4j.store.test.movie.Movie#rating[primary]]
10:07:10,434 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@f5441c2[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,434 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@64a92f6a[11,org.cumulus4j.store.test.movie.Movie#starring[collectionElement]]
10:07:10,434 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1f680bc7[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,434 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@67dd45ec[14,org.cumulus4j.store.test.movie.Movie#writtenBy[collectionElement]]
10:07:10,434 DEBUG [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: end loading (took 1698 ms). class=org.cumulus4j.store.test.movie.Movie
10:07:10,451 TRACE [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
10:07:10,451 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=8 value=[]
10:07:10,451 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,451 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1f680bc7[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:10,451 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,451 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=6 value=[]
10:07:10,451 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,451 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@f5441c2[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:10,452 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=5 value=null
10:07:10,452 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,452 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=4 value=[]
10:07:10,452 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,452 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@59557c78[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:10,452 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,452 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,452 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=1 value=[]
10:07:10,452 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,452 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1d34eda[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:10,452 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=0 value=[]
10:07:10,452 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:10,453 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@45d0c44f[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:10,453 TRACE [qtp307046058-2509][Cumulus4jPersistenceHandler] insertObject: Created new DataEntry for: 1
10:07:10,453 INFO  [qtp307046058-2509][AbstractCryptoManager] getEncryptionAlgorithm: Property 'cumulus4j.encryptionAlgorithm' is not set. Using default algorithm 'Twofish/GCM/NoPadding'.
10:07:10,453 INFO  [qtp307046058-2509][AbstractCryptoManager] getMACAlgorithm: Property 'cumulus4j.macAlgorithm' is not set. Using default MAC algorithm 'NONE'.
10:07:15,915 DEBUG [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: entered
10:07:15,916 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
10:07:17,513 DEBUG [KeyStore][KeyStore$ExipreCacheEntryTimerTask] run: 1 users left in cache.
10:07:18,945 INFO  [SessionManager][SessionManager$ExpireSessionTimerTask] run: Expiring session: userName='marco' cryptoSessionID='test-i18yq8kz--ky3icz362hn7_kc4m35v2*1*0ir4pf'.
10:07:18,946 DEBUG [SessionManager][CachedMasterKey] clear: Clearing for userName='marco'.
10:07:18,946 DEBUG [SessionManager][MasterKey] clear: Clearing org.cumulus4j.keystore.MasterKey@c08adbb
10:07:18,946 DEBUG [SessionManager][Session] destroy: Destroying session for userName='marco' cryptoSessionID='test-i18yq8kz--ky3icz362hn7_kc4m35v2*1*0ir4pf'.
10:07:18,947 DEBUG [SessionManager][SessionManager$ExpireSessionTimerTask] run: 0 sessions left.
10:07:19,690 DEBUG [CryptoCache][CryptoCache$CleanupTask] run: entered
10:07:19,690 INFO  [CryptoCache][CryptoCache] getCryptoCacheEntryExpiryAgeMSec: Property 'cumulus4j.CryptoCache.entryExpiryAge' cannot be read, because NucleusContext was garbage-collected. Using fallback value 300000.
10:07:19,690 DEBUG [CryptoCache][CryptoCache] removeExpiredEntries: Removed 0 instances of CryptoCacheKeyEncryptionKeyEntry (1 left).
10:07:19,690 DEBUG [CryptoCache][CryptoCache] removeExpiredEntries: Removed 0 instances of CryptoCacheKeyDecrypterEntry (1 left).
10:07:19,690 DEBUG [CryptoCache][CryptoCache] removeExpiredEntries: Removed 0 instances of CryptoCacheKeyEntry (1 left).
10:07:19,690 DEBUG [CryptoCache][CryptoCache] removeExpiredEntries: Removed 0 instances of CryptoCacheCipherEntry (2 left).
10:07:19,690 DEBUG [CryptoCache][CryptoCache] removeExpiredEntries: Removed 0 instances of empty List<CryptoCacheCipherEntry> (2 non-empty lists left).
10:07:22,799 DEBUG [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: entered
10:07:22,799 INFO  [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: AbstractCryptoManager was garbage-collected. Cancelling this TimerTask.
10:07:28,505 DEBUG [AbstractCryptoManager][AbstractCryptoManager$CloseExpiredSessionsTask] run: entered
10:07:28,677 DEBUG [CryptoCache][CryptoCache$CleanupTask] run: entered
10:07:28,677 INFO  [CryptoCache][CryptoCache] getCryptoCacheEntryExpiryAgeMSec: Property 'cumulus4j.CryptoCache.entryExpiryAge' is not set. Using default value 1800000.
10:07:28,677 DEBUG [CryptoCache][CryptoCache] removeExpiredEntries: Removed 0 instances of CryptoCacheKeyEncryptionKeyEntry (1 left).
10:07:28,677 DEBUG [CryptoCache][CryptoCache] removeExpiredEntries: Removed 0 instances of CryptoCacheKeyDecrypterEntry (1 left).
10:07:28,677 DEBUG [CryptoCache][CryptoCache] removeExpiredEntries: Removed 0 instances of CryptoCacheKeyEntry (1 left).
10:07:28,677 DEBUG [CryptoCache][CryptoCache] removeExpiredEntries: Removed 0 instances of CryptoCacheCipherEntry (2 left).
10:07:28,677 DEBUG [CryptoCache][CryptoCache] removeExpiredEntries: Removed 0 instances of empty List<CryptoCacheCipherEntry> (2 non-empty lists left).
10:07:37,249 DEBUG [qtp307046058-2507][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: Returning request: null
10:07:37,255 DEBUG [Thread-11][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:07:37,259 DEBUG [qtp307046058-2517][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:07:37,263 DEBUG [qtp307046058-2517][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: Entered.
10:07:37,673 DEBUG [qtp307046058-2474][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: Returning request: null
10:07:37,675 DEBUG [Thread-8][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:07:37,682 DEBUG [qtp307046058-2507][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:07:37,685 DEBUG [qtp307046058-2507][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: Entered.
10:07:38,344 DEBUG [KeyStore][KeyStore$ExipreCacheEntryTimerTask] run: 1 users left in cache.
10:07:38,386 DEBUG [SessionManager][SessionManager$ExpireSessionTimerTask] run: 1 sessions left.
10:07:39,006 DEBUG [qtp307046058-2476][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: Returning request: null
10:07:39,010 DEBUG [Thread-15][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:07:39,017 DEBUG [qtp307046058-2474][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:07:39,021 DEBUG [qtp307046058-2474][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: Entered.
10:07:39,043 DEBUG [qtp307046058-2497][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: Returning request: null
10:07:39,046 DEBUG [Thread-13][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:07:39,050 DEBUG [qtp307046058-2497][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:07:39,055 DEBUG [qtp307046058-2497][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: Entered.
10:07:39,972 DEBUG [qtp307046058-2508][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: Returning request: null
10:07:39,976 DEBUG [Thread-17][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:07:39,973 DEBUG [qtp307046058-2511][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: Returning request: null
10:07:39,983 DEBUG [qtp307046058-2508][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:07:39,983 DEBUG [qtp307046058-2476][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:07:39,985 DEBUG [qtp307046058-2508][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: Entered.
10:07:39,986 DEBUG [qtp307046058-2476][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: Entered.
10:07:39,980 DEBUG [Thread-16][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:07:40,027 DEBUG [qtp307046058-2510][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: Returning request: null
10:07:40,030 DEBUG [Thread-14][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:07:40,033 DEBUG [qtp307046058-2511][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:07:40,036 DEBUG [qtp307046058-2511][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: Entered.
10:07:44,979 DEBUG [qtp307046058-2498][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: Returning request: null
10:07:44,983 DEBUG [Thread-6][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:07:44,986 DEBUG [qtp307046058-2510][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:07:44,988 DEBUG [qtp307046058-2510][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18yq8kz--ky3icz362hn7_kc4m35v2]: Entered.
10:07:45,542 INFO  [qtp307046058-2509][CryptoCache] Persistence property 'cumulus4j.CryptoCache.cleanupTimer.period' is not set. Using default value 60000.
10:07:45,543 DEBUG [qtp307046058-2509][MessageBrokerPMF] [eof9fu] _query[requestID=091swh1y5y49rbt9x60rc188a]: Entered with request: org.cumulus4j.keymanager.back.shared.GetActiveEncryptionKeyRequest@bf993131[091swh1y5y49rbt9x60rc188a,test-8362680472692879091_k39lp45d*1*0q9pd0]
10:07:45,593 DEBUG [qtp307046058-2509][MessageBrokerPMF] [eof9fu] _query[requestID=091swh1y5y49rbt9x60rc188a]: Request persisted.
10:07:45,648 DEBUG [qtp307046058-2476][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: Returning request: org.cumulus4j.keymanager.back.shared.GetActiveEncryptionKeyRequest@bf993131[091swh1y5y49rbt9x60rc188a,test-8362680472692879091_k39lp45d*1*0q9pd0]
10:07:45,648 ERROR [qtp307046058-2497][Persistence] Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@3bf654de" (id="091swh1y5y49rbt9x60rc188a") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
10:07:45,648 DEBUG [qtp307046058-2476][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.GetActiveEncryptionKeyRequest matching=true
10:07:45,649 WARN  [qtp307046058-2497][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDOOptimisticVerificationException: Transaction failed to commit
NestedThrowables:
javax.jdo.JDOOptimisticVerificationException: Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@3bf654de" (id="091swh1y5y49rbt9x60rc188a") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
FailedObject:org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@bf993131
10:07:45,651 DEBUG [Thread-16][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Request matching=true
10:07:45,656 ERROR [qtp307046058-2511][Persistence] Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@3cb9161f" (id="091swh1y5y49rbt9x60rc188a") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
10:07:45,663 WARN  [qtp307046058-2511][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDOOptimisticVerificationException: Transaction failed to commit
NestedThrowables:
javax.jdo.JDOOptimisticVerificationException: Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@3cb9161f" (id="091swh1y5y49rbt9x60rc188a") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
FailedObject:org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@bf993131
10:07:45,663 ERROR [qtp307046058-2508][Persistence] Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@3d164e67" (id="091swh1y5y49rbt9x60rc188a") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
10:07:45,664 WARN  [qtp307046058-2508][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: javax.jdo.JDOOptimisticVerificationException: Transaction failed to commit
NestedThrowables:
javax.jdo.JDOOptimisticVerificationException: Object "org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@3d164e67" (id="091swh1y5y49rbt9x60rc188a") has been changed in the datastore since your last read. Your transaction is using version "1" but this doesnt exist in the datastore now
FailedObject:org.cumulus4j.store.crypto.keymanager.messagebroker.pmf.PendingRequest@bf993131
10:07:45,667 DEBUG [Thread-16][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.GetActiveEncryptionKeyResponse matching=true
10:07:45,671 DEBUG [qtp307046058-2498][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:07:45,675 DEBUG [qtp307046058-2498][MessageBrokerPMF] [eof9fu] _pushResponse[requestID=091swh1y5y49rbt9x60rc188a]: Entered.
10:07:45,737 DEBUG [qtp307046058-2498][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-8362680472692879091_k39lp45d]: Entered.
10:07:46,054 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Created new Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with key and IV.
10:07:46,055 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,064 TRACE [qtp307046058-2509][Cumulus4jPersistenceHandler] insertObject: Persisted new non-embedded DataEntry for: 1
10:07:46,065 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,065 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,065 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@45d0c44f[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:46,082 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,083 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,092 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1d34eda[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:46,095 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,096 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,115 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,116 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,142 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,143 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,152 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@59557c78[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:46,155 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,156 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,158 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@f5441c2[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:46,162 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,163 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,165 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1f680bc7[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:46,169 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,169 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,173 DEBUG [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: begin loading. class=org.cumulus4j.store.test.movie.Rating
10:07:46,173 DEBUG [qtp307046058-2509][Cumulus4jStoreManager] registerClass: clazz=org.cumulus4j.store.test.movie.Rating
10:07:46,176 DEBUG [qtp307046058-2509][ClassMeta] jdoPreStore: org.cumulus4j.store.model.ClassMeta@2a4fbdd2[null,org.cumulus4j.store.test.movie.Rating]
10:07:46,178 DEBUG [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta == null => populating. this=org.cumulus4j.store.model.ClassMeta@2a4fbdd2[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,179 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@4b67601b[null,org.cumulus4j.store.test.movie.Rating#name[primary]]
10:07:46,181 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@2a4fbdd2[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,182 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@4b67601b[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
10:07:46,183 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@4b67601b[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
10:07:46,183 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@2a4fbdd2[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,183 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@645783be[null,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
10:07:46,186 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@2a4fbdd2[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,186 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@645783be[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
10:07:46,188 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@645783be[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
10:07:46,188 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@2a4fbdd2[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,189 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@4b67601b[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
10:07:46,189 DEBUG [qtp307046058-2509][FieldMeta] getEmbeddedClassMeta: this.embeddedClassMetaLoaded == false => loading. this=org.cumulus4j.store.model.FieldMeta@4b67601b[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
10:07:46,191 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@645783be[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
10:07:46,192 DEBUG [qtp307046058-2509][ClassMeta] jdoPostDetach: attached=org.cumulus4j.store.model.ClassMeta@2a4fbdd2[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,192 DEBUG [qtp307046058-2509][ClassMeta] jdoPostDetach: Detaching this.fieldName2FieldMeta: attached=org.cumulus4j.store.model.ClassMeta@2a4fbdd2[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,192 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@2a4fbdd2[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,192 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@645783be[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
10:07:46,192 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@645783be[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
10:07:46,192 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@645783be[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
10:07:46,193 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@645783be[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
10:07:46,193 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@4b67601b[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
10:07:46,193 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@4b67601b[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
10:07:46,193 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@4b67601b[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
10:07:46,193 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@4b67601b[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
10:07:46,193 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6dfb9bab[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,193 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@21a92ff6[16,org.cumulus4j.store.test.movie.Rating#ratingID[primary]]
10:07:46,193 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@6a8bd0bd[15,org.cumulus4j.store.test.movie.Rating#name[primary]]
10:07:46,194 DEBUG [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: end loading (took 21 ms). class=org.cumulus4j.store.test.movie.Rating
10:07:46,194 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6dfb9bab[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,194 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6dfb9bab[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,194 TRACE [qtp307046058-2509][Cumulus4jPersistenceHandler] insertObject: Created new DataEntry for: 1
10:07:46,194 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,195 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,197 TRACE [qtp307046058-2509][Cumulus4jPersistenceHandler] insertObject: Persisted new non-embedded DataEntry for: 1
10:07:46,197 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6dfb9bab[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,197 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6dfb9bab[2,org.cumulus4j.store.test.movie.Rating]
10:07:46,200 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,201 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,206 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,207 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,210 TRACE [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
10:07:46,210 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=8 value=[]
10:07:46,210 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,210 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1f680bc7[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:46,210 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,210 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=6 value=[]
10:07:46,210 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,210 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@f5441c2[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:46,210 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=5 value=null
10:07:46,210 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,211 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=4 value=[]
10:07:46,211 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,211 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@59557c78[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:46,211 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,211 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,211 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=1 value=[]
10:07:46,211 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,211 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1d34eda[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:46,211 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=0 value=[]
10:07:46,211 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,211 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@45d0c44f[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:46,211 TRACE [qtp307046058-2509][Cumulus4jPersistenceHandler] insertObject: Created new DataEntry for: 2
10:07:46,212 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,212 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,215 TRACE [qtp307046058-2509][Cumulus4jPersistenceHandler] insertObject: Persisted new non-embedded DataEntry for: 2
10:07:46,215 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@45d0c44f[1,org.cumulus4j.store.test.movie.Movie#directedBy[primary]]
10:07:46,219 TRACE [qtp307046058-2509][CryptoCache] getKeyData: Found cached key with keyID=1.
10:07:46,220 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Created new Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with key and IV.
10:07:46,221 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,222 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,222 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,222 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1d34eda[3,org.cumulus4j.store.test.movie.Movie#languages[primary]]
10:07:46,238 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,238 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,238 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,239 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,243 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,244 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,249 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,250 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,252 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@59557c78[7,org.cumulus4j.store.test.movie.Movie#producedBy[primary]]
10:07:46,256 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,256 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,257 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,257 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,258 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@f5441c2[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:46,262 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,263 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,263 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,263 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,264 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@1f680bc7[13,org.cumulus4j.store.test.movie.Movie#writtenBy[primary]]
10:07:46,268 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,269 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,269 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,269 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,272 DEBUG [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: begin loading. class=org.cumulus4j.store.test.movie.Person
10:07:46,272 DEBUG [qtp307046058-2509][Cumulus4jStoreManager] registerClass: clazz=org.cumulus4j.store.test.movie.Person
10:07:46,275 DEBUG [qtp307046058-2509][ClassMeta] jdoPreStore: org.cumulus4j.store.model.ClassMeta@6bfdd94b[null,org.cumulus4j.store.test.movie.Person]
10:07:46,277 DEBUG [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta == null => populating. this=org.cumulus4j.store.model.ClassMeta@6bfdd94b[3,org.cumulus4j.store.test.movie.Person]
10:07:46,279 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@73e0fe6[null,org.cumulus4j.store.test.movie.Person#name[primary]]
10:07:46,281 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6bfdd94b[3,org.cumulus4j.store.test.movie.Person]
10:07:46,281 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@73e0fe6[17,org.cumulus4j.store.test.movie.Person#name[primary]]
10:07:46,282 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@73e0fe6[17,org.cumulus4j.store.test.movie.Person#name[primary]]
10:07:46,282 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6bfdd94b[3,org.cumulus4j.store.test.movie.Person]
10:07:46,283 DEBUG [qtp307046058-2509][FieldMeta] jdoPreStore: org.cumulus4j.store.model.FieldMeta@b003e74[null,org.cumulus4j.store.test.movie.Person#personID[primary]]
10:07:46,285 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6bfdd94b[3,org.cumulus4j.store.test.movie.Person]
10:07:46,285 DEBUG [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta == null => populating. this=org.cumulus4j.store.model.FieldMeta@b003e74[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
10:07:46,286 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@b003e74[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
10:07:46,286 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6bfdd94b[3,org.cumulus4j.store.test.movie.Person]
10:07:46,286 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@73e0fe6[17,org.cumulus4j.store.test.movie.Person#name[primary]]
10:07:46,286 DEBUG [qtp307046058-2509][FieldMeta] getEmbeddedClassMeta: this.embeddedClassMetaLoaded == false => loading. this=org.cumulus4j.store.model.FieldMeta@73e0fe6[17,org.cumulus4j.store.test.movie.Person#name[primary]]
10:07:46,288 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@b003e74[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
10:07:46,289 DEBUG [qtp307046058-2509][ClassMeta] jdoPostDetach: attached=org.cumulus4j.store.model.ClassMeta@6bfdd94b[3,org.cumulus4j.store.test.movie.Person]
10:07:46,289 DEBUG [qtp307046058-2509][ClassMeta] jdoPostDetach: Detaching this.fieldName2FieldMeta: attached=org.cumulus4j.store.model.ClassMeta@6bfdd94b[3,org.cumulus4j.store.test.movie.Person]
10:07:46,289 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@6bfdd94b[3,org.cumulus4j.store.test.movie.Person]
10:07:46,289 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@73e0fe6[17,org.cumulus4j.store.test.movie.Person#name[primary]]
10:07:46,290 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@73e0fe6[17,org.cumulus4j.store.test.movie.Person#name[primary]]
10:07:46,290 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@73e0fe6[17,org.cumulus4j.store.test.movie.Person#name[primary]]
10:07:46,290 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@73e0fe6[17,org.cumulus4j.store.test.movie.Person#name[primary]]
10:07:46,290 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: attached=org.cumulus4j.store.model.FieldMeta@b003e74[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
10:07:46,290 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.role2SubFieldMeta: attached=org.cumulus4j.store.model.FieldMeta@b003e74[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
10:07:46,291 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@b003e74[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
10:07:46,291 DEBUG [qtp307046058-2509][FieldMeta] jdoPostDetach: Detaching this.embeddedClassMeta: attached=org.cumulus4j.store.model.FieldMeta@b003e74[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
10:07:46,291 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@3cf9a614[3,org.cumulus4j.store.test.movie.Person]
10:07:46,291 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@2a068a52[17,org.cumulus4j.store.test.movie.Person#name[primary]]
10:07:46,291 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@5191f2c5[18,org.cumulus4j.store.test.movie.Person#personID[primary]]
10:07:46,292 DEBUG [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: end loading (took 20 ms). class=org.cumulus4j.store.test.movie.Person
10:07:46,292 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@3cf9a614[3,org.cumulus4j.store.test.movie.Person]
10:07:46,292 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@3cf9a614[3,org.cumulus4j.store.test.movie.Person]
10:07:46,292 TRACE [qtp307046058-2509][Cumulus4jPersistenceHandler] insertObject: Created new DataEntry for: 1
10:07:46,292 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,293 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,295 TRACE [qtp307046058-2509][Cumulus4jPersistenceHandler] insertObject: Persisted new non-embedded DataEntry for: 1
10:07:46,295 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@3cf9a614[3,org.cumulus4j.store.test.movie.Person]
10:07:46,295 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@3cf9a614[3,org.cumulus4j.store.test.movie.Person]
10:07:46,299 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,299 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,305 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,305 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,308 TRACE [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
10:07:46,326 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,327 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,327 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=6 value=[org.cumulus4j.store.test.movie.Person@1]
10:07:46,327 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,328 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@f5441c2[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:46,328 TRACE [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Person
10:07:46,343 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,344 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,344 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,344 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@f5441c2[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:46,360 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,360 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,360 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,361 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,361 TRACE [qtp307046058-2509][FieldMeta] getRole2SubFieldMeta: this.role2SubFieldMeta != null (already populated). this=org.cumulus4j.store.model.FieldMeta@f5441c2[10,org.cumulus4j.store.test.movie.Movie#starring[primary]]
10:07:46,365 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,366 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,371 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,372 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,374 TRACE [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
10:07:46,378 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,378 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,379 TRACE [qtp307046058-2509][StoreFieldManager] storeObjectField: classMeta.className=org.cumulus4j.store.test.movie.Movie fieldNumber=5 value=org.cumulus4j.store.test.movie.Rating@1
10:07:46,379 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,379 TRACE [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Rating
10:07:46,382 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,383 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,383 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,385 DEBUG [qtp307046058-2512][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: Returning request: null
10:07:46,388 DEBUG [Thread-12][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.NullResponse matching=true
10:07:46,391 DEBUG [qtp307046058-2476][JAXBContextResolver] getContext: objectType=org.cumulus4j.keymanager.back.shared.Response matching=true
10:07:46,393 DEBUG [qtp307046058-2476][MessageBrokerPMF] [eof9fu] _pollRequest[cryptoSessionIDPrefix=test-i18ys604-1md1hmesbnji7_juc6wh78]: Entered.
10:07:46,406 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,407 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@1248481982 for opmode=ENCRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,447 TRACE [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
10:07:46,447 TRACE [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
10:07:46,461 TRACE [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClassID: found cache entry. classID=1
10:07:46,461 TRACE [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
10:07:46,479 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,480 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,481 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,481 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,481 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,481 TRACE [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClassID: found cache entry. classID=1
10:07:46,481 TRACE [qtp307046058-2509][Cumulus4jStoreManager] getClassMetaByClass: found cache entry. class=org.cumulus4j.store.test.movie.Movie
10:07:46,485 TRACE [qtp307046058-2509][CryptoCache] acquireCipherEntry: Found cached Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING and keyID=1. Initialising it with new IV (without key).
10:07:46,485 TRACE [qtp307046058-2509][CryptoCache] releaseCipherEntry: Releasing Cipher@463176163 for opmode=DECRYPT, encryptionAlgorithm=TWOFISH/GCM/NOPADDING keyID=1.
10:07:46,486 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,486 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
10:07:46,486 TRACE [qtp307046058-2509][ClassMeta] getFieldName2FieldMeta: this.fieldName2FieldMeta != null (already populated). this=org.cumulus4j.store.model.ClassMeta@55d28e2a[1,org.cumulus4j.store.test.movie.Movie]
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 270.304 sec

Results :

Tests run: 3, Failures: 0, Errors: 0, Skipped: 0

[JENKINS] Recording test results
[INFO] 
[INFO] --- maven-source-plugin:2.1.2:jar-no-fork (attach-sources) @ org.cumulus4j.integrationtest.webapp ---
[INFO] org already added, skipping
[INFO] org/cumulus4j already added, skipping
[INFO] org/cumulus4j/integrationtest already added, skipping
[INFO] org/cumulus4j/integrationtest/webapp already added, skipping
[INFO] LICENCE.txt already added, skipping
[INFO] cumulus4j-test-datanucleus.properties already added, skipping
[INFO] Building jar: /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.integrationtest.webapp/target/org.cumulus4j.integrationtest.webapp-1.2.1-SNAPSHOT-sources.jar
[INFO] org already added, skipping
[INFO] org/cumulus4j already added, skipping
[INFO] org/cumulus4j/integrationtest already added, skipping
[INFO] org/cumulus4j/integrationtest/webapp already added, skipping
[INFO] LICENCE.txt already added, skipping
[INFO] cumulus4j-test-datanucleus.properties already added, skipping
[INFO] 
[INFO] --- maven-install-plugin:2.4:install (default-install) @ org.cumulus4j.integrationtest.webapp ---
[INFO] Installing /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.integrationtest.webapp/target/org.cumulus4j.integrationtest.webapp-1.2.1-SNAPSHOT.war to /home/tomcat/.m2/repository/org/cumulus4j/org.cumulus4j.integrationtest.webapp/1.2.1-SNAPSHOT/org.cumulus4j.integrationtest.webapp-1.2.1-SNAPSHOT.war
[INFO] Installing /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.integrationtest.webapp/pom.xml to /home/tomcat/.m2/repository/org/cumulus4j/org.cumulus4j.integrationtest.webapp/1.2.1-SNAPSHOT/org.cumulus4j.integrationtest.webapp-1.2.1-SNAPSHOT.pom
[INFO] Installing /home/tomcat/.jenkins/workspace/org.cumulus4j/org.cumulus4j/org.cumulus4j.integrationtest.webapp/target/org.cumulus4j.integrationtest.webapp-1.2.1-SNAPSHOT-sources.jar to /home/tomcat/.m2/repository/org/cumulus4j/org.cumulus4j.integrationtest.webapp/1.2.1-SNAPSHOT/org.cumulus4j.integrationtest.webapp-1.2.1-SNAPSHOT-sources.jar