Investigate failing test case on master

[aeneasr]

Describe the bug

--- FAIL: TestMutatorIDToken (8.14s)
    --- FAIL: TestMutatorIDToken/method=mutate (0.05s)
        --- FAIL: TestMutatorIDToken/method=mutate/case=test_token_cache (8.10s)
            --- FAIL: TestMutatorIDToken/method=mutate/case=test_token_cache/subcase=same_tokens_because_session_extra_changed_but_claims_ignore_the_extra_claims (1.00s)
                mutator_id_token_test.go:254: 
                    	Error Trace:	mutator_id_token_test.go:254
                    	Error:      	Not equal: 
                    	            	expected: "eyJhbGciOiJFUzI1NiIsImtpZCI6IjIxZDllZWZlLTM0YjYtNDJiMy1iNjQzLTJiMzBlMGFiNTllMCIsInR5cCI6IkpXVCJ9.eyJhdWQiOlsiZm9vIl0sImV4cCI6MTU4MzQxNjA2NSwiZm9vIjoiYmF6IiwiaWF0IjoxNTgzNDE2MDYyLCJpc3MiOiIvZm9vL2JhciIsImp0aSI6IjYyZTA5MzJkLTI4YWEtNDA5NC1hMWI1LTE4NDAzMTZlMjBiZiIsIm5iZiI6MTU4MzQxNjA2Miwic3ViIjoiZm9vIn0.B_6bY6IxdCLbVwcnJp9NZhAVGMqG_4c2V0FjKZDuU6XKUmCnXQvCx8aEMUgDeAk4XPbWLEqPXmiV5xYy5QhkxA"
                    	            	actual  : "eyJhbGciOiJFUzI1NiIsImtpZCI6IjIxZDllZWZlLTM0YjYtNDJiMy1iNjQzLTJiMzBlMGFiNTllMCIsInR5cCI6IkpXVCJ9.eyJhdWQiOlsiZm9vIl0sImV4cCI6MTU4MzQxNjA2NiwiZm9vIjoiYmF6IiwiaWF0IjoxNTgzNDE2MDYzLCJpc3MiOiIvZm9vL2JhciIsImp0aSI6IjJhZWQ0Y2NjLTUzNDctNDNmYy1iYmMxLWU3OWNlYWIzMjNkZiIsIm5iZiI6MTU4MzQxNjA2Mywic3ViIjoiZm9vIn0.xz7tilGzWT_tfRaqLuTuR9jRL1av7DvE7HxC8Zg5n7seH96bw2_GSskGxw1faxGF_H-IcpEA4oNmkHYbzCfTsQ"
                    	            	
                    	            	Diff:
                    	            	--- Expected
                    	            	+++ Actual
                    	            	@@ -1 +1 @@
                    	            	-eyJhbGciOiJFUzI1NiIsImtpZCI6IjIxZDllZWZlLTM0YjYtNDJiMy1iNjQzLTJiMzBlMGFiNTllMCIsInR5cCI6IkpXVCJ9.eyJhdWQiOlsiZm9vIl0sImV4cCI6MTU4MzQxNjA2NSwiZm9vIjoiYmF6IiwiaWF0IjoxNTgzNDE2MDYyLCJpc3MiOiIvZm9vL2JhciIsImp0aSI6IjYyZTA5MzJkLTI4YWEtNDA5NC1hMWI1LTE4NDAzMTZlMjBiZiIsIm5iZiI6MTU4MzQxNjA2Miwic3ViIjoiZm9vIn0.B_6bY6IxdCLbVwcnJp9NZhAVGMqG_4c2V0FjKZDuU6XKUmCnXQvCx8aEMUgDeAk4XPbWLEqPXmiV5xYy5QhkxA
                    	            	+eyJhbGciOiJFUzI1NiIsImtpZCI6IjIxZDllZWZlLTM0YjYtNDJiMy1iNjQzLTJiMzBlMGFiNTllMCIsInR5cCI6IkpXVCJ9.eyJhdWQiOlsiZm9vIl0sImV4cCI6MTU4MzQxNjA2NiwiZm9vIjoiYmF6IiwiaWF0IjoxNTgzNDE2MDYzLCJpc3MiOiIvZm9vL2JhciIsImp0aSI6IjJhZWQ0Y2NjLTUzNDctNDNmYy1iYmMxLWU3OWNlYWIzMjNkZiIsIm5iZiI6MTU4MzQxNjA2Mywic3ViIjoiZm9vIn0.xz7tilGzWT_tfRaqLuTuR9jRL1av7DvE7HxC8Zg5n7seH96bw2_GSskGxw1faxGF_H-IcpEA4oNmkHYbzCfTsQ
                    	Test:       	TestMutatorIDToken/method=mutate/case=test_token_cache/subcase=same_tokens_because_session_extra_changed_but_claims_ignore_the_extra_claims
FAIL
coverage: 22.8
FAIL	github.com/ory/oathkeeper/pipeline/mutate	9.004s
FAIL
exit status 1

Reproducing the bug

It appears that this is a clock issue where one token is being issued one second after the other one.

[aeneasr]

I believe this is caused by the cache policy which rejects some inserts and thus causes this case where the token should be in the cache (but isn't) and therefore causes this error.

[aeneasr]

The cache hit rate is unfortunately pretty low here, out of 10 runs approximately 3 fail - maybe this test does not make that much sense?