opendatahub-io / notebooks

Notebook images for ODH
Apache License 2.0
15 stars 51 forks source link

consolidate the logs of python script into container logs #579

Closed harshad16 closed 2 weeks ago

harshad16 commented 2 weeks ago

consolidate the logs of python script into container logs

Description

consolidate the logs of python script into container logs Related-to: https://issues.redhat.com/browse/RHOAIENG-6780

How Has This Been Tested?

a = 10 b = 0 c = a/b



The Expected result:

The log should be shown directly in the pod logs:
![Screenshot from 2024-06-21 04-14-58](https://github.com/opendatahub-io/elyra/assets/14028058/2f00a857-b09f-42fe-96dc-b9997ba013a2)

## Merge criteria:
<!--- This PR will be merged by any repository approver when it meets all the points in the checklist -->
<!--- Go over all the following points, and put an `x` in all the boxes that apply. -->

- [x] The commits are squashed in a cohesive manner and have meaningful messages.
- [x] Testing instructions have been added in the PR body (for PRs involving changes that are not immediately obvious).
- [x] The developer has manually tested the changes and verified that the changes work
openshift-ci[bot] commented 2 weeks ago

[APPROVALNOTIFIER] This PR is NOT APPROVED

This pull-request has been approved by: Once this PR has been reviewed and has the lgtm label, please ask for approval from harshad16. For more information see the Kubernetes Code Review Process.

The full list of commands accepted by this bot can be found here.

Needs approval from an approver in each of these files: - **[OWNERS](https://github.com/opendatahub-io/notebooks/blob/main/OWNERS)** Approvers can indicate their approval by writing `/approve` in a comment Approvers can cancel approval by writing `/approve cancel` in a comment
atheo89 commented 2 weeks ago

Great work Harshad, I was able to run the pipeline and see the logs

First I run the steps that are described on the PR

[I 11:59:41.096] 'new-test':'test-script' - executing python script using 'python3 test-script.py'
[I 11:59:41.096] ----------------------Python logs start----------------------
Traceback (most recent call last):
File "/opt/app-root/src/test-script.py", line 10, in <module>
c = a/b
ZeroDivisionError: division by zero
[I 11:59:41.122] ----------------------Python logs ends----------------------

But i confused by the error :rofl:

[E 11:59:41.122] Unexpected error: <class 'subprocess.CalledProcessError'>
[E 11:59:41.122] Error details: Command '['python3', 'test-script.py']' returned non-zero exit status 1.
Traceback (most recent call last):
File "/opt/app-root/src/bootstrapper.py", line 758, in <module>
main()
File "/opt/app-root/src/bootstrapper.py", line 748, in main
file_op.execute()
File "/opt/app-root/src/bootstrapper.py", line 507, in execute
raise ex
File "/opt/app-root/src/bootstrapper.py", line 496, in execute
raise subprocess.CalledProcessError(return_code, run_args)
subprocess.CalledProcessError: Command '['python3', 'test-script.py']' returned non-zero exit status 1.
I0621 11:59:41.162471 42 launcher_v2.go:151] publish success.
F0621 11:59:41.162532 42 main.go:49] failed to execute component: exit status 1
time="2024-06-21T11:59:41.654Z" level=info msg="sub-process exited" argo=true error="<nil>"
Error: exit status 1
time="2024-06-21T11:59:42.615Z" level=info msg="sub-process exited" argo=true error="<nil>"
Error: exit status 1

Then i realized that this error is normal and should be there because the script was wrong due to the exceptionZeroDivisionError:

So in order to double check it, i created another python script without errors and everything was good!

Python Script

import logging
logging.basicConfig(level=logging.INFO)
logger= logging.getLogger("test")
logger.info("this is a python script")
print("this is a print statement")

Logs:

[I 12:34:51.090] 'script-without-errors':'python-script-without-errors' - dependencies processed (0.327 secs)
[I 12:34:51.090] 'script-without-errors':'python-script-without-errors' - executing python script using 'python3 python-script-without-errors.py'
[I 12:34:51.090] ----------------------Python logs start----------------------
INFO:test:this is a python script
this is a print statement
[I 12:34:51.127] ----------------------Python logs ends----------------------

Also I did a test (with your testing .py) to see the old behavior and indeed i couldn't see info logging

test-script.py
tar: Removing leading `/' from member names
tar: .: Cannot utime: Operation not permitted
tar: Exiting with failure status due to previous errors
[I 12:28:09.371] 'old-runtime':'test-script' - dependencies processed (0.315 secs)
[I 12:28:09.371] 'old-runtime':'test-script' - executing python script using 'python3 test-script.py' to 'test-script.log'
[E 12:28:09.386] Unexpected error: <class 'subprocess.CalledProcessError'>
[E 12:28:09.386] Error details: Command '['python3', 'test-script.py']' returned non-zero exit status 1.
[D 12:28:09.428] https://hnalla-test.s3.us-east-1.amazonaws.com:443 "PUT /old-runtime-0621122722/test-script.log HTTP/1.1" 200 0
[I 12:28:09.429] 'old-runtime':'test-script' - uploaded test-script.log to bucket: hnalla-test object: old-runtime-0621122722/test-script.log (0.042 secs)
Traceback (most recent call last):
File "/opt/app-root/src/bootstrapper.py", line 746, in <module>
main()
File "/opt/app-root/src/bootstrapper.py", line 736, in main
file_op.execute()
File "/opt/app-root/src/bootstrapper.py", line 501, in execute
raise ex
File "/opt/app-root/src/bootstrapper.py", line 488, in execute
subprocess.run(run_args, stdout=log_file, stderr=subprocess.STDOUT, check=True)
File "/usr/lib64/python3.9/subprocess.py", line 528, in run
raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '['python3', 'test-script.py']' returned non-zero exit status 1.
I0621 12:28:09.471644 43 launcher_v2.go:151] publish success.
F0621 12:28:09.471747 43 main.go:49] failed to execute component: exit status 1
time="2024-06-21T12:28:09.618Z" level=info msg="sub-process exited" argo=true error="<nil>"
Error: exit status 1
time="2024-06-21T12:28:10.573Z" level=info msg="sub-process exited" argo=true error="<nil>"
Error: exit status 1
openshift-ci[bot] commented 2 weeks ago

@harshad16: The following tests failed, say /retest to rerun all failed tests or /retest-required to rerun all mandatory failed tests:

Test name Commit Details Required Rerun command
ci/prow/notebooks-e2e-tests 32002377973ea3bf0bb7bfc174cec0abbeec5d8a link true /test notebooks-e2e-tests
ci/prow/codeserver-notebook-e2e-tests 32002377973ea3bf0bb7bfc174cec0abbeec5d8a link true /test codeserver-notebook-e2e-tests
ci/prow/notebooks-ubi8-e2e-tests 32002377973ea3bf0bb7bfc174cec0abbeec5d8a link true /test notebooks-ubi8-e2e-tests
ci/prow/notebooks-ubi9-e2e-tests 32002377973ea3bf0bb7bfc174cec0abbeec5d8a link true /test notebooks-ubi9-e2e-tests
ci/prow/intel-notebooks-e2e-tests 32002377973ea3bf0bb7bfc174cec0abbeec5d8a link true /test intel-notebooks-e2e-tests
ci/prow/rstudio-notebook-e2e-tests 32002377973ea3bf0bb7bfc174cec0abbeec5d8a link true /test rstudio-notebook-e2e-tests
ci/prow/anaconda-ubi8-e2e-tests 32002377973ea3bf0bb7bfc174cec0abbeec5d8a link true /test anaconda-ubi8-e2e-tests

Full PR test history. Your PR dashboard.

Instructions for interacting with me using PR comments are available [here](https://git.k8s.io/community/contributors/guide/pull-requests.md). If you have questions or suggestions related to my behavior, please file an issue against the [kubernetes-sigs/prow](https://github.com/kubernetes-sigs/prow/issues/new?title=Prow%20issue:) repository. I understand the commands that are listed [here](https://go.k8s.io/bot-commands).
harshad16 commented 2 weeks ago

Thank you for the excellent review Merging this to get a release out.