You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@beam.apache.org by "Ning Kang (Jira)" <ji...@apache.org> on 2019/12/19 18:44:00 UTC

[jira] [Commented] (BEAM-8991) RuntimeError in log_handler_test

    [ https://issues.apache.org/jira/browse/BEAM-8991?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17000296#comment-17000296 ] 

Ning Kang commented on BEAM-8991:
---------------------------------

Got it, thanks!

 

I've also experienced something interesting when running tests.

Say if you intentionally log something at warning level and if you do it in the __main__ scope, such warning log will fail tests when running on Jenkins. Some gradle tasks will just exit when they see warning level logs.

However, if you move the warning log to some local scope, say some constructor of some class, the warning log would not fail those gradle tasks.

> RuntimeError in log_handler_test
> --------------------------------
>
>                 Key: BEAM-8991
>                 URL: https://issues.apache.org/jira/browse/BEAM-8991
>             Project: Beam
>          Issue Type: Bug
>          Components: sdk-py-core
>            Reporter: Ning Kang
>            Priority: Major
>             Fix For: Not applicable
>
>
> Now is:
> {code:java}
> apache_beam.runners.worker.log_handler_test.FnApiLogRecordHandlerTest.test_exc_info (from py27-gcp-pytest)Failing for the past 1 build (Since #1290 )Took 78 ms.Error MessageIndexError: list index out of rangeStacktraceself = <apache_beam.runners.worker.log_handler_test.FnApiLogRecordHandlerTest testMethod=test_exc_info>
>     def test_exc_info(self):
>       try:
>         raise ValueError('some message')
>       except ValueError:
>         _LOGGER.error('some error', exc_info=True)
>     
>       self.fn_log_handler.close()
>     
> >     log_entry = self.test_logging_service.log_records_received[0].log_entries[0]
> E     IndexError: list index out of range
> apache_beam/runners/worker/log_handler_test.py:110: IndexErrorStandard ErrorERROR:apache_beam.runners.worker.log_handler_test:some error
> Traceback (most recent call last):
>   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Phrase/src/sdks/python/test-suites/tox/py2/build/srcs/sdks/python/apache_beam/runners/worker/log_handler_test.py", line 104, in test_exc_info
>     raise ValueError('some message')
> ValueError: some message
> {code}
>  Marking it as a duplicate of BEAM-8974.
> Was:
> {code:java}
> 19:28:06 > Task :sdks:python:test-suites:tox:py35:testPy35Cython
> .Exception in thread Thread-1715:
> 19:28:06 Traceback (most recent call last):
> 19:28:06   File "apache_beam/runners/common.py", line 879, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     return self.do_fn_invoker.invoke_process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 495, in apache_beam.runners.common.SimpleInvoker.invoke_process
> 19:28:06     windowed_value, self.process_method(windowed_value.value))
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/transforms/core.py", line 1434, in <lambda>
> 19:28:06     wrapper = lambda x: [fn(x)]
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/fn_api_runner_test.py", line 620, in raise_error
> 19:28:06     raise RuntimeError('x')
> 19:28:06 RuntimeError: x
> 19:28:06 
> 19:28:06 During handling of the above exception, another exception occurred:
> 19:28:06 
> 19:28:06 Traceback (most recent call last):
> 19:28:06   File "/usr/lib/python3.5/threading.py", line 914, in _bootstrap_inner
> 19:28:06     self.run()
> 19:28:06   File "/usr/lib/python3.5/threading.py", line 862, in run
> 19:28:06     self._target(*self._args, **self._kwargs)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/local_job_service.py", line 270, in _run_job
> 19:28:06     self._pipeline_proto)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/fn_api_runner.py", line 461, in run_via_runner_api
> 19:28:06     return self.run_stages(stage_context, stages)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/fn_api_runner.py", line 553, in run_stages
> 19:28:06     stage_results.process_bundle.monitoring_infos)
> 19:28:06   File "/usr/lib/python3.5/contextlib.py", line 77, in __exit__
> 19:28:06     self.gen.throw(type, value, traceback)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/fn_api_runner.py", line 500, in maybe_profile
> 19:28:06     yield
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/fn_api_runner.py", line 550, in run_stages
> 19:28:06     stage_context.safe_coders)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/fn_api_runner.py", line 870, in _run_stage
> 19:28:06     result, splits = bundle_manager.process_bundle(data_input, data_output)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/fn_api_runner.py", line 2052, in process_bundle
> 19:28:06     part, expected_outputs), part_inputs):
> 19:28:06   File "/usr/lib/python3.5/concurrent/futures/_base.py", line 556, in result_iterator
> 19:28:06     yield future.result()
> 19:28:06   File "/usr/lib/python3.5/concurrent/futures/_base.py", line 405, in result
> 19:28:06     return self.__get_result()
> 19:28:06   File "/usr/lib/python3.5/concurrent/futures/_base.py", line 357, in __get_result
> 19:28:06     raise self._exception
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/utils/thread_pool_executor.py", line 42, in run
> 19:28:06     self._future.set_result(self._fn(*self._fn_args, **self._fn_kwargs))
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/fn_api_runner.py", line 2052, in <lambda>
> 19:28:06     part, expected_outputs), part_inputs):
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/fn_api_runner.py", line 1977, in process_bundle
> 19:28:06     result_future = self._worker_handler.control_conn.push(process_bundle_req)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/fn_api_runner.py", line 1319, in push
> 19:28:06     response = self.worker.do_instruction(request)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/worker/sdk_worker.py", line 341, in do_instruction
> 19:28:06     request.instruction_id)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/worker/sdk_worker.py", line 384, in process_bundle
> 19:28:06     requires_finalization=requests_finalization))
> 19:28:06   File "/usr/lib/python3.5/contextlib.py", line 77, in __exit__
> 19:28:06     self.gen.throw(type, value, traceback)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/worker/sdk_worker.py", line 717, in process_instruction_id
> 19:28:06     yield
> 19:28:06   File "/usr/lib/python3.5/contextlib.py", line 77, in __exit__
> 19:28:06     self.gen.throw(type, value, traceback)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/fn_api_runner.py", line 1055, in process_instruction_id
> 19:28:06     yield
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/worker/sdk_worker.py", line 717, in process_instruction_id
> 19:28:06     yield
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/worker/sdk_worker.py", line 384, in process_bundle
> 19:28:06     requires_finalization=requests_finalization))
> 19:28:06   File "/usr/lib/python3.5/contextlib.py", line 77, in __exit__
> 19:28:06     self.gen.throw(type, value, traceback)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/worker/sdk_worker.py", line 481, in maybe_profile
> 19:28:06     yield
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/worker/sdk_worker.py", line 375, in process_bundle
> 19:28:06     bundle_processor.process_bundle(instruction_id))
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/worker/bundle_processor.py", line 809, in process_bundle
> 19:28:06     data.transform_id].process_encoded(data.data)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/worker/bundle_processor.py", line 204, in process_encoded
> 19:28:06     self.output(decoded_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 301, in apache_beam.runners.worker.operations.Operation.output
> 19:28:06     def output(self, windowed_value, output_index=0):
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 303, in apache_beam.runners.worker.operations.Operation.output
> 19:28:06     cython.cast(Receiver, self.receivers[output_index]).receive(windowed_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 177, in apache_beam.runners.worker.operations.SingletonConsumerSet.receive
> 19:28:06     self.consumer.process(windowed_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 656, in apache_beam.runners.worker.operations.DoOperation.process
> 19:28:06     with self.scoped_process_state:
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 657, in apache_beam.runners.worker.operations.DoOperation.process
> 19:28:06     delayed_application = self.dofn_receiver.receive(o)
> 19:28:06   File "apache_beam/runners/common.py", line 874, in apache_beam.runners.common.DoFnRunner.receive
> 19:28:06     self.process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 881, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     self._reraise_augmented(exn)
> 19:28:06   File "apache_beam/runners/common.py", line 935, in apache_beam.runners.common.DoFnRunner._reraise_augmented
> 19:28:06     raise
> 19:28:06   File "apache_beam/runners/common.py", line 879, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     return self.do_fn_invoker.invoke_process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 494, in apache_beam.runners.common.SimpleInvoker.invoke_process
> 19:28:06     output_processor.process_outputs(
> 19:28:06   File "apache_beam/runners/common.py", line 1022, in apache_beam.runners.common._OutputProcessor.process_outputs
> 19:28:06     self.main_receivers.receive(windowed_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 177, in apache_beam.runners.worker.operations.SingletonConsumerSet.receive
> 19:28:06     self.consumer.process(windowed_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 656, in apache_beam.runners.worker.operations.DoOperation.process
> 19:28:06     with self.scoped_process_state:
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 657, in apache_beam.runners.worker.operations.DoOperation.process
> 19:28:06     delayed_application = self.dofn_receiver.receive(o)
> 19:28:06   File "apache_beam/runners/common.py", line 874, in apache_beam.runners.common.DoFnRunner.receive
> 19:28:06     self.process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 881, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     self._reraise_augmented(exn)
> 19:28:06   File "apache_beam/runners/common.py", line 935, in apache_beam.runners.common.DoFnRunner._reraise_augmented
> 19:28:06     raise
> 19:28:06   File "apache_beam/runners/common.py", line 879, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     return self.do_fn_invoker.invoke_process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 494, in apache_beam.runners.common.SimpleInvoker.invoke_process
> 19:28:06     output_processor.process_outputs(
> 19:28:06   File "apache_beam/runners/common.py", line 1022, in apache_beam.runners.common._OutputProcessor.process_outputs
> 19:28:06     self.main_receivers.receive(windowed_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 177, in apache_beam.runners.worker.operations.SingletonConsumerSet.receive
> 19:28:06     self.consumer.process(windowed_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 656, in apache_beam.runners.worker.operations.DoOperation.process
> 19:28:06     with self.scoped_process_state:
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 657, in apache_beam.runners.worker.operations.DoOperation.process
> 19:28:06     delayed_application = self.dofn_receiver.receive(o)
> 19:28:06   File "apache_beam/runners/common.py", line 874, in apache_beam.runners.common.DoFnRunner.receive
> 19:28:06     self.process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 881, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     self._reraise_augmented(exn)
> 19:28:06   File "apache_beam/runners/common.py", line 935, in apache_beam.runners.common.DoFnRunner._reraise_augmented
> 19:28:06     raise
> 19:28:06   File "apache_beam/runners/common.py", line 879, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     return self.do_fn_invoker.invoke_process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 494, in apache_beam.runners.common.SimpleInvoker.invoke_process
> 19:28:06     output_processor.process_outputs(
> 19:28:06   File "apache_beam/runners/common.py", line 1022, in apache_beam.runners.common._OutputProcessor.process_outputs
> 19:28:06     self.main_receivers.receive(windowed_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 177, in apache_beam.runners.worker.operations.SingletonConsumerSet.receive
> 19:28:06     self.consumer.process(windowed_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 656, in apache_beam.runners.worker.operations.DoOperation.process
> 19:28:06     with self.scoped_process_state:
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 657, in apache_beam.runners.worker.operations.DoOperation.process
> 19:28:06     delayed_application = self.dofn_receiver.receive(o)
> 19:28:06   File "apache_beam/runners/common.py", line 874, in apache_beam.runners.common.DoFnRunner.receive
> 19:28:06     self.process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 881, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     self._reraise_augmented(exn)
> 19:28:06   File "apache_beam/runners/common.py", line 935, in apache_beam.runners.common.DoFnRunner._reraise_augmented
> 19:28:06     raise
> 19:28:06   File "apache_beam/runners/common.py", line 879, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     return self.do_fn_invoker.invoke_process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 494, in apache_beam.runners.common.SimpleInvoker.invoke_process
> 19:28:06     output_processor.process_outputs(
> 19:28:06   File "apache_beam/runners/common.py", line 1022, in apache_beam.runners.common._OutputProcessor.process_outputs
> 19:28:06     self.main_receivers.receive(windowed_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 177, in apache_beam.runners.worker.operations.SingletonConsumerSet.receive
> 19:28:06     self.consumer.process(windowed_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 656, in apache_beam.runners.worker.operations.DoOperation.process
> 19:28:06     with self.scoped_process_state:
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 657, in apache_beam.runners.worker.operations.DoOperation.process
> 19:28:06     delayed_application = self.dofn_receiver.receive(o)
> 19:28:06   File "apache_beam/runners/common.py", line 874, in apache_beam.runners.common.DoFnRunner.receive
> 19:28:06     self.process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 881, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     self._reraise_augmented(exn)
> 19:28:06   File "apache_beam/runners/common.py", line 935, in apache_beam.runners.common.DoFnRunner._reraise_augmented
> 19:28:06     raise
> 19:28:06   File "apache_beam/runners/common.py", line 879, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     return self.do_fn_invoker.invoke_process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 494, in apache_beam.runners.common.SimpleInvoker.invoke_process
> 19:28:06     output_processor.process_outputs(
> 19:28:06   File "apache_beam/runners/common.py", line 1022, in apache_beam.runners.common._OutputProcessor.process_outputs
> 19:28:06     self.main_receivers.receive(windowed_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 177, in apache_beam.runners.worker.operations.SingletonConsumerSet.receive
> 19:28:06     self.consumer.process(windowed_value)
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 656, in apache_beam.runners.worker.operations.DoOperation.process
> 19:28:06     with self.scoped_process_state:
> 19:28:06   File "apache_beam/runners/worker/operations.py", line 657, in apache_beam.runners.worker.operations.DoOperation.process
> 19:28:06     delayed_application = self.dofn_receiver.receive(o)
> 19:28:06   File "apache_beam/runners/common.py", line 874, in apache_beam.runners.common.DoFnRunner.receive
> 19:28:06     self.process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 881, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     self._reraise_augmented(exn)
> 19:28:06   File "apache_beam/runners/common.py", line 950, in apache_beam.runners.common.DoFnRunner._reraise_augmented
> 19:28:06     raise_with_traceback(new_exn)
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/target/.tox-py35-cython-pytest/py35-cython-pytest/lib/python3.5/site-packages/future/utils/__init__.py", line 419, in raise_with_traceback
> 19:28:06     raise exc.with_traceback(traceback)
> 19:28:06   File "apache_beam/runners/common.py", line 879, in apache_beam.runners.common.DoFnRunner.process
> 19:28:06     return self.do_fn_invoker.invoke_process(windowed_value)
> 19:28:06   File "apache_beam/runners/common.py", line 495, in apache_beam.runners.common.SimpleInvoker.invoke_process
> 19:28:06     windowed_value, self.process_method(windowed_value.value))
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/transforms/core.py", line 1434, in <lambda>
> 19:28:06     wrapper = lambda x: [fn(x)]
> 19:28:06   File "/home/jenkins/jenkins-slave/workspace/beam_PreCommit_Python_Commit@2/src/sdks/python/test-suites/tox/py35/build/srcs/sdks/python/apache_beam/runners/portability/fn_api_runner_test.py", line 620, in raise_error
> 19:28:06     raise RuntimeError('x')
> 19:28:06 RuntimeError: x [while running 'StageC']
> {code}



--
This message was sent by Atlassian Jira
(v8.3.4#803005)