oci_test: flaky test

[srenatus]

https://github.com/open-policy-agent/opa/runs/6751372092?check_suite_focus=true#step:6:250

--- FAIL: TestEnablePrintStatementsForBundles (3.19s)
    oci_test.go:113: expected logs to contain "Bundle load skipped, server replied with not modified." but got: time="2022-06-06T07:06:45Z" level=info msg="Initializing server." addrs="[:0]" diagnostic-addrs="[]"
        time="2022-06-06T07:06:45Z" level=debug msg="maxprocs: Leaving GOMAXPROCS=3: CPU quota undefined"
        time="2022-06-06T07:06:45Z" level=info msg="Starting bundle loader." name=test plugin=bundle
        time="2022-06-06T07:06:45Z" level=debug msg="OCI - Download starting."
        time="2022-06-06T07:06:45Z" level=debug msg="Server initialized."
        time="2022-06-06T07:06:45Z" level=debug msg="Bundle activation in progress (). Opening storage transaction." name=test plugin=bundle
        time="2022-06-06T07:06:45Z" level=debug msg="Opened storage transaction (4)." name=test plugin=bundle
        time="2022-06-06T07:06:45Z" level=debug msg="Closing storage transaction (4)." name=test plugin=bundle
        time="2022-06-06T07:06:45Z" level=info msg="Bundle loaded and activated successfully. Etag updated to 25b364c604ee9c9ee17cd4cd08bf932d020517acfccde2a50719bb36d70eaa2b." name=test plugin=bundle
        time="2022-06-06T07:06:45Z" level=debug msg="OCI - Waiting 2.987628311s before next download/retry."
        time="2022-06-06T07:06:45Z" level=info msg="Received request." client_addr="[::1]:55219" req_body= req_id=1 req_method=GET req_params="map[bundles:[]]" req_path=/health
        time="2022-06-06T07:06:45Z" level=info msg="Sent response." client_addr="[::1]:55219" req_id=1 req_method=GET req_path=/health resp_body="{}" resp_bytes=2 resp_duration=0.50225 resp_status=200
        time="2022-06-06T07:06:45Z" level=info msg="Received request." client_addr="[::1]:55220" req_body="{\"input\":{\"user\":{\"properties\":{\"department\":\"Operations\",\"title\":\"IT Manager\"}}}}" req_id=2 req_method=POST req_params="map[]" req_path=/v1/data/peoplefinder/POST/api/users/allowed
        time="2022-06-06T07:06:45Z" level=info msg="Sent response." client_addr="[::1]:55220" req_id=2 req_method=POST req_path=/v1/data/peoplefinder/POST/api/users/allowed resp_body="{\"decision_id\":\"5de2f053-5044-4892-85da-a24c823e002a\",\"result\":true}" resp_bytes=68 resp_duration=0.624664 resp_status=200
        time="2022-06-06T07:06:45Z" level=info msg="Received request." client_addr="[::1]:55220" req_body="{\"input\":{\"user\":{\"properties\":{\"department\":\"IT\",\"title\":\"Engineer\"}}}}" req_id=3 req_method=POST req_params="map[]" req_path=/v1/data/peoplefinder/POST/api/users/allowed
        time="2022-06-06T07:06:45Z" level=info msg="Sent response." client_addr="[::1]:55220" req_id=3 req_method=POST req_path=/v1/data/peoplefinder/POST/api/users/allowed resp_body="{\"decision_id\":\"9d90a93a-639b-4068-a32e-3072a0360651\",\"result\":false}" resp_bytes=69 resp_duration=0.527622 resp_status=200
FAIL
FAIL	github.com/open-policy-agent/opa/test/e2e/oci	3.796s

[srenatus]

https://github.com/open-policy-agent/opa/runs/6861240502?check_suite_focus=true#step:6:354

[Joffref]

I'm not sure, but I think this condition should be refactored at the same time.

from this :
if !strings.Contains(string(readBuf), "false") { t.Fatalf("expected true but got: %s", response) }
to this :
if !strings.Contains(string(readBuf), "false") { t.Fatalf("expected false but got: %s", response) }

[Joffref]

After looking at the test deeper, I think this condition and this condition couldn't verify at the same time.

But i'm not really sure could someone confirm my thought.

[srenatus]

The tests often pass. The assertions seem contradicting but they are not: first the bundle is activated, and on the second try, its activation is unnecessary and skipped.

[Joffref]

Maybe a missing time.Sleep ?

[carabasdaniel]

Added a small sleep to wait for second trigger to kick in bfbe9c7

[Joffref]

I hope that will solve this issue!