Adjust Pulumi message logging

[JimMadge]

✅ Checklist

• You have given your pull request a meaningful title (e.g. Enable foobar integration rather than 515 foobar).
• You are targeting the appropriate branch. If you're not certain which one this is, it should be develop.
• Your branch is up-to-date with the target branch (it probably was when you started, but it may have changed since then).

🚦 Depends on

⤴️ Summary

• Set Pulumi output verbosity based on console handler level (proxy for --verbose option)
• Remove colour from Pulumi output
• Collect these arguments in ProjectManager.pulumi_extra_args

🌂 Related issues

Closes #1952

🔬 Tests

Needs to be tested

[jemrobinson]

I find the Pulumi colour-coding quite helpful - is it possible to keep this?

[github-actions]

Coverage report

Click to see where and how coverage changed

File	Statements	Missing	Coverage	Coverage (new stmts)	Lines missing
data_safe_haven/infrastructure
project_manager.py					76-87, 296, 326
data_safe_haven/logging
logger.py
plain_file_handler.py
Project Total

This report was generated by python-coverage-comment-action

[JimMadge]

Probably, I will have a look at how easy that is.

https://rich.readthedocs.io/en/stable/reference/text.html?highlight=ansi#rich.text.Text.from_ansi might be the answer.

[JimMadge]

@jemrobinson Hopefully the last two commits help.

[jemrobinson]

@JimMadge : for me this fails with from_ansi() got multiple values for argument 'logger'

Full traceback

hatch run dsh shm deploy
File pulumi.yaml does not exist in blob storage.
Azure user: jrobinson@turing.ac.uk (3f1a8e26-eae2-4539-952a-0a6184ec248a)
Azure tenant ID: 4395f4a7-e455-4f95-8a9f-1fbaef6384f9)
Is this the Azure account you expect? [y/n] (n): y
Loaded stack shm-green.
Refreshing stack shm-green.
Pulumi deployment failed.
from_ansi() got multiple values for argument 'logger'
Could not deploy Data Safe Haven Management environment.
Pulumi deployment failed.
from_ansi() got multiple values for argument 'logger'
╭─────────────────────────────── Traceback (most recent call last) ────────────────────────────────╮
│ /Users/jrobinson/Developer/data-safe-haven/code/dsh-upstream/data_safe_haven/infrastructure/proj │
│ ect_manager.py:196 in deploy                                                                     │
│                                                                                                  │
│   193 │   │   │   self.apply_config_options()                                                    │
│   194 │   │   │   if force:                                                                      │
│   195 │   │   │   │   self.cancel()                                                              │
│ ❱ 196 │   │   │   self.refresh()                                                                 │
│   197 │   │   │   self.preview()                                                                 │
│   198 │   │   │   # self.update()                                                                │
│   199 │   │   except Exception as exc:                                                           │
│                                                                                                  │
│ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │
│ │ force = False                                                                                │ │
│ │   msg = "Pulumi deployment failed.\nfrom_ansi() got multiple values for argument 'logger'"   │ │
│ │  self = <data_safe_haven.infrastructure.project_manager.SHMProjectManager object at          │ │
│ │         0x115a26120>                                                                         │ │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │
│                                                                                                  │
│ /Users/jrobinson/Developer/data-safe-haven/code/dsh-upstream/data_safe_haven/infrastructure/proj │
│ ect_manager.py:327 in refresh                                                                    │
│                                                                                                  │
│   324 │   │   try:                                                                               │
│   325 │   │   │   self.logger.info(f"Refreshing stack [green]{self.stack.name}[/].")             │
│   326 │   │   │   # Note that we disable parallelisation which can cause deadlock                │
│ ❱ 327 │   │   │   self.stack.refresh(parallel=1, **self.pulumi_extra_args)                       │
│   328 │   │   except automation.CommandError as exc:                                             │
│   329 │   │   │   msg = f"Pulumi refresh failed.\n{exc}"                                         │
│   330 │   │   │   raise DataSafeHavenPulumiError(msg) from exc                                   │
│                                                                                                  │
│ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │
│ │ self = <data_safe_haven.infrastructure.project_manager.SHMProjectManager object at           │ │
│ │        0x115a26120>                                                                          │ │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │
│                                                                                                  │
│ /Users/jrobinson/Library/Application                                                             │
│ Support/hatch/env/virtual/data-safe-haven/VH-Q8i5v/data-safe-haven/lib/python3.12/site-packages/ │
│ pulumi/automation/_stack.py:520 in refresh                                                       │
│                                                                                                  │
│    517 │   │   │   log_watcher_thread.start()                                                    │
│    518 │   │                                                                                     │
│    519 │   │   try:                                                                              │
│ ❱  520 │   │   │   refresh_result = self._run_pulumi_cmd_sync(args, on_output)                   │
│    521 │   │   finally:                                                                          │
│    522 │   │   │   _cleanup(temp_dir, log_watcher_thread)                                        │
│    523                                                                                           │
│                                                                                                  │
│ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │
│ │               args = [                                                                       │ │
│ │                      │   'refresh',                                                          │ │
│ │                      │   '--yes',                                                            │ │
│ │                      │   '--skip-preview',                                                   │ │
│ │                      │   '--parallel',                                                       │ │
│ │                      │   '1',                                                                │ │
│ │                      │   '--color',                                                          │ │
│ │                      │   'always',                                                           │ │
│ │                      │   '--logflow',                                                        │ │
│ │                      │   '--exec-kind',                                                      │ │
│ │                      │   'auto.inline',                                                      │ │
│ │                      │   ... +3                                                              │ │
│ │                      ]                                                                       │ │
│ │              color = 'always'                                                                │ │
│ │              debug = None                                                                    │ │
│ │  expect_no_changes = None                                                                    │ │
│ │         extra_args = ['--parallel', '1', '--color', 'always', '--logflow']                   │ │
│ │               kind = 'auto.inline'                                                           │ │
│ │           log_flow = True                                                                    │ │
│ │     log_to_std_err = None                                                                    │ │
│ │      log_verbosity = None                                                                    │ │
│ │ log_watcher_thread = None                                                                    │ │
│ │            message = None                                                                    │ │
│ │           on_event = None                                                                    │ │
│ │          on_output = functools.partial(<function from_ansi at 0x100f13880>, logger=<Logger   │ │
│ │                      data_safe_haven (NOTSET)>)                                              │ │
│ │           parallel = 1                                                                       │ │
│ │               self = <repr-error "'DeclarativeSHM' object has no attribute '__name__'">      │ │
│ │       show_secrets = True                                                                    │ │
│ │   suppress_outputs = None                                                                    │ │
│ │  suppress_progress = None                                                                    │ │
│ │             target = None                                                                    │ │
│ │           temp_dir = None                                                                    │ │
│ │            tracing = None                                                                    │ │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │
│                                                                                                  │
│ /Users/jrobinson/Library/Application                                                             │
│ Support/hatch/env/virtual/data-safe-haven/VH-Q8i5v/data-safe-haven/lib/python3.12/site-packages/ │
│ pulumi/automation/_stack.py:839 in _run_pulumi_cmd_sync                                          │
│                                                                                                  │
│    836 │   │   additional_args = self.workspace.serialize_args_for_op(self.name)                 │
│    837 │   │   args.extend(additional_args)                                                      │
│    838 │   │   args.extend(["--stack", self.name])                                               │
│ ❱  839 │   │   result = self.workspace.pulumi_command.run(                                       │
│    840 │   │   │   args, self.workspace.work_dir, envs, on_output                                │
│    841 │   │   )                                                                                 │
│    842 │   │   self.workspace.post_command_callback(self.name)                                   │
│                                                                                                  │
│ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │
│ │ additional_args = []                                                                         │ │
│ │            args = [                                                                          │ │
│ │                   │   'refresh',                                                             │ │
│ │                   │   '--yes',                                                               │ │
│ │                   │   '--skip-preview',                                                      │ │
│ │                   │   '--parallel',                                                          │ │
│ │                   │   '1',                                                                   │ │
│ │                   │   '--color',                                                             │ │
│ │                   │   'always',                                                              │ │
│ │                   │   '--logflow',                                                           │ │
│ │                   │   '--exec-kind',                                                         │ │
│ │                   │   'auto.inline',                                                         │ │
│ │                   │   ... +3                                                                 │ │
│ │                   ]                                                                          │ │
│ │            envs = {                                                                          │ │
│ │                   │   'PULUMI_DEBUG_COMMANDS': 'true',                                       │ │
│ │                   │   'AZURE_STORAGE_ACCOUNT': 'shmgreencontext',                            │ │
│ │                   │   'AZURE_STORAGE_KEY':                                                   │ │
│ │                   'EEA0vC7mhx5vgKZJNe4v54watbDr7IRinS/IpmMcs5wTqRJIrqcPp41DaEe9OioFN0c4Hj4r… │ │
│ │                   │   'AZURE_KEYVAULT_AUTH_VIA_CLI': 'true'                                  │ │
│ │                   }                                                                          │ │
│ │       on_output = functools.partial(<function from_ansi at 0x100f13880>, logger=<Logger      │ │
│ │                   data_safe_haven (NOTSET)>)                                                 │ │
│ │            self = <repr-error "'DeclarativeSHM' object has no attribute '__name__'">         │ │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │
│                                                                                                  │
│ /Users/jrobinson/Library/Application                                                             │
│ Support/hatch/env/virtual/data-safe-haven/VH-Q8i5v/data-safe-haven/lib/python3.12/site-packages/ │
│ pulumi/automation/_cmd.py:226 in run                                                             │
│                                                                                                  │
│   223 │   │   │   │   │   if output:                                                             │
│   224 │   │   │   │   │   │   text = output.rstrip()                                             │
│   225 │   │   │   │   │   │   if on_output:                                                      │
│ ❱ 226 │   │   │   │   │   │   │   on_output(text)                                                │
│   227 │   │   │   │   │   │   stdout_chunks.append(text)                                         │
│   228 │   │   │   │                                                                              │
│   229 │   │   │   │   code = process.returncode                                                  │
│                                                                                                  │
│ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │
│ │ additional_env = {                                                                           │ │
│ │                  │   'PULUMI_DEBUG_COMMANDS': 'true',                                        │ │
│ │                  │   'AZURE_STORAGE_ACCOUNT': 'shmgreencontext',                             │ │
│ │                  │   'AZURE_STORAGE_KEY':                                                    │ │
│ │                  'EEA0vC7mhx5vgKZJNe4v54watbDr7IRinS/IpmMcs5wTqRJIrqcPp41DaEe9OioFN0c4Hj4rr… │ │
│ │                  │   'AZURE_KEYVAULT_AUTH_VIA_CLI': 'true'                                   │ │
│ │                  }                                                                           │ │
│ │           args = [                                                                           │ │
│ │                  │   'refresh',                                                              │ │
│ │                  │   '--yes',                                                                │ │
│ │                  │   '--skip-preview',                                                       │ │
│ │                  │   '--parallel',                                                           │ │
│ │                  │   '1',                                                                    │ │
│ │                  │   '--color',                                                              │ │
│ │                  │   'always',                                                               │ │
│ │                  │   '--logflow',                                                            │ │
│ │                  │   '--exec-kind',                                                          │ │
│ │                  │   'auto.inline',                                                          │ │
│ │                  │   ... +3                                                                  │ │
│ │                  ]                                                                           │ │
│ │            cmd = [                                                                           │ │
│ │                  │   'pulumi',                                                               │ │
│ │                  │   'refresh',                                                              │ │
│ │                  │   '--yes',                                                                │ │
│ │                  │   '--skip-preview',                                                       │ │
│ │                  │   '--parallel',                                                           │ │
│ │                  │   '1',                                                                    │ │
│ │                  │   '--color',                                                              │ │
│ │                  │   'always',                                                               │ │
│ │                  │   '--logflow',                                                            │ │
│ │                  │   '--exec-kind',                                                          │ │
│ │                  │   ... +4                                                                  │ │
│ │                  ]                                                                           │ │
│ │            cwd = '/var/folders/dg/n8x2zdyd7pb74pg355wx867c0000gq/T/automation-eber9w76'      │ │
│ │            env = {                                                                           │ │
│ │                  │   'TERM_PROGRAM': 'iTerm.app',                                            │ │
│ │                  │   '_P9K_TTY': '/dev/ttys015',                                             │ │
│ │                  │   'PYENV_ROOT': '/Users/jrobinson/.pyenv',                                │ │
│ │                  │   'SHELL': '/bin/zsh',                                                    │ │
│ │                  │   'TERM': 'xterm-256color',                                               │ │
│ │                  │   'TMPDIR': '/var/folders/dg/n8x2zdyd7pb74pg355wx867c0000gq/T/',          │ │
│ │                  │   'TERM_PROGRAM_VERSION': '3.5.2',                                        │ │
│ │                  │   'TERM_SESSION_ID': 'w0t3p0:C3A0F696-6276-43AB-8B7A-4151B97EDA6A',       │ │
│ │                  │   'ZSH': '/Users/jrobinson/.oh-my-zsh',                                   │ │
│ │                  │   'USER': 'jrobinson',                                                    │ │
│ │                  │   ... +38                                                                 │ │
│ │                  }                                                                           │ │
│ │      on_output = functools.partial(<function from_ansi at 0x100f13880>, logger=<Logger       │ │
│ │                  data_safe_haven (NOTSET)>)                                                  │ │
│ │         output = '\x1b[38;5;13m\x1b[1mRefreshing (shm-green):\x1b[0m\n'                      │ │
│ │        process = <Popen: returncode: -13 args: ['pulumi', 'refresh', '--yes',                │ │
│ │                  '--skip-preview...>                                                         │ │
│ │           self = <pulumi.automation._cmd.PulumiCommand object at 0x115dc5910>                │ │
│ │    stderr_file = <_io.BufferedRandom name=8>                                                 │ │
│ │  stdout_chunks = []                                                                          │ │
│ │           text = '\x1b[38;5;13m\x1b[1mRefreshing (shm-green):\x1b[0m'                        │ │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │
╰──────────────────────────────────────────────────────────────────────────────────────────────────╯
TypeError: from_ansi() got multiple values for argument 'logger'

The above exception was the direct cause of the following exception:

╭─────────────────────────────── Traceback (most recent call last) ────────────────────────────────╮
│ /Users/jrobinson/Developer/data-safe-haven/code/dsh-upstream/data_safe_haven/commands/shm.py:68  │
│ in deploy                                                                                        │
│                                                                                                  │
│    65 │   │                                                                                      │
│    66 │   │   # Deploy Azure infrastructure with Pulumi                                          │
│    67 │   │   if force is None:                                                                  │
│ ❱  68 │   │   │   stack.deploy()                                                                 │
│    69 │   │   else:                                                                              │
│    70 │   │   │   stack.deploy(force=force)                                                      │
│    71                                                                                            │
│                                                                                                  │
│ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │
│ │              config = SHMConfig(                                                             │ │
│ │                       │   azure=ConfigSectionAzure(                                          │ │
│ │                       │   │   subscription_id='3f1a8e26-eae2-4539-952a-0a6184ec248a',        │ │
│ │                       │   │   tenant_id='4395f4a7-e455-4f95-8a9f-1fbaef6384f9'               │ │
│ │                       │   ),                                                                 │ │
│ │                       │   shm=ConfigSectionSHM(                                              │ │
│ │                       │   │   entra_tenant_id='cb94a6f6-ef7a-42ab-bcad-4f0b887cfd3e',        │ │
│ │                       │   │   fqdn='green.develop.turingsafehaven.ac.uk'                     │ │
│ │                       │   )                                                                  │ │
│ │                       )                                                                      │ │
│ │             context = Context(                                                               │ │
│ │                       │   subscription_name='Data Safe Haven Development',                   │ │
│ │                       │   admin_group_id='347c68cb-261f-4a3e-ac3e-6af860b5fec9',             │ │
│ │                       │   location='uksouth',                                                │ │
│ │                       │   name='Green'                                                       │ │
│ │                       )                                                                      │ │
│ │               force = None                                                                   │ │
│ │           graph_api = <data_safe_haven.external.api.graph_api.GraphApi object at             │ │
│ │                       0x1158f4530>                                                           │ │
│ │                 msg = 'Could not deploy Data Safe Haven Management environment.\nPulumi      │ │
│ │                       deployment faile'+56                                                   │ │
│ │       pulumi_config = DSHPulumiConfig(                                                       │ │
│ │                       │                                                                      │ │
│ │                       encrypted_key='YkVfbko5QlJJZzVuNmtLNVhsQ2ViTjhBRm9hRlZ4ZW9WSC1VcGhMam… │ │
│ │                       │   projects={                                                         │ │
│ │                       │   │   'green': DSHPulumiProject(                                     │ │
│ │                       │   │   │   stack_config={                                             │ │
│ │                       │   │   │   │   'azure-native:location': 'uksouth',                    │ │
│ │                       │   │   │   │   'azure-native:subscriptionId':                         │ │
│ │                       '3f1a8e26-eae2-4539-952a-0a6184ec248a',                                │ │
│ │                       │   │   │   │   'azure-native:tenantId':                               │ │
│ │                       '4395f4a7-e455-4f95-8a9f-1fbaef6384f9',                                │ │
│ │                       │   │   │   │   'data-safe-haven:verification-azuread-custom-domain':  │ │
│ │                       'MS='                                                                  │ │
│ │                       │   │   │   }                                                          │ │
│ │                       │   │   )                                                              │ │
│ │                       │   }                                                                  │ │
│ │                       )                                                                      │ │
│ │               stack = <data_safe_haven.infrastructure.project_manager.SHMProjectManager      │ │
│ │                       object at 0x115a26120>                                                 │ │
│ │ verification_record = 'MS='                                                                  │ │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │
│                                                                                                  │
│ /Users/jrobinson/Developer/data-safe-haven/code/dsh-upstream/data_safe_haven/infrastructure/proj │
│ ect_manager.py:201 in deploy                                                                     │
│                                                                                                  │
│   198 │   │   │   # self.update()                                                                │
│   199 │   │   except Exception as exc:                                                           │
│   200 │   │   │   msg = f"Pulumi deployment failed.\n{exc}"                                      │
│ ❱ 201 │   │   │   raise DataSafeHavenPulumiError(msg) from exc                                   │
│   202 │                                                                                          │
│   203 │   def destroy(self) -> None:                                                             │
│   204 │   │   """Destroy deployed infrastructure."""                                             │
│                                                                                                  │
│ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │
│ │ force = False                                                                                │ │
│ │   msg = "Pulumi deployment failed.\nfrom_ansi() got multiple values for argument 'logger'"   │ │
│ │  self = <data_safe_haven.infrastructure.project_manager.SHMProjectManager object at          │ │
│ │         0x115a26120>                                                                         │ │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │
╰──────────────────────────────────────────────────────────────────────────────────────────────────╯
DataSafeHavenPulumiError: Pulumi deployment failed.
from_ansi() got multiple values for argument 'logger'

The above exception was the direct cause of the following exception:

╭─────────────────────────────── Traceback (most recent call last) ────────────────────────────────╮
│ /Users/jrobinson/Developer/data-safe-haven/code/dsh-upstream/data_safe_haven/commands/shm.py:84  │
│ in deploy                                                                                        │
│                                                                                                  │
│    81 │   │   # print("Could not deploy Data Safe Haven Management environment.")                │
│    82 │   │   # raise typer.Exit(code=1) from exc                                                │
│    83 │   │   msg = f"Could not deploy Data Safe Haven Management environment.\n{exc}"           │
│ ❱  84 │   │   raise DataSafeHavenError(msg) from exc                                             │
│    85 │   finally:                                                                               │
│    86 │   │   # Upload Pulumi config to blob storage                                             │
│    87 │   │   pulumi_config.upload(context)                                                      │
│                                                                                                  │
│ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │
│ │              config = SHMConfig(                                                             │ │
│ │                       │   azure=ConfigSectionAzure(                                          │ │
│ │                       │   │   subscription_id='3f1a8e26-eae2-4539-952a-0a6184ec248a',        │ │
│ │                       │   │   tenant_id='4395f4a7-e455-4f95-8a9f-1fbaef6384f9'               │ │
│ │                       │   ),                                                                 │ │
│ │                       │   shm=ConfigSectionSHM(                                              │ │
│ │                       │   │   entra_tenant_id='cb94a6f6-ef7a-42ab-bcad-4f0b887cfd3e',        │ │
│ │                       │   │   fqdn='green.develop.turingsafehaven.ac.uk'                     │ │
│ │                       │   )                                                                  │ │
│ │                       )                                                                      │ │
│ │             context = Context(                                                               │ │
│ │                       │   subscription_name='Data Safe Haven Development',                   │ │
│ │                       │   admin_group_id='347c68cb-261f-4a3e-ac3e-6af860b5fec9',             │ │
│ │                       │   location='uksouth',                                                │ │
│ │                       │   name='Green'                                                       │ │
│ │                       )                                                                      │ │
│ │               force = None                                                                   │ │
│ │           graph_api = <data_safe_haven.external.api.graph_api.GraphApi object at             │ │
│ │                       0x1158f4530>                                                           │ │
│ │                 msg = 'Could not deploy Data Safe Haven Management environment.\nPulumi      │ │
│ │                       deployment faile'+56                                                   │ │
│ │       pulumi_config = DSHPulumiConfig(                                                       │ │
│ │                       │                                                                      │ │
│ │                       encrypted_key='YkVfbko5QlJJZzVuNmtLNVhsQ2ViTjhBRm9hRlZ4ZW9WSC1VcGhMam… │ │
│ │                       │   projects={                                                         │ │
│ │                       │   │   'green': DSHPulumiProject(                                     │ │
│ │                       │   │   │   stack_config={                                             │ │
│ │                       │   │   │   │   'azure-native:location': 'uksouth',                    │ │
│ │                       │   │   │   │   'azure-native:subscriptionId':                         │ │
│ │                       '3f1a8e26-eae2-4539-952a-0a6184ec248a',                                │ │
│ │                       │   │   │   │   'azure-native:tenantId':                               │ │
│ │                       '4395f4a7-e455-4f95-8a9f-1fbaef6384f9',                                │ │
│ │                       │   │   │   │   'data-safe-haven:verification-azuread-custom-domain':  │ │
│ │                       'MS='                                                                  │ │
│ │                       │   │   │   }                                                          │ │
│ │                       │   │   )                                                              │ │
│ │                       │   }                                                                  │ │
│ │                       )                                                                      │ │
│ │               stack = <data_safe_haven.infrastructure.project_manager.SHMProjectManager      │ │
│ │                       object at 0x115a26120>                                                 │ │
│ │ verification_record = 'MS='                                                                  │ │
│ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │
╰──────────────────────────────────────────────────────────────────────────────────────────────────╯
DataSafeHavenError: Could not deploy Data Safe Haven Management environment.
Pulumi deployment failed.
from_ansi() got multiple values for argument 'logger'

Update: fixed in 6cd29be

[jemrobinson]

Some thoughts/questions

[JimMadge]

Odd bug in efc59b8.

I think get_logger and/or init_logging were being called on import, so when the fixture tries to make a Logger with a temporary directory it just appended handlers to an existing Logger using the real directory.

Another instance of the way logging working being strange. Still, Tryign to work against it also introduces problems.

[jemrobinson]

LGTM. I've just tested and it looks like it's working. Any further problems can be a new issue.

[jemrobinson]

@JimMadge : is this one ready to merge too?