Using Hadoop client lib jars at 3.2.0, provided by Spark.
PYSPARK_PYTHON=/opt/conda-analytics/bin/python3
Picked up JAVA_TOOL_OPTIONS: -Dfile.encoding=UTF-8
Picked up JAVA_TOOL_OPTIONS: -Dfile.encoding=UTF-8
24/01/12 13:40:15 INFO SparkContext: Running Spark version 3.1.2
24/01/12 13:40:15 WARN SparkConf: Note that spark.local.dir will be overridden by the value set by the cluster manager (via SPARK_LOCAL_DIRS in mesos/standalone/kubernetes and LOCAL_DIRS in YARN).
24/01/12 13:40:15 INFO ResourceUtils: ==============================================================
24/01/12 13:40:15 INFO ResourceUtils: No custom resources configured for spark.driver.
24/01/12 13:40:15 INFO ResourceUtils: ==============================================================
24/01/12 13:40:15 INFO SparkContext: Submitted application: dumps_publish_wikitext_raw_to_xml__publish_simplewiki_to_xml__20240111
24/01/12 13:40:15 INFO ResourceProfile: Limiting resource is cpus at 2 tasks per executor
24/01/12 13:40:15 INFO ResourceProfileManager: Added ResourceProfile id: 0
24/01/12 13:40:15 INFO SecurityManager: Changing view acls to: jebe
24/01/12 13:40:15 INFO SecurityManager: Changing modify acls to: jebe
24/01/12 13:40:15 INFO SecurityManager: Changing view acls groups to:
24/01/12 13:40:15 INFO SecurityManager: Changing modify acls groups to:
24/01/12 13:40:15 INFO SecurityManager: SecurityManager: authentication enabled; ui acls disabled; users with view permissions: Set(jebe); groups with view permissions: Set(); users with modify permissions: Set(jebe); groups with modify permissions: Set()
24/01/12 13:40:16 WARN Utils: Service 'sparkDriver' could not bind on port 12000. Attempting port 12001.
24/01/12 13:40:16 WARN Utils: Service 'sparkDriver' could not bind on port 12001. Attempting port 12002.
24/01/12 13:40:16 WARN Utils: Service 'sparkDriver' could not bind on port 12002. Attempting port 12003.
24/01/12 13:40:16 WARN Utils: Service 'sparkDriver' could not bind on port 12003. Attempting port 12004.
24/01/12 13:40:16 WARN Utils: Service 'sparkDriver' could not bind on port 12004. Attempting port 12005.
24/01/12 13:40:16 WARN Utils: Service 'sparkDriver' could not bind on port 12005. Attempting port 12006.
24/01/12 13:40:16 INFO Utils: Successfully started service 'sparkDriver' on port 12006.
24/01/12 13:40:16 INFO SparkEnv: Registering MapOutputTracker
24/01/12 13:40:16 INFO SparkEnv: Registering BlockManagerMaster
24/01/12 13:40:16 INFO BlockManagerMasterEndpoint: Using org.apache.spark.storage.DefaultTopologyMapper for getting topology information
24/01/12 13:40:16 INFO BlockManagerMasterEndpoint: BlockManagerMasterEndpoint up
24/01/12 13:40:16 INFO SparkEnv: Registering BlockManagerMasterHeartbeat
24/01/12 13:40:16 INFO DiskBlockManager: Created local directory at /srv/spark-tmp/blockmgr-2da583c1-d9af-4c7c-8cf9-7ee58d53ec0a
24/01/12 13:40:16 INFO MemoryStore: MemoryStore started with capacity 8.4 GiB
24/01/12 13:40:16 INFO SparkEnv: Registering OutputCommitCoordinator
24/01/12 13:40:16 INFO log: Logging initialized @7794ms to org.sparkproject.jetty.util.log.Slf4jLog
24/01/12 13:40:16 WARN Utils: Service 'SparkUI' could not bind on port 4040. Attempting port 4041.
24/01/12 13:40:16 WARN Utils: Service 'SparkUI' could not bind on port 4041. Attempting port 4042.
24/01/12 13:40:16 WARN Utils: Service 'SparkUI' could not bind on port 4042. Attempting port 4043.
24/01/12 13:40:16 WARN Utils: Service 'SparkUI' could not bind on port 4043. Attempting port 4044.
24/01/12 13:40:16 WARN Utils: Service 'SparkUI' could not bind on port 4044. Attempting port 4045.
24/01/12 13:40:16 WARN Utils: Service 'SparkUI' could not bind on port 4045. Attempting port 4046.
24/01/12 13:40:16 INFO AbstractConnector: Started ServerConnector@4b4d124{HTTP/1.1, (http/1.1)}{0.0.0.0:4046}
24/01/12 13:40:16 INFO Utils: Successfully started service 'SparkUI' on port 4046.
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@75dd0f94{/jobs,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@1d7c9811{/jobs/json,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@6451a288{/jobs/job,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@18b40fe6{/jobs/job/json,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@67d5ac2f{/stages,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@1d637673{/stages/json,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@636dbfe7{/stages/stage,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@7dd3981e{/stages/stage/json,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@4a04ca74{/stages/pool,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@24aedcc5{/stages/pool/json,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@1850f2da{/storage,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@6ace919c{/storage/json,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@5f5c187d{/storage/rdd,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@58182b96{/storage/rdd/json,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@8f6b4ab{/environment,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@770cae59{/environment/json,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@4bdb04c8{/executors,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@3ce7394f{/executors/json,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@74cd798f{/executors/threadDump,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@63c99f7{/executors/threadDump/json,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@601f264d{/static,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@35e07e19{/,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@2036f83{/api,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@48fc0211{/jobs/job/kill,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@7d088813{/stages/stage/kill,null,AVAILABLE,@Spark}
24/01/12 13:40:17 INFO SparkUI: Bound SparkUI to 0.0.0.0, and started at http://stat1007.eqiad.wmnet:4046
24/01/12 13:40:17 INFO SparkContext: Added JAR hdfs:///wmf/cache/artifacts/airflow/analytics/refinery-job-0.2.24-shaded.jar at hdfs:///wmf/cache/artifacts/airflow/analytics/refinery-job-0.2.24-shaded.jar with timestamp 1705066815671
24/01/12 13:40:17 INFO HadoopDelegationTokenManager: Attempting to load user's ticket cache.
24/01/12 13:40:17 INFO HiveConf: Found configuration file file:/etc/spark3/conf/hive-site.xml
24/01/12 13:40:17 INFO HadoopFSDelegationTokenProvider: getting token for: DFS[DFSClient[clientName=DFSClient_NONMAPREDUCE_-1980631662_1, ugi=jebe@WIKIMEDIA (auth:KERBEROS)]] with renewer yarn/an-master1001.eqiad.wmnet@WIKIMEDIA
24/01/12 13:40:18 INFO DFSClient: Created token for jebe: HDFS_DELEGATION_TOKEN owner=jebe@WIKIMEDIA, renewer=yarn, realUser=, issueDate=1705066817837, maxDate=1705671617837, sequenceNumber=22392873, masterKeyId=1767 on ha-hdfs:analytics-hadoop
24/01/12 13:40:18 INFO HadoopFSDelegationTokenProvider: getting token for: DFS[DFSClient[clientName=DFSClient_NONMAPREDUCE_-1980631662_1, ugi=jebe@WIKIMEDIA (auth:KERBEROS)]] with renewer jebe@WIKIMEDIA
24/01/12 13:40:18 INFO DFSClient: Created token for jebe: HDFS_DELEGATION_TOKEN owner=jebe@WIKIMEDIA, renewer=jebe, realUser=, issueDate=1705066818033, maxDate=1705671618033, sequenceNumber=22392874, masterKeyId=1767 on ha-hdfs:analytics-hadoop
24/01/12 13:40:18 INFO HadoopFSDelegationTokenProvider: Renewal interval is 86400283 for token HDFS_DELEGATION_TOKEN
24/01/12 13:40:19 INFO SparkHadoopUtil: Updating delegation tokens for current user.
24/01/12 13:40:19 INFO Utils: Using initial executors = 0, max of spark.dynamicAllocation.initialExecutors, spark.dynamicAllocation.minExecutors and spark.executor.instances
24/01/12 13:40:19 INFO Client: Requesting a new application from cluster with 86 NodeManagers
24/01/12 13:40:20 INFO Configuration: resource-types.xml not found
24/01/12 13:40:20 INFO ResourceUtils: Unable to find 'resource-types.xml'.
24/01/12 13:40:20 INFO Client: Verifying our application has not requested more than the maximum memory capability of the cluster (49152 MB per container)
24/01/12 13:40:20 INFO Client: Will allocate AM container, with 896 MB memory including 384 MB overhead
24/01/12 13:40:20 INFO Client: Setting up container launch context for our AM
24/01/12 13:40:20 INFO Client: Setting up the launch environment for our AM container
24/01/12 13:40:20 INFO Client: Preparing resources for our AM container
24/01/12 13:40:20 INFO Client: Source and destination file systems are the same. Not copying hdfs:/user/spark/share/lib/spark-3.1.2-assembly.jar
24/01/12 13:40:20 INFO Client: Uploading resource file:/srv/spark-tmp/spark-3ed69458-8cf6-496f-b5dd-8cd5c38e33ab/__spark_conf__6845374601472918198.zip -> hdfs://analytics-hadoop/user/jebe/.sparkStaging/application_1704805203730_16243/__spark_conf__.zip
24/01/12 13:40:21 INFO SecurityManager: Changing view acls to: jebe
24/01/12 13:40:21 INFO SecurityManager: Changing modify acls to: jebe
24/01/12 13:40:21 INFO SecurityManager: Changing view acls groups to:
24/01/12 13:40:21 INFO SecurityManager: Changing modify acls groups to:
24/01/12 13:40:21 INFO SecurityManager: SecurityManager: authentication enabled; ui acls disabled; users with view permissions: Set(jebe); groups with view permissions: Set(); users with modify permissions: Set(jebe); groups with modify permissions: Set()
24/01/12 13:40:21 INFO Client: Submitting application application_1704805203730_16243 to ResourceManager
24/01/12 13:40:22 INFO YarnClientImpl: Submitted application application_1704805203730_16243
24/01/12 13:40:23 INFO Client: Application report for application_1704805203730_16243 (state: ACCEPTED)
24/01/12 13:40:28 INFO YarnClientSchedulerBackend: Application application_1704805203730_16243 has started running.
24/01/12 13:40:28 WARN Utils: Service 'org.apache.spark.network.netty.NettyBlockTransferService' could not bind on port 13000. Attempting port 13001.
24/01/12 13:40:28 WARN Utils: Service 'org.apache.spark.network.netty.NettyBlockTransferService' could not bind on port 13001. Attempting port 13002.
24/01/12 13:40:28 WARN Utils: Service 'org.apache.spark.network.netty.NettyBlockTransferService' could not bind on port 13002. Attempting port 13003.
24/01/12 13:40:28 WARN Utils: Service 'org.apache.spark.network.netty.NettyBlockTransferService' could not bind on port 13003. Attempting port 13004.
24/01/12 13:40:28 WARN Utils: Service 'org.apache.spark.network.netty.NettyBlockTransferService' could not bind on port 13004. Attempting port 13005.
24/01/12 13:40:28 WARN Utils: Service 'org.apache.spark.network.netty.NettyBlockTransferService' could not bind on port 13005. Attempting port 13006.
24/01/12 13:40:28 INFO Utils: Successfully started service 'org.apache.spark.network.netty.NettyBlockTransferService' on port 13006.
24/01/12 13:40:28 INFO NettyBlockTransferService: Server created on stat1007.eqiad.wmnet:13006
24/01/12 13:40:28 INFO BlockManager: Using org.apache.spark.storage.RandomBlockReplicationPolicy for block replication policy
24/01/12 13:40:28 INFO BlockManagerMaster: Registering BlockManager BlockManagerId(driver, stat1007.eqiad.wmnet, 13006, None)
24/01/12 13:40:28 INFO BlockManagerMasterEndpoint: Registering block manager stat1007.eqiad.wmnet:13006 with 8.4 GiB RAM, BlockManagerId(driver, stat1007.eqiad.wmnet, 13006, None)
24/01/12 13:40:28 INFO BlockManagerMaster: Registered BlockManager BlockManagerId(driver, stat1007.eqiad.wmnet, 13006, None)
24/01/12 13:40:28 INFO BlockManager: external shuffle service port = 7337
24/01/12 13:40:28 INFO BlockManager: Initialized BlockManager: BlockManagerId(driver, stat1007.eqiad.wmnet, 13006, None)
24/01/12 13:40:28 INFO ServerInfo: Adding filter to /metrics/json: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter
24/01/12 13:40:28 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@6a97517{/metrics/json,null,AVAILABLE,@Spark}
24/01/12 13:40:28 INFO SingleEventLogFileWriter: Logging events to hdfs:/var/log/spark/application_1704805203730_16243.lz4.inprogress
24/01/12 13:40:28 INFO Utils: Using initial executors = 0, max of spark.dynamicAllocation.initialExecutors, spark.dynamicAllocation.minExecutors and spark.executor.instances
24/01/12 13:40:28 WARN YarnSchedulerBackend$YarnSchedulerEndpoint: Attempted to request executors before the AM has registered!
24/01/12 13:40:28 INFO YarnClientSchedulerBackend: SchedulerBackend is ready for scheduling beginning after reached minRegisteredResourcesRatio: 0.8
24/01/12 13:40:29 INFO YarnSchedulerBackend$YarnSchedulerEndpoint: ApplicationMaster registered as NettyRpcEndpointRef(spark-client://YarnAM)
24/01/12 13:40:29 INFO ServerInfo: Adding filter to /SQL: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter
24/01/12 13:40:29 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@1117cc7c{/SQL,null,AVAILABLE,@Spark}
24/01/12 13:40:29 INFO ServerInfo: Adding filter to /SQL/json: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter
24/01/12 13:40:29 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@2b06f498{/SQL/json,null,AVAILABLE,@Spark}
24/01/12 13:40:29 INFO ServerInfo: Adding filter to /SQL/execution: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter
24/01/12 13:40:29 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@642d34f1{/SQL/execution,null,AVAILABLE,@Spark}
24/01/12 13:40:29 INFO ServerInfo: Adding filter to /SQL/execution/json: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter
24/01/12 13:40:29 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@6f740044{/SQL/execution/json,null,AVAILABLE,@Spark}
24/01/12 13:40:29 INFO ServerInfo: Adding filter to /static/sql: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter
24/01/12 13:40:29 INFO ContextHandler: Started o.s.j.s.ServletContextHandler@21948bd1{/static/sql,null,AVAILABLE,@Spark}
24/01/12 13:40:30 INFO MediawikiDumper: Mediawiki Dumper
24/01/12 13:40:30 INFO MediawikiDumper: Mediawiki Dumper: About to dump simplewiki at 2024-01-01
24/01/12 13:40:30 INFO MediawikiDumper: Mediawiki Dumper: from wmf_dumps.wikitext_raw_rc2 to /user/jebe/data/archive/content_dump_test/
24/01/12 13:40:30 INFO MediawikiDumper: Mediawiki Dumper: step 1/5: build base revisions dataframe
24/01/12 13:40:31 INFO HiveConf: Found configuration file file:/etc/spark3/conf/hive-site.xml
24/01/12 13:40:32 INFO SessionState: Created HDFS directory: /tmp/hive/jebe/10e9eac7-a84a-4a98-9ec0-c85a0f7c1af0
24/01/12 13:40:32 INFO SessionState: Created local directory: /tmp/jebe/10e9eac7-a84a-4a98-9ec0-c85a0f7c1af0
24/01/12 13:40:32 INFO SessionState: Created HDFS directory: /tmp/hive/jebe/10e9eac7-a84a-4a98-9ec0-c85a0f7c1af0/_tmp_space.db
24/01/12 13:40:32 INFO metastore: Trying to connect to metastore with URI thrift://analytics-hive.eqiad.wmnet:9083
24/01/12 13:40:32 INFO metastore: Opened a connection to metastore, current connections: 1
24/01/12 13:40:32 INFO metastore: Connected to metastore.
24/01/12 13:40:33 INFO Hive: Registering function english_stemmer org.wikimedia.analytics.refinery.hive.Stemmer
24/01/12 13:40:33 INFO metastore: Trying to connect to metastore with URI thrift://analytics-hive.eqiad.wmnet:9083
24/01/12 13:40:33 INFO metastore: Opened a connection to metastore, current connections: 1
24/01/12 13:40:33 INFO metastore: Connected to metastore.
24/01/12 13:40:33 INFO BaseMetastoreTableOperations: Refreshing table metadata from new version: /wmf/data/wmf_dumps/wikitext_raw_rc2/metadata/03975-38b5d4e9-aae0-415d-a805-baad369a73da.metadata.json
24/01/12 13:40:34 INFO BaseMetastoreCatalog: Table loaded by catalog: spark_catalog.wmf_dumps.wikitext_raw_rc2
24/01/12 13:40:36 INFO MemoryStore: Block broadcast_0 stored as values in memory (estimated size 32.0 KiB, free 8.4 GiB)
24/01/12 13:40:36 INFO MemoryStore: Block broadcast_0_piece0 stored as bytes in memory (estimated size 30.9 KiB, free 8.4 GiB)
24/01/12 13:40:36 INFO BlockManagerInfo: Added broadcast_0_piece0 in memory on stat1007.eqiad.wmnet:13006 (size: 30.9 KiB, free: 8.4 GiB)
24/01/12 13:40:36 INFO SparkContext: Created broadcast 0 from broadcast at SparkBatchScan.java:142
24/01/12 13:40:36 INFO SnapshotScan: Scanning table spark_catalog.wmf_dumps.wikitext_raw_rc2 snapshot 4861734485253907190 created at 2024-01-12T13:26:32.899+00:00 with filter (((revision_timestamp IS NOT NULL AND wiki_db IS NOT NULL) AND revision_timestamp < (16-digit-int)) AND wiki_db = (hash-10b04362))
24/01/12 13:40:39 INFO MemoryStore: Block broadcast_1 stored as values in memory (estimated size 32.0 KiB, free 8.4 GiB)
24/01/12 13:40:39 INFO MemoryStore: Block broadcast_1_piece0 stored as bytes in memory (estimated size 30.9 KiB, free 8.4 GiB)
24/01/12 13:40:39 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on stat1007.eqiad.wmnet:13006 (size: 30.9 KiB, free: 8.4 GiB)
24/01/12 13:40:39 INFO SparkContext: Created broadcast 1 from broadcast at SparkBatchScan.java:142
24/01/12 13:40:41 INFO SparkContext: Starting job: rdd at PagesPartitionsDefiner.scala:88
24/01/12 13:40:41 INFO DAGScheduler: Registering RDD 3 (rdd at PagesPartitionsDefiner.scala:88) as input to shuffle 0
24/01/12 13:40:41 INFO DAGScheduler: Got job 0 (rdd at PagesPartitionsDefiner.scala:88) with 200 output partitions
24/01/12 13:40:41 INFO DAGScheduler: Final stage: ResultStage 1 (rdd at PagesPartitionsDefiner.scala:88)
24/01/12 13:40:41 INFO DAGScheduler: Parents of final stage: List(ShuffleMapStage 0)
24/01/12 13:40:41 INFO DAGScheduler: Missing parents: List(ShuffleMapStage 0)
24/01/12 13:40:41 INFO DAGScheduler: Submitting ShuffleMapStage 0 (MapPartitionsRDD[3] at rdd at PagesPartitionsDefiner.scala:88), which has no missing parents
24/01/12 13:40:41 INFO MemoryStore: Block broadcast_2 stored as values in memory (estimated size 30.1 KiB, free 8.4 GiB)
24/01/12 13:40:41 INFO MemoryStore: Block broadcast_2_piece0 stored as bytes in memory (estimated size 13.4 KiB, free 8.4 GiB)
24/01/12 13:40:41 INFO BlockManagerInfo: Added broadcast_2_piece0 in memory on stat1007.eqiad.wmnet:13006 (size: 13.4 KiB, free: 8.4 GiB)
24/01/12 13:40:41 INFO SparkContext: Created broadcast 2 from broadcast at DAGScheduler.scala:1388
24/01/12 13:40:41 INFO DAGScheduler: Submitting 148 missing tasks from ShuffleMapStage 0 (MapPartitionsRDD[3] at rdd at PagesPartitionsDefiner.scala:88) (first 15 tasks are for partitions Vector(0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14))
24/01/12 13:40:41 INFO YarnScheduler: Adding task set 0.0 with 148 tasks resource profile 0
24/01/12 13:40:41 INFO ExecutorAllocationManager: Requesting 1 new executor because tasks are backlogged (new desired total will be 1 for resource profile id: 0)
24/01/12 13:40:46 INFO ExecutorAllocationManager: Requesting 2 new executors because tasks are backlogged (new desired total will be 3 for resource profile id: 0)
24/01/12 13:40:46 INFO ExecutorAllocationManager: Requesting 4 new executors because tasks are backlogged (new desired total will be 7 for resource profile id: 0)
24/01/12 13:40:47 INFO ExecutorAllocationManager: Requesting 8 new executors because tasks are backlogged (new desired total will be 15 for resource profile id: 0)
24/01/12 13:40:48 INFO ExecutorAllocationManager: Requesting 1 new executor because tasks are backlogged (new desired total will be 16 for resource profile id: 0)
24/01/12 13:40:51 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.5.40:41718) with ID 5, ResourceProfileId 0
24/01/12 13:40:51 INFO ExecutorMonitor: New executor 5 has registered (new total is 2)
24/01/12 13:40:51 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1102.eqiad.wmnet:33061 with 2004.6 MiB RAM, BlockManagerId(5, an-worker1102.eqiad.wmnet, 33061, None)
24/01/12 13:40:51 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.53.46:49450) with ID 9, ResourceProfileId 0
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 9 has registered (new total is 3)
24/01/12 13:40:52 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.53.46:49458) with ID 10, ResourceProfileId 0
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 10 has registered (new total is 4)
24/01/12 13:40:52 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1116.eqiad.wmnet:42965 with 2004.6 MiB RAM, BlockManagerId(9, an-worker1116.eqiad.wmnet, 42965, None)
24/01/12 13:40:52 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.21.13:37168) with ID 15, ResourceProfileId 0
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 15 has registered (new total is 5)
24/01/12 13:40:52 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1116.eqiad.wmnet:38999 with 2004.6 MiB RAM, BlockManagerId(10, an-worker1116.eqiad.wmnet, 38999, None)
24/01/12 13:40:52 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.21.119:43390) with ID 2, ResourceProfileId 0
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 2 has registered (new total is 6)
24/01/12 13:40:52 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1128.eqiad.wmnet:35005 with 2004.6 MiB RAM, BlockManagerId(15, an-worker1128.eqiad.wmnet, 35005, None)
24/01/12 13:40:52 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.21.119:43406) with ID 3, ResourceProfileId 0
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 3 has registered (new total is 7)
24/01/12 13:40:52 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.5.8:53522) with ID 14, ResourceProfileId 0
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 14 has registered (new total is 8)
24/01/12 13:40:52 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1083.eqiad.wmnet:45911 with 2004.6 MiB RAM, BlockManagerId(2, an-worker1083.eqiad.wmnet, 45911, None)
24/01/12 13:40:52 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.5.8:53536) with ID 13, ResourceProfileId 0
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 13 has registered (new total is 9)
24/01/12 13:40:52 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.5.8:53552) with ID 11, ResourceProfileId 0
24/01/12 13:40:52 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.5.8:53562) with ID 12, ResourceProfileId 0
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 11 has registered (new total is 10)
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 12 has registered (new total is 11)
24/01/12 13:40:52 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.53.37:49346) with ID 7, ResourceProfileId 0
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 7 has registered (new total is 12)
24/01/12 13:40:52 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1083.eqiad.wmnet:40809 with 2004.6 MiB RAM, BlockManagerId(3, an-worker1083.eqiad.wmnet, 40809, None)
24/01/12 13:40:52 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1119.eqiad.wmnet:34183 with 2004.6 MiB RAM, BlockManagerId(13, an-worker1119.eqiad.wmnet, 34183, None)
24/01/12 13:40:52 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.53.37:49352) with ID 6, ResourceProfileId 0
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 6 has registered (new total is 13)
24/01/12 13:40:52 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1119.eqiad.wmnet:45881 with 2004.6 MiB RAM, BlockManagerId(12, an-worker1119.eqiad.wmnet, 45881, None)
24/01/12 13:40:52 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1119.eqiad.wmnet:38383 with 2004.6 MiB RAM, BlockManagerId(11, an-worker1119.eqiad.wmnet, 38383, None)
24/01/12 13:40:52 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1095.eqiad.wmnet:38457 with 2004.6 MiB RAM, BlockManagerId(7, an-worker1095.eqiad.wmnet, 38457, None)
24/01/12 13:40:52 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1095.eqiad.wmnet:45475 with 2004.6 MiB RAM, BlockManagerId(6, an-worker1095.eqiad.wmnet, 45475, None)
24/01/12 13:40:52 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.138.9:50050) with ID 8, ResourceProfileId 0
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 8 has registered (new total is 14)
24/01/12 13:40:52 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1153.eqiad.wmnet:46731 with 2004.6 MiB RAM, BlockManagerId(8, an-worker1153.eqiad.wmnet, 46731, None)
24/01/12 13:40:52 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.139.2:37658) with ID 16, ResourceProfileId 0
24/01/12 13:40:52 INFO ExecutorMonitor: New executor 16 has registered (new total is 15)
24/01/12 13:40:52 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1143.eqiad.wmnet:42097 with 2004.6 MiB RAM, BlockManagerId(16, an-worker1143.eqiad.wmnet, 42097, None)
24/01/12 13:40:53 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.5.28:37500) with ID 1, ResourceProfileId 0
24/01/12 13:40:53 INFO ExecutorMonitor: New executor 1 has registered (new total is 16)
24/01/12 13:40:53 INFO BlockManagerInfo: Added broadcast_2_piece0 in memory on an-worker1102.eqiad.wmnet:33061 (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:40:53 INFO BlockManagerMasterEndpoint: Registering block manager an-worker1079.eqiad.wmnet:44645 with 2004.6 MiB RAM, BlockManagerId(1, an-worker1079.eqiad.wmnet, 44645, None)
24/01/12 13:40:55 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1116.eqiad.wmnet:42965 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:40:55 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1119.eqiad.wmnet:45881 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:40:55 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1119.eqiad.wmnet:37683 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:40:55 INFO BlockManagerInfo: Added broadcast_2_piece0 in memory on an-worker1095.eqiad.wmnet:45475 (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:40:55 INFO BlockManagerInfo: Added broadcast_2_piece0 in memory on an-worker1095.eqiad.wmnet:38457 (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:40:55 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1128.eqiad.wmnet:35005 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:40:55 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1119.eqiad.wmnet:34183 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:40:55 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1119.eqiad.wmnet:38383 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:40:55 INFO BlockManagerInfo: Added broadcast_2_piece0 in memory on an-worker1083.eqiad.wmnet:40809 (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:40:55 INFO BlockManagerInfo: Added broadcast_2_piece0 in memory on an-worker1083.eqiad.wmnet:45911 (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:40:55 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1143.eqiad.wmnet:42097 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:40:55 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1153.eqiad.wmnet:46731 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:40:56 INFO BlockManagerInfo: Added broadcast_2_piece0 in memory on an-worker1079.eqiad.wmnet:44645 (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:40:56 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1095.eqiad.wmnet:45475 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:40:56 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1095.eqiad.wmnet:38457 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:40:56 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1083.eqiad.wmnet:45911 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:40:56 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1083.eqiad.wmnet:40809 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:40:57 INFO YarnSchedulerBackend$YarnDriverEndpoint: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.64.21.121:56590) with ID 4, ResourceProfileId 0
24/01/12 13:40:57 INFO ExecutorMonitor: New executor 4 has registered (new total is 17)
24/01/12 13:40:57 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on an-worker1079.eqiad.wmnet:44645 (size: 30.9 KiB, free: 2004.6 MiB)
24/01/12 13:41:14 INFO TaskSetManager: Finished task 60.0 in stage 0.0 (TID 130) in 3388 ms on an-worker1119.eqiad.wmnet (executor 11) (130/148)
24/01/12 13:41:14 INFO TaskSetManager: Finished task 91.0 in stage 0.0 (TID 125) in 4173 ms on an-worker1095.eqiad.wmnet (executor 7) (131/148)
24/01/12 13:41:14 INFO TaskSetManager: Finished task 69.0 in stage 0.0 (TID 121) in 4555 ms on an-worker1095.eqiad.wmnet (executor 7) (132/148)
24/01/12 13:41:14 INFO TaskSetManager: Finished task 81.0 in stage 0.0 (TID 133) in 3617 ms on an-worker1116.eqiad.wmnet (executor 9) (133/148)
24/01/12 13:41:14 INFO TaskSetManager: Finished task 97.0 in stage 0.0 (TID 131) in 3753 ms on an-worker1095.eqiad.wmnet (executor 6) (134/148)
24/01/12 13:41:14 INFO TaskSetManager: Finished task 65.0 in stage 0.0 (TID 134) in 3153 ms on an-worker1102.eqiad.wmnet (executor 5) (135/148)
24/01/12 13:41:15 INFO TaskSetManager: Finished task 86.0 in stage 0.0 (TID 135) in 3114 ms on an-worker1116.eqiad.wmnet (executor 9) (136/148)
24/01/12 13:41:15 INFO TaskSetManager: Finished task 83.0 in stage 0.0 (TID 136) in 3423 ms on an-worker1102.eqiad.wmnet (executor 5) (137/148)
24/01/12 13:41:16 INFO TaskSetManager: Finished task 100.0 in stage 0.0 (TID 137) in 3836 ms on an-worker1095.eqiad.wmnet (executor 6) (138/148)
24/01/12 13:41:16 INFO TaskSetManager: Finished task 55.0 in stage 0.0 (TID 140) in 3223 ms on an-worker1128.eqiad.wmnet (executor 15) (139/148)
24/01/12 13:41:17 INFO TaskSetManager: Finished task 98.0 in stage 0.0 (TID 143) in 3355 ms on an-worker1153.eqiad.wmnet (executor 8) (140/148)
24/01/12 13:41:17 INFO TaskSetManager: Finished task 82.0 in stage 0.0 (TID 142) in 3443 ms on an-worker1119.eqiad.wmnet (executor 14) (141/148)
24/01/12 13:41:17 INFO TaskSetManager: Finished task 105.0 in stage 0.0 (TID 145) in 3085 ms on an-worker1119.eqiad.wmnet (executor 14) (142/148)
24/01/12 13:41:17 INFO TaskSetManager: Finished task 104.0 in stage 0.0 (TID 144) in 3478 ms on an-worker1153.eqiad.wmnet (executor 8) (143/148)
24/01/12 13:41:17 INFO TaskSetManager: Finished task 56.0 in stage 0.0 (TID 141) in 3580 ms on an-worker1128.eqiad.wmnet (executor 15) (144/148)
24/01/12 13:41:17 INFO TaskSetManager: Finished task 110.0 in stage 0.0 (TID 146) in 3111 ms on an-worker1119.eqiad.wmnet (executor 11) (145/148)
24/01/12 13:41:17 INFO TaskSetManager: Finished task 111.0 in stage 0.0 (TID 147) in 3179 ms on an-worker1119.eqiad.wmnet (executor 11) (146/148)
24/01/12 13:41:18 INFO TaskSetManager: Finished task 67.0 in stage 0.0 (TID 138) in 5141 ms on an-worker1085.eqiad.wmnet (executor 4) (147/148)
24/01/12 13:41:18 INFO TaskSetManager: Finished task 52.0 in stage 0.0 (TID 139) in 5117 ms on an-worker1085.eqiad.wmnet (executor 4) (148/148)
24/01/12 13:41:18 INFO YarnScheduler: Removed TaskSet 0.0, whose tasks have all completed, from pool
24/01/12 13:41:18 INFO DAGScheduler: ShuffleMapStage 0 (rdd at PagesPartitionsDefiner.scala:88) finished in 37.362 s
24/01/12 13:41:18 INFO DAGScheduler: looking for newly runnable stages
24/01/12 13:41:18 INFO DAGScheduler: running: Set()
24/01/12 13:41:18 INFO DAGScheduler: waiting: Set(ResultStage 1)
24/01/12 13:41:18 INFO DAGScheduler: failed: Set()
24/01/12 13:41:18 INFO DAGScheduler: Submitting ResultStage 1 (MapPartitionsRDD[8] at rdd at PagesPartitionsDefiner.scala:88), which has no missing parents
24/01/12 13:41:18 INFO MemoryStore: Block broadcast_3 stored as values in memory (estimated size 31.4 KiB, free 8.4 GiB)
24/01/12 13:41:18 INFO MemoryStore: Block broadcast_3_piece0 stored as bytes in memory (estimated size 15.1 KiB, free 8.4 GiB)
24/01/12 13:41:18 INFO BlockManagerInfo: Added broadcast_3_piece0 in memory on stat1007.eqiad.wmnet:13006 (size: 15.1 KiB, free: 8.4 GiB)
24/01/12 13:41:18 INFO SparkContext: Created broadcast 3 from broadcast at DAGScheduler.scala:1388
24/01/12 13:41:18 INFO DAGScheduler: Submitting 200 missing tasks from ResultStage 1 (MapPartitionsRDD[8] at rdd at PagesPartitionsDefiner.scala:88) (first 15 tasks are for partitions Vector(0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14))
24/01/12 13:41:18 INFO YarnScheduler: Adding task set 1.0 with 200 tasks resource profile 0
24/01/12 13:41:19 INFO ExecutorAllocationManager: Requesting 16 new executors because tasks are backlogged (new desired total will be 16 for resource profile id: 0)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 149.0 in stage 1.0 (TID 297) in 105 ms on an-worker1095.eqiad.wmnet (executor 7) (144/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 99.0 in stage 1.0 (TID 247) in 212 ms on an-worker1083.eqiad.wmnet (executor 2) (167/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 172.0 in stage 1.0 (TID 320) in 40 ms on an-worker1119.eqiad.wmnet (executor 12) (168/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 158.0 in stage 1.0 (TID 306) in 128 ms on an-worker1153.eqiad.wmnet (executor 8) (169/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 157.0 in stage 1.0 (TID 305) in 128 ms on an-worker1153.eqiad.wmnet (executor 8) (170/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 175.0 in stage 1.0 (TID 323) in 35 ms on an-worker1095.eqiad.wmnet (executor 7) (171/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 178.0 in stage 1.0 (TID 326) in 33 ms on an-worker1083.eqiad.wmnet (executor 3) (172/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 171.0 in stage 1.0 (TID 319) in 57 ms on an-worker1143.eqiad.wmnet (executor 16) (173/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 173.0 in stage 1.0 (TID 321) in 51 ms on an-worker1128.eqiad.wmnet (executor 15) (174/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 179.0 in stage 1.0 (TID 327) in 38 ms on an-worker1119.eqiad.wmnet (executor 11) (175/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 174.0 in stage 1.0 (TID 322) in 46 ms on an-worker1119.eqiad.wmnet (executor 12) (176/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 177.0 in stage 1.0 (TID 325) in 44 ms on an-worker1143.eqiad.wmnet (executor 16) (177/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 176.0 in stage 1.0 (TID 324) in 46 ms on an-worker1116.eqiad.wmnet (executor 10) (178/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 185.0 in stage 1.0 (TID 333) in 37 ms on an-worker1102.eqiad.wmnet (executor 5) (179/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 180.0 in stage 1.0 (TID 328) in 42 ms on an-worker1119.eqiad.wmnet (executor 13) (180/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 190.0 in stage 1.0 (TID 338) in 35 ms on an-worker1102.eqiad.wmnet (executor 5) (181/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 182.0 in stage 1.0 (TID 330) in 41 ms on an-worker1128.eqiad.wmnet (executor 15) (182/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 184.0 in stage 1.0 (TID 332) in 40 ms on an-worker1116.eqiad.wmnet (executor 10) (183/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 188.0 in stage 1.0 (TID 336) in 38 ms on an-worker1119.eqiad.wmnet (executor 11) (184/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 181.0 in stage 1.0 (TID 329) in 46 ms on an-worker1083.eqiad.wmnet (executor 3) (185/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 189.0 in stage 1.0 (TID 337) in 39 ms on an-worker1119.eqiad.wmnet (executor 13) (186/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 186.0 in stage 1.0 (TID 334) in 43 ms on an-worker1119.eqiad.wmnet (executor 14) (187/200)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1119.eqiad.wmnet:37683 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 199.0 in stage 1.0 (TID 347) in 35 ms on an-worker1119.eqiad.wmnet (executor 12) (188/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 191.0 in stage 1.0 (TID 339) in 44 ms on an-worker1119.eqiad.wmnet (executor 14) (189/200)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1095.eqiad.wmnet:38457 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1095.eqiad.wmnet:45475 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1119.eqiad.wmnet:38383 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on stat1007.eqiad.wmnet:13006 in memory (size: 13.4 KiB, free: 8.4 GiB)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 183.0 in stage 1.0 (TID 331) in 52 ms on an-worker1095.eqiad.wmnet (executor 7) (190/200)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1119.eqiad.wmnet:34183 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1128.eqiad.wmnet:35005 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 193.0 in stage 1.0 (TID 341) in 45 ms on an-worker1116.eqiad.wmnet (executor 9) (191/200)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1083.eqiad.wmnet:40809 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 196.0 in stage 1.0 (TID 344) in 43 ms on an-worker1116.eqiad.wmnet (executor 9) (192/200)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1102.eqiad.wmnet:33061 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1116.eqiad.wmnet:38999 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1119.eqiad.wmnet:45881 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1083.eqiad.wmnet:45911 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1143.eqiad.wmnet:42097 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1153.eqiad.wmnet:46731 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 192.0 in stage 1.0 (TID 340) in 53 ms on an-worker1095.eqiad.wmnet (executor 6) (193/200)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1116.eqiad.wmnet:42965 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 187.0 in stage 1.0 (TID 335) in 60 ms on an-worker1095.eqiad.wmnet (executor 6) (194/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 198.0 in stage 1.0 (TID 346) in 60 ms on an-worker1083.eqiad.wmnet (executor 2) (195/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 195.0 in stage 1.0 (TID 343) in 65 ms on an-worker1083.eqiad.wmnet (executor 2) (196/200)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1079.eqiad.wmnet:44645 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 197.0 in stage 1.0 (TID 345) in 88 ms on an-worker1079.eqiad.wmnet (executor 1) (197/200)
24/01/12 13:41:19 INFO TaskSetManager: Finished task 194.0 in stage 1.0 (TID 342) in 97 ms on an-worker1079.eqiad.wmnet (executor 1) (198/200)
24/01/12 13:41:19 INFO BlockManagerInfo: Removed broadcast_2_piece0 on an-worker1085.eqiad.wmnet:43491 in memory (size: 13.4 KiB, free: 2004.6 MiB)
24/01/12 13:41:20 INFO TaskSetManager: Finished task 19.0 in stage 1.0 (TID 167) in 1862 ms on an-worker1085.eqiad.wmnet (executor 4) (199/200)
24/01/12 13:41:20 INFO TaskSetManager: Finished task 3.0 in stage 1.0 (TID 151) in 1870 ms on an-worker1085.eqiad.wmnet (executor 4) (200/200)
24/01/12 13:41:20 INFO YarnScheduler: Removed TaskSet 1.0, whose tasks have all completed, from pool
24/01/12 13:41:20 INFO DAGScheduler: ResultStage 1 (rdd at PagesPartitionsDefiner.scala:88) finished in 1.901 s
24/01/12 13:41:20 INFO DAGScheduler: Job 0 is finished. Cancelling potential speculative or zombie tasks for this job
24/01/12 13:41:20 INFO YarnScheduler: Killing all running tasks in stage 1: Stage finished
24/01/12 13:41:20 INFO DAGScheduler: Job 0 finished: rdd at PagesPartitionsDefiner.scala:88, took 39.418946 s
24/01/12 13:41:20 INFO MemoryStore: Block broadcast_4 stored as values in memory (estimated size 32.0 KiB, free 8.4 GiB)
24/01/12 13:41:20 INFO MemoryStore: Block broadcast_4_piece0 stored as bytes in memory (estimated size 30.9 KiB, free 8.4 GiB)
24/01/12 13:41:20 INFO BlockManagerInfo: Added broadcast_4_piece0 in memory on stat1007.eqiad.wmnet:13006 (size: 30.9 KiB, free: 8.4 GiB)
24/01/12 13:41:20 INFO SparkContext: Created broadcast 4 from broadcast at SparkBatchScan.java:142
24/01/12 13:41:20 INFO SnapshotScan: Scanning table spark_catalog.wmf_dumps.wikitext_raw_rc2 snapshot 4861734485253907190 created at 2024-01-12T13:26:32.899+00:00 with filter (((revision_timestamp IS NOT NULL AND wiki_db IS NOT NULL) AND revision_timestamp < (16-digit-int)) AND wiki_db = (hash-10b04362))
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on stat1007.eqiad.wmnet:13006 in memory (size: 15.1 KiB, free: 8.4 GiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1128.eqiad.wmnet:35005 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1116.eqiad.wmnet:38999 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1119.eqiad.wmnet:45881 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1083.eqiad.wmnet:40809 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1102.eqiad.wmnet:33061 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1083.eqiad.wmnet:45911 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1119.eqiad.wmnet:37683 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1116.eqiad.wmnet:42965 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1143.eqiad.wmnet:42097 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1119.eqiad.wmnet:38383 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1085.eqiad.wmnet:43491 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1153.eqiad.wmnet:46731 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1095.eqiad.wmnet:45475 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1095.eqiad.wmnet:38457 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1119.eqiad.wmnet:34183 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:21 INFO BlockManagerInfo: Removed broadcast_3_piece0 on an-worker1079.eqiad.wmnet:44645 in memory (size: 15.1 KiB, free: 2004.6 MiB)
24/01/12 13:41:23 INFO MemoryStore: Block broadcast_5 stored as values in memory (estimated size 32.0 KiB, free 8.4 GiB)
24/01/12 13:41:23 INFO MemoryStore: Block broadcast_5_piece0 stored as bytes in memory (estimated size 30.9 KiB, free 8.4 GiB)
24/01/12 13:41:23 INFO BlockManagerInfo: Added broadcast_5_piece0 in memory on stat1007.eqiad.wmnet:13006 (size: 30.9 KiB, free: 8.4 GiB)
24/01/12 13:41:23 INFO SparkContext: Created broadcast 5 from broadcast at SparkBatchScan.java:142
24/01/12 13:41:24 INFO SparkContext: Starting job: count at PagesPartitionsDefiner.scala:101
24/01/12 13:41:24 INFO DAGScheduler: Registering RDD 18 (count at PagesPartitionsDefiner.scala:101) as input to shuffle 2
24/01/12 13:41:24 INFO DAGScheduler: Got job 1 (count at PagesPartitionsDefiner.scala:101) with 1 output partitions
24/01/12 13:41:24 INFO DAGScheduler: Final stage: ResultStage 3 (count at PagesPartitionsDefiner.scala:101)
24/01/12 13:41:24 INFO DAGScheduler: Parents of final stage: List(ShuffleMapStage 2)
24/01/12 13:41:24 INFO DAGScheduler: Missing parents: List(ShuffleMapStage 2)
24/01/12 13:41:24 INFO DAGScheduler: Submitting ShuffleMapStage 2 (MapPartitionsRDD[18] at count at PagesPartitionsDefiner.scala:101), which has no missing parents
24/01/12 13:41:24 INFO MemoryStore: Block broadcast_6 stored as values in memory (estimated size 14.5 KiB, free 8.4 GiB)
24/01/12 13:41:24 INFO MemoryStore: Block broadcast_6_piece0 stored as bytes in memory (estimated size 6.5 KiB, free 8.4 GiB)
24/01/12 13:41:24 INFO BlockManagerInfo: Added broadcast_6_piece0 in memory on stat1007.eqiad.wmnet:13006 (size: 6.5 KiB, free: 8.4 GiB)
24/01/12 13:41:24 INFO SparkContext: Created broadcast 6 from broadcast at DAGScheduler.scala:1388
24/01/12 13:41:24 INFO DAGScheduler: Submitting 149 missing tasks from ShuffleMapStage 2 (MapPartitionsRDD[18] at count at PagesPartitionsDefiner.scala:101) (first 15 tasks are for partitions Vector(0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14))
24/01/12 13:41:24 INFO YarnScheduler: Adding task set 2.0 with 149 tasks resource profile 0
24/01/12 13:41:25 INFO TaskSetManager: Finished task 12.0 in stage 2.0 (TID 355) in 928 ms on an-worker1119.eqiad.wmnet (executor 14) (22/149)
24/01/12 13:41:25 INFO ExecutorAllocationManager: Requesting 16 new executors because tasks are backlogged (new desired total will be 16 for resource profile id: 0)
24/01/12 13:41:33 INFO TaskSetManager: Finished task 100.0 in stage 2.0 (TID 494) in 84 ms on an-worker1102.eqiad.wmnet (executor 5) (143/149)
24/01/12 13:41:33 INFO TaskSetManager: Finished task 107.0 in stage 2.0 (TID 495) in 91 ms on an-worker1083.eqiad.wmnet (executor 2) (144/149)
24/01/12 13:41:33 INFO TaskSetManager: Finished task 57.0 in stage 2.0 (TID 491) in 168 ms on an-worker1116.eqiad.wmnet (executor 10) (145/149)
24/01/12 13:41:33 INFO TaskSetManager: Finished task 97.0 in stage 2.0 (TID 493) in 167 ms on an-worker1095.eqiad.wmnet (executor 7) (146/149)
24/01/12 13:41:33 INFO TaskSetManager: Finished task 139.0 in stage 2.0 (TID 496) in 289 ms on an-worker1143.eqiad.wmnet (executor 16) (147/149)
24/01/12 13:41:33 INFO TaskSetManager: Finished task 58.0 in stage 2.0 (TID 492) in 413 ms on an-worker1085.eqiad.wmnet (executor 4) (148/149)
24/01/12 13:41:33 INFO TaskSetManager: Finished task 51.0 in stage 2.0 (TID 490) in 442 ms on an-worker1083.eqiad.wmnet (executor 3) (149/149)
24/01/12 13:41:33 INFO YarnScheduler: Removed TaskSet 2.0, whose tasks have all completed, from pool
24/01/12 13:41:33 INFO DAGScheduler: ShuffleMapStage 2 (count at PagesPartitionsDefiner.scala:101) finished in 8.908 s
24/01/12 13:41:33 INFO DAGScheduler: looking for newly runnable stages
24/01/12 13:41:33 INFO DAGScheduler: running: Set()
24/01/12 13:41:33 INFO DAGScheduler: waiting: Set(ResultStage 3)
24/01/12 13:41:33 INFO DAGScheduler: failed: Set()
24/01/12 13:41:33 INFO DAGScheduler: Submitting ResultStage 3 (MapPartitionsRDD[21] at count at PagesPartitionsDefiner.scala:101), which has no missing parents
24/01/12 13:41:33 INFO MemoryStore: Block broadcast_7 stored as values in memory (estimated size 10.1 KiB, free 8.4 GiB)
24/01/12 13:41:33 INFO MemoryStore: Block broadcast_7_piece0 stored as bytes in memory (estimated size 5.0 KiB, free 8.4 GiB)
24/01/12 13:41:33 INFO BlockManagerInfo: Added broadcast_7_piece0 in memory on stat1007.eqiad.wmnet:13006 (size: 5.0 KiB, free: 8.4 GiB)
24/01/12 13:41:33 INFO SparkContext: Created broadcast 7 from broadcast at DAGScheduler.scala:1388
24/01/12 13:41:33 INFO DAGScheduler: Submitting 1 missing tasks from ResultStage 3 (MapPartitionsRDD[21] at count at PagesPartitionsDefiner.scala:101) (first 15 tasks are for partitions Vector(0))
24/01/12 13:41:33 INFO YarnScheduler: Adding task set 3.0 with 1 tasks resource profile 0
24/01/12 13:41:33 INFO BlockManagerInfo: Added broadcast_7_piece0 in memory on an-worker1119.eqiad.wmnet:38383 (size: 5.0 KiB, free: 2004.5 MiB)
24/01/12 13:41:33 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 2 to 10.64.5.8:53552
24/01/12 13:41:33 INFO TaskSetManager: Finished task 0.0 in stage 3.0 (TID 497) in 74 ms on an-worker1119.eqiad.wmnet (executor 11) (1/1)
24/01/12 13:41:33 INFO YarnScheduler: Removed TaskSet 3.0, whose tasks have all completed, from pool
24/01/12 13:41:33 INFO DAGScheduler: ResultStage 3 (count at PagesPartitionsDefiner.scala:101) finished in 0.093 s
24/01/12 13:41:33 INFO DAGScheduler: Job 1 is finished. Cancelling potential speculative or zombie tasks for this job
24/01/12 13:41:33 INFO YarnScheduler: Killing all running tasks in stage 3: Stage finished
24/01/12 13:41:33 INFO DAGScheduler: Job 1 finished: count at PagesPartitionsDefiner.scala:101, took 9.019340 s
24/01/12 13:41:33 WARN package: Truncated the string representation of a plan since it was too large. This behavior can be adjusted by setting 'spark.sql.debug.maxToStringFields'.
24/01/12 13:41:33 INFO AbstractConnector: Stopped Spark@4b4d124{HTTP/1.1, (http/1.1)}{0.0.0.0:4046}
24/01/12 13:41:33 INFO SparkUI: Stopped Spark web UI at http://stat1007.eqiad.wmnet:4046
24/01/12 13:41:33 INFO YarnClientSchedulerBackend: Interrupting monitor thread
24/01/12 13:41:33 INFO YarnClientSchedulerBackend: Shutting down all executors
24/01/12 13:41:33 INFO YarnSchedulerBackend$YarnDriverEndpoint: Asking each executor to shut down
24/01/12 13:41:33 INFO YarnClientSchedulerBackend: YARN client scheduler backend Stopped
24/01/12 13:41:34 INFO MapOutputTrackerMasterEndpoint: MapOutputTrackerMasterEndpoint stopped!
24/01/12 13:41:34 INFO MemoryStore: MemoryStore cleared
24/01/12 13:41:34 INFO BlockManager: BlockManager stopped
24/01/12 13:41:34 INFO BlockManagerMaster: BlockManagerMaster stopped
24/01/12 13:41:34 INFO OutputCommitCoordinator$OutputCommitCoordinatorEndpoint: OutputCommitCoordinator stopped!
24/01/12 13:41:34 INFO SparkContext: Successfully stopped SparkContext
Exception in thread "main" org.apache.spark.SparkException: Task not serializable
at org.apache.spark.util.ClosureCleaner$.ensureSerializable(ClosureCleaner.scala:416)
at org.apache.spark.util.ClosureCleaner$.clean(ClosureCleaner.scala:406)
at org.apache.spark.util.ClosureCleaner$.clean(ClosureCleaner.scala:162)
at org.apache.spark.SparkContext.clean(SparkContext.scala:2459)
at org.apache.spark.rdd.RDD.$anonfun$mapPartitions$1(RDD.scala:860)
at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:151)
at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:112)
at org.apache.spark.rdd.RDD.withScope(RDD.scala:414)
at org.apache.spark.rdd.RDD.mapPartitions(RDD.scala:859)
at org.wikimedia.analytics.refinery.job.mediawikidumper.PagesPartitionsDefiner.definePartitions(PagesPartitionsDefiner.scala:52)
at org.wikimedia.analytics.refinery.job.mediawikidumper.PagesPartitionsDefiner.<init>(PagesPartitionsDefiner.scala:43)
at org.wikimedia.analytics.refinery.job.mediawikidumper.MediawikiDumper$.apply(MediawikiDumper.scala:54)
at org.wikimedia.analytics.refinery.job.mediawikidumper.MediawikiDumper$.main(MediawikiDumper.scala:357)
at org.wikimedia.analytics.refinery.job.mediawikidumper.MediawikiDumper.main(MediawikiDumper.scala)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.apache.spark.deploy.JavaMainApplication.start(SparkApplication.scala:52)
at org.apache.spark.deploy.SparkSubmit.org$apache$spark$deploy$SparkSubmit$$runMain(SparkSubmit.scala:951)
at org.apache.spark.deploy.SparkSubmit.doRunMain$1(SparkSubmit.scala:180)
at org.apache.spark.deploy.SparkSubmit.submit(SparkSubmit.scala:203)
at org.apache.spark.deploy.SparkSubmit.doSubmit(SparkSubmit.scala:90)
at org.apache.spark.deploy.SparkSubmit$$anon$2.doSubmit(SparkSubmit.scala:1039)
at org.apache.spark.deploy.SparkSubmit$.main(SparkSubmit.scala:1048)
at org.apache.spark.deploy.SparkSubmit.main(SparkSubmit.scala)