CLI: Reduce logging output in production environments

[sermayoral]

1. What is not working as documented?

photoprism backup CLI thows a new info message in 2023.05 version which appears even when you set the log level to warning

2. How can we reproduce it?

In the CLI, execute the following command:

docker exec photoprism photoprism -l warning backup -i -f

3. What behavior do you expect?

Do not see info errors

4. What could be the cause of your problem?

A new message has been created using a different logger, or using an inappropriate log level

5. Can you provide us with example files for testing, error logs, or screenshots?

An execution without specifying the log level (default is info) returns the following messages, that is right:

docker exec photoprism photoprism  backup -i -f
time="2023-05-04T21:03:31Z" level=info msg="config: plus extension loaded [1.976566ms]"
time="2023-05-04T21:03:31Z" level=warning msg="replacing existing backup"
time="2023-05-04T21:03:31Z" level=info msg="writing backup to /photoprism/storage/backup/mysql/2023-05-04.sql"
time="2023-05-04T21:03:34Z" level=info msg="completed in 3.441416258s"

An execution specifying the log level to warning returns the following messages, that is wrong:

docker exec photoprism photoprism -l warning backup -i -f
time="2023-05-04T21:02:49Z" level=info msg="config: plus extension loaded [2.863629ms]"
time="2023-05-04T21:02:49Z" level=warning msg="replacing existing backup"

As you can see, now it doesn't show any info message except the "config: plus extension loaded" message, which is info and should NOT appear. The last message is correct, because it has warning level.

6. Which software versions do you use?

(a) PhotoPrism ARM64 Build 230504-cbf48798c

(b) MariaDB 10.11

(c) Debian Bullseye 64 bits.

(d) Browser Types: N/A

(e) Ad Blockers; N/A

7. On what kind of device is PhotoPrism installed?

Indifferent

8. Do you use a Reverse Proxy, Firewall, VPN, or CDN?

Indifferent

[lastzero]

Could you also describe your use case so we may propose a workaround or other parameters?

[sermayoral]

@lastzero yes. I'm using duplicati to do a backup every day of all my system. When the photoprism backup command throws a message, duplicati undestand it as a warning, and i receive a mail that photoprism thows a message that i should review.

This is working well in 2022.11 version. The first problem was after updating to 20230502 version.

[javilopezalarcon]

@lastzero yes. I'm using duplicati to do a backup every day of all my system. When the photoprism backup command throws a message, duplicati undestand it as a warning, and i receive a mail that photoprism thows a message that i should review.

This is working well in 2022.11 version. The first problem was after updating to 20230502 version.

I have exactly the same problem, well described, I also use duplicati

[lastzero]

My changes reduce the logger output to an absolute minimum when you combine -l warning with the --prod flag:

# photoprism -l warning --prod backup -i
ERRO[2023-05-05T07:50:18Z] /photoprism/storage/backup/mysql/2023-05-05.sql already exists 

An updated development preview will be available soon. Happy testing!

[lastzero]

The preview image has been updated so you can test if it works for you:

• https://hub.docker.com/r/photoprism/photoprism/tags
• https://docs.photoprism.app/getting-started/updates/#development-preview

[sermayoral]

Thank you very much @lastzero. I will check as soon as I arrive home this afternoon 😊

[sermayoral]

@lastzero is the preview image multi-arch?

docker compose up -d photoprism
[+] Running 0/1
 ⠋ photoprism Pulling                                                                                                       3.1s 
no matching manifest for linux/arm64/v8 in the manifest list entries

SOLVED using photoprism/photoprism:preview-arm64

[lastzero]

It's an old tag, don't use it. I've started a new multi-arch preview build for you.

[lastzero]

Preview and tag updated, so you can test it on ARM64.

[sermayoral]

The preview-arm64 works:

docker exec photoprism photoprism -l warning backup -i -f
time="2023-05-05T16:22:39Z" level=warning msg="replacing existing backup"

But is and old tag. Testing the new one

[sermayoral]

@lastzero, working great.

Build 230505-7a7ffbced

Default log level:

docker exec photoprism photoprism backup -i -f
time="2023-05-05T16:32:27Z" level=warning msg="replacing existing backup"
time="2023-05-05T16:32:27Z" level=info msg="writing backup to /photoprism/storage/backup/mysql/2023-05-05.sql"
time="2023-05-05T16:32:29Z" level=info msg="completed in 1.764198639s"

Warning log level:

docker exec photoprism photoprism -l warning backup -i -f
time="2023-05-05T16:31:59Z" level=warning msg="replacing existing backup"

Default log level with --prod

docker exec photoprism photoprism --prod backup -i -f
time="2023-05-05T16:36:48Z" level=warning msg="replacing existing backup"
time="2023-05-05T16:36:48Z" level=info msg="writing backup to /photoprism/storage/backup/mysql/2023-05-05.sql"
time="2023-05-05T16:36:50Z" level=info msg="completed in 1.827114428s"

Warning log level with --prod

docker exec photoprism photoprism -l warning --prod backup -i -f
time="2023-05-05T16:35:12Z" level=warning msg="replacing existing backup"

I see no differences between using --prod or not. But in both cases info errors are no longer displayed when the warning level is specified :-)

[lastzero]

The --prod option can make a difference if, for example, the PHOTOPRISM_DEBUG environment variable is set, which displays debug logs at startup until the log level config option is applied.

[lastzero]

Would it be acceptable for you to use the preview build for the next few days until we have enough other changes so that it's worth tagging a new stable release?

[sermayoral]

@lastzero sure :-).

If I can test something else, just tell me it.

[lastzero]

We've released this as an update for you today:

• https://github.com/photoprism/photoprism/releases/tag/230506-9de9a3540