Reduce Python INFO logging verbosity at start-up

[jrmccluskey]

Makes two changes to Python worker start-up logging to reduce the verbosity of INFO logs:

1. Log imports for beam-plugins and modules for beam-plugins at DEBUG instead of INFO (~20 lines per worker)
2. Has pip invocations at worker start-up run at quiet level 1, suppressing INFO logs (>50 lines per worker)

This reduces the noisy boilerplate logging that happens during these steps but still surfaces errors that occur.

---

Thank you for your contribution! Follow this checklist to help us incorporate your contribution quickly and easily:

• Mention the appropriate issue in your description (for example: addresses #123), if applicable. This will automatically add a link to the pull request in the issue. If you would like the issue to automatically close on merging the pull request, comment fixes #<ISSUE NUMBER> instead.
• Update CHANGES.md with noteworthy changes.
• If this contribution is large, please file an Apache Individual Contributor License Agreement.

See the Contributor Guide for more tips on how to make review process smoother.

To check the build health, please visit https://github.com/apache/beam/blob/master/.test-infra/BUILD_STATUS.md

GitHub Actions Tests Status (on master branch)

See CI.md for more information about GitHub Actions CI.

[codecov]

Codecov Report

Merging #27577 (75369ab) into master (510f294) will decrease coverage by 0.01%.
The diff coverage is 50.00%.

@@            Coverage Diff             @@
##           master   #27577      +/-   ##
==========================================
- Coverage   71.14%   71.14%   -0.01%     
==========================================
  Files         861      861              
  Lines      104560   104570      +10     
==========================================
+ Hits        74393    74398       +5     
- Misses      28618    28623       +5     
  Partials     1549     1549              

Flag	Coverage Δ
go	53.67% <ø> (+0.01%)	⬆️
python	80.33% <50.00%> (-0.01%)	⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

Impacted Files	Coverage Δ
...thon/apache_beam/runners/worker/sdk_worker_main.py	77.71% <50.00%> (ø)

... and 9 files with indirect coverage changes

📣 We’re building smart automated test selection to slash your CI/CD build times. Learn more

[jrmccluskey]

Run Python_Examples PreCommit

[jrmccluskey]

Run Python_Integration PreCommit

[github-actions]

Assigning reviewers. If you would like to opt out of this review, comment assign to next reviewer:

R: @damccorm for label python.

Available commands:

• stop reviewer notifications - opt out of the automated review tooling
• remind me after tests pass - tag the comment author after tests pass
• waiting on author - shift the attention set back to the author (any comment or push by the author will return the attention set to the reviewers)

The PR bot will only process comments in the main thread (not review comments).

[damccorm]

LGTM, thanks

[Abacn]

This has caused #27641, specifically this line:

https://github.com/jrmccluskey/beam/blob/75369abcdf404979b33d95729683ceaef42846a1/sdks/python/container/piputil.go#L41C5-L41C9

TBH it's hard to diagnose, because container startup logs are not available on Jenkins.

[jrmccluskey]

Hmm that's strange. @Abacn what's wrong with the -q directive to that pip invocation?

[Abacn]

I ran the test locally and print the command, see the following log:

2023/07/25 15:58:21 Downloaded: /tmp/staged/1-a718a1badc013e9e1a0699567f5fad265b0d5cece0dc3f59c1945a4ab596ff93 (sha256: f104a8fb92682acb4db31e154d0fad91bfffbe0f60807a3a5d5b1880263660e0, size: 24)

2023/07/25 15:58:21 Downloaded: /tmp/staged/sklearn_model (sha256: 772ec91b39ec95a29fa02e1f7c3d593b4eaed05d89eda704b3e126e0ab4c7173, size: 1286)

2023/07/25 15:58:21 Downloaded: /tmp/staged/beautifulsoup4-4.12.2-py3-none-any.whl (sha256: bd2520ca0d9d7d12694a53d44ac482d181b4ec1888909b035a3dbf40d0f57d4a, size: 142979)

2023/07/25 15:58:21 Installing setup packages ...

2023/07/25 15:58:21 -m pip install -q -r /tmp/staged/1-a718a1badc013e9e1a0699567f5fad265b0d5cece0dc3f59c1945a4ab596ff93 --no-cache-dir --disable-pip-version-check --no-index --no-deps --find-links /tmp/staged

ERROR: Directory '/tmp/staged' is not installable. Neither 'setup.py' nor 'pyproject.toml' found.

2023/07/25 15:58:22 failed to install required packages: failed to install requirements: exit status 1

[Abacn]

I put -q either after --find-links or before -q same issue

update:

there are two invocations I see. Need fix both.

The problem is the -q placement between --find-links /tmp/staged makes the latter option not effective

[Abacn]

Root caused, will open a PR for this

[jrmccluskey]

SGTM, send it to me when it's ready