Improve stability test_compileservice_recompile_backoff test case. (PR #9024)

# Description

Improve stability `test_compileservice_recompile_backoff` test case.

* Mark test case with `no_agent=True` so that no ERROR log line is created if the agentmanager tries to create a scheduler.
* Improve the error reporting of the `LogSequence.contains()` method in case an unexpected ERROR log line is found.

Pytest output:

```
13:46:21  _ test_compileservice_recompile_backoff[0-The recompile_backoff environment setting is disabled-20] _
13:46:21
13:46:21  mocked_compiler_service_block = <queue.Queue object at 0x7f63bae800b0>
13:46:21  server = <inmanta.server.protocol.Server object at 0x7f63bb7c7440>
13:46:21  client = <inmanta.protocol.endpoints.Client object at 0x7f63c4908470>
13:46:21  environment = 'eacaffb2-bef5-4c15-8337-358925b0aa06'
13:46:21  caplog = <_pytest.logging.LogCaptureFixture object at 0x7f63bb81dd30>
13:46:21  recompile_backoff = '0'
13:46:21  expected_log_message = 'The recompile_backoff environment setting is disabled'
13:46:21  expected_log_level = 20
13:46:21
13:46:21      @pytest.mark.parametrize(
13:46:21          "recompile_backoff,expected_log_message,expected_log_level",
13:46:21          [
13:46:21              ("2.1", "The recompile_backoff environment setting is enabled and set to 2.1 seconds", logging.INFO),
13:46:21              ("0", "The recompile_backoff environment setting is disabled", logging.INFO),
13:46:21          ],
13:46:21      )
13:46:21      async def test_compileservice_recompile_backoff(
13:46:21          mocked_compiler_service_block,
13:46:21          server,
13:46:21          client,
13:46:21          environment,
13:46:21          caplog,
13:46:21          recompile_backoff: str,
13:46:21          expected_log_message: str,
13:46:21          expected_log_level: int,
13:46:21      ):
13:46:21          """
13:46:21          Test the recompile_backoff setting when multiple recompiles are requested in a short amount of time
13:46:21          """
13:46:21          with caplog.at_level(logging.DEBUG):
13:46:21              env = await data.Environment.get_by_id(environment)
13:46:21              await env.set(data.RECOMPILE_BACKOFF, recompile_backoff)
13:46:21              compilerslice: CompilerService = server.get_slice(SLICE_COMPILER)
13:46:21
13:46:21              # request compiles in rapid succession
13:46:21              remote_id1 = uuid.uuid4()
13:46:21              await compilerslice.request_recompile(
13:46:21                  env=env, force_update=False, do_export=False, remote_id=remote_id1, env_vars={"my_unique_var": "1"}
13:46:21              )
13:46:21              remote_id2 = uuid.uuid4()
13:46:21              compile_id2, _ = await compilerslice.request_recompile(
13:46:21                  env=env, force_update=False, do_export=False, remote_id=remote_id2
13:46:21              )
13:46:21
13:46:21              remote_id3 = uuid.uuid4()
13:46:21              compile_id3, _ = await compilerslice.request_recompile(
13:46:21                  env=env, force_update=False, do_export=True, remote_id=remote_id3
13:46:21              )
13:46:21
13:46:21              result = await client.get_compile_queue(environment)
13:46:21              assert len(result.result["queue"]) == 3
13:46:21              assert result.code == 200
13:46:21
13:46:21              # Start working through it
13:46:21              for i in range(3):
13:46:21                  await run_compile_and_wait_until_compile_is_done(compilerslice, mocked_compiler_service_block, env.id)
13:46:21
13:46:21  >           LogSequence(caplog, allow_errors=False).contains(
13:46:21                  "inmanta.server.services.compilerservice", logging.DEBUG, "Running recompile without waiting"
13:46:21              ).contains("inmanta.server.services.compilerservice", expected_log_level, expected_log_message).contains(
13:46:21                  "inmanta.server.services.compilerservice", logging.DEBUG, "Running recompile without waiting"
13:46:21              )
13:46:21
13:46:21  tests/server/test_compilerservice.py:1606:
13:46:21  _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
13:46:21
13:46:21  self = <utils.LogSequence object at 0x7f63bd44d6d0>
13:46:21  loggerpart = 'inmanta.server.services.compilerservice', level = 10
13:46:21  msg = 'Running recompile without waiting', min_level = inf
13:46:21
13:46:21      def contains(self, loggerpart, level, msg, min_level: int = math.inf) -> "LogSequence":
13:46:21          """
13:46:21          :param loggerpart: part of the logger name to match
13:46:21          :param level: exact log level to match
13:46:21          :param min_level: minimal level to match (works as normal loglevel settings that take all higher levels)
13:46:21          :param msg: part of the message to match on
13:46:21          """
13:46:21          index = self._find(loggerpart, level, msg, self.index, min_level)
13:46:21          if not self.allow_errors:
13:46:21              # first error is later
13:46:21              idxe = self._find("", logging.ERROR, "", self.index, min_level)
13:46:21  >           assert idxe == -1 or idxe >= index
13:46:21  E           AssertionError
13:46:21
13:46:21  tests/utils.py:253: AssertionError
```

# Self Check:

- [ ] ~~Attached issue to pull request~~
- [x] Changelog entry
- [x] Type annotations are present
- [x] Code is clear and sufficiently documented
- [x] No (preventable) type errors (check using make mypy or make mypy-diff)
- [x] Sufficient test cases (reproduces the bug/tests the requested feature)
- [x] Correct, in line with design
- [ ] ~~End user documentation is included or an issue is created for end-user documentation~~
- [ ] If this PR fixes a race condition in the test suite, also push the fix to the relevant stable branche(s) (see [test-fixes](https://internal.inmanta.com/development/core/tasks/build-master.html#test-fixes) for more info)

Author: arnaudsjs

changelogs/unreleased/improve-stability-recompile-backoff-test.yml

@@ -0,0 +1,4 @@
+---
+description: "Improve stability test_compileservice_recompile_backoff test case."
+change-type: patch
+destination-branches: [master, iso8]

tests/server/test_compilerservice.py

@@ -1582,6 +1582,7 @@ async def test_git_uses_environment_variables(environment_factory: EnvironmentFa
     assert "trace: " in report.errstream
 
 
+@pytest.mark.parametrize("no_agent", [True])
 @pytest.mark.parametrize(
     "recompile_backoff,expected_log_message,expected_log_level",
     [

tests/utils.py

@@ -245,7 +245,7 @@ def contains(self, loggerpart, level, msg, min_level: int = math.inf) -> "LogSeq
         if not self.allow_errors:
             # first error is later
             idxe = self._find("", logging.ERROR, "", self.index, min_level)
-            assert idxe == -1 or idxe >= index
+            assert idxe == -1 or idxe >= index, f"Unexpected ERROR log line found: {self.caplog.records[idxe]}"
         assert index >= 0, "could not find " + msg
         return LogSequence(self.caplog, index + 1, self.allow_errors, self.ignore)