print is not thread-safe, so should not be used in signal handler#9222
Merged
Conversation
Codecov ReportAttention: Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## main #9222 +/- ##
=======================================
Coverage 78.01% 78.01%
=======================================
Files 150 150
Lines 18827 18828 +1
Branches 3220 3221 +1
=======================================
+ Hits 14688 14689 +1
+ Misses 3836 3835 -1
- Partials 303 304 +1
Flags with carried forward coverage won't be shown. Click here to find out more. ☔ View full report in Codecov by Sentry. |
auvipy
requested changes
Sep 4, 2024
auvipy
left a comment
Member
There was a problem hiding this comment.
please fix the merge conflicts
Nusnus
approved these changes
Sep 4, 2024
Nusnus
requested changes
Sep 4, 2024
Nusnus
left a comment
Member
There was a problem hiding this comment.
@Zhong-z the smoke tests are failing on a real issue.
2024-09-04T12:47:28.6884582Z ------------------- default_worker_container: silly_villani --------------------
2024-09-04T12:47:28.6885146Z Changed worker configuration: {
2024-09-04T12:47:28.6885584Z "worker_pool_restarts": true,
2024-09-04T12:47:28.6885984Z "task_acks_late": true
2024-09-04T12:47:28.6886344Z }
2024-09-04T12:47:28.6886680Z
2024-09-04T12:47:28.6887193Z -------------- smoke_tests_worker@be6028dd6fb3 v5.5.0b2 (immunity)
2024-09-04T12:47:28.6887678Z --- ***** -----
2024-09-04T12:47:28.6888279Z -- ******* ---- Linux-6.5.0-1025-azure-x86_64-with-glibc2.36 2024-09-04 12:46:12
2024-09-04T12:47:28.6888823Z - *** --- * ---
2024-09-04T12:47:28.6889251Z - ** ---------- [config]
2024-09-04T12:47:28.6889732Z - ** ---------- .> app: celery_test_app:0x7f050969dcd0
2024-09-04T12:47:28.6890303Z - ** ---------- .> transport: sqs://b09f0037a174:4566//
2024-09-04T12:47:28.6890970Z - ** ---------- .> results: redis://161584cfa3c5/0
2024-09-04T12:47:28.6891510Z - *** --- * --- .> concurrency: 4 (prefork)
2024-09-04T12:47:28.6892274Z -- ******* ---- .> task events: OFF (enable -E to monitor tasks in this worker)
2024-09-04T12:47:28.6892899Z --- ***** -----
2024-09-04T12:47:28.6893222Z -------------- [queues]
2024-09-04T12:47:28.6893852Z .> smoke_tests_queue exchange=smoke_tests_queue(direct) key=smoke_tests_queue
2024-09-04T12:47:28.6894479Z
2024-09-04T12:47:28.6894649Z
2024-09-04T12:47:28.6894810Z [tasks]
2024-09-04T12:47:28.6895158Z . pytest_celery.vendors.worker.tasks.add
2024-09-04T12:47:28.6895716Z . pytest_celery.vendors.worker.tasks.add_replaced
2024-09-04T12:47:28.6896243Z . pytest_celery.vendors.worker.tasks.fail
2024-09-04T12:47:28.6896741Z . pytest_celery.vendors.worker.tasks.identity
2024-09-04T12:47:28.6897300Z . pytest_celery.vendors.worker.tasks.noop
2024-09-04T12:47:28.6897797Z . pytest_celery.vendors.worker.tasks.ping
2024-09-04T12:47:28.6898242Z . pytest_celery.vendors.worker.tasks.sleep
2024-09-04T12:47:28.6898802Z . pytest_celery.vendors.worker.tasks.xsum
2024-09-04T12:47:28.6899323Z . t.integration.tasks.add
2024-09-04T12:47:28.6899790Z . t.integration.tasks.add_chord_to_chord
2024-09-04T12:47:28.6900275Z . t.integration.tasks.add_ignore_result
2024-09-04T12:47:28.6900686Z . t.integration.tasks.add_not_typed
2024-09-04T12:47:28.6901176Z . t.integration.tasks.add_pydantic
2024-09-04T12:47:28.6901620Z . t.integration.tasks.add_replaced
2024-09-04T12:47:28.6902046Z . t.integration.tasks.add_to_all
2024-09-04T12:47:28.6902558Z . t.integration.tasks.add_to_all_to_chord
2024-09-04T12:47:28.6903143Z . t.integration.tasks.build_chain_inside_task
2024-09-04T12:47:28.6903627Z . t.integration.tasks.chain_add
2024-09-04T12:47:28.6904128Z . t.integration.tasks.chord_add
2024-09-04T12:47:28.6904611Z . t.integration.tasks.collect_ids
2024-09-04T12:47:28.6905065Z . t.integration.tasks.delayed_sum
2024-09-04T12:47:28.6905564Z . t.integration.tasks.delayed_sum_with_soft_guard
2024-09-04T12:47:28.6906062Z . t.integration.tasks.errback_new_style
2024-09-04T12:47:28.6906540Z . t.integration.tasks.errback_old_style
2024-09-04T12:47:28.6907040Z . t.integration.tasks.fail
2024-09-04T12:47:28.6907445Z . t.integration.tasks.fail_replaced
2024-09-04T12:47:28.6907870Z . t.integration.tasks.fail_unpickleable
2024-09-04T12:47:28.6908379Z . t.integration.tasks.identity
2024-09-04T12:47:28.6908797Z . t.integration.tasks.ids
2024-09-04T12:47:28.6909242Z . t.integration.tasks.mul
2024-09-04T12:47:28.6909713Z . t.integration.tasks.print_unicode
2024-09-04T12:47:28.6910137Z . t.integration.tasks.raise_error
2024-09-04T12:47:28.6910629Z . t.integration.tasks.rebuild_signature
2024-09-04T12:47:28.6911072Z . t.integration.tasks.redis_count
2024-09-04T12:47:28.6911763Z . t.integration.tasks.redis_echo
2024-09-04T12:47:28.6912462Z . t.integration.tasks.redis_echo_group_id
2024-09-04T12:47:28.6912930Z . t.integration.tasks.replace_with_chain
2024-09-04T12:47:28.6913446Z . t.integration.tasks.replace_with_chain_which_raises
2024-09-04T12:47:28.6914051Z . t.integration.tasks.replace_with_empty_chain
2024-09-04T12:47:28.6914581Z . t.integration.tasks.replace_with_stamped_task
2024-09-04T12:47:28.6915073Z . t.integration.tasks.replaced_with_me
2024-09-04T12:47:28.6915614Z . t.integration.tasks.retry
2024-09-04T12:47:28.6916031Z . t.integration.tasks.retry_once
2024-09-04T12:47:28.6916466Z . t.integration.tasks.retry_once_headers
2024-09-04T12:47:28.6917015Z . t.integration.tasks.retry_once_priority
2024-09-04T12:47:28.6917491Z . t.integration.tasks.retry_unpickleable
2024-09-04T12:47:28.6917929Z . t.integration.tasks.return_exception
2024-09-04T12:47:28.6918538Z . t.integration.tasks.return_nested_signature_chain_chain
2024-09-04T12:47:28.6919123Z . t.integration.tasks.return_nested_signature_chain_chord
2024-09-04T12:47:28.6919793Z . t.integration.tasks.return_nested_signature_chain_group
2024-09-04T12:47:28.6920373Z . t.integration.tasks.return_nested_signature_chord_chain
2024-09-04T12:47:28.6921091Z . t.integration.tasks.return_nested_signature_chord_chord
2024-09-04T12:47:28.6922192Z . t.integration.tasks.return_nested_signature_chord_group
2024-09-04T12:47:28.6922994Z . t.integration.tasks.return_nested_signature_group_chain
2024-09-04T12:47:28.6923878Z . t.integration.tasks.return_nested_signature_group_chord
2024-09-04T12:47:28.6924582Z . t.integration.tasks.return_nested_signature_group_group
2024-09-04T12:47:28.6925108Z . t.integration.tasks.return_priority
2024-09-04T12:47:28.6925537Z . t.integration.tasks.return_properties
2024-09-04T12:47:28.6926104Z . t.integration.tasks.second_order_replace1
2024-09-04T12:47:28.6926593Z . t.integration.tasks.second_order_replace2
2024-09-04T12:47:28.6927079Z . t.integration.tasks.sleeping
2024-09-04T12:47:28.6927643Z . t.integration.tasks.soft_time_limit_must_exceed_time_limit
2024-09-04T12:47:28.6928133Z . t.integration.tasks.tsum
2024-09-04T12:47:28.6928594Z . t.integration.tasks.write_to_file_and_return_int
2024-09-04T12:47:28.6929219Z . t.integration.tasks.xsum
2024-09-04T12:47:28.6929633Z . t.smoke.tasks.long_running_task
2024-09-04T12:47:28.6930100Z . t.smoke.tasks.noop
2024-09-04T12:47:28.6930443Z . t.smoke.tasks.replace_with_task
2024-09-04T12:47:28.6930920Z . t.smoke.tasks.self_termination_delay_timeout
2024-09-04T12:47:28.6931506Z . t.smoke.tasks.self_termination_exhaust_memory
2024-09-04T12:47:28.6931996Z . t.smoke.tasks.self_termination_sigkill
2024-09-04T12:47:28.6932485Z . t.smoke.tasks.self_termination_system_exit
2024-09-04T12:47:28.6933202Z . t.smoke.tasks.soft_time_limit_lower_than_time_limit
2024-09-04T12:47:28.6933793Z . t.smoke.tasks.soft_time_limit_must_exceed_time_limit
2024-09-04T12:47:28.6934151Z
2024-09-04T12:47:28.6935231Z [2024-09-04 12:46:12,254: WARNING/MainProcess] /celery/celery/worker/consumer/consumer.py:508: CPendingDeprecationWarning: The broker_connection_retry configuration setting will no longer determine
2024-09-04T12:47:28.6936601Z whether broker connection retries are made during startup in Celery 6.0 and above.
2024-09-04T12:47:28.6937407Z If you wish to retain the existing behavior for retrying connections on startup,
2024-09-04T12:47:28.6938093Z you should set broker_connection_retry_on_startup to True.
2024-09-04T12:47:28.6938623Z warnings.warn(
2024-09-04T12:47:28.6938859Z
2024-09-04T12:47:28.6939275Z [2024-09-04 12:46:12,270: INFO/MainProcess] Found credentials in environment variables.
2024-09-04T12:47:28.6940133Z [2024-09-04 12:46:14,407: INFO/MainProcess] Connected to sqs://b09f0037a174:4566//
2024-09-04T12:47:28.6941612Z [2024-09-04 12:46:14,407: WARNING/MainProcess] /celery/celery/worker/consumer/consumer.py:508: CPendingDeprecationWarning: The broker_connection_retry configuration setting will no longer determine
2024-09-04T12:47:28.6942880Z whether broker connection retries are made during startup in Celery 6.0 and above.
2024-09-04T12:47:28.6943873Z If you wish to retain the existing behavior for retrying connections on startup,
2024-09-04T12:47:28.6944564Z you should set broker_connection_retry_on_startup to True.
2024-09-04T12:47:28.6945092Z warnings.warn(
2024-09-04T12:47:28.6945326Z
2024-09-04T12:47:28.6945787Z [2024-09-04 12:46:14,420: INFO/MainProcess] Found credentials in environment variables.
2024-09-04T12:47:28.6946620Z [2024-09-04 12:46:14,491: INFO/MainProcess] smoke_tests_worker@be6028dd6fb3 ready.
2024-09-04T12:47:28.6947644Z [2024-09-04 12:46:15,032: INFO/MainProcess] Task t.smoke.tasks.long_running_task[b7bc79db-cba2-408e-8c29-66239c1204e3] received
2024-09-04T12:47:28.6949042Z [2024-09-04 12:46:15,034: INFO/ForkPoolWorker-2] t.smoke.tasks.long_running_task[b7bc79db-cba2-408e-8c29-66239c1204e3]: Starting long running task
2024-09-04T12:47:28.6950378Z [2024-09-04 12:46:15,038: CRITICAL/MainProcess] Unrecoverable error: AttributeError("'LoggingProxy' object has no attribute 'fileno'")
2024-09-04T12:47:28.6951916Z Traceback (most recent call last):
2024-09-04T12:47:28.6952633Z File "/celery/celery/worker/worker.py", line 203, in start
2024-09-04T12:47:28.6953180Z self.blueprint.start(self)
2024-09-04T12:47:28.6953700Z File "/celery/celery/bootsteps.py", line 116, in start
2024-09-04T12:47:28.6954257Z step.start(parent)
2024-09-04T12:47:28.6954794Z File "/celery/celery/bootsteps.py", line 365, in start
2024-09-04T12:47:28.6955339Z return self.obj.start()
2024-09-04T12:47:28.6955675Z ^^^^^^^^^^^^^^^^
2024-09-04T12:47:28.6956225Z File "/celery/celery/worker/consumer/consumer.py", line 340, in start
2024-09-04T12:47:28.6956852Z blueprint.start(self)
2024-09-04T12:47:28.6957322Z File "/celery/celery/bootsteps.py", line 116, in start
2024-09-04T12:47:28.6957822Z step.start(parent)
2024-09-04T12:47:28.6958404Z File "/celery/celery/worker/consumer/consumer.py", line 758, in start
2024-09-04T12:47:28.6958982Z c.loop(*c.loop_args())
2024-09-04T12:47:28.6959437Z File "/celery/celery/worker/loops.py", line 97, in asynloop
2024-09-04T12:47:28.6959997Z next(loop)
2024-09-04T12:47:28.6960821Z File "/usr/local/lib/python3.11/site-packages/kombu/asynchronous/hub.py", line 317, in create_loop
2024-09-04T12:47:28.6961527Z events = poll(poll_timeout)
2024-09-04T12:47:28.6961975Z ^^^^^^^^^^^^^^^^^^
2024-09-04T12:47:28.6962674Z File "/usr/local/lib/python3.11/site-packages/kombu/utils/eventio.py", line 83, in poll
2024-09-04T12:47:28.6963540Z return self._epoll.poll(timeout if timeout is not None else -1)
2024-09-04T12:47:28.6964099Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-09-04T12:47:28.6964906Z File "/celery/celery/apps/worker.py", line 303, in _handle_request
2024-09-04T12:47:28.6965702Z safe_say(f'worker: {how} shutdown (MainProcess)', sys.stdout)
2024-09-04T12:47:28.6966363Z File "/celery/celery/apps/worker.py", line 83, in safe_say
2024-09-04T12:47:28.6966969Z os.write(fd.fileno(), f'\n{msg}\n'.encode())
2024-09-04T12:47:28.6967537Z ^^^^^^^^^
2024-09-04T12:47:28.6968093Z AttributeError: 'LoggingProxy' object has no attribute 'fileno'
2024-09-04T12:47:28.6969106Z [2024-09-04 12:46:15,049: ERROR/MainProcess] Error on stopping Pool: AttributeError("'LoggingProxy' object has no attribute 'fileno'")
2024-09-04T12:47:28.6970003Z Traceback (most recent call last):
2024-09-04T12:47:28.6970529Z File "/celery/celery/worker/worker.py", line 203, in start
2024-09-04T12:47:28.6971117Z self.blueprint.start(self)
2024-09-04T12:47:28.6971671Z File "/celery/celery/bootsteps.py", line 116, in start
2024-09-04T12:47:28.6972124Z step.start(parent)
2024-09-04T12:47:28.6972600Z File "/celery/celery/bootsteps.py", line 365, in start
2024-09-04T12:47:28.6973164Z return self.obj.start()
2024-09-04T12:47:28.6973529Z ^^^^^^^^^^^^^^^^
2024-09-04T12:47:28.6974137Z File "/celery/celery/worker/consumer/consumer.py", line 340, in start
2024-09-04T12:47:28.6974940Z blueprint.start(self)
2024-09-04T12:47:28.6975425Z File "/celery/celery/bootsteps.py", line 116, in start
2024-09-04T12:47:28.6976005Z step.start(parent)
2024-09-04T12:47:28.6976537Z File "/celery/celery/worker/consumer/consumer.py", line 758, in start
2024-09-04T12:47:28.6977099Z c.loop(*c.loop_args())
2024-09-04T12:47:28.6977647Z File "/celery/celery/worker/loops.py", line 97, in asynloop
2024-09-04T12:47:28.6978159Z next(loop)
2024-09-04T12:47:28.6978882Z File "/usr/local/lib/python3.11/site-packages/kombu/asynchronous/hub.py", line 317, in create_loop
2024-09-04T12:47:28.6979682Z events = poll(poll_timeout)
2024-09-04T12:47:28.6980029Z ^^^^^^^^^^^^^^^^^^
2024-09-04T12:47:28.6980789Z File "/usr/local/lib/python3.11/site-packages/kombu/utils/eventio.py", line 83, in poll
2024-09-04T12:47:28.6981679Z return self._epoll.poll(timeout if timeout is not None else -1)
2024-09-04T12:47:28.6982248Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-09-04T12:47:28.6982922Z File "/celery/celery/apps/worker.py", line 303, in _handle_request
2024-09-04T12:47:28.6983639Z safe_say(f'worker: {how} shutdown (MainProcess)', sys.stdout)
2024-09-04T12:47:28.6984266Z File "/celery/celery/apps/worker.py", line 83, in safe_say
2024-09-04T12:47:28.6984880Z os.write(fd.fileno(), f'\n{msg}\n'.encode())
2024-09-04T12:47:28.6985334Z ^^^^^^^^^
2024-09-04T12:47:28.6985844Z AttributeError: 'LoggingProxy' object has no attribute 'fileno'
2024-09-04T12:47:28.6986214Z
2024-09-04T12:47:28.6986587Z During handling of the above exception, another exception occurred:
2024-09-04T12:47:28.6986977Z
2024-09-04T12:47:28.6987156Z Traceback (most recent call last):
2024-09-04T12:47:28.6987748Z File "/celery/celery/bootsteps.py", line 148, in send_all
2024-09-04T12:47:28.6988290Z fun(parent, *args)
2024-09-04T12:47:28.6988728Z File "/celery/celery/bootsteps.py", line 369, in stop
2024-09-04T12:47:28.6989222Z return self.obj.stop()
2024-09-04T12:47:28.6989647Z ^^^^^^^^^^^^^^^
2024-09-04T12:47:28.6990118Z File "/celery/celery/concurrency/base.py", line 121, in stop
2024-09-04T12:47:28.6990701Z self.on_stop()
2024-09-04T12:47:28.6991334Z File "/celery/celery/concurrency/prefork.py", line 143, in on_stop
2024-09-04T12:47:28.6992040Z self._pool.join()
2024-09-04T12:47:28.6992849Z File "/usr/local/lib/python3.11/site-packages/billiard/pool.py", line 1619, in join
2024-09-04T12:47:28.6993525Z stop_if_not_current(self._result_handler)
2024-09-04T12:47:28.6994425Z File "/usr/local/lib/python3.11/site-packages/billiard/pool.py", line 144, in stop_if_not_current
2024-09-04T12:47:28.6995179Z thread.stop(timeout)
2024-09-04T12:47:28.6996016Z File "/usr/local/lib/python3.11/site-packages/billiard/pool.py", line 525, in stop
2024-09-04T12:47:28.6996644Z self.on_stop_not_started()
2024-09-04T12:47:28.6997294Z File "/celery/celery/concurrency/asynpool.py", line 360, in on_stop_not_started
2024-09-04T12:47:28.6997941Z iterate_file_descriptors_safely(
2024-09-04T12:47:28.6998628Z File "/celery/celery/concurrency/asynpool.py", line 215, in iterate_file_descriptors_safely
2024-09-04T12:47:28.6999374Z hub_method(fd, *hub_args, **hub_kwargs)
2024-09-04T12:47:28.7000014Z File "/celery/celery/concurrency/asynpool.py", line 390, in _flush_outqueue
2024-09-04T12:47:28.7000649Z sleep(0.5)
2024-09-04T12:47:28.7001155Z File "/celery/celery/apps/worker.py", line 303, in _handle_request
2024-09-04T12:47:28.7001893Z safe_say(f'worker: {how} shutdown (MainProcess)', sys.stdout)
2024-09-04T12:47:28.7002583Z File "/celery/celery/apps/worker.py", line 83, in safe_say
2024-09-04T12:47:28.7003189Z os.write(fd.fileno(), f'\n{msg}\n'.encode())
2024-09-04T12:47:28.7003634Z ^^^^^^^^^
2024-09-04T12:47:28.7004211Z AttributeError: 'LoggingProxy' object has no attribute ‘fileno'
Nusnus
approved these changes
Sep 8, 2024
19 tasks
6 tasks
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Note: Before submitting this pull request, please review our contributing
guidelines.
Description
I sometime got
RuntimeError: reentrant call inside <_io.BufferedWriter name='<stdout>'>during worker's lifecycle.see others have similar issue https://stackoverflow.com/questions/45680378/how-to-explain-the-reentrant-runtimeerror-caused-by-printing-in-signal-handlers#comment126485747_56330763
We should not use
printinside signal handlers because it's not thread-safe (not actually safe as the name suggested). There might be other cases ofprintinside signal handlers, but I was only able to identify these obvious ones. 😄See similar issue and thread in gunicorn.
An alternative solution is not to log/print anything.