11087.738false111330org.subshare.core.crypto.EncrypterDecrypterStreamTest18.6480symmetricWithoutIvfalsePASSED symmetricWithoutIv: cipherTransformation=AES_CBC_PKCS5PADDING symmetricWithoutIv: Generating 10461949 random bytes plaintext took 446 ms. 11:56:24.654 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory symmetricWithoutIv: Creating symmetric key took 2157 ms. symmetricWithoutIv: Encrypting 10461949 bytes plaintext to 10461958 bytes ciphertext took 2208 ms. symmetricWithoutIv: Decrypting 10461958 bytes ciphertext to 10461949 bytes plaintext took 7 ...[truncated 37193 chars]... 4934 bytes plaintext took 237 ms. asymmetricCombiWithRandomIv: asymmetricCipherTransformation=RSA_OAEPWITHSHA1ANDMGF1PADDING asymmetricCombiWithRandomIv: symmetricCipherTransformation=TWOFISH_CFB_NOPADDING asymmetricCombiWithRandomIv: Generating 9334629 random bytes plaintext took 60 ms. asymmetricCombiWithRandomIv: Encrypting 9334629 bytes plaintext to 9335173 bytes ciphertext took 474 ms. asymmetricCombiWithRandomIv: Decrypting 9335173 bytes ciphertext to 9334629 bytes plaintext took 490 ms. 0org.subshare.core.crypto.EncrypterDecrypterStreamTest9.3580symmetricWithRandomIvfalsePASSED symmetricWithoutIv: cipherTransformation=AES_CBC_PKCS5PADDING symmetricWithoutIv: Generating 10461949 random bytes plaintext took 446 ms. 11:56:24.654 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory symmetricWithoutIv: Creating symmetric key took 2157 ms. symmetricWithoutIv: Encrypting 10461949 bytes plaintext to 10461958 bytes ciphertext took 2208 ms. symmetricWithoutIv: Decrypting 10461958 bytes ciphertext to 10461949 bytes plaintext took 7 ...[truncated 37193 chars]... 4934 bytes plaintext took 237 ms. asymmetricCombiWithRandomIv: asymmetricCipherTransformation=RSA_OAEPWITHSHA1ANDMGF1PADDING asymmetricCombiWithRandomIv: symmetricCipherTransformation=TWOFISH_CFB_NOPADDING asymmetricCombiWithRandomIv: Generating 9334629 random bytes plaintext took 60 ms. asymmetricCombiWithRandomIv: Encrypting 9334629 bytes plaintext to 9335173 bytes ciphertext took 474 ms. asymmetricCombiWithRandomIv: Decrypting 9335173 bytes ciphertext to 9334629 bytes plaintext took 490 ms. 0org.subshare.core.crypto.EncrypterDecrypterStreamTest5.8750asymmetricPlainfalsePASSED symmetricWithoutIv: cipherTransformation=AES_CBC_PKCS5PADDING symmetricWithoutIv: Generating 10461949 random bytes plaintext took 446 ms. 11:56:24.654 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory symmetricWithoutIv: Creating symmetric key took 2157 ms. symmetricWithoutIv: Encrypting 10461949 bytes plaintext to 10461958 bytes ciphertext took 2208 ms. symmetricWithoutIv: Decrypting 10461958 bytes ciphertext to 10461949 bytes plaintext took 7 ...[truncated 37193 chars]... 4934 bytes plaintext took 237 ms. asymmetricCombiWithRandomIv: asymmetricCipherTransformation=RSA_OAEPWITHSHA1ANDMGF1PADDING asymmetricCombiWithRandomIv: symmetricCipherTransformation=TWOFISH_CFB_NOPADDING asymmetricCombiWithRandomIv: Generating 9334629 random bytes plaintext took 60 ms. asymmetricCombiWithRandomIv: Encrypting 9334629 bytes plaintext to 9335173 bytes ciphertext took 474 ms. asymmetricCombiWithRandomIv: Decrypting 9335173 bytes ciphertext to 9334629 bytes plaintext took 490 ms. 0org.subshare.core.crypto.EncrypterDecrypterStreamTest22.4240asymmetricCombiWithRandomIvfalsePASSED symmetricWithoutIv: cipherTransformation=AES_CBC_PKCS5PADDING symmetricWithoutIv: Generating 10461949 random bytes plaintext took 446 ms. 11:56:24.654 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory symmetricWithoutIv: Creating symmetric key took 2157 ms. symmetricWithoutIv: Encrypting 10461949 bytes plaintext to 10461958 bytes ciphertext took 2208 ms. symmetricWithoutIv: Decrypting 10461958 bytes ciphertext to 10461949 bytes plaintext took 7 ...[truncated 37193 chars]... 4934 bytes plaintext took 237 ms. asymmetricCombiWithRandomIv: asymmetricCipherTransformation=RSA_OAEPWITHSHA1ANDMGF1PADDING asymmetricCombiWithRandomIv: symmetricCipherTransformation=TWOFISH_CFB_NOPADDING asymmetricCombiWithRandomIv: Generating 9334629 random bytes plaintext took 60 ms. asymmetricCombiWithRandomIv: Encrypting 9334629 bytes plaintext to 9335173 bytes ciphertext took 474 ms. asymmetricCombiWithRandomIv: Decrypting 9335173 bytes ciphertext to 9334629 bytes plaintext took 490 ms. 56.305org.subshare.core.crypto.EncrypterDecrypterStreamTest symmetricWithoutIv: cipherTransformation=AES_CBC_PKCS5PADDING symmetricWithoutIv: Generating 10461949 random bytes plaintext took 446 ms. 11:56:24.654 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory symmetricWithoutIv: Creating symmetric key took 2157 ms. symmetricWithoutIv: Encrypting 10461949 bytes plaintext to 10461958 bytes ciphertext took 2208 ms. symmetricWithoutIv: Decrypting 10461958 bytes ciphertext to 10461949 bytes plaintext took 7 ...[truncated 37193 chars]... 4934 bytes plaintext took 237 ms. asymmetricCombiWithRandomIv: asymmetricCipherTransformation=RSA_OAEPWITHSHA1ANDMGF1PADDING asymmetricCombiWithRandomIv: symmetricCipherTransformation=TWOFISH_CFB_NOPADDING asymmetricCombiWithRandomIv: Generating 9334629 random bytes plaintext took 60 ms. asymmetricCombiWithRandomIv: Encrypting 9334629 bytes plaintext to 9335173 bytes ciphertext took 474 ms. asymmetricCombiWithRandomIv: Decrypting 9335173 bytes ciphertext to 9334629 bytes plaintext took 490 ms. 2019-07-27T09:56:220org.subshare.core.file.EncryptedDataFileTest1.3040writeReadSimpleEncryptedDataFilefalsePASSED1.304org.subshare.core.file.EncryptedDataFileTest2019-07-27T09:56:260org.subshare.core.gpg.GnuPgTest6.5260encryptSignAndDecryptVerifyfalsePASSED>>> pub >>> keyID: 16686379b818da48 fingerprint: E8:3E:05:6D:B9:48:9E:0E:4B:56:05:89:16:68:63:79:B8:18:DA:48 masterKey: true encryptionKey: false userID: Niklas Schiffler <nick@nightlabs.de> userID: Niklas Schiffler <nschiffler@nightlabs.de> signature.keyID: 16686379b818da48 signature.signatureType: POSITIVE_CERTIFICATION signature.keyID: 3a7e3c9cbce48dc2 signature.signatureType: POSITIVE_CERTIFICATION signature.keyID: ead508863c3db998 signature.signatureType: POSITIVE_CERTIFICATION signature.ke ...[truncated 26887 chars]... ewizards.co> signature.keyID: d7a92a24aa97ddbd signature.signatureType: POSITIVE_CERTIFICATION <<< pub <<< >>> pub >>> keyID: a58da7d810b74edf fingerprint: 6F:EA:38:9D:83:64:EE:9E:0C:D9:9B:86:A5:8D:A7:D8:10:B7:4E:DF masterKey: false encryptionKey: true signature.keyID: d7a92a24aa97ddbd signature.signatureType: SUBKEY_BINDING <<< pub <<< >>> sec >>> keyID: d7a92a24aa97ddbd userID: Marco หงุ่ยตระกูล-Schulze (TEST) <marco@codewizards.co> <<< sec <<< >>> sec >>> keyID: a58da7d810b74edf <<< sec <<< 0org.subshare.core.gpg.GnuPgTest0.940encryptAndDecryptfalsePASSED>>> pub >>> keyID: 16686379b818da48 fingerprint: E8:3E:05:6D:B9:48:9E:0E:4B:56:05:89:16:68:63:79:B8:18:DA:48 masterKey: true encryptionKey: false userID: Niklas Schiffler <nick@nightlabs.de> userID: Niklas Schiffler <nschiffler@nightlabs.de> signature.keyID: 16686379b818da48 signature.signatureType: POSITIVE_CERTIFICATION signature.keyID: 3a7e3c9cbce48dc2 signature.signatureType: POSITIVE_CERTIFICATION signature.keyID: ead508863c3db998 signature.signatureType: POSITIVE_CERTIFICATION signature.ke ...[truncated 26887 chars]... ewizards.co> signature.keyID: d7a92a24aa97ddbd signature.signatureType: POSITIVE_CERTIFICATION <<< pub <<< >>> pub >>> keyID: a58da7d810b74edf fingerprint: 6F:EA:38:9D:83:64:EE:9E:0C:D9:9B:86:A5:8D:A7:D8:10:B7:4E:DF masterKey: false encryptionKey: true signature.keyID: d7a92a24aa97ddbd signature.signatureType: SUBKEY_BINDING <<< pub <<< >>> sec >>> keyID: d7a92a24aa97ddbd userID: Marco หงุ่ยตระกูล-Schulze (TEST) <marco@codewizards.co> <<< sec <<< >>> sec >>> keyID: a58da7d810b74edf <<< sec <<< 0org.subshare.core.gpg.GnuPgTest0.7340readPubringGpgfalsePASSED>>> pub >>> keyID: 16686379b818da48 fingerprint: E8:3E:05:6D:B9:48:9E:0E:4B:56:05:89:16:68:63:79:B8:18:DA:48 masterKey: true encryptionKey: false userID: Niklas Schiffler <nick@nightlabs.de> userID: Niklas Schiffler <nschiffler@nightlabs.de> signature.keyID: 16686379b818da48 signature.signatureType: POSITIVE_CERTIFICATION signature.keyID: 3a7e3c9cbce48dc2 signature.signatureType: POSITIVE_CERTIFICATION signature.keyID: ead508863c3db998 signature.signatureType: POSITIVE_CERTIFICATION signature.ke ...[truncated 26887 chars]... ewizards.co> signature.keyID: d7a92a24aa97ddbd signature.signatureType: POSITIVE_CERTIFICATION <<< pub <<< >>> pub >>> keyID: a58da7d810b74edf fingerprint: 6F:EA:38:9D:83:64:EE:9E:0C:D9:9B:86:A5:8D:A7:D8:10:B7:4E:DF masterKey: false encryptionKey: true signature.keyID: d7a92a24aa97ddbd signature.signatureType: SUBKEY_BINDING <<< pub <<< >>> sec >>> keyID: d7a92a24aa97ddbd userID: Marco หงุ่ยตระกูล-Schulze (TEST) <marco@codewizards.co> <<< sec <<< >>> sec >>> keyID: a58da7d810b74edf <<< sec <<< 0org.subshare.core.gpg.GnuPgTest0.0050readSecringGpgfalsePASSED>>> pub >>> keyID: 16686379b818da48 fingerprint: E8:3E:05:6D:B9:48:9E:0E:4B:56:05:89:16:68:63:79:B8:18:DA:48 masterKey: true encryptionKey: false userID: Niklas Schiffler <nick@nightlabs.de> userID: Niklas Schiffler <nschiffler@nightlabs.de> signature.keyID: 16686379b818da48 signature.signatureType: POSITIVE_CERTIFICATION signature.keyID: 3a7e3c9cbce48dc2 signature.signatureType: POSITIVE_CERTIFICATION signature.keyID: ead508863c3db998 signature.signatureType: POSITIVE_CERTIFICATION signature.ke ...[truncated 26887 chars]... ewizards.co> signature.keyID: d7a92a24aa97ddbd signature.signatureType: POSITIVE_CERTIFICATION <<< pub <<< >>> pub >>> keyID: a58da7d810b74edf fingerprint: 6F:EA:38:9D:83:64:EE:9E:0C:D9:9B:86:A5:8D:A7:D8:10:B7:4E:DF masterKey: false encryptionKey: true signature.keyID: d7a92a24aa97ddbd signature.signatureType: SUBKEY_BINDING <<< pub <<< >>> sec >>> keyID: d7a92a24aa97ddbd userID: Marco หงุ่ยตระกูล-Schulze (TEST) <marco@codewizards.co> <<< sec <<< >>> sec >>> keyID: a58da7d810b74edf <<< sec <<< 8.205org.subshare.core.gpg.GnuPgTest>>> pub >>> keyID: 16686379b818da48 fingerprint: E8:3E:05:6D:B9:48:9E:0E:4B:56:05:89:16:68:63:79:B8:18:DA:48 masterKey: true encryptionKey: false userID: Niklas Schiffler <nick@nightlabs.de> userID: Niklas Schiffler <nschiffler@nightlabs.de> signature.keyID: 16686379b818da48 signature.signatureType: POSITIVE_CERTIFICATION signature.keyID: 3a7e3c9cbce48dc2 signature.signatureType: POSITIVE_CERTIFICATION signature.keyID: ead508863c3db998 signature.signatureType: POSITIVE_CERTIFICATION signature.ke ...[truncated 26887 chars]... ewizards.co> signature.keyID: d7a92a24aa97ddbd signature.signatureType: POSITIVE_CERTIFICATION <<< pub <<< >>> pub >>> keyID: a58da7d810b74edf fingerprint: 6F:EA:38:9D:83:64:EE:9E:0C:D9:9B:86:A5:8D:A7:D8:10:B7:4E:DF masterKey: false encryptionKey: true signature.keyID: d7a92a24aa97ddbd signature.signatureType: SUBKEY_BINDING <<< pub <<< >>> sec >>> keyID: d7a92a24aa97ddbd userID: Marco หงุ่ยตระกูล-Schulze (TEST) <marco@codewizards.co> <<< sec <<< >>> sec >>> keyID: a58da7d810b74edf <<< sec <<< 2019-07-27T09:56:190org.subshare.core.io.LimitedInputStreamTest2.1750randomLengthWithUnderlyingSameLengthfalsePASSED2.175org.subshare.core.io.LimitedInputStreamTest2019-07-27T09:56:180org.subshare.core.io.MultiInputStreamTest8.6170randomCombifalsePASSED8.617org.subshare.core.io.MultiInputStreamTest2019-07-27T09:56:170org.subshare.core.pgp.PgpTest4.4040inlineSignThenEncryptAndDecryptThenVerifyfalsePASSED11:56:22.482 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:56:22.549 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:22.674 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/uxLmwPhBB8TVAEFoFSoCeQ/.gnupg 11:56:22.693 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/uxLmwPhBB8TVAEFoFSoCeQ/.gnupg 11:56:24.264 [Test ...[truncated 27265 chars]... :54) [gradle-base-services-3.1.jar:3.1] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) [gradle-base-services-3.1.jar:3.1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212] 11:56:36.100 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.core.pgp.PgpTest0.1520signAndVerifyViaPgpSignablefalsePASSED11:56:22.482 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:56:22.549 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:22.674 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/uxLmwPhBB8TVAEFoFSoCeQ/.gnupg 11:56:22.693 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/uxLmwPhBB8TVAEFoFSoCeQ/.gnupg 11:56:24.264 [Test ...[truncated 27265 chars]... :54) [gradle-base-services-3.1.jar:3.1] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) [gradle-base-services-3.1.jar:3.1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212] 11:56:36.100 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.core.pgp.PgpTest1.3950inlineSignAndVerifyfalsePASSED11:56:22.482 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:56:22.549 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:22.674 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/uxLmwPhBB8TVAEFoFSoCeQ/.gnupg 11:56:22.693 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/uxLmwPhBB8TVAEFoFSoCeQ/.gnupg 11:56:24.264 [Test ...[truncated 27265 chars]... :54) [gradle-base-services-3.1.jar:3.1] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) [gradle-base-services-3.1.jar:3.1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212] 11:56:36.100 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.core.pgp.PgpTest0.3120exportImportPublicKeyfalsePASSED11:56:22.482 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:56:22.549 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:22.674 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/uxLmwPhBB8TVAEFoFSoCeQ/.gnupg 11:56:22.693 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/uxLmwPhBB8TVAEFoFSoCeQ/.gnupg 11:56:24.264 [Test ...[truncated 27265 chars]... :54) [gradle-base-services-3.1.jar:3.1] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) [gradle-base-services-3.1.jar:3.1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212] 11:56:36.100 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.core.pgp.PgpTest5.6840detachedSignAndVerifyfalsePASSED11:56:22.482 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:56:22.549 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:22.674 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/uxLmwPhBB8TVAEFoFSoCeQ/.gnupg 11:56:22.693 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/uxLmwPhBB8TVAEFoFSoCeQ/.gnupg 11:56:24.264 [Test ...[truncated 27265 chars]... :54) [gradle-base-services-3.1.jar:3.1] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) [gradle-base-services-3.1.jar:3.1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212] 11:56:36.100 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11.947org.subshare.core.pgp.PgpTest11:56:22.482 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:56:22.549 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:22.674 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/uxLmwPhBB8TVAEFoFSoCeQ/.gnupg 11:56:22.693 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/uxLmwPhBB8TVAEFoFSoCeQ/.gnupg 11:56:24.264 [Test ...[truncated 27265 chars]... :54) [gradle-base-services-3.1.jar:3.1] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) [gradle-base-services-3.1.jar:3.1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212] 11:56:36.100 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T09:56:240org.subshare.core.user.AddDuplicateUserRepoKeyPublicKeyToUserTest3.4020addAllDifferentUserRepoKeyPublicKeysToUserfalsePASSED0org.subshare.core.user.AddDuplicateUserRepoKeyPublicKeyToUserTest0.0190addAllSameUserRepoKeyPublicKeyInCollectionToUserfalsePASSED0org.subshare.core.user.AddDuplicateUserRepoKeyPublicKeyToUserTest0.0090addSameUserRepoKeyPublicKeyTwiceToUserfalsePASSED0org.subshare.core.user.AddDuplicateUserRepoKeyPublicKeyToUserTest0.020addDifferentUserRepoKeyPublicKeysToUserfalsePASSED3.45org.subshare.core.user.AddDuplicateUserRepoKeyPublicKeyToUserTest2019-07-27T09:56:180org.subshare.core.user.UserRegistryTest3.3310addUserfalsePASSED11:56:27.461 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:56:27.522 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:27.638 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.640 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.838 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:56:27.839 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.841 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: secringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/secring.gpg' 11:56:27.856 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=70c642ca41cd4390 11:56:27.857 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=49bd4210ee77b7f8 11:56:27.858 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=d7a92a24aa97ddbd 11:56:27.858 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=a58da7d810b74edf 11:56:27.858 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: pubringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/pubring.gpg' 11:56:27.931 [Test worker] DEBUG o.s.c.p.g.TrustDbFactory - createTrustDb: Creating *real* TrustDb instance. 11:56:30.796 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:30.831 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:30.836 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:30.836 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.837 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.840 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:56:30.840 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.840 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.841 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: secringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/secring.gpg' 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=70c642ca41cd4390 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=49bd4210ee77b7f8 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=d7a92a24aa97ddbd 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=a58da7d810b74edf 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: pubringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/pubring.gpg' 11:56:30.850 [Test worker] DEBUG o.s.c.p.g.TrustDbFactory - createTrustDb: Creating *real* TrustDb instance. 11:56:30.851 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:31.352 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:31.853 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:32.354 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:32.855 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:33.356 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:33.857 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:34.359 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:34.864 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:35.366 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:35.868 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:36.369 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:36.870 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:37.374 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:37.876 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:38.378 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:38.765 [TrustDbFactory.deferredCloseTimer] DEBUG o.s.c.p.g.TrustDbFactory$DeferredCloseTimerTask - run: Closing *real* TrustDb instance. 11:56:38.880 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:39.451 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:39.456 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:39.564 [Test worker] INFO o.b.o.w.i.TrustDbImpl - updateTrustDb: Next trust-db expiration date: 2021-03-21T18:43:12 11:56:39.604 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:39.610 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:39.610 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.610 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.614 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:56:39.615 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.615 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.616 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: secringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/secring.gpg' 11:56:39.617 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=70c642ca41cd4390 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=49bd4210ee77b7f8 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=d7a92a24aa97ddbd 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=a58da7d810b74edf 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: pubringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/pubring.gpg' 11:56:39.629 [Test worker] DEBUG o.s.c.p.g.TrustDbFactory - createTrustDb: Creating *real* TrustDb instance. 11:56:39.632 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:40.134 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:40.638 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:41.139 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:41.641 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:42.143 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:42.644 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:43.145 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:43.652 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:44.154 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:44.655 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:45.158 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:45.659 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:46.161 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:46.663 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:47.165 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:47.667 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:48.170 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:48.674 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:49.176 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:49.574 [TrustDbFactory.deferredCloseTimer] DEBUG o.s.c.p.g.TrustDbFactory$DeferredCloseTimerTask - run: Closing *real* TrustDb instance. 11:56:49.741 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:52.206 [Test worker] INFO o.s.c.c.KeyFactory - Creating asymmetric key pair with defaults took 2461 ms. 11:56:52.217 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:52.314 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:52.368 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 1org.subshare.core.user.UserRegistryTest8.773org.junit.ComparisonFailure: expected:<[not trust]ed> but was:<[expir]ed>org.junit.ComparisonFailure: expected:<[not trust]ed> but was:<[expir]ed> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at org.subshare.core.user.UserRegistryTest.testGpgKeyTrustLevels(UserRegistryTest.java:110) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.lang.reflect.Method.invoke(Method.java:498) at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:114) at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:57) at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:66) at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.lang.reflect.Method.invoke(Method.java:498) at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35) at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24) at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32) at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93) at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:109) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.lang.reflect.Method.invoke(Method.java:498) at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35) at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24) at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:377) at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:54) at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 370testGpgKeyTrustLevelsfalseREGRESSION11:56:27.461 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:56:27.522 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:27.638 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.640 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.838 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:56:27.839 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.841 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: secringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/secring.gpg' 11:56:27.856 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=70c642ca41cd4390 11:56:27.857 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=49bd4210ee77b7f8 11:56:27.858 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=d7a92a24aa97ddbd 11:56:27.858 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=a58da7d810b74edf 11:56:27.858 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: pubringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/pubring.gpg' 11:56:27.931 [Test worker] DEBUG o.s.c.p.g.TrustDbFactory - createTrustDb: Creating *real* TrustDb instance. 11:56:30.796 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:30.831 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:30.836 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:30.836 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.837 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.840 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:56:30.840 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.840 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.841 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: secringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/secring.gpg' 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=70c642ca41cd4390 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=49bd4210ee77b7f8 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=d7a92a24aa97ddbd 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=a58da7d810b74edf 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: pubringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/pubring.gpg' 11:56:30.850 [Test worker] DEBUG o.s.c.p.g.TrustDbFactory - createTrustDb: Creating *real* TrustDb instance. 11:56:30.851 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:31.352 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:31.853 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:32.354 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:32.855 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:33.356 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:33.857 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:34.359 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:34.864 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:35.366 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:35.868 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:36.369 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:36.870 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:37.374 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:37.876 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:38.378 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:38.765 [TrustDbFactory.deferredCloseTimer] DEBUG o.s.c.p.g.TrustDbFactory$DeferredCloseTimerTask - run: Closing *real* TrustDb instance. 11:56:38.880 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:39.451 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:39.456 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:39.564 [Test worker] INFO o.b.o.w.i.TrustDbImpl - updateTrustDb: Next trust-db expiration date: 2021-03-21T18:43:12 11:56:39.604 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:39.610 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:39.610 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.610 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.614 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:56:39.615 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.615 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.616 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: secringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/secring.gpg' 11:56:39.617 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=70c642ca41cd4390 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=49bd4210ee77b7f8 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=d7a92a24aa97ddbd 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=a58da7d810b74edf 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: pubringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/pubring.gpg' 11:56:39.629 [Test worker] DEBUG o.s.c.p.g.TrustDbFactory - createTrustDb: Creating *real* TrustDb instance. 11:56:39.632 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:40.134 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:40.638 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:41.139 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:41.641 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:42.143 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:42.644 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:43.145 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:43.652 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:44.154 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:44.655 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:45.158 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:45.659 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:46.161 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:46.663 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:47.165 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:47.667 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:48.170 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:48.674 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:49.176 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:49.574 [TrustDbFactory.deferredCloseTimer] DEBUG o.s.c.p.g.TrustDbFactory$DeferredCloseTimerTask - run: Closing *real* TrustDb instance. 11:56:49.741 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:52.206 [Test worker] INFO o.s.c.c.KeyFactory - Creating asymmetric key pair with defaults took 2461 ms. 11:56:52.217 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:52.314 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:52.368 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.core.user.UserRegistryTest12.760initUserRegistryFromGpgKeysfalsePASSED11:56:27.461 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:56:27.522 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:27.638 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.640 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.838 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:56:27.839 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.841 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: secringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/secring.gpg' 11:56:27.856 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=70c642ca41cd4390 11:56:27.857 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=49bd4210ee77b7f8 11:56:27.858 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=d7a92a24aa97ddbd 11:56:27.858 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=a58da7d810b74edf 11:56:27.858 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: pubringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/pubring.gpg' 11:56:27.931 [Test worker] DEBUG o.s.c.p.g.TrustDbFactory - createTrustDb: Creating *real* TrustDb instance. 11:56:30.796 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:30.831 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:30.836 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:30.836 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.837 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.840 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:56:30.840 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.840 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.841 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: secringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/secring.gpg' 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=70c642ca41cd4390 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=49bd4210ee77b7f8 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=d7a92a24aa97ddbd 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=a58da7d810b74edf 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: pubringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/pubring.gpg' 11:56:30.850 [Test worker] DEBUG o.s.c.p.g.TrustDbFactory - createTrustDb: Creating *real* TrustDb instance. 11:56:30.851 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:31.352 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:31.853 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:32.354 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:32.855 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:33.356 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:33.857 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:34.359 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:34.864 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:35.366 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:35.868 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:36.369 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:36.870 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:37.374 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:37.876 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:38.378 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:38.765 [TrustDbFactory.deferredCloseTimer] DEBUG o.s.c.p.g.TrustDbFactory$DeferredCloseTimerTask - run: Closing *real* TrustDb instance. 11:56:38.880 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:39.451 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:39.456 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:39.564 [Test worker] INFO o.b.o.w.i.TrustDbImpl - updateTrustDb: Next trust-db expiration date: 2021-03-21T18:43:12 11:56:39.604 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:39.610 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:39.610 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.610 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.614 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:56:39.615 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.615 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.616 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: secringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/secring.gpg' 11:56:39.617 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=70c642ca41cd4390 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=49bd4210ee77b7f8 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=d7a92a24aa97ddbd 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=a58da7d810b74edf 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: pubringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/pubring.gpg' 11:56:39.629 [Test worker] DEBUG o.s.c.p.g.TrustDbFactory - createTrustDb: Creating *real* TrustDb instance. 11:56:39.632 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:40.134 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:40.638 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:41.139 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:41.641 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:42.143 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:42.644 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:43.145 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:43.652 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:44.154 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:44.655 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:45.158 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:45.659 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:46.161 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:46.663 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:47.165 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:47.667 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:48.170 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:48.674 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:49.176 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:49.574 [TrustDbFactory.deferredCloseTimer] DEBUG o.s.c.p.g.TrustDbFactory$DeferredCloseTimerTask - run: Closing *real* TrustDb instance. 11:56:49.741 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:52.206 [Test worker] INFO o.s.c.c.KeyFactory - Creating asymmetric key pair with defaults took 2461 ms. 11:56:52.217 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:52.314 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:52.368 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 24.864org.subshare.core.user.UserRegistryTest11:56:27.461 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:56:27.522 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:27.638 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.640 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.838 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:56:27.839 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.841 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:27.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: secringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/secring.gpg' 11:56:27.856 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=70c642ca41cd4390 11:56:27.857 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=49bd4210ee77b7f8 11:56:27.858 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=d7a92a24aa97ddbd 11:56:27.858 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=a58da7d810b74edf 11:56:27.858 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: pubringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/pubring.gpg' 11:56:27.931 [Test worker] DEBUG o.s.c.p.g.TrustDbFactory - createTrustDb: Creating *real* TrustDb instance. 11:56:30.796 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:30.831 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:30.836 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:30.836 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.837 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.840 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:56:30.840 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.840 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:30.841 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: secringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/secring.gpg' 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=70c642ca41cd4390 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=49bd4210ee77b7f8 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=d7a92a24aa97ddbd 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=a58da7d810b74edf 11:56:30.842 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: pubringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/pubring.gpg' 11:56:30.850 [Test worker] DEBUG o.s.c.p.g.TrustDbFactory - createTrustDb: Creating *real* TrustDb instance. 11:56:30.851 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:31.352 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:31.853 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:32.354 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:32.855 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:33.356 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:33.857 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:34.359 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:34.864 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:35.366 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:35.868 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:36.369 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:36.870 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:37.374 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:37.876 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:38.378 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:38.765 [TrustDbFactory.deferredCloseTimer] DEBUG o.s.c.p.g.TrustDbFactory$DeferredCloseTimerTask - run: Closing *real* TrustDb instance. 11:56:38.880 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:39.451 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:39.456 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:39.564 [Test worker] INFO o.b.o.w.i.TrustDbImpl - updateTrustDb: Next trust-db expiration date: 2021-03-21T18:43:12 11:56:39.604 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:39.610 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:56:39.610 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.610 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.614 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:56:39.615 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.615 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg 11:56:39.616 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: secringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/secring.gpg' 11:56:39.617 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=70c642ca41cd4390 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=49bd4210ee77b7f8 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=d7a92a24aa97ddbd 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: read secretKey with pgpKeyId=a58da7d810b74edf 11:56:39.618 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - load: pubringFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/pubring.gpg' 11:56:39.629 [Test worker] DEBUG o.s.c.p.g.TrustDbFactory - createTrustDb: Creating *real* TrustDb instance. 11:56:39.632 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:40.134 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:40.638 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:41.139 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:41.641 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:42.143 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:42.644 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:43.145 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:43.652 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:44.154 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:44.655 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:45.158 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:45.659 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:46.161 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:46.663 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:47.165 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:47.667 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:48.170 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:48.674 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:49.176 [Test worker] WARN o.b.o.w.IoRandomAccessFile - Locking file '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.core/build/UBsH5cBr6eqjLYZILDOnfg/.gnupg/trustdb.gpg' failed. Retrying. 11:56:49.574 [TrustDbFactory.deferredCloseTimer] DEBUG o.s.c.p.g.TrustDbFactory$DeferredCloseTimerTask - run: Closing *real* TrustDb instance. 11:56:49.741 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:52.206 [Test worker] INFO o.s.c.c.KeyFactory - Creating asymmetric key pair with defaults took 2461 ms. 11:56:52.217 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:52.314 [Test worker] DEBUG o.s.c.p.PgpRegistry - getPgpOrFail: returning existing Pgp instance. 11:56:52.368 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T09:56:270org.subshare.core.user.UserRepoKeyRingVsPublicKeysUserImplTest2.3040firstAddPublicKeysThenCreateUserRepoKeyRingfalsePASSED0org.subshare.core.user.UserRepoKeyRingVsPublicKeysUserImplTest0.060firstCreateUserRepoKeyRingThenAddPublicKeysfalsePASSED2.3639998org.subshare.core.user.UserRepoKeyRingVsPublicKeysUserImplTest2019-07-27T09:56:18114org.subshare.crypto.AsymmetricKeyTest0.015257generateManySymmetricKeystrueSKIPPED0org.subshare.crypto.AsymmetricKeyTest10.9210encodeDecodeRSAwithOAEPwithSHA1andMGF1PaddingfalsePASSED0org.subshare.crypto.AsymmetricKeyTest4.9570encodeDecodeRSAfalsePASSED15.893org.subshare.crypto.AsymmetricKeyTest2019-07-27T09:57:300org.subshare.crypto.CipherTest3.910testLookupAllSupportedCiphersfalsePASSED11:57:37.589 [Test worker] INFO o.s.c.CipherTest - testLookupAllSupportedCiphers: Successfully created 29934 ciphers in 3707 msec. 11:57:37.973 [Test worker] INFO o.s.c.CipherTest - transformation=AES.FAST// 11:57:37.978 [Test worker] INFO o.s.c.CipherTest - testNullAsKeyParameter: Transformation "AES.FAST//" does not support IV => Skipping. 11:57:37.981 [Test worker] INFO o.s.c.CipherTest - transformation=AES.FAST//NOPADDING 11:57:37.987 [Test worker] INFO o.s.c.CipherTest - testNullAsKeyP ...[truncated 3456005 chars]... s.c.CipherTest - transformation=Twofish/CBC/PKCS5Padding 11:57:52.700 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CFB/NoPadding 11:57:52.956 [Test worker] INFO o.s.c.CipherTest - transformation=AES/CBC/PKCS5Padding 11:57:53.370 [Test worker] INFO o.s.c.CipherTest - transformation=AES/CFB/NoPadding 11:57:53.881 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CBC/PKCS5Padding 11:57:54.080 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CFB/NoPadding 0org.subshare.crypto.CipherTest11.1180testNullAsKeyParameterfalsePASSED11:57:37.589 [Test worker] INFO o.s.c.CipherTest - testLookupAllSupportedCiphers: Successfully created 29934 ciphers in 3707 msec. 11:57:37.973 [Test worker] INFO o.s.c.CipherTest - transformation=AES.FAST// 11:57:37.978 [Test worker] INFO o.s.c.CipherTest - testNullAsKeyParameter: Transformation "AES.FAST//" does not support IV => Skipping. 11:57:37.981 [Test worker] INFO o.s.c.CipherTest - transformation=AES.FAST//NOPADDING 11:57:37.987 [Test worker] INFO o.s.c.CipherTest - testNullAsKeyP ...[truncated 3456005 chars]... s.c.CipherTest - transformation=Twofish/CBC/PKCS5Padding 11:57:52.700 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CFB/NoPadding 11:57:52.956 [Test worker] INFO o.s.c.CipherTest - transformation=AES/CBC/PKCS5Padding 11:57:53.370 [Test worker] INFO o.s.c.CipherTest - transformation=AES/CFB/NoPadding 11:57:53.881 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CBC/PKCS5Padding 11:57:54.080 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CFB/NoPadding 0org.subshare.crypto.CipherTest0.1110testLookupCompatibilityWithJCEfalsePASSED11:57:37.589 [Test worker] INFO o.s.c.CipherTest - testLookupAllSupportedCiphers: Successfully created 29934 ciphers in 3707 msec. 11:57:37.973 [Test worker] INFO o.s.c.CipherTest - transformation=AES.FAST// 11:57:37.978 [Test worker] INFO o.s.c.CipherTest - testNullAsKeyParameter: Transformation "AES.FAST//" does not support IV => Skipping. 11:57:37.981 [Test worker] INFO o.s.c.CipherTest - transformation=AES.FAST//NOPADDING 11:57:37.987 [Test worker] INFO o.s.c.CipherTest - testNullAsKeyP ...[truncated 3456005 chars]... s.c.CipherTest - transformation=Twofish/CBC/PKCS5Padding 11:57:52.700 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CFB/NoPadding 11:57:52.956 [Test worker] INFO o.s.c.CipherTest - transformation=AES/CBC/PKCS5Padding 11:57:53.370 [Test worker] INFO o.s.c.CipherTest - transformation=AES/CFB/NoPadding 11:57:53.881 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CBC/PKCS5Padding 11:57:54.080 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CFB/NoPadding 0org.subshare.crypto.CipherTest5.340testSymmetricEncryptionWithoutIvfalsePASSED11:57:37.589 [Test worker] INFO o.s.c.CipherTest - testLookupAllSupportedCiphers: Successfully created 29934 ciphers in 3707 msec. 11:57:37.973 [Test worker] INFO o.s.c.CipherTest - transformation=AES.FAST// 11:57:37.978 [Test worker] INFO o.s.c.CipherTest - testNullAsKeyParameter: Transformation "AES.FAST//" does not support IV => Skipping. 11:57:37.981 [Test worker] INFO o.s.c.CipherTest - transformation=AES.FAST//NOPADDING 11:57:37.987 [Test worker] INFO o.s.c.CipherTest - testNullAsKeyP ...[truncated 3456005 chars]... s.c.CipherTest - transformation=Twofish/CBC/PKCS5Padding 11:57:52.700 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CFB/NoPadding 11:57:52.956 [Test worker] INFO o.s.c.CipherTest - transformation=AES/CBC/PKCS5Padding 11:57:53.370 [Test worker] INFO o.s.c.CipherTest - transformation=AES/CFB/NoPadding 11:57:53.881 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CBC/PKCS5Padding 11:57:54.080 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CFB/NoPadding 0org.subshare.crypto.CipherTest0.1660testSymmetricEncryptionCompatibilityWithJCE_BouncyCastleProviderfalsePASSED11:57:37.589 [Test worker] INFO o.s.c.CipherTest - testLookupAllSupportedCiphers: Successfully created 29934 ciphers in 3707 msec. 11:57:37.973 [Test worker] INFO o.s.c.CipherTest - transformation=AES.FAST// 11:57:37.978 [Test worker] INFO o.s.c.CipherTest - testNullAsKeyParameter: Transformation "AES.FAST//" does not support IV => Skipping. 11:57:37.981 [Test worker] INFO o.s.c.CipherTest - transformation=AES.FAST//NOPADDING 11:57:37.987 [Test worker] INFO o.s.c.CipherTest - testNullAsKeyP ...[truncated 3456005 chars]... s.c.CipherTest - transformation=Twofish/CBC/PKCS5Padding 11:57:52.700 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CFB/NoPadding 11:57:52.956 [Test worker] INFO o.s.c.CipherTest - transformation=AES/CBC/PKCS5Padding 11:57:53.370 [Test worker] INFO o.s.c.CipherTest - transformation=AES/CFB/NoPadding 11:57:53.881 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CBC/PKCS5Padding 11:57:54.080 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CFB/NoPadding 20.645org.subshare.crypto.CipherTest11:57:37.589 [Test worker] INFO o.s.c.CipherTest - testLookupAllSupportedCiphers: Successfully created 29934 ciphers in 3707 msec. 11:57:37.973 [Test worker] INFO o.s.c.CipherTest - transformation=AES.FAST// 11:57:37.978 [Test worker] INFO o.s.c.CipherTest - testNullAsKeyParameter: Transformation "AES.FAST//" does not support IV => Skipping. 11:57:37.981 [Test worker] INFO o.s.c.CipherTest - transformation=AES.FAST//NOPADDING 11:57:37.987 [Test worker] INFO o.s.c.CipherTest - testNullAsKeyP ...[truncated 3456005 chars]... s.c.CipherTest - transformation=Twofish/CBC/PKCS5Padding 11:57:52.700 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CFB/NoPadding 11:57:52.956 [Test worker] INFO o.s.c.CipherTest - transformation=AES/CBC/PKCS5Padding 11:57:53.370 [Test worker] INFO o.s.c.CipherTest - transformation=AES/CFB/NoPadding 11:57:53.881 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CBC/PKCS5Padding 11:57:54.080 [Test worker] INFO o.s.c.CipherTest - transformation=Twofish/CFB/NoPadding 2019-07-27T09:57:330org.subshare.crypto.GCMTest6.5270testEncryptionWithCipherfalsePASSED*** 0 *** *** 1 *** *** 2 *** *** 3 *** *** 4 *** *** 5 *** *** 6 *** *** 7 *** *** 8 *** *** 9 *** *** 10 *** *** 11 *** *** 12 *** *** 13 *** *** 14 *** *** 15 *** *** 16 *** *** 17 *** *** 18 *** *** 19 *** *** 20 *** *** 21 *** *** 22 *** *** 23 *** *** 24 *** *** 25 *** *** 26 *** *** 27 *** *** 28 *** *** 29 *** *** 30 *** *** 31 *** *** 32 *** *** 33 *** *** 34 *** *** 35 *** *** 36 *** *** 37 *** *** 38 *** *** 39 *** *** 40 *** *** 41 *** *** 42 *** *** 43 *** *** 44 *** *** 45 *** *** ...[truncated 296780 chars]... 70 *** *** gcm 9971 *** *** gcm 9972 *** *** gcm 9973 *** *** gcm 9974 *** *** gcm 9975 *** *** gcm 9976 *** *** gcm 9977 *** *** gcm 9978 *** *** gcm 9979 *** *** gcm 9980 *** *** gcm 9981 *** *** gcm 9982 *** *** gcm 9983 *** *** gcm 9984 *** *** gcm 9985 *** *** gcm 9986 *** *** gcm 9987 *** *** gcm 9988 *** *** gcm 9989 *** *** gcm 9990 *** *** gcm 9991 *** *** gcm 9992 *** *** gcm 9993 *** *** gcm 9994 *** *** gcm 9995 *** *** gcm 9996 *** *** gcm 9997 *** *** gcm 9998 *** *** gcm 9999 *** 0org.subshare.crypto.GCMTest2.650testEncryptionWithBCLowLevelAPIfalsePASSED*** 0 *** *** 1 *** *** 2 *** *** 3 *** *** 4 *** *** 5 *** *** 6 *** *** 7 *** *** 8 *** *** 9 *** *** 10 *** *** 11 *** *** 12 *** *** 13 *** *** 14 *** *** 15 *** *** 16 *** *** 17 *** *** 18 *** *** 19 *** *** 20 *** *** 21 *** *** 22 *** *** 23 *** *** 24 *** *** 25 *** *** 26 *** *** 27 *** *** 28 *** *** 29 *** *** 30 *** *** 31 *** *** 32 *** *** 33 *** *** 34 *** *** 35 *** *** 36 *** *** 37 *** *** 38 *** *** 39 *** *** 40 *** *** 41 *** *** 42 *** *** 43 *** *** 44 *** *** 45 *** *** ...[truncated 296780 chars]... 70 *** *** gcm 9971 *** *** gcm 9972 *** *** gcm 9973 *** *** gcm 9974 *** *** gcm 9975 *** *** gcm 9976 *** *** gcm 9977 *** *** gcm 9978 *** *** gcm 9979 *** *** gcm 9980 *** *** gcm 9981 *** *** gcm 9982 *** *** gcm 9983 *** *** gcm 9984 *** *** gcm 9985 *** *** gcm 9986 *** *** gcm 9987 *** *** gcm 9988 *** *** gcm 9989 *** *** gcm 9990 *** *** gcm 9991 *** *** gcm 9992 *** *** gcm 9993 *** *** gcm 9994 *** *** gcm 9995 *** *** gcm 9996 *** *** gcm 9997 *** *** gcm 9998 *** *** gcm 9999 *** 9.177org.subshare.crypto.GCMTest*** 0 *** *** 1 *** *** 2 *** *** 3 *** *** 4 *** *** 5 *** *** 6 *** *** 7 *** *** 8 *** *** 9 *** *** 10 *** *** 11 *** *** 12 *** *** 13 *** *** 14 *** *** 15 *** *** 16 *** *** 17 *** *** 18 *** *** 19 *** *** 20 *** *** 21 *** *** 22 *** *** 23 *** *** 24 *** *** 25 *** *** 26 *** *** 27 *** *** 28 *** *** 29 *** *** 30 *** *** 31 *** *** 32 *** *** 33 *** *** 34 *** *** 35 *** *** 36 *** *** 37 *** *** 38 *** *** 39 *** *** 40 *** *** 41 *** *** 42 *** *** 43 *** *** 44 *** *** 45 *** *** ...[truncated 296780 chars]... 70 *** *** gcm 9971 *** *** gcm 9972 *** *** gcm 9973 *** *** gcm 9974 *** *** gcm 9975 *** *** gcm 9976 *** *** gcm 9977 *** *** gcm 9978 *** *** gcm 9979 *** *** gcm 9980 *** *** gcm 9981 *** *** gcm 9982 *** *** gcm 9983 *** *** gcm 9984 *** *** gcm 9985 *** *** gcm 9986 *** *** gcm 9987 *** *** gcm 9988 *** *** gcm 9989 *** *** gcm 9990 *** *** gcm 9991 *** *** gcm 9992 *** *** gcm 9993 *** *** gcm 9994 *** *** gcm 9995 *** *** gcm 9996 *** *** gcm 9997 *** *** gcm 9998 *** *** gcm 9999 *** 2019-07-27T09:57:340org.subshare.crypto.MACBenchmark0.1150testByteOrderfalsePASSED11:57:34.470 [Test worker] INFO o.s.c.MACBenchmark - short1 = 9938 11:57:34.525 [Test worker] INFO o.s.c.MACBenchmark - short2 = 9938 11:57:34.527 [Test worker] INFO o.s.c.MACBenchmark - int1 = 9938 0org.subshare.crypto.MACBenchmark5.5930benchmarkCreateManyInitialisedMACCalculatorsfalsePASSED11:57:34.470 [Test worker] INFO o.s.c.MACBenchmark - short1 = 9938 11:57:34.525 [Test worker] INFO o.s.c.MACBenchmark - short2 = 9938 11:57:34.527 [Test worker] INFO o.s.c.MACBenchmark - int1 = 9938 0org.subshare.crypto.MACBenchmark0.2340benchmarkCreateManyUNinitialisedMACCalculatorsfalsePASSED11:57:34.470 [Test worker] INFO o.s.c.MACBenchmark - short1 = 9938 11:57:34.525 [Test worker] INFO o.s.c.MACBenchmark - short2 = 9938 11:57:34.527 [Test worker] INFO o.s.c.MACBenchmark - int1 = 9938 0org.subshare.crypto.MACBenchmark20.7960benchmarkCalculateManyMACsWithNewMACCalculatorfalsePASSED11:57:34.470 [Test worker] INFO o.s.c.MACBenchmark - short1 = 9938 11:57:34.525 [Test worker] INFO o.s.c.MACBenchmark - short2 = 9938 11:57:34.527 [Test worker] INFO o.s.c.MACBenchmark - int1 = 9938 0org.subshare.crypto.MACBenchmark17.6840benchmarkCalculateManyMACsWithSameMACCalculatorfalsePASSED11:57:34.470 [Test worker] INFO o.s.c.MACBenchmark - short1 = 9938 11:57:34.525 [Test worker] INFO o.s.c.MACBenchmark - short2 = 9938 11:57:34.527 [Test worker] INFO o.s.c.MACBenchmark - int1 = 9938 44.421997org.subshare.crypto.MACBenchmark11:57:34.470 [Test worker] INFO o.s.c.MACBenchmark - short1 = 9938 11:57:34.525 [Test worker] INFO o.s.c.MACBenchmark - short2 = 9938 11:57:34.527 [Test worker] INFO o.s.c.MACBenchmark - int1 = 9938 2019-07-27T09:57:340org.subshare.crypto.MACTest6.5530testAllSupportedMACsfalsePASSED6.553org.subshare.crypto.MACTest2019-07-27T09:57:320org.subshare.crypto.ShowSupportedAlgosForDocumentation0.2060showSupportedBlockCipherModesfalsePASSED>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** BlockCipherMode *** CBC CBC-CTS CCM CFB CFB104 CFB112 CFB120 CFB128 CFB136 CFB144 CFB152 CFB16 CFB160 CFB168 CFB176 CFB184 CFB192 CFB200 CFB208 CFB216 CFB224 CFB232 CFB24 CFB240 CFB248 CFB256 CFB32 CFB40 CFB48 CFB56 CFB64 CFB72 CFB8 CFB80 CFB88 CFB96 CTS EAX ECB GCM GOFB OFB OFB104 OFB112 OFB120 OFB128 OFB136 OFB144 OFB152 OFB16 OFB160 OFB168 OFB176 OFB184 OFB192 OFB200 OFB208 OFB216 OFB224 OFB232 OFB24 OFB240 OFB248 OFB256 OFB32 OFB40 OFB48 OFB56 OFB64 ...[truncated 1515 chars]... ADDING NOPADDING PKCS5 PKCS5PADDING PKCS7 PKCS7PADDING TBC TBCPADDING X9.23 X9.23PADDING ZEROBYTE ZEROBYTEPADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** Padding/asymmetricBlock *** ISO9796-1 ISO9796-1PADDING NOPADDING OAEP OAEPPADDING OAEPWITHSHA1ANDMGF1 OAEPWITHSHA1ANDMGF1PADDING PKCS1 PKCS1PADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** Padding/symmetricStream *** NOPADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 0org.subshare.crypto.ShowSupportedAlgosForDocumentation0.0610showSupportedCipherEnginesfalsePASSED>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** BlockCipherMode *** CBC CBC-CTS CCM CFB CFB104 CFB112 CFB120 CFB128 CFB136 CFB144 CFB152 CFB16 CFB160 CFB168 CFB176 CFB184 CFB192 CFB200 CFB208 CFB216 CFB224 CFB232 CFB24 CFB240 CFB248 CFB256 CFB32 CFB40 CFB48 CFB56 CFB64 CFB72 CFB8 CFB80 CFB88 CFB96 CTS EAX ECB GCM GOFB OFB OFB104 OFB112 OFB120 OFB128 OFB136 OFB144 OFB152 OFB16 OFB160 OFB168 OFB176 OFB184 OFB192 OFB200 OFB208 OFB216 OFB224 OFB232 OFB24 OFB240 OFB248 OFB256 OFB32 OFB40 OFB48 OFB56 OFB64 ...[truncated 1515 chars]... ADDING NOPADDING PKCS5 PKCS5PADDING PKCS7 PKCS7PADDING TBC TBCPADDING X9.23 X9.23PADDING ZEROBYTE ZEROBYTEPADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** Padding/asymmetricBlock *** ISO9796-1 ISO9796-1PADDING NOPADDING OAEP OAEPPADDING OAEPWITHSHA1ANDMGF1 OAEPWITHSHA1ANDMGF1PADDING PKCS1 PKCS1PADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** Padding/symmetricStream *** NOPADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 0org.subshare.crypto.ShowSupportedAlgosForDocumentation0.0340showSupportedMACsfalsePASSED>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** BlockCipherMode *** CBC CBC-CTS CCM CFB CFB104 CFB112 CFB120 CFB128 CFB136 CFB144 CFB152 CFB16 CFB160 CFB168 CFB176 CFB184 CFB192 CFB200 CFB208 CFB216 CFB224 CFB232 CFB24 CFB240 CFB248 CFB256 CFB32 CFB40 CFB48 CFB56 CFB64 CFB72 CFB8 CFB80 CFB88 CFB96 CTS EAX ECB GCM GOFB OFB OFB104 OFB112 OFB120 OFB128 OFB136 OFB144 OFB152 OFB16 OFB160 OFB168 OFB176 OFB184 OFB192 OFB200 OFB208 OFB216 OFB224 OFB232 OFB24 OFB240 OFB248 OFB256 OFB32 OFB40 OFB48 OFB56 OFB64 ...[truncated 1515 chars]... ADDING NOPADDING PKCS5 PKCS5PADDING PKCS7 PKCS7PADDING TBC TBCPADDING X9.23 X9.23PADDING ZEROBYTE ZEROBYTEPADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** Padding/asymmetricBlock *** ISO9796-1 ISO9796-1PADDING NOPADDING OAEP OAEPPADDING OAEPWITHSHA1ANDMGF1 OAEPWITHSHA1ANDMGF1PADDING PKCS1 PKCS1PADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** Padding/symmetricStream *** NOPADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 0org.subshare.crypto.ShowSupportedAlgosForDocumentation0.0040showSupportedPaddingsfalsePASSED>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** BlockCipherMode *** CBC CBC-CTS CCM CFB CFB104 CFB112 CFB120 CFB128 CFB136 CFB144 CFB152 CFB16 CFB160 CFB168 CFB176 CFB184 CFB192 CFB200 CFB208 CFB216 CFB224 CFB232 CFB24 CFB240 CFB248 CFB256 CFB32 CFB40 CFB48 CFB56 CFB64 CFB72 CFB8 CFB80 CFB88 CFB96 CTS EAX ECB GCM GOFB OFB OFB104 OFB112 OFB120 OFB128 OFB136 OFB144 OFB152 OFB16 OFB160 OFB168 OFB176 OFB184 OFB192 OFB200 OFB208 OFB216 OFB224 OFB232 OFB24 OFB240 OFB248 OFB256 OFB32 OFB40 OFB48 OFB56 OFB64 ...[truncated 1515 chars]... ADDING NOPADDING PKCS5 PKCS5PADDING PKCS7 PKCS7PADDING TBC TBCPADDING X9.23 X9.23PADDING ZEROBYTE ZEROBYTEPADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** Padding/asymmetricBlock *** ISO9796-1 ISO9796-1PADDING NOPADDING OAEP OAEPPADDING OAEPWITHSHA1ANDMGF1 OAEPWITHSHA1ANDMGF1PADDING PKCS1 PKCS1PADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** Padding/symmetricStream *** NOPADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 0.305org.subshare.crypto.ShowSupportedAlgosForDocumentation>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** BlockCipherMode *** CBC CBC-CTS CCM CFB CFB104 CFB112 CFB120 CFB128 CFB136 CFB144 CFB152 CFB16 CFB160 CFB168 CFB176 CFB184 CFB192 CFB200 CFB208 CFB216 CFB224 CFB232 CFB24 CFB240 CFB248 CFB256 CFB32 CFB40 CFB48 CFB56 CFB64 CFB72 CFB8 CFB80 CFB88 CFB96 CTS EAX ECB GCM GOFB OFB OFB104 OFB112 OFB120 OFB128 OFB136 OFB144 OFB152 OFB16 OFB160 OFB168 OFB176 OFB184 OFB192 OFB200 OFB208 OFB216 OFB224 OFB232 OFB24 OFB240 OFB248 OFB256 OFB32 OFB40 OFB48 OFB56 OFB64 ...[truncated 1515 chars]... ADDING NOPADDING PKCS5 PKCS5PADDING PKCS7 PKCS7PADDING TBC TBCPADDING X9.23 X9.23PADDING ZEROBYTE ZEROBYTEPADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** Padding/asymmetricBlock *** ISO9796-1 ISO9796-1PADDING NOPADDING OAEP OAEPPADDING OAEPWITHSHA1ANDMGF1 OAEPWITHSHA1ANDMGF1PADDING PKCS1 PKCS1PADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> *** Padding/symmetricStream *** NOPADDING <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 2019-07-27T09:57:340org.subshare.local.CryptreeImplGrantRevokeReadPermissionTest87.650grantAndRevokeReadPermissionfalsePASSED11:58:46.097 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:46.430 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:48.984 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [eccf704]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.local/build/repo/jyld407h-t8gqb-local' 11:58:49.187 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1813 ms. 11: ...[truncated 41640 chars]... INFO o.s.l.CryptreeImplGrantRevokeReadPermissionTest - Local sync...: 90.83% 12:00:13.542 [Test worker] INFO o.s.l.CryptreeImplGrantRevokeReadPermissionTest - Local sync...: 96.55% 12:00:13.574 [Test worker] INFO o.s.l.CryptreeImplGrantRevokeReadPermissionTest - Local sync...: 100.00% 12:00:13.845 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [eccf704]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:00:13.849 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 87.65org.subshare.local.CryptreeImplGrantRevokeReadPermissionTest11:58:46.097 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:46.430 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:48.984 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [eccf704]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.local/build/repo/jyld407h-t8gqb-local' 11:58:49.187 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1813 ms. 11: ...[truncated 41640 chars]... INFO o.s.l.CryptreeImplGrantRevokeReadPermissionTest - Local sync...: 90.83% 12:00:13.542 [Test worker] INFO o.s.l.CryptreeImplGrantRevokeReadPermissionTest - Local sync...: 96.55% 12:00:13.574 [Test worker] INFO o.s.l.CryptreeImplGrantRevokeReadPermissionTest - Local sync...: 100.00% 12:00:13.845 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [eccf704]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:00:13.849 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T09:58:460org.subshare.local.CryptreeImplGrantRevokeWritePermissionTest76.8070grantWritePermissionWithoutGrantPermissionfalsePASSED11:58:45.855 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:46.150 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:48.656 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [43cadd35]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.local/build/repo/jyld3zyw-dq5mp-local' 11:58:48.910 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1091 ms. 11 ...[truncated 208653 chars]... nTest - Local sync...: 79.60% 12:03:20.126 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 90.83% 12:03:20.151 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 96.55% 12:03:20.170 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 100.00% 12:03:20.198 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [79346d3]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:03:20.200 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.CryptreeImplGrantRevokeWritePermissionTest33.7290writeWithWritePermissionInParentParentfalsePASSED11:58:45.855 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:46.150 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:48.656 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [43cadd35]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.local/build/repo/jyld3zyw-dq5mp-local' 11:58:48.910 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1091 ms. 11 ...[truncated 208653 chars]... nTest - Local sync...: 79.60% 12:03:20.126 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 90.83% 12:03:20.151 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 96.55% 12:03:20.170 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 100.00% 12:03:20.198 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [79346d3]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:03:20.200 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.CryptreeImplGrantRevokeWritePermissionTest35.7750writeWithWritePermissionInParentfalsePASSED11:58:45.855 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:46.150 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:48.656 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [43cadd35]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.local/build/repo/jyld3zyw-dq5mp-local' 11:58:48.910 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1091 ms. 11 ...[truncated 208653 chars]... nTest - Local sync...: 79.60% 12:03:20.126 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 90.83% 12:03:20.151 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 96.55% 12:03:20.170 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 100.00% 12:03:20.198 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [79346d3]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:03:20.200 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.CryptreeImplGrantRevokeWritePermissionTest29.3980writeWithWritePermissionDirectDirfalsePASSED11:58:45.855 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:46.150 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:48.656 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [43cadd35]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.local/build/repo/jyld3zyw-dq5mp-local' 11:58:48.910 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1091 ms. 11 ...[truncated 208653 chars]... nTest - Local sync...: 79.60% 12:03:20.126 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 90.83% 12:03:20.151 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 96.55% 12:03:20.170 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 100.00% 12:03:20.198 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [79346d3]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:03:20.200 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.CryptreeImplGrantRevokeWritePermissionTest32.1670writeWithoutWritePermissionfalsePASSED11:58:45.855 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:46.150 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:48.656 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [43cadd35]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.local/build/repo/jyld3zyw-dq5mp-local' 11:58:48.910 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1091 ms. 11 ...[truncated 208653 chars]... nTest - Local sync...: 79.60% 12:03:20.126 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 90.83% 12:03:20.151 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 96.55% 12:03:20.170 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 100.00% 12:03:20.198 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [79346d3]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:03:20.200 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.CryptreeImplGrantRevokeWritePermissionTest33.3820writeWithWritePermissionInParentParentGrantedIndirectlyfalsePASSED11:58:45.855 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:46.150 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:48.656 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [43cadd35]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.local/build/repo/jyld3zyw-dq5mp-local' 11:58:48.910 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1091 ms. 11 ...[truncated 208653 chars]... nTest - Local sync...: 79.60% 12:03:20.126 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 90.83% 12:03:20.151 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 96.55% 12:03:20.170 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 100.00% 12:03:20.198 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [79346d3]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:03:20.200 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.CryptreeImplGrantRevokeWritePermissionTest32.9960writeWithWritePermissionDirectFilefalsePASSED11:58:45.855 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:46.150 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:48.656 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [43cadd35]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.local/build/repo/jyld3zyw-dq5mp-local' 11:58:48.910 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1091 ms. 11 ...[truncated 208653 chars]... nTest - Local sync...: 79.60% 12:03:20.126 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 90.83% 12:03:20.151 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 96.55% 12:03:20.170 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 100.00% 12:03:20.198 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [79346d3]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:03:20.200 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 274.254org.subshare.local.CryptreeImplGrantRevokeWritePermissionTest11:58:45.855 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:46.150 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:48.656 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [43cadd35]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.local/build/repo/jyld3zyw-dq5mp-local' 11:58:48.910 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1091 ms. 11 ...[truncated 208653 chars]... nTest - Local sync...: 79.60% 12:03:20.126 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 90.83% 12:03:20.151 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 96.55% 12:03:20.170 [Test worker] INFO o.s.l.AbstractPermissionTest - Local sync...: 100.00% 12:03:20.198 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [79346d3]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:03:20.200 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T09:58:450org.subshare.local.FilePaddingLengthRandomTest15.5710testDistributionfalsePASSED11:58:48.400 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory lengthCategory2HitCount: {_100K=300654, _1M=147189, _10M=47161, _100M=3027, _1G=1969, _10G=0} lengthCategory2HitPercentage: {_100K=601, _1M=294, _10M=94, _100M=6, _1G=4, _10G=0} 11486 0org.subshare.local.FilePaddingLengthRandomTest0.0310generateOneRandomLengthfalsePASSED11:58:48.400 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory lengthCategory2HitCount: {_100K=300654, _1M=147189, _10M=47161, _100M=3027, _1G=1969, _10G=0} lengthCategory2HitPercentage: {_100K=601, _1M=294, _10M=94, _100M=6, _1G=4, _10G=0} 11486 15.602org.subshare.local.FilePaddingLengthRandomTest11:58:48.400 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory lengthCategory2HitCount: {_100K=300654, _1M=147189, _10M=47161, _100M=3027, _1G=1969, _10G=0} lengthCategory2HitPercentage: {_100K=601, _1M=294, _10M=94, _100M=6, _1G=4, _10G=0} 11486 2019-07-27T09:58:440org.subshare.local.persistence.CollisionTest3.1780xorUids1falsePASSED0org.subshare.local.persistence.CollisionTest0.0020xorUids2falsePASSED3.18org.subshare.local.persistence.CollisionTest2019-07-27T09:58:430org.subshare.local.sign.SignableTest3.8880signAndSerializeAndVerifyfalsePASSED11:58:46.640 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:49.397 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:49.492 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1508 ms. 11:58:51.049 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:51.052 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 905 chars]... o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.084 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.163 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.206 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.258 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.310 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.362 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.sign.SignableTest0.110signAndModifyCryptoKeyIdAndVerifyfalsePASSED11:58:46.640 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:49.397 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:49.492 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1508 ms. 11:58:51.049 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:51.052 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 905 chars]... o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.084 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.163 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.206 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.258 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.310 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.362 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.sign.SignableTest0.1220signAndVerifyfalsePASSED11:58:46.640 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:49.397 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:49.492 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1508 ms. 11:58:51.049 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:51.052 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 905 chars]... o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.084 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.163 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.206 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.258 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.310 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.362 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.sign.SignableTest0.0940signAndModifySignatureCreatedAndVerifyfalsePASSED11:58:46.640 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:49.397 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:49.492 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1508 ms. 11:58:51.049 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:51.052 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 905 chars]... o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.084 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.163 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.206 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.258 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.310 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.362 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.sign.SignableTest0.1040signAndModifyCryptoRepoFileIdAndVerifyfalsePASSED11:58:46.640 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:49.397 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:49.492 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1508 ms. 11:58:51.049 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:51.052 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 905 chars]... o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.084 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.163 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.206 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.258 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.310 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.362 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 4.318org.subshare.local.sign.SignableTest11:58:46.640 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:49.397 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:49.492 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1508 ms. 11:58:51.049 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:51.052 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 905 chars]... o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.084 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.163 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.206 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.258 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.310 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 11:58:57.362 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T09:58:530org.subshare.local.sign.SignerVerifierStreamTest32.1780signRsaWithSha1falsePASSED11:58:46.984 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:48.438 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:48.624 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1376 ms. 11:58:50.024 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:50.025 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 5060 chars]... all run #93 signAndVerifyRandomManySmall run #94 signAndVerifyRandomManySmall run #95 signAndVerifyRandomManySmall run #96 signAndVerifyRandomManySmall run #97 signAndVerifyRandomManySmall run #98 signAndVerifyRandomManySmall run #99 signAndVerifyRandomManySmall run #100 12:00:22.086 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:22.118 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:28.547 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.sign.SignerVerifierStreamTest0.0860signAndVerifySimpleBlockReadfalsePASSED11:58:46.984 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:48.438 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:48.624 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1376 ms. 11:58:50.024 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:50.025 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 5060 chars]... all run #93 signAndVerifyRandomManySmall run #94 signAndVerifyRandomManySmall run #95 signAndVerifyRandomManySmall run #96 signAndVerifyRandomManySmall run #97 signAndVerifyRandomManySmall run #98 signAndVerifyRandomManySmall run #99 signAndVerifyRandomManySmall run #100 12:00:22.086 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:22.118 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:28.547 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.sign.SignerVerifierStreamTest34.3570sha1DigestfalsePASSED11:58:46.984 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:48.438 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:48.624 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1376 ms. 11:58:50.024 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:50.025 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 5060 chars]... all run #93 signAndVerifyRandomManySmall run #94 signAndVerifyRandomManySmall run #95 signAndVerifyRandomManySmall run #96 signAndVerifyRandomManySmall run #97 signAndVerifyRandomManySmall run #98 signAndVerifyRandomManySmall run #99 signAndVerifyRandomManySmall run #100 12:00:22.086 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:22.118 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:28.547 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.sign.SignerVerifierStreamTest10.1730signAndVerifyRandomBrokenfalsePASSED11:58:46.984 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:48.438 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:48.624 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1376 ms. 11:58:50.024 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:50.025 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 5060 chars]... all run #93 signAndVerifyRandomManySmall run #94 signAndVerifyRandomManySmall run #95 signAndVerifyRandomManySmall run #96 signAndVerifyRandomManySmall run #97 signAndVerifyRandomManySmall run #98 signAndVerifyRandomManySmall run #99 signAndVerifyRandomManySmall run #100 12:00:22.086 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:22.118 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:28.547 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.sign.SignerVerifierStreamTest13.4750signAndVerifyRandomManySmallfalsePASSED11:58:46.984 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:48.438 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:48.624 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1376 ms. 11:58:50.024 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:50.025 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 5060 chars]... all run #93 signAndVerifyRandomManySmall run #94 signAndVerifyRandomManySmall run #95 signAndVerifyRandomManySmall run #96 signAndVerifyRandomManySmall run #97 signAndVerifyRandomManySmall run #98 signAndVerifyRandomManySmall run #99 signAndVerifyRandomManySmall run #100 12:00:22.086 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:22.118 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:28.547 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.local.sign.SignerVerifierStreamTest6.460signAndVerifyRandomfalsePASSED11:58:46.984 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:48.438 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:48.624 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1376 ms. 11:58:50.024 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:50.025 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 5060 chars]... all run #93 signAndVerifyRandomManySmall run #94 signAndVerifyRandomManySmall run #95 signAndVerifyRandomManySmall run #96 signAndVerifyRandomManySmall run #97 signAndVerifyRandomManySmall run #98 signAndVerifyRandomManySmall run #99 signAndVerifyRandomManySmall run #100 12:00:22.086 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:22.118 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:28.547 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 96.729004org.subshare.local.sign.SignerVerifierStreamTest11:58:46.984 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 11:58:48.438 [Test worker] DEBUG o.s.c.p.g.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 11:58:48.624 [Test worker] INFO c.c.c.c.c.ConfigImpl - getLastModifiedAndWaitIfNeeded: Waiting 1376 ms. 11:58:50.024 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: dirString=${user.home}/.gnupg 11:58:50.025 [Test worker] DEBUG o.s.c.p.g.GnuPgDir - getFile: result=/home/tomcat/.gnupg 11 ...[truncated 5060 chars]... all run #93 signAndVerifyRandomManySmall run #94 signAndVerifyRandomManySmall run #95 signAndVerifyRandomManySmall run #96 signAndVerifyRandomManySmall run #97 signAndVerifyRandomManySmall run #98 signAndVerifyRandomManySmall run #99 signAndVerifyRandomManySmall run #100 12:00:22.086 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:22.118 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:00:28.547 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T09:58:510org.subshare.rest.client.transport.CryptreeRepoTransportTest32.4270encryptAndSignAndVerifyAndDecryptfalsePASSED12:03:26.952 [Test worker] INFO c.c.cloudstore.core.oio.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 12:03:27.830 [Test worker] DEBUG o.s.c.pgp.gnupg.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 12:03:27.849 [Test worker] DEBUG c.c.c.core.config.ConfigImpl - getPropertyAsNonEmptyTrimmedString: System property with key='subshare.gnupg.dir' is not set (config is queried next). 12:03:27.850 [Test worker] DEBUG c.c.c.core.config.ConfigImpl - read: Reading propertie ...[truncated 44523 chars]... y='subshare.signerTransformation' is not set (config is queried next). 12:03:58.763 [Test worker] DEBUG c.c.c.core.config.ConfigImpl - getPropertyAsNonEmptyTrimmedString: System property with key='subshare.symmetricCipherTransformation' is not set (config is queried next). 12:03:58.857 [Test worker] DEBUG o.s.r.c.t.CryptreeRestRepoTransportImpl - close: There is no localRepoManager. 12:03:58.857 [Test worker] DEBUG o.s.r.c.t.CryptreeRestRepoTransportImpl - close: There is no restRepoTransport. 32.427org.subshare.rest.client.transport.CryptreeRepoTransportTest12:03:26.952 [Test worker] INFO c.c.cloudstore.core.oio.OioRegistry - Preferred implementation 'IoFileFactory' for fileFactory 12:03:27.830 [Test worker] DEBUG o.s.c.pgp.gnupg.BcWithLocalGnuPgPgp - loadIfNeeded: invoking load(). 12:03:27.849 [Test worker] DEBUG c.c.c.core.config.ConfigImpl - getPropertyAsNonEmptyTrimmedString: System property with key='subshare.gnupg.dir' is not set (config is queried next). 12:03:27.850 [Test worker] DEBUG c.c.c.core.config.ConfigImpl - read: Reading propertie ...[truncated 44523 chars]... y='subshare.signerTransformation' is not set (config is queried next). 12:03:58.763 [Test worker] DEBUG c.c.c.core.config.ConfigImpl - getPropertyAsNonEmptyTrimmedString: System property with key='subshare.symmetricCipherTransformation' is not set (config is queried next). 12:03:58.857 [Test worker] DEBUG o.s.r.c.t.CryptreeRestRepoTransportImpl - close: There is no localRepoManager. 12:03:58.857 [Test worker] DEBUG o.s.r.c.t.CryptreeRestRepoTransportImpl - close: There is no restRepoTransport. 2019-07-27T10:03:260org.subshare.test.BackupRestoreRepoToRepoSyncIT281.820backupRestoreClientRepofalsePASSED12:30:16.989 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:30:17.806 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [65e5e2e]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle8hq8-oswxc-local-src' 12:30:17.817 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [65e5e2e]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle8hq8-oswxc-local-src' locked ...[truncated 338213 chars]... [5bb2a244]close: Deferring shut down of real LocalRepoManager 10000 ms. 12:34:58.335 [Test worker] INFO o.s.t.AbstractRepoToRepoSyncIT - Synchronising...: 100.00% 12:34:58.336 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7e1b904e]getCloseDeferredMillis: closeDeferredMillis=10000 12:34:58.336 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7e1b904e]close: Deferring shut down of real LocalRepoManager 10000 ms. 12:34:58.806 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 80org.subshare.test.BackupRestoreRepoToRepoSyncIT0.0291backupRestoreServerRepotrueSKIPPED12:30:16.989 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:30:17.806 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [65e5e2e]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle8hq8-oswxc-local-src' 12:30:17.817 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [65e5e2e]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle8hq8-oswxc-local-src' locked ...[truncated 338213 chars]... [5bb2a244]close: Deferring shut down of real LocalRepoManager 10000 ms. 12:34:58.335 [Test worker] INFO o.s.t.AbstractRepoToRepoSyncIT - Synchronising...: 100.00% 12:34:58.336 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7e1b904e]getCloseDeferredMillis: closeDeferredMillis=10000 12:34:58.336 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7e1b904e]close: Deferring shut down of real LocalRepoManager 10000 ms. 12:34:58.806 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 281.82org.subshare.test.BackupRestoreRepoToRepoSyncIT12:30:16.989 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:30:17.806 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [65e5e2e]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle8hq8-oswxc-local-src' 12:30:17.817 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [65e5e2e]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle8hq8-oswxc-local-src' locked ...[truncated 338213 chars]... [5bb2a244]close: Deferring shut down of real LocalRepoManager 10000 ms. 12:34:58.335 [Test worker] INFO o.s.t.AbstractRepoToRepoSyncIT - Synchronising...: 100.00% 12:34:58.336 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7e1b904e]getCloseDeferredMillis: closeDeferredMillis=10000 12:34:58.336 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7e1b904e]close: Deferring shut down of real LocalRepoManager 10000 ms. 12:34:58.806 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:30:160org.subshare.test.BrokenSignatureIT244.0090uploadBrokenSignaturefalsePASSEDJul 27, 2019 12:04:30 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:35 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.074 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:18.636 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/onQHJaYrwLYzy_3cq5NQeA/.subshare/ssl.server/keystore' does not exist! 12:04:18.640 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 504658 chars]... ncurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:54) [gradle-base-services-3.1.jar:3.1] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) [gradle-base-services-3.1.jar:3.1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212] 0org.subshare.test.BrokenSignatureIT129.1650downloadBrokenSignaturefalsePASSEDJul 27, 2019 12:04:30 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:35 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.074 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:18.636 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/onQHJaYrwLYzy_3cq5NQeA/.subshare/ssl.server/keystore' does not exist! 12:04:18.640 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 504658 chars]... ncurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:54) [gradle-base-services-3.1.jar:3.1] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) [gradle-base-services-3.1.jar:3.1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212] 373.174org.subshare.test.BrokenSignatureITJul 27, 2019 12:04:30 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:35 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.074 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:18.636 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/onQHJaYrwLYzy_3cq5NQeA/.subshare/ssl.server/keystore' does not exist! 12:04:18.640 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 504658 chars]... ncurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:54) [gradle-base-services-3.1.jar:3.1] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) [gradle-base-services-3.1.jar:3.1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212] 2019-07-27T10:04:370org.subshare.test.CollisionOnClientRepoToRepoSyncIT255.7870newFileVsNewFileCollisionOnClientfalsePASSED12:27:47.776 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:27:48.563 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' 12:27:48.567 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' locke ...[truncated 1954229 chars]... : closeDeferredMillis=20000 12:44:23.620 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [3a1eb493]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]getCloseDeferredMillis: closeDeferredMillis=20000 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.975 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.CollisionOnClientRepoToRepoSyncIT172.0180newDirectoryVsNewDirectoryCollisionOnClientfalsePASSED12:27:47.776 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:27:48.563 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' 12:27:48.567 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' locke ...[truncated 1954229 chars]... : closeDeferredMillis=20000 12:44:23.620 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [3a1eb493]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]getCloseDeferredMillis: closeDeferredMillis=20000 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.975 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.CollisionOnClientRepoToRepoSyncIT208.9230modifiedFileVsDeletedFileCollisionOnClientfalsePASSED12:27:47.776 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:27:48.563 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' 12:27:48.567 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' locke ...[truncated 1954229 chars]... : closeDeferredMillis=20000 12:44:23.620 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [3a1eb493]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]getCloseDeferredMillis: closeDeferredMillis=20000 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.975 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.CollisionOnClientRepoToRepoSyncIT138.3370modifiedFileVsModifiedFileCollisionOnClientfalsePASSED12:27:47.776 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:27:48.563 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' 12:27:48.567 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' locke ...[truncated 1954229 chars]... : closeDeferredMillis=20000 12:44:23.620 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [3a1eb493]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]getCloseDeferredMillis: closeDeferredMillis=20000 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.975 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.CollisionOnClientRepoToRepoSyncIT117.4710deletedFileVsModifiedFileCollisionOnClientfalsePASSED12:27:47.776 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:27:48.563 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' 12:27:48.567 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' locke ...[truncated 1954229 chars]... : closeDeferredMillis=20000 12:44:23.620 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [3a1eb493]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]getCloseDeferredMillis: closeDeferredMillis=20000 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.975 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.CollisionOnClientRepoToRepoSyncIT103.6560newFileVsNewDirectoryCollisionOnClientfalsePASSED12:27:47.776 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:27:48.563 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' 12:27:48.567 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' locke ...[truncated 1954229 chars]... : closeDeferredMillis=20000 12:44:23.620 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [3a1eb493]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]getCloseDeferredMillis: closeDeferredMillis=20000 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.975 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 996.1921org.subshare.test.CollisionOnClientRepoToRepoSyncIT12:27:47.776 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:27:48.563 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' 12:27:48.567 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [61d4bf68]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyle5akx-ozucg-local-src' locke ...[truncated 1954229 chars]... : closeDeferredMillis=20000 12:44:23.620 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [3a1eb493]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]getCloseDeferredMillis: closeDeferredMillis=20000 12:44:23.621 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [5e0ad898]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:44:23.975 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:27:470org.subshare.test.CollisionOnServerRepoToRepoSyncIT365.0570newFileVsNewFileUploadedCollisionOnServerfalsePASSEDJul 27, 2019 12:04:29 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:34 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.476 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:19.760 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/OTCAY_19zlhrTRpNn9MJug/.subshare/ssl.server/keystore' does not exist! 12:04:19.763 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 1047712 chars]... : closeDeferredMillis=20000 12:21:12.929 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4d2f7769]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:21:12.947 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4f77e4be]getCloseDeferredMillis: closeDeferredMillis=20000 12:21:12.948 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4f77e4be]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:21:13.382 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.CollisionOnServerRepoToRepoSyncIT631.30newFileVsNewFileUploadingCollisionOnServerfalsePASSEDJul 27, 2019 12:04:29 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:34 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.476 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:19.760 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/OTCAY_19zlhrTRpNn9MJug/.subshare/ssl.server/keystore' does not exist! 12:04:19.763 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 1047712 chars]... : closeDeferredMillis=20000 12:21:12.929 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4d2f7769]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:21:12.947 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4f77e4be]getCloseDeferredMillis: closeDeferredMillis=20000 12:21:12.948 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4f77e4be]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:21:13.382 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 996.357org.subshare.test.CollisionOnServerRepoToRepoSyncITJul 27, 2019 12:04:29 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:34 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.476 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:19.760 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/OTCAY_19zlhrTRpNn9MJug/.subshare/ssl.server/keystore' does not exist! 12:04:19.763 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 1047712 chars]... : closeDeferredMillis=20000 12:21:12.929 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4d2f7769]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:21:12.947 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4f77e4be]getCloseDeferredMillis: closeDeferredMillis=20000 12:21:12.948 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4f77e4be]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:21:13.382 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:04:370org.subshare.test.IgnoreRuleRepoToRepoSyncIT340.4730ignoreRulesAddedAfterFilesSyncedfalsePASSEDJul 27, 2019 12:04:52 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:56 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.684 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:19.708 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/PUv2TAgCaTC4rGZojR5Jkw/.subshare/ssl.server/keystore' does not exist! 12:04:19.713 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 986397 chars]... : closeDeferredMillis=20000 12:18:56.958 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [33db7321]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:18:56.967 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4ecc1577]getCloseDeferredMillis: closeDeferredMillis=20000 12:18:56.968 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4ecc1577]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:18:57.410 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.IgnoreRuleRepoToRepoSyncIT259.5450ignoreRulesBecomeDisabledfalsePASSEDJul 27, 2019 12:04:52 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:56 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.684 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:19.708 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/PUv2TAgCaTC4rGZojR5Jkw/.subshare/ssl.server/keystore' does not exist! 12:04:19.713 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 986397 chars]... : closeDeferredMillis=20000 12:18:56.958 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [33db7321]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:18:56.967 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4ecc1577]getCloseDeferredMillis: closeDeferredMillis=20000 12:18:56.968 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4ecc1577]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:18:57.410 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.IgnoreRuleRepoToRepoSyncIT237.4790ignoreRulesExistBeforeAffectedFilesfalsePASSEDJul 27, 2019 12:04:52 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:56 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.684 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:19.708 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/PUv2TAgCaTC4rGZojR5Jkw/.subshare/ssl.server/keystore' does not exist! 12:04:19.713 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 986397 chars]... : closeDeferredMillis=20000 12:18:56.958 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [33db7321]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:18:56.967 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4ecc1577]getCloseDeferredMillis: closeDeferredMillis=20000 12:18:56.968 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4ecc1577]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:18:57.410 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 837.497org.subshare.test.IgnoreRuleRepoToRepoSyncITJul 27, 2019 12:04:52 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:56 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.684 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:19.708 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/PUv2TAgCaTC4rGZojR5Jkw/.subshare/ssl.server/keystore' does not exist! 12:04:19.713 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 986397 chars]... : closeDeferredMillis=20000 12:18:56.958 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [33db7321]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:18:56.967 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4ecc1577]getCloseDeferredMillis: closeDeferredMillis=20000 12:18:56.968 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4ecc1577]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:18:57.410 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:04:590org.subshare.test.InterruptedRepoToRepoSyncIT197.4310interruptSyncDownAndResumefalsePASSED12:21:14.219 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:21:15.309 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [547cab0b]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldwv55-r670m-local-src' 12:21:15.314 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [547cab0b]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldwv55-r670m-local-src' locke ...[truncated 450504 chars]... : closeDeferredMillis=20000 12:27:46.700 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [2d070428]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:27:46.707 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [1eba2cb1]getCloseDeferredMillis: closeDeferredMillis=20000 12:27:46.707 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [1eba2cb1]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:27:47.320 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.InterruptedRepoToRepoSyncIT195.6710interruptSyncUpAndResumefalsePASSED12:21:14.219 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:21:15.309 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [547cab0b]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldwv55-r670m-local-src' 12:21:15.314 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [547cab0b]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldwv55-r670m-local-src' locke ...[truncated 450504 chars]... : closeDeferredMillis=20000 12:27:46.700 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [2d070428]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:27:46.707 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [1eba2cb1]getCloseDeferredMillis: closeDeferredMillis=20000 12:27:46.707 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [1eba2cb1]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:27:47.320 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 393.102org.subshare.test.InterruptedRepoToRepoSyncIT12:21:14.219 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:21:15.309 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [547cab0b]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldwv55-r670m-local-src' 12:21:15.314 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [547cab0b]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldwv55-r670m-local-src' locke ...[truncated 450504 chars]... : closeDeferredMillis=20000 12:27:46.700 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [2d070428]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:27:46.707 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [1eba2cb1]getCloseDeferredMillis: closeDeferredMillis=20000 12:27:46.707 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [1eba2cb1]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:27:47.320 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:21:140org.subshare.test.InviteUserAndSyncIT209.6690inviteUserAndSync_singleReadPermissionOnSubdirfalsePASSED12:29:23.246 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>>>>>>>>>>>>> *** 12:29:23.247 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>> before >>> *** 12:29:23.637 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:29:23.638 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:29:23.640 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org. ...[truncated 1416744 chars]... s: closeDeferredMillis=20000 12:39:11.178 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [983c732]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:39:11.182 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [27a1853d]getCloseDeferredMillis: closeDeferredMillis=20000 12:39:11.183 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [27a1853d]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:39:11.622 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.InviteUserAndSyncIT194.4450inviteUserAndSync_singleWritePermissionOnRootfalsePASSED12:29:23.246 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>>>>>>>>>>>>> *** 12:29:23.247 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>> before >>> *** 12:29:23.637 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:29:23.638 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:29:23.640 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org. ...[truncated 1416744 chars]... s: closeDeferredMillis=20000 12:39:11.178 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [983c732]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:39:11.182 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [27a1853d]getCloseDeferredMillis: closeDeferredMillis=20000 12:39:11.183 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [27a1853d]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:39:11.622 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.InviteUserAndSyncIT184.2640inviteUserAndSync_singleReadPermissionOnRootfalsePASSED12:29:23.246 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>>>>>>>>>>>>> *** 12:29:23.247 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>> before >>> *** 12:29:23.637 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:29:23.638 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:29:23.640 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org. ...[truncated 1416744 chars]... s: closeDeferredMillis=20000 12:39:11.178 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [983c732]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:39:11.182 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [27a1853d]getCloseDeferredMillis: closeDeferredMillis=20000 12:39:11.183 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [27a1853d]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:39:11.622 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 588.37805org.subshare.test.InviteUserAndSyncIT12:29:23.246 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>>>>>>>>>>>>> *** 12:29:23.247 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>> before >>> *** 12:29:23.637 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:29:23.638 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:29:23.640 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org. ...[truncated 1416744 chars]... s: closeDeferredMillis=20000 12:39:11.178 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [983c732]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:39:11.182 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [27a1853d]getCloseDeferredMillis: closeDeferredMillis=20000 12:39:11.183 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [27a1853d]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:39:11.622 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:29:230org.subshare.test.InviteUserWithNormalAndMetaOnlyRepoIT356.060inviteUserAndSync_withMetaOnly_singleWritePermissionOnRootfalsePASSED12:15:57.478 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>>>>>>>>>>>>> *** 12:15:57.480 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>> before >>> *** 12:15:57.798 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:15:57.821 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:15:57.823 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org. ...[truncated 449972 chars]... s: closeDeferredMillis=20000 12:21:53.137 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [78c8282]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:21:53.138 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [6210cd3b]getCloseDeferredMillis: closeDeferredMillis=20000 12:21:53.138 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [6210cd3b]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:21:53.527 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 356.06org.subshare.test.InviteUserWithNormalAndMetaOnlyRepoIT12:15:57.478 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>>>>>>>>>>>>> *** 12:15:57.480 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>> before >>> *** 12:15:57.798 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:15:57.821 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:15:57.823 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org. ...[truncated 449972 chars]... s: closeDeferredMillis=20000 12:21:53.137 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [78c8282]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:21:53.138 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [6210cd3b]getCloseDeferredMillis: closeDeferredMillis=20000 12:21:53.138 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [6210cd3b]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:21:53.527 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:15:570org.subshare.test.Issue4IT157.4350issue_4_syncFileDeletedAfterLocalSyncfalsePASSED12:10:51.071 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:10:52.032 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7957260]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldji7o-1r0ch-local-src' 12:10:52.045 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7957260]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldji7o-1r0ch-local-src' locked ...[truncated 161163 chars]... - [722bdeec]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:13:28.177 [Test worker] INFO o.s.t.AbstractRepoToRepoSyncIT - Synchronising...: 100.00% 12:13:28.178 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7957260]getCloseDeferredMillis: closeDeferredMillis=20000 12:13:28.178 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7957260]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:13:28.502 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 157.435org.subshare.test.Issue4IT12:10:51.071 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:10:52.032 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7957260]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldji7o-1r0ch-local-src' 12:10:52.045 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7957260]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldji7o-1r0ch-local-src' locked ...[truncated 161163 chars]... - [722bdeec]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:13:28.177 [Test worker] INFO o.s.t.AbstractRepoToRepoSyncIT - Synchronising...: 100.00% 12:13:28.178 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7957260]getCloseDeferredMillis: closeDeferredMillis=20000 12:13:28.178 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7957260]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:13:28.502 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:10:510org.subshare.test.Issue5IT435.7640issue_5_inviteMultipleFriendsfalsePASSEDJul 27, 2019 12:04:30 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:35 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.845 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:19.962 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/OVfiL6aGwDdgGU_0vZTU4Q/.subshare/ssl.server/keystore' does not exist! 12:04:19.968 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 540136 chars]... : closeDeferredMillis=20000 12:11:52.542 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7b71290f]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:11:52.543 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [53ad7023]getCloseDeferredMillis: closeDeferredMillis=20000 12:11:52.543 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [53ad7023]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:11:52.982 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 435.764org.subshare.test.Issue5ITJul 27, 2019 12:04:30 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:35 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.845 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:19.962 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/OVfiL6aGwDdgGU_0vZTU4Q/.subshare/ssl.server/keystore' does not exist! 12:04:19.968 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 540136 chars]... : closeDeferredMillis=20000 12:11:52.542 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7b71290f]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:11:52.543 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [53ad7023]getCloseDeferredMillis: closeDeferredMillis=20000 12:11:52.543 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [53ad7023]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:11:52.982 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:04:370org.subshare.test.Issue8IT595.8090issue_8_threesomeWithFreshmenfalsePASSED 12:19:03.869 [Test worker] INFO o.s.t.AbstractMultiUserIT - 12:19:03.874 [Test worker] INFO o.s.t.AbstractMultiUserIT - ******************************************************************** 12:19:03.875 [Test worker] INFO o.s.t.AbstractMultiUserIT - *** marco *** 12:19:03.881 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:19:03.882 [Test worker] INFO o.s.t.AbstractMultiUserIT - MockUp<GnuPgDir>.getInstance: testUser=marco 12:19:03.883 [Test worker] INFO o.s.t.PgpTestU ...[truncated 1265177 chars]... nager 20000 ms. 12:28:50.317 [Test worker] INFO o.s.t.AbstractMultiUserIT - MockUp<ServerRepoRegistryImpl>.getInstance: testUser=xenia 12:28:50.318 [Test worker] INFO o.s.t.AbstractMultiUserIT - MockUp<UserRegistryImpl>.getInstance: testUser=xenia 12:28:50.348 [Test worker] INFO o.s.t.AbstractMultiUserIT - MockUp<UserRegistryImpl>.getInstance: testUser=xenia 12:28:50.349 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487ec64b]close: Deferring shut down of real LocalRepoManager 20000 ms. 595.809org.subshare.test.Issue8IT 12:19:03.869 [Test worker] INFO o.s.t.AbstractMultiUserIT - 12:19:03.874 [Test worker] INFO o.s.t.AbstractMultiUserIT - ******************************************************************** 12:19:03.875 [Test worker] INFO o.s.t.AbstractMultiUserIT - *** marco *** 12:19:03.881 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:19:03.882 [Test worker] INFO o.s.t.AbstractMultiUserIT - MockUp<GnuPgDir>.getInstance: testUser=marco 12:19:03.883 [Test worker] INFO o.s.t.PgpTestU ...[truncated 1265177 chars]... nager 20000 ms. 12:28:50.317 [Test worker] INFO o.s.t.AbstractMultiUserIT - MockUp<ServerRepoRegistryImpl>.getInstance: testUser=xenia 12:28:50.318 [Test worker] INFO o.s.t.AbstractMultiUserIT - MockUp<UserRegistryImpl>.getInstance: testUser=xenia 12:28:50.348 [Test worker] INFO o.s.t.AbstractMultiUserIT - MockUp<UserRegistryImpl>.getInstance: testUser=xenia 12:28:50.349 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487ec64b]close: Deferring shut down of real LocalRepoManager 20000 ms. 2019-07-27T10:18:570org.subshare.test.LocalServerClientIT1.050invokeSimpleStaticMethodfalsePASSED12:11:54.022 [Test worker] INFO c.c.c.l.s.LocalServer - logMemoryStats: max=455.5 MiB, allocated=285.5 MiB, used=102.7 MiB, available=352.8 MiB 12:11:55.100 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:11:56.140 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:11:56.145 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:11:56.698 [qtp1946403320-25] ERROR c.c.c.l.r.s.DefaultExceptionMapper - java.lang.SecurityException: Invocation denied: Meth ...[truncated 79735 chars]... :54) [gradle-base-services-3.1.jar:3.1] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) [gradle-base-services-3.1.jar:3.1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212] 12:11:59.766 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.LocalServerClientIT3.6250invokeDeniedMethodsfalsePASSED12:11:54.022 [Test worker] INFO c.c.c.l.s.LocalServer - logMemoryStats: max=455.5 MiB, allocated=285.5 MiB, used=102.7 MiB, available=352.8 MiB 12:11:55.100 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:11:56.140 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:11:56.145 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:11:56.698 [qtp1946403320-25] ERROR c.c.c.l.r.s.DefaultExceptionMapper - java.lang.SecurityException: Invocation denied: Meth ...[truncated 79735 chars]... :54) [gradle-base-services-3.1.jar:3.1] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) [gradle-base-services-3.1.jar:3.1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212] 12:11:59.766 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 4.675org.subshare.test.LocalServerClientIT12:11:54.022 [Test worker] INFO c.c.c.l.s.LocalServer - logMemoryStats: max=455.5 MiB, allocated=285.5 MiB, used=102.7 MiB, available=352.8 MiB 12:11:55.100 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:11:56.140 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:11:56.145 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:11:56.698 [qtp1946403320-25] ERROR c.c.c.l.r.s.DefaultExceptionMapper - java.lang.SecurityException: Invocation denied: Meth ...[truncated 79735 chars]... :54) [gradle-base-services-3.1.jar:3.1] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) [gradle-base-services-3.1.jar:3.1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212] 12:11:59.766 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:11:550org.subshare.test.LockerSyncIT17.2090syncServerRegistryfalsePASSED12:28:56.187 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:28:56.198 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/PUv2TAgCaTC4rGZojR5Jkw/client1/.gnupg/pubring.gpg' 12:28:56.199 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/secring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subs ...[truncated 124485 chars]... ker] INFO o.s.c.l.s.LockerSync - syncDown: serverId='bchCeo_xol44kk9PaWP1Ug' serverName='null' pgpKeyId=d7a92a24aa97ddbd lockerContentName='userRegistry.subshare' 12:29:20.393 [Test worker] DEBUG o.s.c.p.g.BcPgpDecoder - verifySignature: signingPgpKeyIds=[d7a92a24aa97ddbd] 12:29:20.396 [Test worker] DEBUG o.s.c.p.g.BcPgpDecoder - decodeEncrypted: encryptingPgpKeyIds=[a58da7d810b74edf] 12:29:20.432 [Test worker] DEBUG o.s.c.p.g.BcPgpDecoder - verifySignature: signingPgpKeyIds=[d7a92a24aa97ddbd] 0org.subshare.test.LockerSyncIT12.3260syncUserRegistryfalsePASSED12:28:56.187 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:28:56.198 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/PUv2TAgCaTC4rGZojR5Jkw/client1/.gnupg/pubring.gpg' 12:28:56.199 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/secring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subs ...[truncated 124485 chars]... ker] INFO o.s.c.l.s.LockerSync - syncDown: serverId='bchCeo_xol44kk9PaWP1Ug' serverName='null' pgpKeyId=d7a92a24aa97ddbd lockerContentName='userRegistry.subshare' 12:29:20.393 [Test worker] DEBUG o.s.c.p.g.BcPgpDecoder - verifySignature: signingPgpKeyIds=[d7a92a24aa97ddbd] 12:29:20.396 [Test worker] DEBUG o.s.c.p.g.BcPgpDecoder - decodeEncrypted: encryptingPgpKeyIds=[a58da7d810b74edf] 12:29:20.432 [Test worker] DEBUG o.s.c.p.g.BcPgpDecoder - verifySignature: signingPgpKeyIds=[d7a92a24aa97ddbd] 29.535org.subshare.test.LockerSyncIT12:28:56.187 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:28:56.198 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/PUv2TAgCaTC4rGZojR5Jkw/client1/.gnupg/pubring.gpg' 12:28:56.199 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/secring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subs ...[truncated 124485 chars]... ker] INFO o.s.c.l.s.LockerSync - syncDown: serverId='bchCeo_xol44kk9PaWP1Ug' serverName='null' pgpKeyId=d7a92a24aa97ddbd lockerContentName='userRegistry.subshare' 12:29:20.393 [Test worker] DEBUG o.s.c.p.g.BcPgpDecoder - verifySignature: signingPgpKeyIds=[d7a92a24aa97ddbd] 12:29:20.396 [Test worker] DEBUG o.s.c.p.g.BcPgpDecoder - decodeEncrypted: encryptingPgpKeyIds=[a58da7d810b74edf] 12:29:20.432 [Test worker] DEBUG o.s.c.p.g.BcPgpDecoder - verifySignature: signingPgpKeyIds=[d7a92a24aa97ddbd] 2019-07-27T10:28:530org.subshare.test.MetaOnlyRepoSyncIT306.9460syncFromLocalToRemoteToMetaOnlyAddingFilesfalsePASSEDJul 27, 2019 12:04:33 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:38 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.026 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:18.679 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/rMaaQGMJsZw2Z2UdXdtv2Q/.subshare/ssl.server/keystore' does not exist! 12:04:18.685 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 652394 chars]... ring shut down of real LocalRepoManager 20000 ms. 12:15:56.782 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487f687c]getCloseDeferredMillis: closeDeferredMillis=20000 12:15:56.782 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487f687c]getMaxOpenMillis: maxOpenMillis=1200000 12:15:56.782 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487f687c]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:15:57.102 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.MetaOnlyRepoSyncIT177.5470syncFromLocalToRemoteToMetaOnlyfalsePASSEDJul 27, 2019 12:04:33 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:38 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.026 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:18.679 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/rMaaQGMJsZw2Z2UdXdtv2Q/.subshare/ssl.server/keystore' does not exist! 12:04:18.685 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 652394 chars]... ring shut down of real LocalRepoManager 20000 ms. 12:15:56.782 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487f687c]getCloseDeferredMillis: closeDeferredMillis=20000 12:15:56.782 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487f687c]getMaxOpenMillis: maxOpenMillis=1200000 12:15:56.782 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487f687c]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:15:57.102 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.MetaOnlyRepoSyncIT191.7070syncFromLocalToRemoteToMetaOnlyRemovingFilesfalsePASSEDJul 27, 2019 12:04:33 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:38 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.026 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:18.679 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/rMaaQGMJsZw2Z2UdXdtv2Q/.subshare/ssl.server/keystore' does not exist! 12:04:18.685 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 652394 chars]... ring shut down of real LocalRepoManager 20000 ms. 12:15:56.782 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487f687c]getCloseDeferredMillis: closeDeferredMillis=20000 12:15:56.782 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487f687c]getMaxOpenMillis: maxOpenMillis=1200000 12:15:56.782 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487f687c]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:15:57.102 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 676.2org.subshare.test.MetaOnlyRepoSyncITJul 27, 2019 12:04:33 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... Jul 27, 2019 12:04:38 PM org.glassfish.jersey.server.ApplicationHandler initialize INFO: Initiating Jersey application, version Jersey: 2.5.1 2014-01-02 13:43:00... 12:04:15.026 [Test worker] INFO c.c.c.c.o.OioRegistry - Preferred implementation 'NioFileFactory' for fileFactory 12:04:18.679 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: keyStoreFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/rMaaQGMJsZw2Z2UdXdtv2Q/.subshare/ssl.server/keystore' does not exist! 12:04:18.685 [cloudStoreServerThread] INFO c.c.c.s.CloudStoreServer - initKeyStore: Creating RSA key pair (this might take a whil ...[truncated 652394 chars]... ring shut down of real LocalRepoManager 20000 ms. 12:15:56.782 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487f687c]getCloseDeferredMillis: closeDeferredMillis=20000 12:15:56.782 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487f687c]getMaxOpenMillis: maxOpenMillis=1200000 12:15:56.782 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [487f687c]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:15:57.102 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:04:400org.subshare.test.MultiplePgpKeysSingleUserRegistryIT4.1190multiplePgpKeysSingleUserRegistryfalsePASSED12:42:29.370 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:42:29.371 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/onQHJaYrwLYzy_3cq5NQeA/.gnupg/pubring.gpg' 12:42:29.372 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/secring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org ...[truncated 2804 chars]... y pair with publicExponent='65537' strength='1024' certainty='12' took 75 ms. 12:42:32.516 [Test worker] DEBUG o.s.c.u.UserImpl - createUserRepoKey: pgpKey=PgpKey[bbef20af171556db, [Alexander Bieber (TEST) <alex@nightlabs.de>]], userRepoKey=UserRepoKeyImpl[userRepoKeyId=gyquvQRV_mtZEs9r0TP24Q, invitation=false] 12:42:32.558 [Test worker] DEBUG o.s.c.p.g.BcPgpDecoder - verifySignature: signingPgpKeyIds=[d7a92a24aa97ddbd] 12:42:33.056 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 4.119org.subshare.test.MultiplePgpKeysSingleUserRegistryIT12:42:29.370 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:42:29.371 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/jvm/onQHJaYrwLYzy_3cq5NQeA/.gnupg/pubring.gpg' 12:42:29.372 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/secring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org ...[truncated 2804 chars]... y pair with publicExponent='65537' strength='1024' certainty='12' took 75 ms. 12:42:32.516 [Test worker] DEBUG o.s.c.u.UserImpl - createUserRepoKey: pgpKey=PgpKey[bbef20af171556db, [Alexander Bieber (TEST) <alex@nightlabs.de>]], userRepoKey=UserRepoKeyImpl[userRepoKeyId=gyquvQRV_mtZEs9r0TP24Q, invitation=false] 12:42:32.558 [Test worker] DEBUG o.s.c.p.g.BcPgpDecoder - verifySignature: signingPgpKeyIds=[d7a92a24aa97ddbd] 12:42:33.056 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:42:280org.subshare.test.PathPrefixedConfigInheritanceRepoToRepoSyncIT288.4770parentConfigWithRemotePathPrefixfalsePASSED12:21:53.555 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:21:54.513 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [259b529a]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldxpe6-jdqvb-local-src' 12:21:54.518 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [259b529a]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldxpe6-jdqvb-local-src' locke ...[truncated 503874 chars]... : closeDeferredMillis=20000 12:26:41.639 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [259b529a]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:26:41.640 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [34c76c3e]getCloseDeferredMillis: closeDeferredMillis=20000 12:26:41.640 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [34c76c3e]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:26:42.030 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 288.477org.subshare.test.PathPrefixedConfigInheritanceRepoToRepoSyncIT12:21:53.555 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:21:54.513 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [259b529a]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldxpe6-jdqvb-local-src' 12:21:54.518 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [259b529a]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldxpe6-jdqvb-local-src' locke ...[truncated 503874 chars]... : closeDeferredMillis=20000 12:26:41.639 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [259b529a]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:26:41.640 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [34c76c3e]getCloseDeferredMillis: closeDeferredMillis=20000 12:26:41.640 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [34c76c3e]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:26:42.030 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:21:530org.subshare.test.PermissionIT327.8950interruptPermissionSetInheritancefalsePASSED12:12:11.199 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:12:12.262 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [15de4740]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldl84d-90yqo-local-src' 12:12:12.267 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [15de4740]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldl84d-90yqo-local-src' locke ...[truncated 1492485 chars]... : closeDeferredMillis=20000 12:30:16.200 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [76a69f81]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:30:16.201 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [53a7bff9]getCloseDeferredMillis: closeDeferredMillis=20000 12:30:16.201 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [53a7bff9]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:30:16.573 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.PermissionIT386.110uploadBackdatedSignaturefalsePASSED12:12:11.199 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:12:12.262 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [15de4740]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldl84d-90yqo-local-src' 12:12:12.267 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [15de4740]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldl84d-90yqo-local-src' locke ...[truncated 1492485 chars]... : closeDeferredMillis=20000 12:30:16.200 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [76a69f81]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:30:16.201 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [53a7bff9]getCloseDeferredMillis: closeDeferredMillis=20000 12:30:16.201 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [53a7bff9]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:30:16.573 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.PermissionIT371.3680nonOwnerAdminGrantsWritePermissionfalsePASSED12:12:11.199 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:12:12.262 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [15de4740]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldl84d-90yqo-local-src' 12:12:12.267 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [15de4740]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldl84d-90yqo-local-src' locke ...[truncated 1492485 chars]... : closeDeferredMillis=20000 12:30:16.200 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [76a69f81]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:30:16.201 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [53a7bff9]getCloseDeferredMillis: closeDeferredMillis=20000 12:30:16.201 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [53a7bff9]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:30:16.573 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 1085.373org.subshare.test.PermissionIT12:12:11.199 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:12:12.262 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [15de4740]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldl84d-90yqo-local-src' 12:12:12.267 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [15de4740]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldl84d-90yqo-local-src' locke ...[truncated 1492485 chars]... : closeDeferredMillis=20000 12:30:16.200 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [76a69f81]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:30:16.201 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [53a7bff9]getCloseDeferredMillis: closeDeferredMillis=20000 12:30:16.201 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [53a7bff9]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:30:16.573 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:12:110org.subshare.test.PgpSyncIT2.5960testPgpSyncfalsePASSED12:44:26.360 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:44:28.952 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2.596org.subshare.test.PgpSyncIT12:44:26.360 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:44:28.952 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:44:260org.subshare.test.ReadUserIdentityIT312.2620inviteWithReadInvitationAndGrantReadUserIdentityPermissionLaterfalsePASSED12:26:42.413 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>>>>>>>>>>>>> *** 12:26:42.414 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>> before >>> *** 12:26:42.778 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:26:42.779 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:26:42.780 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org. ...[truncated 494010 chars]... : closeDeferredMillis=20000 12:31:54.298 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [11fbb286]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:31:54.299 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4c2ff277]getCloseDeferredMillis: closeDeferredMillis=20000 12:31:54.299 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4c2ff277]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:31:54.671 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 312.262org.subshare.test.ReadUserIdentityIT12:26:42.413 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>>>>>>>>>>>>> *** 12:26:42.414 [Test worker] INFO o.s.t.AbstractUserRegistryIT - *** >>> before >>> *** 12:26:42.778 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:26:42.779 [Test worker] INFO o.s.t.PgpTestUtil - setupPgp: ownerName=marco 12:26:42.780 [Test worker] INFO o.s.t.PgpTestUtil - copyResource: sourceResName='gpg/marco/pubring.gpg' destinationFile='/home/tomcat/.jenkins/workspace/org.subshare/org. ...[truncated 494010 chars]... : closeDeferredMillis=20000 12:31:54.298 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [11fbb286]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:31:54.299 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4c2ff277]getCloseDeferredMillis: closeDeferredMillis=20000 12:31:54.299 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [4c2ff277]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:31:54.671 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:26:420org.subshare.test.RepoToRepoSyncIT234.6840syncFromLocalToRemoteToLocalAfterCreateAndDeleteFilefalsePASSED12:13:29.147 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:13:29.818 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' 12:13:29.850 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' locked ...[truncated 2555050 chars]... : closeDeferredMillis=20000 12:42:28.042 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7d41ba37]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]getCloseDeferredMillis: closeDeferredMillis=20000 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.479 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.RepoToRepoSyncIT310.4380syncFromLocalToRemoteToLocalWithPathPrefixWithWritePermissionGrantedAndRevokedfalsePASSED12:13:29.147 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:13:29.818 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' 12:13:29.850 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' locked ...[truncated 2555050 chars]... : closeDeferredMillis=20000 12:42:28.042 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7d41ba37]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]getCloseDeferredMillis: closeDeferredMillis=20000 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.479 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.RepoToRepoSyncIT198.6240syncFromLocalToRemoteToLocalfalsePASSED12:13:29.147 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:13:29.818 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' 12:13:29.850 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' locked ...[truncated 2555050 chars]... : closeDeferredMillis=20000 12:42:28.042 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7d41ba37]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]getCloseDeferredMillis: closeDeferredMillis=20000 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.479 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.RepoToRepoSyncIT164.0050syncFromLocalToRemoteToLocalWithPathPrefixWithoutSubdirClearanceKeyfalsePASSED12:13:29.147 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:13:29.818 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' 12:13:29.850 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' locked ...[truncated 2555050 chars]... : closeDeferredMillis=20000 12:42:28.042 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7d41ba37]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]getCloseDeferredMillis: closeDeferredMillis=20000 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.479 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.RepoToRepoSyncIT185.3780syncFromLocalToRemoteToLocalWithPathPrefixfalsePASSED12:13:29.147 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:13:29.818 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' 12:13:29.850 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' locked ...[truncated 2555050 chars]... : closeDeferredMillis=20000 12:42:28.042 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7d41ba37]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]getCloseDeferredMillis: closeDeferredMillis=20000 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.479 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.RepoToRepoSyncIT228.6680syncFromLocalToRemoteToLocalThenDeleteFileAndSyncAgainfalsePASSED12:13:29.147 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:13:29.818 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' 12:13:29.850 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' locked ...[truncated 2555050 chars]... : closeDeferredMillis=20000 12:42:28.042 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7d41ba37]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]getCloseDeferredMillis: closeDeferredMillis=20000 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.479 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.RepoToRepoSyncIT281.8480syncFromLocalToRemoteToLocalWithPathPrefixWithSubdirClearanceKeyfalsePASSED12:13:29.147 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:13:29.818 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' 12:13:29.850 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' locked ...[truncated 2555050 chars]... : closeDeferredMillis=20000 12:42:28.042 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7d41ba37]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]getCloseDeferredMillis: closeDeferredMillis=20000 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.479 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 114org.subshare.test.RepoToRepoSyncIT0.0257syncFromLocalToRemoteToLocalThenCauseDeleteCollisionOnServerDuringUpSynctrueSKIPPED12:13:29.147 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:13:29.818 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' 12:13:29.850 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' locked ...[truncated 2555050 chars]... : closeDeferredMillis=20000 12:42:28.042 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7d41ba37]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]getCloseDeferredMillis: closeDeferredMillis=20000 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.479 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 0org.subshare.test.RepoToRepoSyncIT135.670multiSyncFromLocalToRemoteToLocalWithPathPrefixWithSubdirClearanceKeyfalsePASSED12:13:29.147 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:13:29.818 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' 12:13:29.850 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' locked ...[truncated 2555050 chars]... : closeDeferredMillis=20000 12:42:28.042 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7d41ba37]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]getCloseDeferredMillis: closeDeferredMillis=20000 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.479 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 1739.3151org.subshare.test.RepoToRepoSyncIT12:13:29.147 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:13:29.818 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' 12:13:29.850 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [841b39c]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyldmvyt-oga1l-local-src' locked ...[truncated 2555050 chars]... : closeDeferredMillis=20000 12:42:28.042 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7d41ba37]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]getCloseDeferredMillis: closeDeferredMillis=20000 12:42:28.055 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [389c6620]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:42:28.479 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:13:290org.subshare.test.SymlinkCollisionOnClientRepoToRepoSyncIT203.2120newFileVsNewSymlinkCollisionOnClientfalsePASSED12:34:59.187 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:35:00.025 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7cf30f9e]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyleejhy-cw6ed-local-src' 12:35:00.033 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7cf30f9e]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyleejhy-cw6ed-local-src' locke ...[truncated 316662 chars]... : closeDeferredMillis=20000 12:38:21.993 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7cf30f9e]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:38:21.993 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [517fc325]getCloseDeferredMillis: closeDeferredMillis=20000 12:38:21.993 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [517fc325]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:38:22.392 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 203.212org.subshare.test.SymlinkCollisionOnClientRepoToRepoSyncIT12:34:59.187 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 12:35:00.025 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7cf30f9e]<init>: localRoot='/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyleejhy-cw6ed-local-src' 12:35:00.033 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7cf30f9e]initLockFile: Repository '/home/tomcat/.jenkins/workspace/org.subshare/org.subshare/org.subshare.test/build/repo/jyleejhy-cw6ed-local-src' locke ...[truncated 316662 chars]... : closeDeferredMillis=20000 12:38:21.993 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [7cf30f9e]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:38:21.993 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [517fc325]getCloseDeferredMillis: closeDeferredMillis=20000 12:38:21.993 [Test worker] INFO c.c.c.l.LocalRepoManagerImpl - [517fc325]close: Deferring shut down of real LocalRepoManager 20000 ms. 12:38:22.392 [Test worker] INFO o.s.c.p.PgpRegistry - clearCache: entered. 2019-07-27T10:34:59