alcionai / corso

Free, Secure, and Open-Source Backup for Microsoft 365
https://corsobackup.io
Apache License 2.0
180 stars 28 forks source link

[Bug]: `backup list exchange` does not return anything #5113

Closed eric-johnson-cp closed 7 months ago

eric-johnson-cp commented 8 months ago

What happened?

Following the instructions in the quickstart, I backed up a mailbox two times. Using the returned backup IDs, I confirmed that I could restore the backups to restore folders in my mailbox. However when I run the command ./corso backup list exchange I just get the following output:

Logging to file: /Users/eric.johnson/Library/Logs/corso/logs/2024-01-24T16-01-53Z.log
Connecting to M365                               done
Connecting to repository                      4s done
  ID                                    Started At            Duration    Status     Resource Owner
Connecting to M365                               done
Connecting to repository                      4s done

FWIW, as an experiment I ran the same command with an incorrect AWS token and also with an invalid repository password, and in both cases the log file showed the expected error. However in the log file shown below for a correctly configured run, it appears to connect to the repository fine but then just doesn't give any output.

Corso Version?

Corso version: v0.18.0

Where are you running Corso?

MacOS 14.2.1

Relevant log output

2024-01-24T10:10:28.703-0600    DEBUG   logger/logger.go:415    seeding logger  {"logger_settings": {"File":"/Users/eric.johnson/Library/Logs/corso/logs/2024-01-24T16-10-28Z.log","Format":"text","Level":"debug","PIIHandling":"hash","LogStorage":false}}
2024-01-24T10:10:28.704-0600    DEBUG   config/config.go:126    initializing viper  {"config_file_path": "/Users/eric.johnson/.corso.toml"}
2024-01-24T10:10:28.704-0600    DEBUG   config/config.go:129    initialized config  {"config_file_path": "/Users/eric.johnson/.corso.toml"}
2024-01-24T10:10:28.704-0600    DEBUG   config/config.go:206    found config file   {"configFile": "/Users/eric.johnson/.corso.toml"}
2024-01-24T10:10:28.704-0600    INFO    cli/cli.go:69   cli command {"command": "corso backup list exchange", "flags": ["log-level", "mask-sensitive-data"], "version": "v0.18.0"}
2024-01-24T10:10:28.704-0600    DEBUG   config/config.go:307    reading config from file    {"clues_trace": "968d7ce0", "viper_config_file": "/Users/eric.johnson/.corso.toml"}
2024-01-24T10:10:28.704-0600    INFO    observe/observe.go:275  Connecting to M365  {"acct_provider": "M365", "clues_trace": "660753ba", "acct_id": "7fb4cd0f9beb1a80", "storage_provider": "S3"}
2024-01-24T10:10:28.705-0600    INFO    graph/concurrency_middleware.go:49  turning on the concurrency limiter  {"storage_provider": "S3", "clues_trace": "660753ba", "acct_provider": "M365", "acct_id": "7fb4cd0f9beb1a80", "concurrency_limit": 4}
2024-01-24T10:10:28.708-0600    INFO    observe/observe.go:333  done - Connecting to M365   {"acct_provider": "M365", "clues_trace": "660753ba", "acct_id": "7fb4cd0f9beb1a80", "storage_provider": "S3"}
2024-01-24T10:10:29.197-0600    INFO    observe/observe.go:275  Connecting to repository    {"acct_id": "7fb4cd0f9beb1a80", "storage_provider": "S3", "acct_provider": "M365", "clues_trace": "660753ba"}
2024-01-24T10:10:33.166-0600    INFO    observe/observe.go:333  done - Connecting to repository {"acct_id": "7fb4cd0f9beb1a80", "storage_provider": "S3", "acct_provider": "M365", "clues_trace": "660753ba"}
vkamra commented 8 months ago

@eric-johnson-cp - can you try running the list command this with the --hide-progress flag added i.e. ./corso backup list exchange --hide-progress ?

It's possible the progress bar logic is clobbering the list output.

eric-johnson-cp commented 8 months ago

Success! Yes, adding --hide-progress results in the expected output. It must be as you guessed, that the progress bar is hiding the output, especially since I only have two backups in my list.

ryanfkeepers commented 8 months ago

Heya @eric-johnson-cp. I wasn't able to repro the issue you saw, but I'm hoping that I caught the source of the bug. If you're still able to repro and wouldn't mind helping me out, could I ask you to run this build (https://github.com/alcionai/corso/actions/runs/7675121079) and see if it fixes the issue without calling --hide-progress? Thanks!

OrhanTozan commented 7 months ago

I also encountered this bug, --hide-progress solved it for me

(https://discord.com/channels/1022200980487557130/1022200981376745474/1201608944272023562)

ryanfkeepers commented 7 months ago

Thanks @OrhanTozan! Would you also be willing to try out the above build?

eric-johnson-cp commented 7 months ago

@ryanfkeepers -- yes, the new build fixes the problem! Here's what it looks like with the progress results and then the output:

+ ./corso backup list exchange
Logging to file: /Users/eric.johnson/Library/Logs/corso/logs/2024-01-31T17-09-18Z.log
Connecting to M365                       done
Connecting to repository              2s done
  ID                                    Started at            Duration    Status     Protected resource                         Data                
  be94b1fe-6758-4be5-9e83-9687c7d5b8fe  2024-01-23T16:02:34Z  9.466489s   Completed  eric.johnson@test.com  Contacts,Emails,Events
  e4e2deac-c6b5-4412-b6de-886ea4ed5e83  2024-01-23T16:13:04Z  14.540881s  Completed  eric.johnson@test.com  Contacts,Emails,Events
OrhanTozan commented 7 months ago

@ryanfkeepers what is the status of this issue? Was your fix included in v0.19.0?

ashmrtn commented 7 months ago

hi @OrhanTozan, the fix that was in the build linked in this ticket is included in the v0.19.0

I'm going to close this ticket as the fix has been released