See
<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/1544/display/redirect?page=changes>
Changes:
[sunjincheng121] [BEAM-8557] Add log for the dropped unknown response
[migryz] Bump python precommit timeout
[lcwik] [BEAM-8151] Swap to create SdkWorkers on demand when processing jobs
------------------------------------------
[...truncated 1.67 MB...]
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2951
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2859
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2606
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2594
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2647
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2582
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2930
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2744
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2692
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2587
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2558
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2488
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2846
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2800
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2636
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2842
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2917
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2788
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2811
19/11/15 18:06:08 INFO BlockManagerInfo: Removed broadcast_128_piece0 on
localhost:44963 in memory (size: 10.8 KB, free: 13.5 GB)
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2781
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2511
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2782
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2568
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2780
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2815
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2814
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2689
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2900
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2889
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2768
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2534
19/11/15 18:06:08 INFO BlockManagerInfo: Removed broadcast_121_piece0 on
localhost:44963 in memory (size: 8.9 KB, free: 13.5 GB)
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2894
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2924
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2911
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2640
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2946
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2857
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2718
19/11/15 18:06:08 INFO BlockManagerInfo: Removed broadcast_124_piece0 on
localhost:44963 in memory (size: 11.9 KB, free: 13.5 GB)
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2863
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2756
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2599
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2563
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2537
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2787
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2891
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2717
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2882
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2714
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2486
19/11/15 18:06:08 INFO ContextCleaner: Cleaned accumulator 2477
19/11/15 18:06:09 INFO GrpcLoggingService: Beam Fn Logging client connected.
19/11/15 18:06:09 INFO main: Logging handler created.
19/11/15 18:06:09 INFO start: Status HTTP server running at localhost:35315
19/11/15 18:06:09 INFO main: semi_persistent_directory: /tmp
19/11/15 18:06:09 WARN _load_main_session: No session file found:
/tmp/staged/pickled_main_session. Functions defined in __main__ (interactive
session) may fail.
19/11/15 18:06:09 WARN get_all_options: Discarding unparseable args:
[u'--job_server_timeout=60',
u'--app_name=test_windowing_1573841164.86_4778714a-29be-42cd-938d-04a41f49c8a6',
u'--direct_runner_use_stacked_bundle', u'--spark_master=local',
u'--options_id=30', u'--enable_spark_metric_sinks', u'--pipeline_type_check']
19/11/15 18:06:09 INFO main: Python sdk harness started with pipeline_options:
{'runner': u'None', 'experiments': [u'beam_fn_api'],
'environment_cache_millis': u'0', 'environment_type': u'PROCESS',
'sdk_location': u'container', 'job_name': u'test_windowing_1573841164.86',
'environment_config': u'{"command":
"<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/sdks/python/test-suites/portable/py2/build/sdk_worker.sh"}',>
'sdk_worker_parallelism': u'1', 'job_endpoint': u'localhost:44715'}
19/11/15 18:06:09 INFO __init__: Creating state cache with size 0
19/11/15 18:06:09 INFO __init__: Creating insecure control channel for
localhost:33737.
19/11/15 18:06:09 INFO __init__: Control channel established.
19/11/15 18:06:09 INFO __init__: Initializing SDKHarness with unbounded number
of workers.
19/11/15 18:06:09 INFO FnApiControlClientPoolService: Beam Fn Control client
connected with id 264-1
19/11/15 18:06:09 INFO create_state_handler: Creating insecure state channel
for localhost:42657.
19/11/15 18:06:09 INFO create_state_handler: State channel established.
19/11/15 18:06:09 INFO create_data_channel: Creating client data channel for
localhost:43139
19/11/15 18:06:09 INFO GrpcDataService: Beam Fn Data client connected.
19/11/15 18:06:09 INFO DefaultJobBundleFactory: Closing environment urn:
"beam:env:process:v1"
payload:
"\032\202\001<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/sdks/python/test-suites/portable/py2/build/sdk_worker.sh";>
19/11/15 18:06:09 INFO run: No more requests from control plane
19/11/15 18:06:09 INFO run: SDK Harness waiting for in-flight requests to
complete
19/11/15 18:06:09 WARN BeamFnDataGrpcMultiplexer: Hanged up for unknown
endpoint.
19/11/15 18:06:09 INFO close: Closing all cached grpc data channels.
19/11/15 18:06:09 INFO close: Closing all cached gRPC state handlers.
19/11/15 18:06:09 INFO run: Done consuming work.
19/11/15 18:06:09 INFO main: Python sdk harness exiting.
19/11/15 18:06:09 INFO GrpcLoggingService: Logging client hanged up.
19/11/15 18:06:09 WARN BeamFnDataGrpcMultiplexer: Hanged up for unknown
endpoint.
19/11/15 18:06:09 INFO Executor: Finished task 0.0 in stage 132.0 (TID 160).
13753 bytes result sent to driver
19/11/15 18:06:09 INFO TaskSetManager: Finished task 0.0 in stage 132.0 (TID
160) in 879 ms on localhost (executor driver) (2/2)
19/11/15 18:06:09 INFO TaskSchedulerImpl: Removed TaskSet 132.0, whose tasks
have all completed, from pool
19/11/15 18:06:09 INFO DAGScheduler: ShuffleMapStage 132 (flatMapToPair at
GroupNonMergingWindowsFunctions.java:115) finished in 1.764 s
19/11/15 18:06:09 INFO DAGScheduler: looking for newly runnable stages
19/11/15 18:06:09 INFO DAGScheduler: running: Set()
19/11/15 18:06:09 INFO DAGScheduler: waiting: Set(ResultStage 133)
19/11/15 18:06:09 INFO DAGScheduler: failed: Set()
19/11/15 18:06:09 INFO DAGScheduler: Submitting ResultStage 133
(EmptyOutputSink_0 MapPartitionsRDD[916] at flatMap at
SparkBatchPortablePipelineTranslator.java:311), which has no missing parents
19/11/15 18:06:09 INFO MemoryStore: Block broadcast_130 stored as values in
memory (estimated size 26.1 KB, free 13.5 GB)
19/11/15 18:06:09 INFO MemoryStore: Block broadcast_130_piece0 stored as bytes
in memory (estimated size 12.3 KB, free 13.5 GB)
19/11/15 18:06:09 INFO BlockManagerInfo: Added broadcast_130_piece0 in memory
on localhost:44963 (size: 12.3 KB, free: 13.5 GB)
19/11/15 18:06:09 INFO SparkContext: Created broadcast 130 from broadcast at
DAGScheduler.scala:1161
19/11/15 18:06:09 INFO DAGScheduler: Submitting 1 missing tasks from
ResultStage 133 (EmptyOutputSink_0 MapPartitionsRDD[916] at flatMap at
SparkBatchPortablePipelineTranslator.java:311) (first 15 tasks are for
partitions Vector(0))
19/11/15 18:06:09 INFO TaskSchedulerImpl: Adding task set 133.0 with 1 tasks
19/11/15 18:06:09 INFO TaskSetManager: Starting task 0.0 in stage 133.0 (TID
161, localhost, executor driver, partition 0, NODE_LOCAL, 7662 bytes)
19/11/15 18:06:09 INFO Executor: Running task 0.0 in stage 133.0 (TID 161)
19/11/15 18:06:09 INFO ShuffleBlockFetcherIterator: Getting 2 non-empty blocks
including 2 local blocks and 0 remote blocks
19/11/15 18:06:09 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches in
0 ms
19/11/15 18:06:09 INFO AbstractArtifactRetrievalService: GetManifest for
/tmp/sparktestx7YS_F/job_e9816b93-bb0a-4999-8d39-9fb335121d7a/MANIFEST
19/11/15 18:06:09 INFO AbstractArtifactRetrievalService: GetManifest for
/tmp/sparktestx7YS_F/job_e9816b93-bb0a-4999-8d39-9fb335121d7a/MANIFEST -> 0
artifacts
19/11/15 18:06:10 INFO GrpcLoggingService: Beam Fn Logging client connected.
19/11/15 18:06:10 INFO main: Logging handler created.
19/11/15 18:06:10 INFO start: Status HTTP server running at localhost:34057
19/11/15 18:06:10 INFO main: semi_persistent_directory: /tmp
19/11/15 18:06:10 WARN _load_main_session: No session file found:
/tmp/staged/pickled_main_session. Functions defined in __main__ (interactive
session) may fail.
19/11/15 18:06:10 WARN get_all_options: Discarding unparseable args:
[u'--job_server_timeout=60',
u'--app_name=test_windowing_1573841164.86_4778714a-29be-42cd-938d-04a41f49c8a6',
u'--direct_runner_use_stacked_bundle', u'--spark_master=local',
u'--options_id=30', u'--enable_spark_metric_sinks', u'--pipeline_type_check']
19/11/15 18:06:10 INFO main: Python sdk harness started with pipeline_options:
{'runner': u'None', 'experiments': [u'beam_fn_api'],
'environment_cache_millis': u'0', 'environment_type': u'PROCESS',
'sdk_location': u'container', 'job_name': u'test_windowing_1573841164.86',
'environment_config': u'{"command":
"<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/sdks/python/test-suites/portable/py2/build/sdk_worker.sh"}',>
'sdk_worker_parallelism': u'1', 'job_endpoint': u'localhost:44715'}
19/11/15 18:06:10 INFO __init__: Creating state cache with size 0
19/11/15 18:06:10 INFO __init__: Creating insecure control channel for
localhost:33165.
19/11/15 18:06:10 INFO __init__: Control channel established.
19/11/15 18:06:10 INFO FnApiControlClientPoolService: Beam Fn Control client
connected with id 265-1
19/11/15 18:06:10 INFO __init__: Initializing SDKHarness with unbounded number
of workers.
19/11/15 18:06:10 INFO create_state_handler: Creating insecure state channel
for localhost:36291.
19/11/15 18:06:10 INFO create_state_handler: State channel established.
19/11/15 18:06:10 INFO create_data_channel: Creating client data channel for
localhost:46003
19/11/15 18:06:10 INFO GrpcDataService: Beam Fn Data client connected.
19/11/15 18:06:10 INFO DefaultJobBundleFactory: Closing environment urn:
"beam:env:process:v1"
payload:
"\032\202\001<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/sdks/python/test-suites/portable/py2/build/sdk_worker.sh";>
19/11/15 18:06:10 INFO run: No more requests from control plane
19/11/15 18:06:10 INFO run: SDK Harness waiting for in-flight requests to
complete
19/11/15 18:06:10 INFO close: Closing all cached grpc data channels.
19/11/15 18:06:10 WARN BeamFnDataGrpcMultiplexer: Hanged up for unknown
endpoint.
19/11/15 18:06:10 INFO close: Closing all cached gRPC state handlers.
19/11/15 18:06:10 INFO run: Done consuming work.
19/11/15 18:06:10 INFO main: Python sdk harness exiting.
19/11/15 18:06:10 INFO GrpcLoggingService: Logging client hanged up.
19/11/15 18:06:10 WARN BeamFnDataGrpcMultiplexer: Hanged up for unknown
endpoint.
19/11/15 18:06:10 INFO Executor: Finished task 0.0 in stage 133.0 (TID 161).
11970 bytes result sent to driver
19/11/15 18:06:10 INFO TaskSetManager: Finished task 0.0 in stage 133.0 (TID
161) in 836 ms on localhost (executor driver) (1/1)
19/11/15 18:06:10 INFO TaskSchedulerImpl: Removed TaskSet 133.0, whose tasks
have all completed, from pool
19/11/15 18:06:10 INFO DAGScheduler: ResultStage 133 (foreach at
BoundedDataset.java:124) finished in 0.843 s
19/11/15 18:06:10 INFO DAGScheduler: Job 47 finished: foreach at
BoundedDataset.java:124, took 4.321571 s
19/11/15 18:06:10 INFO SparkPipelineRunner: Job
test_windowing_1573841164.86_4778714a-29be-42cd-938d-04a41f49c8a6 finished.
19/11/15 18:06:10 WARN SparkPipelineResult$BatchMode: Collecting monitoring
infos is not implemented yet in Spark portable runner.
19/11/15 18:06:10 INFO AbstractArtifactRetrievalService: Manifest at
/tmp/sparktestx7YS_F/job_e9816b93-bb0a-4999-8d39-9fb335121d7a/MANIFEST has 0
artifact locations
19/11/15 18:06:10 INFO BeamFileSystemArtifactStagingService: Removed dir
/tmp/sparktestx7YS_F/job_e9816b93-bb0a-4999-8d39-9fb335121d7a/
INFO:root:Job state changed to DONE
.
======================================================================
ERROR: test_pardo_state_with_custom_key_coder (__main__.SparkRunnerTest)
Tests that state requests work correctly when the key coder is an
----------------------------------------------------------------------
Traceback (most recent call last):
File "apache_beam/runners/portability/portable_runner_test.py", line 229, in
test_pardo_state_with_custom_key_coder
equal_to(expected))
File "apache_beam/pipeline.py", line 436, in __exit__
self.run().wait_until_finish()
File "apache_beam/runners/portability/portable_runner.py", line 419, in
wait_until_finish
for state_response in self._state_stream:
File
"<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,>
line 395, in next
return self._next()
File
"<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,>
line 552, in _next
_common.wait(self._state.condition.wait, _response_ready)
File
"<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_common.py";,>
line 140, in wait
_wait_once(wait_fn, MAXIMUM_WAIT_TIMEOUT, spin_cb)
File
"<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_common.py";,>
line 105, in _wait_once
wait_fn(timeout=timeout)
File "/usr/lib/python2.7/threading.py", line 359, in wait
_sleep(delay)
File "apache_beam/runners/portability/portable_runner_test.py", line 73, in
handler
raise BaseException(msg)
BaseException: Timed out after 60 seconds.
======================================================================
ERROR: test_pardo_timers (__main__.SparkRunnerTest)
==================== Timed out after 60 seconds. ====================
----------------------------------------------------------------------
# Thread: <Thread(wait_until_finish_read, started daemon 140009004828416)>
Traceback (most recent call last):
# Thread: <Thread(Thread-120, started daemon 140009013221120)>
File "apache_beam/runners/portability/fn_api_runner_test.py", line 326, in
test_pardo_timers
assert_that(actual, equal_to(expected))
File "apache_beam/pipeline.py", line 436, in __exit__
self.run().wait_until_finish()
File "apache_beam/runners/portability/portable_ru# Thread:
<_MainThread(MainThread, started 140009799784192)>
==================== Timed out after 60 seconds. ====================
nner.py", line 419, in wait_until_finish
for state_response in self._state_stream:
# Thread: <Thread(wait_until_finish_read, started daemon 140008979650304)>
# Thread: <Thread(Thread-126, started daemon 140008988043008)>
# Thread: <_MainThread(MainThread, started 140009799784192)>
File
"<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,>
line 395, in next
return self._next()
File
"<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_channel.py";,>
line 552, in _next
_common.wait(self._state.condition.wait, _response_ready)
File
"<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_common.py";,>
line 140, in wait
_wait_once(wait_fn, MAXIMUM_WAIT_TIMEOUT, spin_cb)
File
"<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/build/gradleenv/1866363813/local/lib/python2.7/site-packages/grpc/_common.py";,>
line 105, in _wait_once
wait_fn(timeout=timeout)
File "/usr/lib/python2.7/threading.py", line 359, in wait
_sleep(delay)
File "apache_beam/runners/portability/portable_runner_test.py", line 73, in
handler
raise BaseException(msg)
BaseException: Timed out after 60 seconds.
======================================================================
ERROR: test_sdf_with_watermark_tracking (__main__.SparkRunnerTest)
----------------------------------------------------------------------
Traceback (most recent call last):
File "apache_beam/runners/portability/fn_api_runner_test.py", line 497, in
test_sdf_with_watermark_tracking
assert_that(actual, equal_to(list(''.join(data))))
File "apache_beam/pipeline.py", line 436, in __exit__
self.run().wait_until_finish()
File "apache_beam/runners/portability/portable_runner.py", line 429, in
wait_until_finish
self._job_id, self._state, self._last_error_message()))
RuntimeError: Pipeline
test_sdf_with_watermark_tracking_1573841156.08_0d288ffc-742a-4125-9e68-2f71c1cef676
failed in state FAILED: java.lang.UnsupportedOperationException: The
ActiveBundle does not have a registered bundle checkpoint handler.
----------------------------------------------------------------------
Ran 38 tests in 291.696s
FAILED (errors=3, skipped=9)
> Task :sdks:python:test-suites:portable:py2:sparkValidatesRunner FAILED
FAILURE: Build failed with an exception.
* Where:
Build file
'<https://builds.apache.org/job/beam_PostCommit_Python_VR_Spark/ws/src/sdks/python/test-suites/portable/py2/build.gradle'>
line: 198
* What went wrong:
Execution failed for task
':sdks:python:test-suites:portable:py2:sparkValidatesRunner'.
> Process 'command 'sh'' finished with non-zero exit value 1
* Try:
Run with --stacktrace option to get the stack trace. Run with --info or --debug
option to get more log output. Run with --scan to get full insights.
* Get more help at https://help.gradle.org
Deprecated Gradle features were used in this build, making it incompatible with
Gradle 6.0.
Use '--warning-mode all' to show the individual deprecation warnings.
See
https://docs.gradle.org/5.2.1/userguide/command_line_interface.html#sec:command_line_warnings
BUILD FAILED in 7m 6s
59 actionable tasks: 46 executed, 13 from cache
Publishing build scan...
https://gradle.com/s/la45teijpxfxk
Build step 'Invoke Gradle script' changed build result to FAILURE
Build step 'Invoke Gradle script' marked build as failure
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
