Skip to content

Instantly share code, notes, and snippets.

@AKB428 AKB428/loglog.log
Created Dec 13, 2015

Embed
What would you like to do?
SpakMLlibでTwitterデータを元にALSでアニメを推薦 spark-submit 3executer メモリ80G
[root@vm27801066 spark-1.5.2-bin-hadoop2.6]# ./bin/spark-submit --master spark://vm27801066:7077 --executor-memory 25G --conf spark.driver.memory=4G ../spark-jars/spark_collaborative_filtering_for_tweet_anime-assembly-1.0.jar /var/data/2015_q4_cf_v1_i.csv 1 876226
Using Spark's default log4j profile: org/apache/spark/log4j-defaults.properties
15/12/13 18:03:02 INFO SparkContext: Running Spark version 1.5.2
15/12/13 18:03:02 WARN NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
15/12/13 18:03:02 INFO SecurityManager: Changing view acls to: root
15/12/13 18:03:02 INFO SecurityManager: Changing modify acls to: root
15/12/13 18:03:02 INFO SecurityManager: SecurityManager: authentication disabled; ui acls disabled; users with view permissions: Set(root); users with modify permissions: Set(root)
15/12/13 18:03:03 INFO Slf4jLogger: Slf4jLogger started
15/12/13 18:03:03 INFO Remoting: Starting remoting
15/12/13 18:03:03 INFO Remoting: Remoting started; listening on addresses :[akka.tcp://sparkDriver@10.112.21.66:53656]
15/12/13 18:03:03 INFO Utils: Successfully started service 'sparkDriver' on port 53656.
15/12/13 18:03:03 INFO SparkEnv: Registering MapOutputTracker
15/12/13 18:03:03 INFO SparkEnv: Registering BlockManagerMaster
15/12/13 18:03:03 INFO DiskBlockManager: Created local directory at /tmp/blockmgr-52eb139d-9171-4528-9484-5247dbefc511
15/12/13 18:03:03 INFO MemoryStore: MemoryStore started with capacity 2.1 GB
15/12/13 18:03:03 INFO HttpFileServer: HTTP File server directory is /tmp/spark-94e9ef51-824a-49f8-931b-81025f5ad6c1/httpd-98cd69b3-8b22-4f93-a8fb-af8937cc0cf8
15/12/13 18:03:03 INFO HttpServer: Starting HTTP Server
15/12/13 18:03:03 INFO Utils: Successfully started service 'HTTP file server' on port 60965.
15/12/13 18:03:03 INFO SparkEnv: Registering OutputCommitCoordinator
15/12/13 18:03:04 INFO Utils: Successfully started service 'SparkUI' on port 4040.
15/12/13 18:03:04 INFO SparkUI: Started SparkUI at http://10.112.21.66:4040
15/12/13 18:03:04 INFO SparkContext: Added JAR file:/root/spark-1.5.2-bin-hadoop2.6/../spark-jars/spark_collaborative_filtering_for_tweet_anime-assembly-1.0.jar at http://10.112.21.66:60965/jars/spark_collaborative_filtering_for_tweet_anime-assembly-1.0.jar with timestamp 1449997384367
15/12/13 18:03:04 WARN MetricsSystem: Using default name DAGScheduler for source because spark.app.id is not set.
15/12/13 18:03:04 INFO AppClient$ClientEndpoint: Connecting to master spark://vm27801066:7077...
15/12/13 18:03:04 INFO SparkDeploySchedulerBackend: Connected to Spark cluster with app ID app-20151213180304-0024
15/12/13 18:03:04 INFO AppClient$ClientEndpoint: Executor added: app-20151213180304-0024/0 on worker-20151208002800-10.111.21.68-41149 (10.111.21.68:41149) with 6 cores
15/12/13 18:03:04 INFO SparkDeploySchedulerBackend: Granted executor ID app-20151213180304-0024/0 on hostPort 10.111.21.68:41149 with 6 cores, 25.0 GB RAM
15/12/13 18:03:04 INFO AppClient$ClientEndpoint: Executor added: app-20151213180304-0024/1 on worker-20151208002800-10.111.21.67-38595 (10.111.21.67:38595) with 6 cores
15/12/13 18:03:04 INFO SparkDeploySchedulerBackend: Granted executor ID app-20151213180304-0024/1 on hostPort 10.111.21.67:38595 with 6 cores, 25.0 GB RAM
15/12/13 18:03:04 INFO AppClient$ClientEndpoint: Executor added: app-20151213180304-0024/2 on worker-20151208002800-10.111.21.81-44585 (10.111.21.81:44585) with 6 cores
15/12/13 18:03:04 INFO SparkDeploySchedulerBackend: Granted executor ID app-20151213180304-0024/2 on hostPort 10.111.21.81:44585 with 6 cores, 25.0 GB RAM
15/12/13 18:03:04 INFO AppClient$ClientEndpoint: Executor updated: app-20151213180304-0024/1 is now LOADING
15/12/13 18:03:04 INFO AppClient$ClientEndpoint: Executor updated: app-20151213180304-0024/2 is now LOADING
15/12/13 18:03:04 INFO AppClient$ClientEndpoint: Executor updated: app-20151213180304-0024/0 is now LOADING
15/12/13 18:03:04 INFO AppClient$ClientEndpoint: Executor updated: app-20151213180304-0024/0 is now RUNNING
15/12/13 18:03:04 INFO AppClient$ClientEndpoint: Executor updated: app-20151213180304-0024/1 is now RUNNING
15/12/13 18:03:04 INFO AppClient$ClientEndpoint: Executor updated: app-20151213180304-0024/2 is now RUNNING
15/12/13 18:03:04 INFO Utils: Successfully started service 'org.apache.spark.network.netty.NettyBlockTransferService' on port 47648.
15/12/13 18:03:04 INFO NettyBlockTransferService: Server created on 47648
15/12/13 18:03:04 INFO BlockManagerMaster: Trying to register BlockManager
15/12/13 18:03:04 INFO BlockManagerMasterEndpoint: Registering block manager 10.112.21.66:47648 with 2.1 GB RAM, BlockManagerId(driver, 10.112.21.66, 47648)
15/12/13 18:03:04 INFO BlockManagerMaster: Registered BlockManager
15/12/13 18:03:05 INFO SparkDeploySchedulerBackend: SchedulerBackend is ready for scheduling beginning after reached minRegisteredResourcesRatio: 0.0
15/12/13 18:03:05 INFO MemoryStore: ensureFreeSpace(157248) called with curMem=0, maxMem=2223023063
15/12/13 18:03:05 INFO MemoryStore: Block broadcast_0 stored as values in memory (estimated size 153.6 KB, free 2.1 GB)
15/12/13 18:03:05 INFO MemoryStore: ensureFreeSpace(14276) called with curMem=157248, maxMem=2223023063
15/12/13 18:03:05 INFO MemoryStore: Block broadcast_0_piece0 stored as bytes in memory (estimated size 13.9 KB, free 2.1 GB)
15/12/13 18:03:05 INFO BlockManagerInfo: Added broadcast_0_piece0 in memory on 10.112.21.66:47648 (size: 13.9 KB, free: 2.1 GB)
15/12/13 18:03:05 INFO SparkContext: Created broadcast 0 from textFile at prediction_save.scala:22
15/12/13 18:03:05 INFO FileInputFormat: Total input paths to process : 1
15/12/13 18:03:06 INFO SparkContext: Starting job: count at ALS.scala:550
15/12/13 18:03:06 INFO DAGScheduler: Registering RDD 4 (mapPartitions at ALS.scala:791)
15/12/13 18:03:06 INFO DAGScheduler: Registering RDD 7 (map at ALS.scala:1034)
15/12/13 18:03:06 INFO DAGScheduler: Got job 0 (count at ALS.scala:550) with 2 output partitions
15/12/13 18:03:06 INFO DAGScheduler: Final stage: ResultStage 2(count at ALS.scala:550)
15/12/13 18:03:06 INFO DAGScheduler: Parents of final stage: List(ShuffleMapStage 1)
15/12/13 18:03:06 INFO DAGScheduler: Missing parents: List(ShuffleMapStage 1)
15/12/13 18:03:06 INFO DAGScheduler: Submitting ShuffleMapStage 0 (MapPartitionsRDD[4] at mapPartitions at ALS.scala:791), which has no missing parents
15/12/13 18:03:06 INFO MemoryStore: ensureFreeSpace(5488) called with curMem=171524, maxMem=2223023063
15/12/13 18:03:06 INFO MemoryStore: Block broadcast_1 stored as values in memory (estimated size 5.4 KB, free 2.1 GB)
15/12/13 18:03:06 INFO MemoryStore: ensureFreeSpace(2950) called with curMem=177012, maxMem=2223023063
15/12/13 18:03:06 INFO MemoryStore: Block broadcast_1_piece0 stored as bytes in memory (estimated size 2.9 KB, free 2.1 GB)
15/12/13 18:03:06 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on 10.112.21.66:47648 (size: 2.9 KB, free: 2.1 GB)
15/12/13 18:03:06 INFO SparkContext: Created broadcast 1 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:06 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 0 (MapPartitionsRDD[4] at mapPartitions at ALS.scala:791)
15/12/13 18:03:06 INFO TaskSchedulerImpl: Adding task set 0.0 with 2 tasks
15/12/13 18:03:07 INFO SparkDeploySchedulerBackend: Registered executor: AkkaRpcEndpointRef(Actor[akka.tcp://sparkExecutor@10.111.21.67:57226/user/Executor#1667993157]) with ID 1
15/12/13 18:03:07 INFO TaskSetManager: Starting task 0.0 in stage 0.0 (TID 0, 10.111.21.67, PROCESS_LOCAL, 2235 bytes)
15/12/13 18:03:07 INFO TaskSetManager: Starting task 1.0 in stage 0.0 (TID 1, 10.111.21.67, PROCESS_LOCAL, 2235 bytes)
15/12/13 18:03:07 INFO SparkDeploySchedulerBackend: Registered executor: AkkaRpcEndpointRef(Actor[akka.tcp://sparkExecutor@10.111.21.81:58038/user/Executor#2036713217]) with ID 2
15/12/13 18:03:07 INFO SparkDeploySchedulerBackend: Registered executor: AkkaRpcEndpointRef(Actor[akka.tcp://sparkExecutor@10.111.21.68:54299/user/Executor#-1623103074]) with ID 0
15/12/13 18:03:07 INFO BlockManagerMasterEndpoint: Registering block manager 10.111.21.67:52391 with 12.9 GB RAM, BlockManagerId(1, 10.111.21.67, 52391)
15/12/13 18:03:07 INFO BlockManagerMasterEndpoint: Registering block manager 10.111.21.81:38534 with 12.9 GB RAM, BlockManagerId(2, 10.111.21.81, 38534)
15/12/13 18:03:07 INFO BlockManagerMasterEndpoint: Registering block manager 10.111.21.68:43411 with 12.9 GB RAM, BlockManagerId(0, 10.111.21.68, 43411)
15/12/13 18:03:09 INFO BlockManagerInfo: Added broadcast_1_piece0 in memory on 10.111.21.67:52391 (size: 2.9 KB, free: 12.9 GB)
15/12/13 18:03:09 INFO BlockManagerInfo: Added broadcast_0_piece0 in memory on 10.111.21.67:52391 (size: 13.9 KB, free: 12.9 GB)
15/12/13 18:03:12 INFO TaskSetManager: Finished task 1.0 in stage 0.0 (TID 1) in 4561 ms on 10.111.21.67 (1/2)
15/12/13 18:03:12 INFO TaskSetManager: Finished task 0.0 in stage 0.0 (TID 0) in 4616 ms on 10.111.21.67 (2/2)
15/12/13 18:03:12 INFO DAGScheduler: ShuffleMapStage 0 (mapPartitions at ALS.scala:791) finished in 5.973 s
15/12/13 18:03:12 INFO TaskSchedulerImpl: Removed TaskSet 0.0, whose tasks have all completed, from pool
15/12/13 18:03:12 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:12 INFO DAGScheduler: running: Set()
15/12/13 18:03:12 INFO DAGScheduler: waiting: Set(ShuffleMapStage 1, ResultStage 2)
15/12/13 18:03:12 INFO DAGScheduler: failed: Set()
15/12/13 18:03:12 INFO DAGScheduler: Missing parents for ShuffleMapStage 1: List()
15/12/13 18:03:12 INFO DAGScheduler: Missing parents for ResultStage 2: List(ShuffleMapStage 1)
15/12/13 18:03:12 INFO DAGScheduler: Submitting ShuffleMapStage 1 (MapPartitionsRDD[7] at map at ALS.scala:1034), which is now runnable
15/12/13 18:03:12 INFO MemoryStore: ensureFreeSpace(6368) called with curMem=179962, maxMem=2223023063
15/12/13 18:03:12 INFO MemoryStore: Block broadcast_2 stored as values in memory (estimated size 6.2 KB, free 2.1 GB)
15/12/13 18:03:12 INFO MemoryStore: ensureFreeSpace(3284) called with curMem=186330, maxMem=2223023063
15/12/13 18:03:12 INFO MemoryStore: Block broadcast_2_piece0 stored as bytes in memory (estimated size 3.2 KB, free 2.1 GB)
15/12/13 18:03:12 INFO BlockManagerInfo: Added broadcast_2_piece0 in memory on 10.112.21.66:47648 (size: 3.2 KB, free: 2.1 GB)
15/12/13 18:03:12 INFO SparkContext: Created broadcast 2 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:12 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 1 (MapPartitionsRDD[7] at map at ALS.scala:1034)
15/12/13 18:03:12 INFO TaskSchedulerImpl: Adding task set 1.0 with 2 tasks
15/12/13 18:03:12 INFO TaskSetManager: Starting task 0.0 in stage 1.0 (TID 2, 10.111.21.81, PROCESS_LOCAL, 1993 bytes)
15/12/13 18:03:12 INFO TaskSetManager: Starting task 1.0 in stage 1.0 (TID 3, 10.111.21.68, PROCESS_LOCAL, 1993 bytes)
15/12/13 18:03:12 INFO BlockManagerInfo: Removed broadcast_1_piece0 on 10.112.21.66:47648 in memory (size: 2.9 KB, free: 2.1 GB)
15/12/13 18:03:12 INFO BlockManagerInfo: Removed broadcast_1_piece0 on 10.111.21.67:52391 in memory (size: 2.9 KB, free: 12.9 GB)
15/12/13 18:03:14 INFO BlockManagerInfo: Added broadcast_2_piece0 in memory on 10.111.21.81:38534 (size: 3.2 KB, free: 12.9 GB)
15/12/13 18:03:14 INFO BlockManagerInfo: Added broadcast_2_piece0 in memory on 10.111.21.68:43411 (size: 3.2 KB, free: 12.9 GB)
15/12/13 18:03:14 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 1 to 10.111.21.81:58038
15/12/13 18:03:14 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 1 is 153 bytes
15/12/13 18:03:15 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 1 to 10.111.21.68:54299
15/12/13 18:03:15 INFO BlockManagerInfo: Added rdd_6_0 in memory on 10.111.21.81:38534 (size: 8.5 MB, free: 12.9 GB)
15/12/13 18:03:15 INFO BlockManagerInfo: Added rdd_6_1 in memory on 10.111.21.68:43411 (size: 8.5 MB, free: 12.9 GB)
15/12/13 18:03:15 INFO TaskSetManager: Finished task 0.0 in stage 1.0 (TID 2) in 3482 ms on 10.111.21.81 (1/2)
15/12/13 18:03:15 INFO TaskSetManager: Finished task 1.0 in stage 1.0 (TID 3) in 3731 ms on 10.111.21.68 (2/2)
15/12/13 18:03:15 INFO TaskSchedulerImpl: Removed TaskSet 1.0, whose tasks have all completed, from pool
15/12/13 18:03:15 INFO DAGScheduler: ShuffleMapStage 1 (map at ALS.scala:1034) finished in 3.733 s
15/12/13 18:03:15 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:15 INFO DAGScheduler: running: Set()
15/12/13 18:03:15 INFO DAGScheduler: waiting: Set(ResultStage 2)
15/12/13 18:03:15 INFO DAGScheduler: failed: Set()
15/12/13 18:03:15 INFO DAGScheduler: Missing parents for ResultStage 2: List()
15/12/13 18:03:15 INFO DAGScheduler: Submitting ResultStage 2 (userOutBlocks MapPartitionsRDD[10] at mapValues at ALS.scala:1071), which is now runnable
15/12/13 18:03:15 INFO MemoryStore: ensureFreeSpace(6952) called with curMem=181176, maxMem=2223023063
15/12/13 18:03:15 INFO MemoryStore: Block broadcast_3 stored as values in memory (estimated size 6.8 KB, free 2.1 GB)
15/12/13 18:03:15 INFO MemoryStore: ensureFreeSpace(3444) called with curMem=188128, maxMem=2223023063
15/12/13 18:03:15 INFO MemoryStore: Block broadcast_3_piece0 stored as bytes in memory (estimated size 3.4 KB, free 2.1 GB)
15/12/13 18:03:15 INFO BlockManagerInfo: Added broadcast_3_piece0 in memory on 10.112.21.66:47648 (size: 3.4 KB, free: 2.1 GB)
15/12/13 18:03:15 INFO SparkContext: Created broadcast 3 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:15 INFO DAGScheduler: Submitting 2 missing tasks from ResultStage 2 (userOutBlocks MapPartitionsRDD[10] at mapValues at ALS.scala:1071)
15/12/13 18:03:15 INFO TaskSchedulerImpl: Adding task set 2.0 with 2 tasks
15/12/13 18:03:15 INFO TaskSetManager: Starting task 0.0 in stage 2.0 (TID 4, 10.111.21.67, PROCESS_LOCAL, 2004 bytes)
15/12/13 18:03:15 INFO TaskSetManager: Starting task 1.0 in stage 2.0 (TID 5, 10.111.21.81, PROCESS_LOCAL, 2004 bytes)
15/12/13 18:03:15 INFO BlockManagerInfo: Added broadcast_3_piece0 in memory on 10.111.21.67:52391 (size: 3.4 KB, free: 12.9 GB)
15/12/13 18:03:15 INFO BlockManagerInfo: Added broadcast_3_piece0 in memory on 10.111.21.81:38534 (size: 3.4 KB, free: 12.9 GB)
15/12/13 18:03:15 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 0 to 10.111.21.81:58038
15/12/13 18:03:15 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 0 is 164 bytes
15/12/13 18:03:15 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 0 to 10.111.21.67:57226
15/12/13 18:03:16 INFO BlockManagerInfo: Added rdd_9_1 in memory on 10.111.21.81:38534 (size: 9.0 MB, free: 12.9 GB)
15/12/13 18:03:16 INFO BlockManagerInfo: Added rdd_10_1 in memory on 10.111.21.81:38534 (size: 2.0 MB, free: 12.9 GB)
15/12/13 18:03:16 INFO TaskSetManager: Finished task 1.0 in stage 2.0 (TID 5) in 529 ms on 10.111.21.81 (1/2)
15/12/13 18:03:16 INFO BlockManagerInfo: Added rdd_9_0 in memory on 10.111.21.67:52391 (size: 9.0 MB, free: 12.9 GB)
15/12/13 18:03:16 INFO BlockManagerInfo: Added rdd_10_0 in memory on 10.111.21.67:52391 (size: 2.0 MB, free: 12.9 GB)
15/12/13 18:03:16 INFO TaskSetManager: Finished task 0.0 in stage 2.0 (TID 4) in 628 ms on 10.111.21.67 (2/2)
15/12/13 18:03:16 INFO TaskSchedulerImpl: Removed TaskSet 2.0, whose tasks have all completed, from pool
15/12/13 18:03:16 INFO DAGScheduler: ResultStage 2 (count at ALS.scala:550) finished in 0.629 s
15/12/13 18:03:16 INFO DAGScheduler: Job 0 finished: count at ALS.scala:550, took 10.473130 s
15/12/13 18:03:16 INFO SparkContext: Starting job: count at ALS.scala:558
15/12/13 18:03:16 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 1 is 153 bytes
15/12/13 18:03:16 INFO DAGScheduler: Registering RDD 12 (map at ALS.scala:1034)
15/12/13 18:03:16 INFO DAGScheduler: Got job 1 (count at ALS.scala:558) with 2 output partitions
15/12/13 18:03:16 INFO DAGScheduler: Final stage: ResultStage 5(count at ALS.scala:558)
15/12/13 18:03:16 INFO DAGScheduler: Parents of final stage: List(ShuffleMapStage 4)
15/12/13 18:03:16 INFO DAGScheduler: Missing parents: List(ShuffleMapStage 4)
15/12/13 18:03:16 INFO DAGScheduler: Submitting ShuffleMapStage 4 (MapPartitionsRDD[12] at map at ALS.scala:1034), which has no missing parents
15/12/13 18:03:16 INFO MemoryStore: ensureFreeSpace(6528) called with curMem=191572, maxMem=2223023063
15/12/13 18:03:16 INFO MemoryStore: Block broadcast_4 stored as values in memory (estimated size 6.4 KB, free 2.1 GB)
15/12/13 18:03:16 INFO MemoryStore: ensureFreeSpace(3319) called with curMem=198100, maxMem=2223023063
15/12/13 18:03:16 INFO MemoryStore: Block broadcast_4_piece0 stored as bytes in memory (estimated size 3.2 KB, free 2.1 GB)
15/12/13 18:03:16 INFO BlockManagerInfo: Added broadcast_4_piece0 in memory on 10.112.21.66:47648 (size: 3.2 KB, free: 2.1 GB)
15/12/13 18:03:16 INFO SparkContext: Created broadcast 4 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:16 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 4 (MapPartitionsRDD[12] at map at ALS.scala:1034)
15/12/13 18:03:16 INFO TaskSchedulerImpl: Adding task set 4.0 with 2 tasks
15/12/13 18:03:16 INFO TaskSetManager: Starting task 1.0 in stage 4.0 (TID 6, 10.111.21.68, PROCESS_LOCAL, 1993 bytes)
15/12/13 18:03:16 INFO TaskSetManager: Starting task 0.0 in stage 4.0 (TID 7, 10.111.21.81, PROCESS_LOCAL, 1993 bytes)
15/12/13 18:03:16 INFO BlockManagerInfo: Added broadcast_4_piece0 in memory on 10.111.21.81:38534 (size: 3.2 KB, free: 12.9 GB)
15/12/13 18:03:16 INFO BlockManagerInfo: Added broadcast_4_piece0 in memory on 10.111.21.68:43411 (size: 3.2 KB, free: 12.9 GB)
15/12/13 18:03:17 INFO TaskSetManager: Finished task 0.0 in stage 4.0 (TID 7) in 1220 ms on 10.111.21.81 (1/2)
15/12/13 18:03:17 INFO TaskSetManager: Finished task 1.0 in stage 4.0 (TID 6) in 1432 ms on 10.111.21.68 (2/2)
15/12/13 18:03:17 INFO TaskSchedulerImpl: Removed TaskSet 4.0, whose tasks have all completed, from pool
15/12/13 18:03:17 INFO DAGScheduler: ShuffleMapStage 4 (map at ALS.scala:1034) finished in 1.434 s
15/12/13 18:03:17 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:17 INFO DAGScheduler: running: Set()
15/12/13 18:03:17 INFO DAGScheduler: waiting: Set(ResultStage 5)
15/12/13 18:03:17 INFO DAGScheduler: failed: Set()
15/12/13 18:03:17 INFO DAGScheduler: Missing parents for ResultStage 5: List()
15/12/13 18:03:17 INFO DAGScheduler: Submitting ResultStage 5 (itemOutBlocks MapPartitionsRDD[15] at mapValues at ALS.scala:1071), which is now runnable
15/12/13 18:03:18 INFO MemoryStore: ensureFreeSpace(7104) called with curMem=201419, maxMem=2223023063
15/12/13 18:03:18 INFO MemoryStore: Block broadcast_5 stored as values in memory (estimated size 6.9 KB, free 2.1 GB)
15/12/13 18:03:18 INFO MemoryStore: ensureFreeSpace(3477) called with curMem=208523, maxMem=2223023063
15/12/13 18:03:18 INFO MemoryStore: Block broadcast_5_piece0 stored as bytes in memory (estimated size 3.4 KB, free 2.1 GB)
15/12/13 18:03:18 INFO BlockManagerInfo: Added broadcast_5_piece0 in memory on 10.112.21.66:47648 (size: 3.4 KB, free: 2.1 GB)
15/12/13 18:03:18 INFO SparkContext: Created broadcast 5 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:18 INFO DAGScheduler: Submitting 2 missing tasks from ResultStage 5 (itemOutBlocks MapPartitionsRDD[15] at mapValues at ALS.scala:1071)
15/12/13 18:03:18 INFO TaskSchedulerImpl: Adding task set 5.0 with 2 tasks
15/12/13 18:03:18 INFO TaskSetManager: Starting task 0.0 in stage 5.0 (TID 8, 10.111.21.81, PROCESS_LOCAL, 2004 bytes)
15/12/13 18:03:18 INFO TaskSetManager: Starting task 1.0 in stage 5.0 (TID 9, 10.111.21.67, PROCESS_LOCAL, 2004 bytes)
15/12/13 18:03:18 INFO BlockManagerInfo: Added broadcast_5_piece0 in memory on 10.111.21.81:38534 (size: 3.4 KB, free: 12.9 GB)
15/12/13 18:03:18 INFO BlockManagerInfo: Added broadcast_5_piece0 in memory on 10.111.21.67:52391 (size: 3.4 KB, free: 12.9 GB)
15/12/13 18:03:18 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 2 to 10.111.21.81:58038
15/12/13 18:03:18 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 2 is 161 bytes
15/12/13 18:03:18 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 2 to 10.111.21.67:57226
15/12/13 18:03:18 INFO BlockManagerInfo: Added rdd_14_1 in memory on 10.111.21.67:52391 (size: 4.0 MB, free: 12.9 GB)
15/12/13 18:03:18 INFO BlockManagerInfo: Added rdd_15_1 in memory on 10.111.21.67:52391 (size: 296.0 B, free: 12.9 GB)
15/12/13 18:03:18 INFO TaskSetManager: Finished task 1.0 in stage 5.0 (TID 9) in 562 ms on 10.111.21.67 (1/2)
15/12/13 18:03:18 INFO BlockManagerInfo: Added rdd_14_0 in memory on 10.111.21.81:38534 (size: 7.3 MB, free: 12.9 GB)
15/12/13 18:03:18 INFO BlockManagerInfo: Added rdd_15_0 in memory on 10.111.21.81:38534 (size: 296.0 B, free: 12.9 GB)
15/12/13 18:03:18 INFO TaskSetManager: Finished task 0.0 in stage 5.0 (TID 8) in 846 ms on 10.111.21.81 (2/2)
15/12/13 18:03:18 INFO DAGScheduler: ResultStage 5 (count at ALS.scala:558) finished in 0.846 s
15/12/13 18:03:18 INFO TaskSchedulerImpl: Removed TaskSet 5.0, whose tasks have all completed, from pool
15/12/13 18:03:18 INFO DAGScheduler: Job 1 finished: count at ALS.scala:558, took 2.327333 s
15/12/13 18:03:19 INFO SparkContext: Starting job: count at ALS.scala:263
15/12/13 18:03:19 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 1 is 153 bytes
15/12/13 18:03:19 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 0 is 164 bytes
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 16 (map at ALS.scala:706)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 21 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 30 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 39 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 48 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 57 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 66 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 75 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 84 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 93 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 102 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 111 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 120 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 129 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 138 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 147 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 156 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 165 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 174 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 183 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Registering RDD 192 (flatMap at ALS.scala:1124)
15/12/13 18:03:19 INFO DAGScheduler: Got job 2 (count at ALS.scala:263) with 2 output partitions
15/12/13 18:03:19 INFO DAGScheduler: Final stage: ResultStage 31(count at ALS.scala:263)
15/12/13 18:03:19 INFO DAGScheduler: Parents of final stage: List(ShuffleMapStage 30, ShuffleMapStage 9)
15/12/13 18:03:19 INFO DAGScheduler: Missing parents: List(ShuffleMapStage 30)
15/12/13 18:03:19 INFO DAGScheduler: Submitting ShuffleMapStage 10 (MapPartitionsRDD[16] at map at ALS.scala:706), which has no missing parents
15/12/13 18:03:19 INFO MemoryStore: ensureFreeSpace(6872) called with curMem=212000, maxMem=2223023063
15/12/13 18:03:19 INFO MemoryStore: Block broadcast_6 stored as values in memory (estimated size 6.7 KB, free 2.1 GB)
15/12/13 18:03:19 INFO MemoryStore: ensureFreeSpace(3451) called with curMem=218872, maxMem=2223023063
15/12/13 18:03:19 INFO MemoryStore: Block broadcast_6_piece0 stored as bytes in memory (estimated size 3.4 KB, free 2.1 GB)
15/12/13 18:03:19 INFO BlockManagerInfo: Added broadcast_6_piece0 in memory on 10.112.21.66:47648 (size: 3.4 KB, free: 2.1 GB)
15/12/13 18:03:19 INFO SparkContext: Created broadcast 6 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:19 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 10 (MapPartitionsRDD[16] at map at ALS.scala:706)
15/12/13 18:03:19 INFO TaskSchedulerImpl: Adding task set 10.0 with 2 tasks
15/12/13 18:03:19 INFO TaskSetManager: Starting task 1.0 in stage 10.0 (TID 10, 10.111.21.81, PROCESS_LOCAL, 1993 bytes)
15/12/13 18:03:19 INFO TaskSetManager: Starting task 0.0 in stage 10.0 (TID 11, 10.111.21.67, PROCESS_LOCAL, 1993 bytes)
15/12/13 18:03:19 INFO BlockManagerInfo: Added broadcast_6_piece0 in memory on 10.111.21.67:52391 (size: 3.4 KB, free: 12.9 GB)
15/12/13 18:03:19 INFO BlockManagerInfo: Added broadcast_6_piece0 in memory on 10.111.21.81:38534 (size: 3.4 KB, free: 12.9 GB)
15/12/13 18:03:20 INFO TaskSetManager: Finished task 1.0 in stage 10.0 (TID 10) in 1088 ms on 10.111.21.81 (1/2)
15/12/13 18:03:20 INFO TaskSetManager: Finished task 0.0 in stage 10.0 (TID 11) in 1123 ms on 10.111.21.67 (2/2)
15/12/13 18:03:20 INFO TaskSchedulerImpl: Removed TaskSet 10.0, whose tasks have all completed, from pool
15/12/13 18:03:20 INFO DAGScheduler: ShuffleMapStage 10 (map at ALS.scala:706) finished in 1.125 s
15/12/13 18:03:20 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:20 INFO DAGScheduler: running: Set()
15/12/13 18:03:20 INFO DAGScheduler: waiting: Set(ShuffleMapStage 15, ShuffleMapStage 30, ShuffleMapStage 16, ResultStage 31, ShuffleMapStage 17, ShuffleMapStage 24, ShuffleMapStage 18, ShuffleMapStage 25, ShuffleMapStage 11, ShuffleMapStage 26, ShuffleMapStage 12, ShuffleMapStage 27, ShuffleMapStage 19, ShuffleMapStage 13, ShuffleMapStage 20, ShuffleMapStage 21, ShuffleMapStage 28, ShuffleMapStage 22, ShuffleMapStage 14, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:20 INFO DAGScheduler: failed: Set()
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 15: List(ShuffleMapStage 14)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 16: List(ShuffleMapStage 15)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 17: List(ShuffleMapStage 16)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 18: List(ShuffleMapStage 17)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 11: List()
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 12: List(ShuffleMapStage 11)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 19: List(ShuffleMapStage 18)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 13: List(ShuffleMapStage 12)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 20: List(ShuffleMapStage 19)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 21: List(ShuffleMapStage 20)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 22: List(ShuffleMapStage 21)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 14: List(ShuffleMapStage 13)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:20 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List(ShuffleMapStage 22)
15/12/13 18:03:20 INFO DAGScheduler: Submitting ShuffleMapStage 11 (MapPartitionsRDD[21] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:20 INFO MemoryStore: ensureFreeSpace(7864) called with curMem=222323, maxMem=2223023063
15/12/13 18:03:20 INFO MemoryStore: Block broadcast_7 stored as values in memory (estimated size 7.7 KB, free 2.1 GB)
15/12/13 18:03:20 INFO MemoryStore: ensureFreeSpace(3653) called with curMem=230187, maxMem=2223023063
15/12/13 18:03:20 INFO MemoryStore: Block broadcast_7_piece0 stored as bytes in memory (estimated size 3.6 KB, free 2.1 GB)
15/12/13 18:03:20 INFO BlockManagerInfo: Added broadcast_7_piece0 in memory on 10.112.21.66:47648 (size: 3.6 KB, free: 2.1 GB)
15/12/13 18:03:20 INFO SparkContext: Created broadcast 7 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:20 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 11 (MapPartitionsRDD[21] at flatMap at ALS.scala:1124)
15/12/13 18:03:20 INFO TaskSchedulerImpl: Adding task set 11.0 with 2 tasks
15/12/13 18:03:20 INFO TaskSetManager: Starting task 0.0 in stage 11.0 (TID 12, 10.111.21.67, PROCESS_LOCAL, 2220 bytes)
15/12/13 18:03:20 INFO TaskSetManager: Starting task 1.0 in stage 11.0 (TID 13, 10.111.21.81, PROCESS_LOCAL, 2220 bytes)
15/12/13 18:03:20 INFO BlockManagerInfo: Added broadcast_7_piece0 in memory on 10.111.21.81:38534 (size: 3.6 KB, free: 12.9 GB)
15/12/13 18:03:20 INFO BlockManagerInfo: Added broadcast_7_piece0 in memory on 10.111.21.67:52391 (size: 3.6 KB, free: 12.9 GB)
15/12/13 18:03:20 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 23 to 10.111.21.81:58038
15/12/13 18:03:20 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 23 is 164 bytes
15/12/13 18:03:20 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 23 to 10.111.21.67:57226
15/12/13 18:03:21 INFO TaskSetManager: Finished task 0.0 in stage 11.0 (TID 12) in 1096 ms on 10.111.21.67 (1/2)
15/12/13 18:03:21 INFO TaskSetManager: Finished task 1.0 in stage 11.0 (TID 13) in 1133 ms on 10.111.21.81 (2/2)
15/12/13 18:03:21 INFO DAGScheduler: ShuffleMapStage 11 (flatMap at ALS.scala:1124) finished in 1.137 s
15/12/13 18:03:21 INFO TaskSchedulerImpl: Removed TaskSet 11.0, whose tasks have all completed, from pool
15/12/13 18:03:21 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:21 INFO DAGScheduler: running: Set()
15/12/13 18:03:21 INFO DAGScheduler: waiting: Set(ShuffleMapStage 15, ShuffleMapStage 30, ShuffleMapStage 16, ResultStage 31, ShuffleMapStage 17, ShuffleMapStage 24, ShuffleMapStage 18, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 12, ShuffleMapStage 27, ShuffleMapStage 19, ShuffleMapStage 13, ShuffleMapStage 20, ShuffleMapStage 21, ShuffleMapStage 28, ShuffleMapStage 22, ShuffleMapStage 14, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:21 INFO DAGScheduler: failed: Set()
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 15: List(ShuffleMapStage 14)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 16: List(ShuffleMapStage 15)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 17: List(ShuffleMapStage 16)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 18: List(ShuffleMapStage 17)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 12: List()
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 19: List(ShuffleMapStage 18)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 13: List(ShuffleMapStage 12)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 20: List(ShuffleMapStage 19)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 21: List(ShuffleMapStage 20)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 22: List(ShuffleMapStage 21)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 14: List(ShuffleMapStage 13)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:21 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List(ShuffleMapStage 22)
15/12/13 18:03:21 INFO DAGScheduler: Submitting ShuffleMapStage 12 (MapPartitionsRDD[30] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:22 INFO MemoryStore: ensureFreeSpace(10040) called with curMem=233840, maxMem=2223023063
15/12/13 18:03:22 INFO MemoryStore: Block broadcast_8 stored as values in memory (estimated size 9.8 KB, free 2.1 GB)
15/12/13 18:03:22 INFO MemoryStore: ensureFreeSpace(4362) called with curMem=243880, maxMem=2223023063
15/12/13 18:03:22 INFO MemoryStore: Block broadcast_8_piece0 stored as bytes in memory (estimated size 4.3 KB, free 2.1 GB)
15/12/13 18:03:22 INFO BlockManagerInfo: Added broadcast_8_piece0 in memory on 10.112.21.66:47648 (size: 4.3 KB, free: 2.1 GB)
15/12/13 18:03:22 INFO SparkContext: Created broadcast 8 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:22 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 12 (MapPartitionsRDD[30] at flatMap at ALS.scala:1124)
15/12/13 18:03:22 INFO TaskSchedulerImpl: Adding task set 12.0 with 2 tasks
15/12/13 18:03:22 INFO TaskSetManager: Starting task 0.0 in stage 12.0 (TID 14, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:22 INFO TaskSetManager: Starting task 1.0 in stage 12.0 (TID 15, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:22 INFO BlockManagerInfo: Added broadcast_8_piece0 in memory on 10.111.21.81:38534 (size: 4.3 KB, free: 12.9 GB)
15/12/13 18:03:22 INFO BlockManagerInfo: Added broadcast_8_piece0 in memory on 10.111.21.67:52391 (size: 4.3 KB, free: 12.9 GB)
15/12/13 18:03:22 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 22 to 10.111.21.81:58038
15/12/13 18:03:22 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 22 is 161 bytes
15/12/13 18:03:22 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 22 to 10.111.21.67:57226
15/12/13 18:03:22 INFO TaskSetManager: Finished task 1.0 in stage 12.0 (TID 15) in 672 ms on 10.111.21.67 (1/2)
15/12/13 18:03:23 INFO TaskSetManager: Finished task 0.0 in stage 12.0 (TID 14) in 1062 ms on 10.111.21.81 (2/2)
15/12/13 18:03:23 INFO DAGScheduler: ShuffleMapStage 12 (flatMap at ALS.scala:1124) finished in 1.065 s
15/12/13 18:03:23 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:23 INFO TaskSchedulerImpl: Removed TaskSet 12.0, whose tasks have all completed, from pool
15/12/13 18:03:23 INFO DAGScheduler: running: Set()
15/12/13 18:03:23 INFO DAGScheduler: waiting: Set(ShuffleMapStage 15, ShuffleMapStage 30, ShuffleMapStage 16, ResultStage 31, ShuffleMapStage 17, ShuffleMapStage 24, ShuffleMapStage 18, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 19, ShuffleMapStage 13, ShuffleMapStage 20, ShuffleMapStage 21, ShuffleMapStage 28, ShuffleMapStage 22, ShuffleMapStage 14, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:23 INFO DAGScheduler: failed: Set()
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 15: List(ShuffleMapStage 14)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 16: List(ShuffleMapStage 15)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 17: List(ShuffleMapStage 16)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 18: List(ShuffleMapStage 17)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 19: List(ShuffleMapStage 18)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 13: List()
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 20: List(ShuffleMapStage 19)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 21: List(ShuffleMapStage 20)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 22: List(ShuffleMapStage 21)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 14: List(ShuffleMapStage 13)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:23 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List(ShuffleMapStage 22)
15/12/13 18:03:23 INFO DAGScheduler: Submitting ShuffleMapStage 13 (MapPartitionsRDD[39] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:23 INFO MemoryStore: ensureFreeSpace(10904) called with curMem=248242, maxMem=2223023063
15/12/13 18:03:23 INFO MemoryStore: Block broadcast_9 stored as values in memory (estimated size 10.6 KB, free 2.1 GB)
15/12/13 18:03:23 INFO MemoryStore: ensureFreeSpace(4589) called with curMem=259146, maxMem=2223023063
15/12/13 18:03:23 INFO MemoryStore: Block broadcast_9_piece0 stored as bytes in memory (estimated size 4.5 KB, free 2.1 GB)
15/12/13 18:03:23 INFO BlockManagerInfo: Added broadcast_9_piece0 in memory on 10.112.21.66:47648 (size: 4.5 KB, free: 2.1 GB)
15/12/13 18:03:23 INFO SparkContext: Created broadcast 9 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:23 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 13 (MapPartitionsRDD[39] at flatMap at ALS.scala:1124)
15/12/13 18:03:23 INFO TaskSchedulerImpl: Adding task set 13.0 with 2 tasks
15/12/13 18:03:23 INFO TaskSetManager: Starting task 0.0 in stage 13.0 (TID 16, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:23 INFO TaskSetManager: Starting task 1.0 in stage 13.0 (TID 17, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:23 INFO BlockManagerInfo: Added broadcast_9_piece0 in memory on 10.111.21.67:52391 (size: 4.5 KB, free: 12.9 GB)
15/12/13 18:03:23 INFO BlockManagerInfo: Added broadcast_9_piece0 in memory on 10.111.21.81:38534 (size: 4.5 KB, free: 12.9 GB)
15/12/13 18:03:23 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 21 to 10.111.21.67:57226
15/12/13 18:03:23 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 21 is 164 bytes
15/12/13 18:03:23 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 21 to 10.111.21.81:58038
15/12/13 18:03:24 INFO TaskSetManager: Finished task 0.0 in stage 13.0 (TID 16) in 1717 ms on 10.111.21.67 (1/2)
15/12/13 18:03:24 INFO TaskSetManager: Finished task 1.0 in stage 13.0 (TID 17) in 1717 ms on 10.111.21.81 (2/2)
15/12/13 18:03:24 INFO TaskSchedulerImpl: Removed TaskSet 13.0, whose tasks have all completed, from pool
15/12/13 18:03:24 INFO DAGScheduler: ShuffleMapStage 13 (flatMap at ALS.scala:1124) finished in 1.723 s
15/12/13 18:03:24 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:24 INFO DAGScheduler: running: Set()
15/12/13 18:03:24 INFO DAGScheduler: waiting: Set(ShuffleMapStage 15, ShuffleMapStage 30, ShuffleMapStage 16, ResultStage 31, ShuffleMapStage 17, ShuffleMapStage 24, ShuffleMapStage 18, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 19, ShuffleMapStage 20, ShuffleMapStage 21, ShuffleMapStage 28, ShuffleMapStage 22, ShuffleMapStage 14, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:24 INFO DAGScheduler: failed: Set()
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 15: List(ShuffleMapStage 14)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 16: List(ShuffleMapStage 15)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 17: List(ShuffleMapStage 16)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 18: List(ShuffleMapStage 17)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 19: List(ShuffleMapStage 18)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 20: List(ShuffleMapStage 19)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 21: List(ShuffleMapStage 20)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 22: List(ShuffleMapStage 21)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 14: List()
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:24 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List(ShuffleMapStage 22)
15/12/13 18:03:24 INFO DAGScheduler: Submitting ShuffleMapStage 14 (MapPartitionsRDD[48] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:24 INFO MemoryStore: ensureFreeSpace(11752) called with curMem=263735, maxMem=2223023063
15/12/13 18:03:24 INFO MemoryStore: Block broadcast_10 stored as values in memory (estimated size 11.5 KB, free 2.1 GB)
15/12/13 18:03:24 INFO MemoryStore: ensureFreeSpace(4748) called with curMem=275487, maxMem=2223023063
15/12/13 18:03:24 INFO MemoryStore: Block broadcast_10_piece0 stored as bytes in memory (estimated size 4.6 KB, free 2.1 GB)
15/12/13 18:03:24 INFO BlockManagerInfo: Added broadcast_10_piece0 in memory on 10.112.21.66:47648 (size: 4.6 KB, free: 2.1 GB)
15/12/13 18:03:24 INFO SparkContext: Created broadcast 10 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:24 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 14 (MapPartitionsRDD[48] at flatMap at ALS.scala:1124)
15/12/13 18:03:24 INFO TaskSchedulerImpl: Adding task set 14.0 with 2 tasks
15/12/13 18:03:24 INFO TaskSetManager: Starting task 0.0 in stage 14.0 (TID 18, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:24 INFO TaskSetManager: Starting task 1.0 in stage 14.0 (TID 19, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:24 INFO BlockManagerInfo: Added broadcast_10_piece0 in memory on 10.111.21.67:52391 (size: 4.6 KB, free: 12.9 GB)
15/12/13 18:03:24 INFO BlockManagerInfo: Added broadcast_10_piece0 in memory on 10.111.21.81:38534 (size: 4.6 KB, free: 12.9 GB)
15/12/13 18:03:24 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 20 to 10.111.21.67:57226
15/12/13 18:03:24 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 20 is 161 bytes
15/12/13 18:03:24 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 20 to 10.111.21.81:58038
15/12/13 18:03:25 INFO TaskSetManager: Finished task 1.0 in stage 14.0 (TID 19) in 527 ms on 10.111.21.67 (1/2)
15/12/13 18:03:25 INFO TaskSetManager: Finished task 0.0 in stage 14.0 (TID 18) in 907 ms on 10.111.21.81 (2/2)
15/12/13 18:03:25 INFO TaskSchedulerImpl: Removed TaskSet 14.0, whose tasks have all completed, from pool
15/12/13 18:03:25 INFO DAGScheduler: ShuffleMapStage 14 (flatMap at ALS.scala:1124) finished in 0.909 s
15/12/13 18:03:25 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:25 INFO DAGScheduler: running: Set()
15/12/13 18:03:25 INFO DAGScheduler: waiting: Set(ShuffleMapStage 15, ShuffleMapStage 30, ShuffleMapStage 16, ResultStage 31, ShuffleMapStage 17, ShuffleMapStage 24, ShuffleMapStage 18, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 19, ShuffleMapStage 20, ShuffleMapStage 21, ShuffleMapStage 28, ShuffleMapStage 22, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:25 INFO DAGScheduler: failed: Set()
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 15: List()
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 16: List(ShuffleMapStage 15)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 17: List(ShuffleMapStage 16)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 18: List(ShuffleMapStage 17)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 19: List(ShuffleMapStage 18)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 20: List(ShuffleMapStage 19)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 21: List(ShuffleMapStage 20)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 22: List(ShuffleMapStage 21)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:25 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List(ShuffleMapStage 22)
15/12/13 18:03:25 INFO DAGScheduler: Submitting ShuffleMapStage 15 (MapPartitionsRDD[57] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:25 INFO MemoryStore: ensureFreeSpace(12600) called with curMem=280235, maxMem=2223023063
15/12/13 18:03:25 INFO MemoryStore: Block broadcast_11 stored as values in memory (estimated size 12.3 KB, free 2.1 GB)
15/12/13 18:03:25 INFO MemoryStore: ensureFreeSpace(4962) called with curMem=292835, maxMem=2223023063
15/12/13 18:03:25 INFO MemoryStore: Block broadcast_11_piece0 stored as bytes in memory (estimated size 4.8 KB, free 2.1 GB)
15/12/13 18:03:25 INFO BlockManagerInfo: Added broadcast_11_piece0 in memory on 10.112.21.66:47648 (size: 4.8 KB, free: 2.1 GB)
15/12/13 18:03:25 INFO SparkContext: Created broadcast 11 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:25 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 15 (MapPartitionsRDD[57] at flatMap at ALS.scala:1124)
15/12/13 18:03:25 INFO TaskSchedulerImpl: Adding task set 15.0 with 2 tasks
15/12/13 18:03:25 INFO TaskSetManager: Starting task 1.0 in stage 15.0 (TID 20, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:25 INFO TaskSetManager: Starting task 0.0 in stage 15.0 (TID 21, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:25 INFO BlockManagerInfo: Added broadcast_11_piece0 in memory on 10.111.21.67:52391 (size: 4.8 KB, free: 12.9 GB)
15/12/13 18:03:25 INFO BlockManagerInfo: Added broadcast_11_piece0 in memory on 10.111.21.81:38534 (size: 4.8 KB, free: 12.9 GB)
15/12/13 18:03:25 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 19 to 10.111.21.67:57226
15/12/13 18:03:25 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 19 is 164 bytes
15/12/13 18:03:25 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 19 to 10.111.21.81:58038
15/12/13 18:03:27 INFO TaskSetManager: Finished task 1.0 in stage 15.0 (TID 20) in 1651 ms on 10.111.21.81 (1/2)
15/12/13 18:03:27 INFO TaskSetManager: Finished task 0.0 in stage 15.0 (TID 21) in 1663 ms on 10.111.21.67 (2/2)
15/12/13 18:03:27 INFO TaskSchedulerImpl: Removed TaskSet 15.0, whose tasks have all completed, from pool
15/12/13 18:03:27 INFO DAGScheduler: ShuffleMapStage 15 (flatMap at ALS.scala:1124) finished in 1.664 s
15/12/13 18:03:27 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:27 INFO DAGScheduler: running: Set()
15/12/13 18:03:27 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ShuffleMapStage 16, ResultStage 31, ShuffleMapStage 17, ShuffleMapStage 24, ShuffleMapStage 18, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 19, ShuffleMapStage 20, ShuffleMapStage 21, ShuffleMapStage 28, ShuffleMapStage 22, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:27 INFO DAGScheduler: failed: Set()
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 16: List()
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 17: List(ShuffleMapStage 16)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 18: List(ShuffleMapStage 17)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 19: List(ShuffleMapStage 18)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 20: List(ShuffleMapStage 19)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 21: List(ShuffleMapStage 20)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 22: List(ShuffleMapStage 21)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:27 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List(ShuffleMapStage 22)
15/12/13 18:03:27 INFO DAGScheduler: Submitting ShuffleMapStage 16 (MapPartitionsRDD[66] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:27 INFO MemoryStore: ensureFreeSpace(13448) called with curMem=297797, maxMem=2223023063
15/12/13 18:03:27 INFO MemoryStore: Block broadcast_12 stored as values in memory (estimated size 13.1 KB, free 2.1 GB)
15/12/13 18:03:27 INFO MemoryStore: ensureFreeSpace(5101) called with curMem=311245, maxMem=2223023063
15/12/13 18:03:27 INFO MemoryStore: Block broadcast_12_piece0 stored as bytes in memory (estimated size 5.0 KB, free 2.1 GB)
15/12/13 18:03:27 INFO BlockManagerInfo: Added broadcast_12_piece0 in memory on 10.112.21.66:47648 (size: 5.0 KB, free: 2.1 GB)
15/12/13 18:03:27 INFO SparkContext: Created broadcast 12 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:27 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 16 (MapPartitionsRDD[66] at flatMap at ALS.scala:1124)
15/12/13 18:03:27 INFO TaskSchedulerImpl: Adding task set 16.0 with 2 tasks
15/12/13 18:03:27 INFO TaskSetManager: Starting task 1.0 in stage 16.0 (TID 22, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:27 INFO TaskSetManager: Starting task 0.0 in stage 16.0 (TID 23, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:27 INFO BlockManagerInfo: Added broadcast_12_piece0 in memory on 10.111.21.67:52391 (size: 5.0 KB, free: 12.9 GB)
15/12/13 18:03:27 INFO BlockManagerInfo: Added broadcast_12_piece0 in memory on 10.111.21.81:38534 (size: 5.0 KB, free: 12.9 GB)
15/12/13 18:03:27 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 18 to 10.111.21.67:57226
15/12/13 18:03:27 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 18 is 161 bytes
15/12/13 18:03:27 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 18 to 10.111.21.81:58038
15/12/13 18:03:28 INFO TaskSetManager: Finished task 1.0 in stage 16.0 (TID 22) in 516 ms on 10.111.21.67 (1/2)
15/12/13 18:03:28 INFO TaskSetManager: Finished task 0.0 in stage 16.0 (TID 23) in 900 ms on 10.111.21.81 (2/2)
15/12/13 18:03:28 INFO DAGScheduler: ShuffleMapStage 16 (flatMap at ALS.scala:1124) finished in 0.903 s
15/12/13 18:03:28 INFO TaskSchedulerImpl: Removed TaskSet 16.0, whose tasks have all completed, from pool
15/12/13 18:03:28 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:28 INFO DAGScheduler: running: Set()
15/12/13 18:03:28 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 17, ShuffleMapStage 24, ShuffleMapStage 18, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 19, ShuffleMapStage 20, ShuffleMapStage 21, ShuffleMapStage 28, ShuffleMapStage 22, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:28 INFO DAGScheduler: failed: Set()
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 17: List()
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 18: List(ShuffleMapStage 17)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 19: List(ShuffleMapStage 18)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 20: List(ShuffleMapStage 19)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 21: List(ShuffleMapStage 20)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 22: List(ShuffleMapStage 21)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:28 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List(ShuffleMapStage 22)
15/12/13 18:03:28 INFO DAGScheduler: Submitting ShuffleMapStage 17 (MapPartitionsRDD[75] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:28 INFO MemoryStore: ensureFreeSpace(14296) called with curMem=316346, maxMem=2223023063
15/12/13 18:03:28 INFO MemoryStore: Block broadcast_13 stored as values in memory (estimated size 14.0 KB, free 2.1 GB)
15/12/13 18:03:28 INFO MemoryStore: ensureFreeSpace(5275) called with curMem=330642, maxMem=2223023063
15/12/13 18:03:28 INFO MemoryStore: Block broadcast_13_piece0 stored as bytes in memory (estimated size 5.2 KB, free 2.1 GB)
15/12/13 18:03:28 INFO BlockManagerInfo: Added broadcast_13_piece0 in memory on 10.112.21.66:47648 (size: 5.2 KB, free: 2.1 GB)
15/12/13 18:03:28 INFO SparkContext: Created broadcast 13 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:28 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 17 (MapPartitionsRDD[75] at flatMap at ALS.scala:1124)
15/12/13 18:03:28 INFO TaskSchedulerImpl: Adding task set 17.0 with 2 tasks
15/12/13 18:03:28 INFO TaskSetManager: Starting task 0.0 in stage 17.0 (TID 24, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:28 INFO TaskSetManager: Starting task 1.0 in stage 17.0 (TID 25, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:28 INFO BlockManagerInfo: Added broadcast_13_piece0 in memory on 10.111.21.81:38534 (size: 5.2 KB, free: 12.9 GB)
15/12/13 18:03:28 INFO BlockManagerInfo: Added broadcast_13_piece0 in memory on 10.111.21.67:52391 (size: 5.2 KB, free: 12.9 GB)
15/12/13 18:03:28 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 17 to 10.111.21.81:58038
15/12/13 18:03:28 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 17 is 164 bytes
15/12/13 18:03:28 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 17 to 10.111.21.67:57226
15/12/13 18:03:30 INFO TaskSetManager: Finished task 1.0 in stage 17.0 (TID 25) in 1659 ms on 10.111.21.81 (1/2)
15/12/13 18:03:30 INFO TaskSetManager: Finished task 0.0 in stage 17.0 (TID 24) in 1691 ms on 10.111.21.67 (2/2)
15/12/13 18:03:30 INFO TaskSchedulerImpl: Removed TaskSet 17.0, whose tasks have all completed, from pool
15/12/13 18:03:30 INFO DAGScheduler: ShuffleMapStage 17 (flatMap at ALS.scala:1124) finished in 1.692 s
15/12/13 18:03:30 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:30 INFO DAGScheduler: running: Set()
15/12/13 18:03:30 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 24, ShuffleMapStage 18, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 19, ShuffleMapStage 20, ShuffleMapStage 21, ShuffleMapStage 28, ShuffleMapStage 22, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:30 INFO DAGScheduler: failed: Set()
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 18: List()
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 19: List(ShuffleMapStage 18)
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 20: List(ShuffleMapStage 19)
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 21: List(ShuffleMapStage 20)
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 22: List(ShuffleMapStage 21)
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:30 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List(ShuffleMapStage 22)
15/12/13 18:03:30 INFO DAGScheduler: Submitting ShuffleMapStage 18 (MapPartitionsRDD[84] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:30 INFO MemoryStore: ensureFreeSpace(15144) called with curMem=335917, maxMem=2223023063
15/12/13 18:03:30 INFO MemoryStore: Block broadcast_14 stored as values in memory (estimated size 14.8 KB, free 2.1 GB)
15/12/13 18:03:30 INFO MemoryStore: ensureFreeSpace(5444) called with curMem=351061, maxMem=2223023063
15/12/13 18:03:30 INFO MemoryStore: Block broadcast_14_piece0 stored as bytes in memory (estimated size 5.3 KB, free 2.1 GB)
15/12/13 18:03:30 INFO BlockManagerInfo: Added broadcast_14_piece0 in memory on 10.112.21.66:47648 (size: 5.3 KB, free: 2.1 GB)
15/12/13 18:03:30 INFO SparkContext: Created broadcast 14 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:30 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 18 (MapPartitionsRDD[84] at flatMap at ALS.scala:1124)
15/12/13 18:03:30 INFO TaskSchedulerImpl: Adding task set 18.0 with 2 tasks
15/12/13 18:03:30 INFO TaskSetManager: Starting task 1.0 in stage 18.0 (TID 26, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:30 INFO TaskSetManager: Starting task 0.0 in stage 18.0 (TID 27, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:30 INFO BlockManagerInfo: Added broadcast_14_piece0 in memory on 10.111.21.67:52391 (size: 5.3 KB, free: 12.9 GB)
15/12/13 18:03:30 INFO BlockManagerInfo: Added broadcast_14_piece0 in memory on 10.111.21.81:38534 (size: 5.3 KB, free: 12.9 GB)
15/12/13 18:03:30 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 16 to 10.111.21.81:58038
15/12/13 18:03:30 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 16 is 161 bytes
15/12/13 18:03:30 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 16 to 10.111.21.67:57226
15/12/13 18:03:30 INFO TaskSetManager: Finished task 1.0 in stage 18.0 (TID 26) in 520 ms on 10.111.21.67 (1/2)
15/12/13 18:03:31 INFO TaskSetManager: Finished task 0.0 in stage 18.0 (TID 27) in 898 ms on 10.111.21.81 (2/2)
15/12/13 18:03:31 INFO TaskSchedulerImpl: Removed TaskSet 18.0, whose tasks have all completed, from pool
15/12/13 18:03:31 INFO DAGScheduler: ShuffleMapStage 18 (flatMap at ALS.scala:1124) finished in 0.901 s
15/12/13 18:03:31 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:31 INFO DAGScheduler: running: Set()
15/12/13 18:03:31 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 24, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 19, ShuffleMapStage 20, ShuffleMapStage 21, ShuffleMapStage 28, ShuffleMapStage 22, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:31 INFO DAGScheduler: failed: Set()
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ShuffleMapStage 19: List()
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ShuffleMapStage 20: List(ShuffleMapStage 19)
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ShuffleMapStage 21: List(ShuffleMapStage 20)
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ShuffleMapStage 22: List(ShuffleMapStage 21)
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:31 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List(ShuffleMapStage 22)
15/12/13 18:03:31 INFO DAGScheduler: Submitting ShuffleMapStage 19 (MapPartitionsRDD[93] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:31 INFO MemoryStore: ensureFreeSpace(15992) called with curMem=356505, maxMem=2223023063
15/12/13 18:03:31 INFO MemoryStore: Block broadcast_15 stored as values in memory (estimated size 15.6 KB, free 2.1 GB)
15/12/13 18:03:31 INFO MemoryStore: ensureFreeSpace(5643) called with curMem=372497, maxMem=2223023063
15/12/13 18:03:31 INFO MemoryStore: Block broadcast_15_piece0 stored as bytes in memory (estimated size 5.5 KB, free 2.1 GB)
15/12/13 18:03:31 INFO BlockManagerInfo: Added broadcast_15_piece0 in memory on 10.112.21.66:47648 (size: 5.5 KB, free: 2.1 GB)
15/12/13 18:03:31 INFO SparkContext: Created broadcast 15 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:31 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 19 (MapPartitionsRDD[93] at flatMap at ALS.scala:1124)
15/12/13 18:03:31 INFO TaskSchedulerImpl: Adding task set 19.0 with 2 tasks
15/12/13 18:03:31 INFO TaskSetManager: Starting task 0.0 in stage 19.0 (TID 28, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:31 INFO TaskSetManager: Starting task 1.0 in stage 19.0 (TID 29, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:31 INFO BlockManagerInfo: Added broadcast_15_piece0 in memory on 10.111.21.67:52391 (size: 5.5 KB, free: 12.9 GB)
15/12/13 18:03:31 INFO BlockManagerInfo: Added broadcast_15_piece0 in memory on 10.111.21.81:38534 (size: 5.5 KB, free: 12.9 GB)
15/12/13 18:03:31 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 15 to 10.111.21.67:57226
15/12/13 18:03:31 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 15 is 164 bytes
15/12/13 18:03:31 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 15 to 10.111.21.81:58038
15/12/13 18:03:32 INFO TaskSetManager: Finished task 1.0 in stage 19.0 (TID 29) in 1661 ms on 10.111.21.81 (1/2)
15/12/13 18:03:32 INFO TaskSetManager: Finished task 0.0 in stage 19.0 (TID 28) in 1694 ms on 10.111.21.67 (2/2)
15/12/13 18:03:32 INFO TaskSchedulerImpl: Removed TaskSet 19.0, whose tasks have all completed, from pool
15/12/13 18:03:32 INFO DAGScheduler: ShuffleMapStage 19 (flatMap at ALS.scala:1124) finished in 1.695 s
15/12/13 18:03:32 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:32 INFO DAGScheduler: running: Set()
15/12/13 18:03:32 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 24, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 20, ShuffleMapStage 21, ShuffleMapStage 28, ShuffleMapStage 22, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:32 INFO DAGScheduler: failed: Set()
15/12/13 18:03:32 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:32 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:32 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:32 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:32 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:32 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:32 INFO DAGScheduler: Missing parents for ShuffleMapStage 20: List()
15/12/13 18:03:32 INFO DAGScheduler: Missing parents for ShuffleMapStage 21: List(ShuffleMapStage 20)
15/12/13 18:03:32 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:32 INFO DAGScheduler: Missing parents for ShuffleMapStage 22: List(ShuffleMapStage 21)
15/12/13 18:03:32 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:32 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List(ShuffleMapStage 22)
15/12/13 18:03:32 INFO DAGScheduler: Submitting ShuffleMapStage 20 (MapPartitionsRDD[102] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:32 INFO MemoryStore: ensureFreeSpace(16840) called with curMem=378140, maxMem=2223023063
15/12/13 18:03:32 INFO MemoryStore: Block broadcast_16 stored as values in memory (estimated size 16.4 KB, free 2.1 GB)
15/12/13 18:03:32 INFO MemoryStore: ensureFreeSpace(5797) called with curMem=394980, maxMem=2223023063
15/12/13 18:03:32 INFO MemoryStore: Block broadcast_16_piece0 stored as bytes in memory (estimated size 5.7 KB, free 2.1 GB)
15/12/13 18:03:32 INFO BlockManagerInfo: Added broadcast_16_piece0 in memory on 10.112.21.66:47648 (size: 5.7 KB, free: 2.1 GB)
15/12/13 18:03:32 INFO SparkContext: Created broadcast 16 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:32 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 20 (MapPartitionsRDD[102] at flatMap at ALS.scala:1124)
15/12/13 18:03:32 INFO TaskSchedulerImpl: Adding task set 20.0 with 2 tasks
15/12/13 18:03:32 INFO TaskSetManager: Starting task 0.0 in stage 20.0 (TID 30, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:32 INFO TaskSetManager: Starting task 1.0 in stage 20.0 (TID 31, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:32 INFO BlockManagerInfo: Added broadcast_16_piece0 in memory on 10.111.21.67:52391 (size: 5.7 KB, free: 12.9 GB)
15/12/13 18:03:32 INFO BlockManagerInfo: Added broadcast_16_piece0 in memory on 10.111.21.81:38534 (size: 5.7 KB, free: 12.9 GB)
15/12/13 18:03:32 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 14 to 10.111.21.81:58038
15/12/13 18:03:32 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 14 is 161 bytes
15/12/13 18:03:32 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 14 to 10.111.21.67:57226
15/12/13 18:03:33 INFO TaskSetManager: Finished task 1.0 in stage 20.0 (TID 31) in 516 ms on 10.111.21.67 (1/2)
15/12/13 18:03:33 INFO TaskSetManager: Finished task 0.0 in stage 20.0 (TID 30) in 901 ms on 10.111.21.81 (2/2)
15/12/13 18:03:33 INFO DAGScheduler: ShuffleMapStage 20 (flatMap at ALS.scala:1124) finished in 0.901 s
15/12/13 18:03:33 INFO TaskSchedulerImpl: Removed TaskSet 20.0, whose tasks have all completed, from pool
15/12/13 18:03:33 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:33 INFO DAGScheduler: running: Set()
15/12/13 18:03:33 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 24, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 21, ShuffleMapStage 28, ShuffleMapStage 22, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:33 INFO DAGScheduler: failed: Set()
15/12/13 18:03:33 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:33 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:33 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:33 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:33 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:33 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:33 INFO DAGScheduler: Missing parents for ShuffleMapStage 21: List()
15/12/13 18:03:33 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:33 INFO DAGScheduler: Missing parents for ShuffleMapStage 22: List(ShuffleMapStage 21)
15/12/13 18:03:33 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:33 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List(ShuffleMapStage 22)
15/12/13 18:03:33 INFO DAGScheduler: Submitting ShuffleMapStage 21 (MapPartitionsRDD[111] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:33 INFO MemoryStore: ensureFreeSpace(17688) called with curMem=400777, maxMem=2223023063
15/12/13 18:03:33 INFO MemoryStore: Block broadcast_17 stored as values in memory (estimated size 17.3 KB, free 2.1 GB)
15/12/13 18:03:33 INFO MemoryStore: ensureFreeSpace(5975) called with curMem=418465, maxMem=2223023063
15/12/13 18:03:33 INFO MemoryStore: Block broadcast_17_piece0 stored as bytes in memory (estimated size 5.8 KB, free 2.1 GB)
15/12/13 18:03:33 INFO BlockManagerInfo: Added broadcast_17_piece0 in memory on 10.112.21.66:47648 (size: 5.8 KB, free: 2.1 GB)
15/12/13 18:03:33 INFO SparkContext: Created broadcast 17 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:33 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 21 (MapPartitionsRDD[111] at flatMap at ALS.scala:1124)
15/12/13 18:03:33 INFO TaskSchedulerImpl: Adding task set 21.0 with 2 tasks
15/12/13 18:03:33 INFO TaskSetManager: Starting task 1.0 in stage 21.0 (TID 32, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:33 INFO TaskSetManager: Starting task 0.0 in stage 21.0 (TID 33, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:33 INFO BlockManagerInfo: Added broadcast_17_piece0 in memory on 10.111.21.81:38534 (size: 5.8 KB, free: 12.9 GB)
15/12/13 18:03:33 INFO BlockManagerInfo: Added broadcast_17_piece0 in memory on 10.111.21.67:52391 (size: 5.8 KB, free: 12.9 GB)
15/12/13 18:03:33 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 13 to 10.111.21.81:58038
15/12/13 18:03:33 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 13 is 164 bytes
15/12/13 18:03:33 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 13 to 10.111.21.67:57226
15/12/13 18:03:35 INFO TaskSetManager: Finished task 1.0 in stage 21.0 (TID 32) in 1662 ms on 10.111.21.81 (1/2)
15/12/13 18:03:35 INFO TaskSetManager: Finished task 0.0 in stage 21.0 (TID 33) in 1667 ms on 10.111.21.67 (2/2)
15/12/13 18:03:35 INFO DAGScheduler: ShuffleMapStage 21 (flatMap at ALS.scala:1124) finished in 1.668 s
15/12/13 18:03:35 INFO TaskSchedulerImpl: Removed TaskSet 21.0, whose tasks have all completed, from pool
15/12/13 18:03:35 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:35 INFO DAGScheduler: running: Set()
15/12/13 18:03:35 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 24, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 28, ShuffleMapStage 22, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:35 INFO DAGScheduler: failed: Set()
15/12/13 18:03:35 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:35 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:35 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:35 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:35 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:35 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:35 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:35 INFO DAGScheduler: Missing parents for ShuffleMapStage 22: List()
15/12/13 18:03:35 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:35 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List(ShuffleMapStage 22)
15/12/13 18:03:35 INFO DAGScheduler: Submitting ShuffleMapStage 22 (MapPartitionsRDD[120] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:35 INFO MemoryStore: ensureFreeSpace(18536) called with curMem=424440, maxMem=2223023063
15/12/13 18:03:35 INFO MemoryStore: Block broadcast_18 stored as values in memory (estimated size 18.1 KB, free 2.1 GB)
15/12/13 18:03:35 INFO MemoryStore: ensureFreeSpace(6158) called with curMem=442976, maxMem=2223023063
15/12/13 18:03:35 INFO MemoryStore: Block broadcast_18_piece0 stored as bytes in memory (estimated size 6.0 KB, free 2.1 GB)
15/12/13 18:03:35 INFO BlockManagerInfo: Added broadcast_18_piece0 in memory on 10.112.21.66:47648 (size: 6.0 KB, free: 2.1 GB)
15/12/13 18:03:35 INFO SparkContext: Created broadcast 18 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:35 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 22 (MapPartitionsRDD[120] at flatMap at ALS.scala:1124)
15/12/13 18:03:35 INFO TaskSchedulerImpl: Adding task set 22.0 with 2 tasks
15/12/13 18:03:35 INFO TaskSetManager: Starting task 1.0 in stage 22.0 (TID 34, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:35 INFO TaskSetManager: Starting task 0.0 in stage 22.0 (TID 35, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:35 INFO BlockManagerInfo: Added broadcast_18_piece0 in memory on 10.111.21.67:52391 (size: 6.0 KB, free: 12.9 GB)
15/12/13 18:03:35 INFO BlockManagerInfo: Added broadcast_18_piece0 in memory on 10.111.21.81:38534 (size: 6.0 KB, free: 12.9 GB)
15/12/13 18:03:35 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 12 to 10.111.21.67:57226
15/12/13 18:03:35 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 12 is 161 bytes
15/12/13 18:03:35 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 12 to 10.111.21.81:58038
15/12/13 18:03:35 INFO TaskSetManager: Finished task 1.0 in stage 22.0 (TID 34) in 508 ms on 10.111.21.67 (1/2)
15/12/13 18:03:36 INFO TaskSetManager: Finished task 0.0 in stage 22.0 (TID 35) in 895 ms on 10.111.21.81 (2/2)
15/12/13 18:03:36 INFO TaskSchedulerImpl: Removed TaskSet 22.0, whose tasks have all completed, from pool
15/12/13 18:03:36 INFO DAGScheduler: ShuffleMapStage 22 (flatMap at ALS.scala:1124) finished in 0.896 s
15/12/13 18:03:36 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:36 INFO DAGScheduler: running: Set()
15/12/13 18:03:36 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 24, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 28, ShuffleMapStage 29, ShuffleMapStage 23)
15/12/13 18:03:36 INFO DAGScheduler: failed: Set()
15/12/13 18:03:36 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:36 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:36 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List(ShuffleMapStage 23)
15/12/13 18:03:36 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:36 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:36 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:36 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:36 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:36 INFO DAGScheduler: Missing parents for ShuffleMapStage 23: List()
15/12/13 18:03:36 INFO DAGScheduler: Submitting ShuffleMapStage 23 (MapPartitionsRDD[129] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:36 INFO MemoryStore: ensureFreeSpace(19384) called with curMem=449134, maxMem=2223023063
15/12/13 18:03:36 INFO MemoryStore: Block broadcast_19 stored as values in memory (estimated size 18.9 KB, free 2.1 GB)
15/12/13 18:03:36 INFO MemoryStore: ensureFreeSpace(6341) called with curMem=468518, maxMem=2223023063
15/12/13 18:03:36 INFO MemoryStore: Block broadcast_19_piece0 stored as bytes in memory (estimated size 6.2 KB, free 2.1 GB)
15/12/13 18:03:36 INFO BlockManagerInfo: Added broadcast_19_piece0 in memory on 10.112.21.66:47648 (size: 6.2 KB, free: 2.1 GB)
15/12/13 18:03:36 INFO SparkContext: Created broadcast 19 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:36 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 23 (MapPartitionsRDD[129] at flatMap at ALS.scala:1124)
15/12/13 18:03:36 INFO TaskSchedulerImpl: Adding task set 23.0 with 2 tasks
15/12/13 18:03:36 INFO TaskSetManager: Starting task 0.0 in stage 23.0 (TID 36, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:36 INFO TaskSetManager: Starting task 1.0 in stage 23.0 (TID 37, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:36 INFO BlockManagerInfo: Added broadcast_19_piece0 in memory on 10.111.21.67:52391 (size: 6.2 KB, free: 12.9 GB)
15/12/13 18:03:36 INFO BlockManagerInfo: Added broadcast_19_piece0 in memory on 10.111.21.81:38534 (size: 6.2 KB, free: 12.9 GB)
15/12/13 18:03:36 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 11 to 10.111.21.81:58038
15/12/13 18:03:36 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 11 is 164 bytes
15/12/13 18:03:36 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 11 to 10.111.21.67:57226
15/12/13 18:03:37 INFO TaskSetManager: Finished task 1.0 in stage 23.0 (TID 37) in 1644 ms on 10.111.21.81 (1/2)
15/12/13 18:03:37 INFO TaskSetManager: Finished task 0.0 in stage 23.0 (TID 36) in 1673 ms on 10.111.21.67 (2/2)
15/12/13 18:03:37 INFO DAGScheduler: ShuffleMapStage 23 (flatMap at ALS.scala:1124) finished in 1.673 s
15/12/13 18:03:37 INFO TaskSchedulerImpl: Removed TaskSet 23.0, whose tasks have all completed, from pool
15/12/13 18:03:37 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:37 INFO DAGScheduler: running: Set()
15/12/13 18:03:37 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 24, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 28, ShuffleMapStage 29)
15/12/13 18:03:37 INFO DAGScheduler: failed: Set()
15/12/13 18:03:37 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:37 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:37 INFO DAGScheduler: Missing parents for ShuffleMapStage 24: List()
15/12/13 18:03:37 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List(ShuffleMapStage 24)
15/12/13 18:03:37 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:37 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:37 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:37 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:37 INFO DAGScheduler: Submitting ShuffleMapStage 24 (MapPartitionsRDD[138] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:37 INFO MemoryStore: ensureFreeSpace(20232) called with curMem=474859, maxMem=2223023063
15/12/13 18:03:37 INFO MemoryStore: Block broadcast_20 stored as values in memory (estimated size 19.8 KB, free 2.1 GB)
15/12/13 18:03:37 INFO MemoryStore: ensureFreeSpace(6496) called with curMem=495091, maxMem=2223023063
15/12/13 18:03:37 INFO MemoryStore: Block broadcast_20_piece0 stored as bytes in memory (estimated size 6.3 KB, free 2.1 GB)
15/12/13 18:03:37 INFO BlockManagerInfo: Added broadcast_20_piece0 in memory on 10.112.21.66:47648 (size: 6.3 KB, free: 2.1 GB)
15/12/13 18:03:37 INFO SparkContext: Created broadcast 20 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:37 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 24 (MapPartitionsRDD[138] at flatMap at ALS.scala:1124)
15/12/13 18:03:37 INFO TaskSchedulerImpl: Adding task set 24.0 with 2 tasks
15/12/13 18:03:37 INFO TaskSetManager: Starting task 0.0 in stage 24.0 (TID 38, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:37 INFO TaskSetManager: Starting task 1.0 in stage 24.0 (TID 39, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:38 INFO BlockManagerInfo: Added broadcast_20_piece0 in memory on 10.111.21.67:52391 (size: 6.3 KB, free: 12.9 GB)
15/12/13 18:03:38 INFO BlockManagerInfo: Added broadcast_20_piece0 in memory on 10.111.21.81:38534 (size: 6.3 KB, free: 12.9 GB)
15/12/13 18:03:38 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 10 to 10.111.21.67:57226
15/12/13 18:03:38 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 10 is 161 bytes
15/12/13 18:03:38 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 10 to 10.111.21.81:58038
15/12/13 18:03:38 INFO TaskSetManager: Finished task 1.0 in stage 24.0 (TID 39) in 506 ms on 10.111.21.67 (1/2)
15/12/13 18:03:38 INFO TaskSetManager: Finished task 0.0 in stage 24.0 (TID 38) in 884 ms on 10.111.21.81 (2/2)
15/12/13 18:03:38 INFO DAGScheduler: ShuffleMapStage 24 (flatMap at ALS.scala:1124) finished in 0.885 s
15/12/13 18:03:38 INFO TaskSchedulerImpl: Removed TaskSet 24.0, whose tasks have all completed, from pool
15/12/13 18:03:38 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:38 INFO DAGScheduler: running: Set()
15/12/13 18:03:38 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 25, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 28, ShuffleMapStage 29)
15/12/13 18:03:38 INFO DAGScheduler: failed: Set()
15/12/13 18:03:38 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:38 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:38 INFO DAGScheduler: Missing parents for ShuffleMapStage 25: List()
15/12/13 18:03:38 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List(ShuffleMapStage 25)
15/12/13 18:03:38 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:38 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:38 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:38 INFO DAGScheduler: Submitting ShuffleMapStage 25 (MapPartitionsRDD[147] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:38 INFO MemoryStore: ensureFreeSpace(21080) called with curMem=501587, maxMem=2223023063
15/12/13 18:03:38 INFO MemoryStore: Block broadcast_21 stored as values in memory (estimated size 20.6 KB, free 2.1 GB)
15/12/13 18:03:38 INFO MemoryStore: ensureFreeSpace(6666) called with curMem=522667, maxMem=2223023063
15/12/13 18:03:38 INFO MemoryStore: Block broadcast_21_piece0 stored as bytes in memory (estimated size 6.5 KB, free 2.1 GB)
15/12/13 18:03:38 INFO BlockManagerInfo: Added broadcast_21_piece0 in memory on 10.112.21.66:47648 (size: 6.5 KB, free: 2.1 GB)
15/12/13 18:03:38 INFO SparkContext: Created broadcast 21 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:38 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 25 (MapPartitionsRDD[147] at flatMap at ALS.scala:1124)
15/12/13 18:03:38 INFO TaskSchedulerImpl: Adding task set 25.0 with 2 tasks
15/12/13 18:03:38 INFO TaskSetManager: Starting task 1.0 in stage 25.0 (TID 40, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:38 INFO TaskSetManager: Starting task 0.0 in stage 25.0 (TID 41, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:38 INFO BlockManagerInfo: Added broadcast_21_piece0 in memory on 10.111.21.81:38534 (size: 6.5 KB, free: 12.9 GB)
15/12/13 18:03:38 INFO BlockManagerInfo: Added broadcast_21_piece0 in memory on 10.111.21.67:52391 (size: 6.5 KB, free: 12.9 GB)
15/12/13 18:03:38 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 9 to 10.111.21.81:58038
15/12/13 18:03:38 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 9 is 164 bytes
15/12/13 18:03:38 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 9 to 10.111.21.67:57226
15/12/13 18:03:40 INFO TaskSetManager: Finished task 1.0 in stage 25.0 (TID 40) in 1641 ms on 10.111.21.81 (1/2)
15/12/13 18:03:40 INFO TaskSetManager: Finished task 0.0 in stage 25.0 (TID 41) in 1724 ms on 10.111.21.67 (2/2)
15/12/13 18:03:40 INFO DAGScheduler: ShuffleMapStage 25 (flatMap at ALS.scala:1124) finished in 1.726 s
15/12/13 18:03:40 INFO TaskSchedulerImpl: Removed TaskSet 25.0, whose tasks have all completed, from pool
15/12/13 18:03:40 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:40 INFO DAGScheduler: running: Set()
15/12/13 18:03:40 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 26, ShuffleMapStage 27, ShuffleMapStage 28, ShuffleMapStage 29)
15/12/13 18:03:40 INFO DAGScheduler: failed: Set()
15/12/13 18:03:40 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:40 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:40 INFO DAGScheduler: Missing parents for ShuffleMapStage 26: List()
15/12/13 18:03:40 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List(ShuffleMapStage 26)
15/12/13 18:03:40 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:40 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:40 INFO DAGScheduler: Submitting ShuffleMapStage 26 (MapPartitionsRDD[156] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:40 INFO MemoryStore: ensureFreeSpace(21928) called with curMem=529333, maxMem=2223023063
15/12/13 18:03:40 INFO MemoryStore: Block broadcast_22 stored as values in memory (estimated size 21.4 KB, free 2.1 GB)
15/12/13 18:03:40 INFO MemoryStore: ensureFreeSpace(6832) called with curMem=551261, maxMem=2223023063
15/12/13 18:03:40 INFO MemoryStore: Block broadcast_22_piece0 stored as bytes in memory (estimated size 6.7 KB, free 2.1 GB)
15/12/13 18:03:40 INFO BlockManagerInfo: Added broadcast_22_piece0 in memory on 10.112.21.66:47648 (size: 6.7 KB, free: 2.1 GB)
15/12/13 18:03:40 INFO SparkContext: Created broadcast 22 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:40 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 26 (MapPartitionsRDD[156] at flatMap at ALS.scala:1124)
15/12/13 18:03:40 INFO TaskSchedulerImpl: Adding task set 26.0 with 2 tasks
15/12/13 18:03:40 INFO TaskSetManager: Starting task 1.0 in stage 26.0 (TID 42, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:40 INFO TaskSetManager: Starting task 0.0 in stage 26.0 (TID 43, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:40 INFO BlockManagerInfo: Added broadcast_22_piece0 in memory on 10.111.21.67:52391 (size: 6.7 KB, free: 12.9 GB)
15/12/13 18:03:40 INFO BlockManagerInfo: Added broadcast_22_piece0 in memory on 10.111.21.81:38534 (size: 6.7 KB, free: 12.9 GB)
15/12/13 18:03:40 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 8 to 10.111.21.67:57226
15/12/13 18:03:40 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 8 is 161 bytes
15/12/13 18:03:40 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 8 to 10.111.21.81:58038
15/12/13 18:03:41 INFO TaskSetManager: Finished task 1.0 in stage 26.0 (TID 42) in 509 ms on 10.111.21.67 (1/2)
15/12/13 18:03:41 INFO TaskSetManager: Finished task 0.0 in stage 26.0 (TID 43) in 929 ms on 10.111.21.81 (2/2)
15/12/13 18:03:41 INFO TaskSchedulerImpl: Removed TaskSet 26.0, whose tasks have all completed, from pool
15/12/13 18:03:41 INFO DAGScheduler: ShuffleMapStage 26 (flatMap at ALS.scala:1124) finished in 0.930 s
15/12/13 18:03:41 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:41 INFO DAGScheduler: running: Set()
15/12/13 18:03:41 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 27, ShuffleMapStage 28, ShuffleMapStage 29)
15/12/13 18:03:41 INFO DAGScheduler: failed: Set()
15/12/13 18:03:41 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:41 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:41 INFO DAGScheduler: Missing parents for ShuffleMapStage 27: List()
15/12/13 18:03:41 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List(ShuffleMapStage 27)
15/12/13 18:03:41 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:41 INFO DAGScheduler: Submitting ShuffleMapStage 27 (MapPartitionsRDD[165] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:41 INFO MemoryStore: ensureFreeSpace(22776) called with curMem=558093, maxMem=2223023063
15/12/13 18:03:41 INFO MemoryStore: Block broadcast_23 stored as values in memory (estimated size 22.2 KB, free 2.1 GB)
15/12/13 18:03:41 INFO MemoryStore: ensureFreeSpace(7002) called with curMem=580869, maxMem=2223023063
15/12/13 18:03:41 INFO MemoryStore: Block broadcast_23_piece0 stored as bytes in memory (estimated size 6.8 KB, free 2.1 GB)
15/12/13 18:03:41 INFO BlockManagerInfo: Added broadcast_23_piece0 in memory on 10.112.21.66:47648 (size: 6.8 KB, free: 2.1 GB)
15/12/13 18:03:41 INFO SparkContext: Created broadcast 23 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:41 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 27 (MapPartitionsRDD[165] at flatMap at ALS.scala:1124)
15/12/13 18:03:41 INFO TaskSchedulerImpl: Adding task set 27.0 with 2 tasks
15/12/13 18:03:41 INFO TaskSetManager: Starting task 1.0 in stage 27.0 (TID 44, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:41 INFO TaskSetManager: Starting task 0.0 in stage 27.0 (TID 45, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:41 INFO BlockManagerInfo: Added broadcast_23_piece0 in memory on 10.111.21.81:38534 (size: 6.8 KB, free: 12.9 GB)
15/12/13 18:03:41 INFO BlockManagerInfo: Added broadcast_23_piece0 in memory on 10.111.21.67:52391 (size: 6.8 KB, free: 12.9 GB)
15/12/13 18:03:41 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 7 to 10.111.21.81:58038
15/12/13 18:03:41 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 7 is 164 bytes
15/12/13 18:03:41 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 7 to 10.111.21.67:57226
15/12/13 18:03:43 INFO TaskSetManager: Finished task 1.0 in stage 27.0 (TID 44) in 1633 ms on 10.111.21.81 (1/2)
15/12/13 18:03:43 INFO TaskSetManager: Finished task 0.0 in stage 27.0 (TID 45) in 1664 ms on 10.111.21.67 (2/2)
15/12/13 18:03:43 INFO TaskSchedulerImpl: Removed TaskSet 27.0, whose tasks have all completed, from pool
15/12/13 18:03:43 INFO DAGScheduler: ShuffleMapStage 27 (flatMap at ALS.scala:1124) finished in 1.665 s
15/12/13 18:03:43 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:43 INFO DAGScheduler: running: Set()
15/12/13 18:03:43 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 28, ShuffleMapStage 29)
15/12/13 18:03:43 INFO DAGScheduler: failed: Set()
15/12/13 18:03:43 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:43 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:43 INFO DAGScheduler: Missing parents for ShuffleMapStage 28: List()
15/12/13 18:03:43 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List(ShuffleMapStage 28)
15/12/13 18:03:43 INFO DAGScheduler: Submitting ShuffleMapStage 28 (MapPartitionsRDD[174] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:43 INFO MemoryStore: ensureFreeSpace(23624) called with curMem=587871, maxMem=2223023063
15/12/13 18:03:43 INFO MemoryStore: Block broadcast_24 stored as values in memory (estimated size 23.1 KB, free 2.1 GB)
15/12/13 18:03:43 INFO MemoryStore: ensureFreeSpace(7167) called with curMem=611495, maxMem=2223023063
15/12/13 18:03:43 INFO MemoryStore: Block broadcast_24_piece0 stored as bytes in memory (estimated size 7.0 KB, free 2.1 GB)
15/12/13 18:03:43 INFO BlockManagerInfo: Added broadcast_24_piece0 in memory on 10.112.21.66:47648 (size: 7.0 KB, free: 2.1 GB)
15/12/13 18:03:43 INFO SparkContext: Created broadcast 24 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:43 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 28 (MapPartitionsRDD[174] at flatMap at ALS.scala:1124)
15/12/13 18:03:43 INFO TaskSchedulerImpl: Adding task set 28.0 with 2 tasks
15/12/13 18:03:43 INFO TaskSetManager: Starting task 0.0 in stage 28.0 (TID 46, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:43 INFO TaskSetManager: Starting task 1.0 in stage 28.0 (TID 47, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:43 INFO BlockManagerInfo: Added broadcast_24_piece0 in memory on 10.111.21.67:52391 (size: 7.0 KB, free: 12.9 GB)
15/12/13 18:03:43 INFO BlockManagerInfo: Added broadcast_24_piece0 in memory on 10.111.21.81:38534 (size: 7.0 KB, free: 12.9 GB)
15/12/13 18:03:43 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 6 to 10.111.21.81:58038
15/12/13 18:03:43 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 6 is 161 bytes
15/12/13 18:03:43 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 6 to 10.111.21.67:57226
15/12/13 18:03:43 INFO TaskSetManager: Finished task 1.0 in stage 28.0 (TID 47) in 516 ms on 10.111.21.67 (1/2)
15/12/13 18:03:44 INFO TaskSetManager: Finished task 0.0 in stage 28.0 (TID 46) in 890 ms on 10.111.21.81 (2/2)
15/12/13 18:03:44 INFO TaskSchedulerImpl: Removed TaskSet 28.0, whose tasks have all completed, from pool
15/12/13 18:03:44 INFO DAGScheduler: ShuffleMapStage 28 (flatMap at ALS.scala:1124) finished in 0.891 s
15/12/13 18:03:44 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:44 INFO DAGScheduler: running: Set()
15/12/13 18:03:44 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31, ShuffleMapStage 29)
15/12/13 18:03:44 INFO DAGScheduler: failed: Set()
15/12/13 18:03:44 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List(ShuffleMapStage 29)
15/12/13 18:03:44 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:44 INFO DAGScheduler: Missing parents for ShuffleMapStage 29: List()
15/12/13 18:03:44 INFO DAGScheduler: Submitting ShuffleMapStage 29 (MapPartitionsRDD[183] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:44 INFO MemoryStore: ensureFreeSpace(24472) called with curMem=618662, maxMem=2223023063
15/12/13 18:03:44 INFO MemoryStore: Block broadcast_25 stored as values in memory (estimated size 23.9 KB, free 2.1 GB)
15/12/13 18:03:44 INFO MemoryStore: ensureFreeSpace(7327) called with curMem=643134, maxMem=2223023063
15/12/13 18:03:44 INFO MemoryStore: Block broadcast_25_piece0 stored as bytes in memory (estimated size 7.2 KB, free 2.1 GB)
15/12/13 18:03:44 INFO BlockManagerInfo: Added broadcast_25_piece0 in memory on 10.112.21.66:47648 (size: 7.2 KB, free: 2.1 GB)
15/12/13 18:03:44 INFO SparkContext: Created broadcast 25 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:44 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 29 (MapPartitionsRDD[183] at flatMap at ALS.scala:1124)
15/12/13 18:03:44 INFO TaskSchedulerImpl: Adding task set 29.0 with 2 tasks
15/12/13 18:03:44 INFO TaskSetManager: Starting task 1.0 in stage 29.0 (TID 48, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:44 INFO TaskSetManager: Starting task 0.0 in stage 29.0 (TID 49, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:44 INFO BlockManagerInfo: Added broadcast_25_piece0 in memory on 10.111.21.81:38534 (size: 7.2 KB, free: 12.9 GB)
15/12/13 18:03:44 INFO BlockManagerInfo: Added broadcast_25_piece0 in memory on 10.111.21.67:52391 (size: 7.2 KB, free: 12.9 GB)
15/12/13 18:03:44 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 5 to 10.111.21.81:58038
15/12/13 18:03:44 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 5 is 164 bytes
15/12/13 18:03:44 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 5 to 10.111.21.67:57226
15/12/13 18:03:45 INFO TaskSetManager: Finished task 1.0 in stage 29.0 (TID 48) in 1634 ms on 10.111.21.81 (1/2)
15/12/13 18:03:45 INFO TaskSetManager: Finished task 0.0 in stage 29.0 (TID 49) in 1735 ms on 10.111.21.67 (2/2)
15/12/13 18:03:45 INFO TaskSchedulerImpl: Removed TaskSet 29.0, whose tasks have all completed, from pool
15/12/13 18:03:45 INFO DAGScheduler: ShuffleMapStage 29 (flatMap at ALS.scala:1124) finished in 1.736 s
15/12/13 18:03:45 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:45 INFO DAGScheduler: running: Set()
15/12/13 18:03:45 INFO DAGScheduler: waiting: Set(ShuffleMapStage 30, ResultStage 31)
15/12/13 18:03:45 INFO DAGScheduler: failed: Set()
15/12/13 18:03:45 INFO DAGScheduler: Missing parents for ShuffleMapStage 30: List()
15/12/13 18:03:45 INFO DAGScheduler: Missing parents for ResultStage 31: List(ShuffleMapStage 30)
15/12/13 18:03:45 INFO DAGScheduler: Submitting ShuffleMapStage 30 (MapPartitionsRDD[192] at flatMap at ALS.scala:1124), which is now runnable
15/12/13 18:03:45 INFO MemoryStore: ensureFreeSpace(25320) called with curMem=650461, maxMem=2223023063
15/12/13 18:03:45 INFO MemoryStore: Block broadcast_26 stored as values in memory (estimated size 24.7 KB, free 2.1 GB)
15/12/13 18:03:45 INFO MemoryStore: ensureFreeSpace(7487) called with curMem=675781, maxMem=2223023063
15/12/13 18:03:45 INFO MemoryStore: Block broadcast_26_piece0 stored as bytes in memory (estimated size 7.3 KB, free 2.1 GB)
15/12/13 18:03:45 INFO BlockManagerInfo: Added broadcast_26_piece0 in memory on 10.112.21.66:47648 (size: 7.3 KB, free: 2.1 GB)
15/12/13 18:03:45 INFO SparkContext: Created broadcast 26 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:45 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 30 (MapPartitionsRDD[192] at flatMap at ALS.scala:1124)
15/12/13 18:03:45 INFO TaskSchedulerImpl: Adding task set 30.0 with 2 tasks
15/12/13 18:03:45 INFO TaskSetManager: Starting task 1.0 in stage 30.0 (TID 50, 10.111.21.67, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:45 INFO TaskSetManager: Starting task 0.0 in stage 30.0 (TID 51, 10.111.21.81, PROCESS_LOCAL, 2297 bytes)
15/12/13 18:03:45 INFO BlockManagerInfo: Added broadcast_26_piece0 in memory on 10.111.21.81:38534 (size: 7.3 KB, free: 12.9 GB)
15/12/13 18:03:45 INFO BlockManagerInfo: Added broadcast_26_piece0 in memory on 10.111.21.67:52391 (size: 7.3 KB, free: 12.9 GB)
15/12/13 18:03:45 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 4 to 10.111.21.81:58038
15/12/13 18:03:45 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 4 is 161 bytes
15/12/13 18:03:45 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 4 to 10.111.21.67:57226
15/12/13 18:03:46 INFO TaskSetManager: Finished task 1.0 in stage 30.0 (TID 50) in 502 ms on 10.111.21.67 (1/2)
15/12/13 18:03:46 INFO TaskSetManager: Finished task 0.0 in stage 30.0 (TID 51) in 894 ms on 10.111.21.81 (2/2)
15/12/13 18:03:46 INFO DAGScheduler: ShuffleMapStage 30 (flatMap at ALS.scala:1124) finished in 0.895 s
15/12/13 18:03:46 INFO TaskSchedulerImpl: Removed TaskSet 30.0, whose tasks have all completed, from pool
15/12/13 18:03:46 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:03:46 INFO DAGScheduler: running: Set()
15/12/13 18:03:46 INFO DAGScheduler: waiting: Set(ResultStage 31)
15/12/13 18:03:46 INFO DAGScheduler: failed: Set()
15/12/13 18:03:46 INFO DAGScheduler: Missing parents for ResultStage 31: List()
15/12/13 18:03:46 INFO DAGScheduler: Submitting ResultStage 31 (users MapPartitionsRDD[208] at mapValues at ALS.scala:255), which is now runnable
15/12/13 18:03:46 INFO MemoryStore: ensureFreeSpace(26528) called with curMem=683268, maxMem=2223023063
15/12/13 18:03:46 INFO MemoryStore: Block broadcast_27 stored as values in memory (estimated size 25.9 KB, free 2.1 GB)
15/12/13 18:03:46 INFO MemoryStore: ensureFreeSpace(7791) called with curMem=709796, maxMem=2223023063
15/12/13 18:03:46 INFO MemoryStore: Block broadcast_27_piece0 stored as bytes in memory (estimated size 7.6 KB, free 2.1 GB)
15/12/13 18:03:46 INFO BlockManagerInfo: Added broadcast_27_piece0 in memory on 10.112.21.66:47648 (size: 7.6 KB, free: 2.1 GB)
15/12/13 18:03:46 INFO SparkContext: Created broadcast 27 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:46 INFO DAGScheduler: Submitting 2 missing tasks from ResultStage 31 (users MapPartitionsRDD[208] at mapValues at ALS.scala:255)
15/12/13 18:03:46 INFO TaskSchedulerImpl: Adding task set 31.0 with 2 tasks
15/12/13 18:03:46 INFO TaskSetManager: Starting task 0.0 in stage 31.0 (TID 52, 10.111.21.67, PROCESS_LOCAL, 2308 bytes)
15/12/13 18:03:46 INFO TaskSetManager: Starting task 1.0 in stage 31.0 (TID 53, 10.111.21.81, PROCESS_LOCAL, 2308 bytes)
15/12/13 18:03:46 INFO BlockManagerInfo: Added broadcast_27_piece0 in memory on 10.111.21.81:38534 (size: 7.6 KB, free: 12.9 GB)
15/12/13 18:03:46 INFO BlockManagerInfo: Added broadcast_27_piece0 in memory on 10.111.21.67:52391 (size: 7.6 KB, free: 12.9 GB)
15/12/13 18:03:46 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 3 to 10.111.21.81:58038
15/12/13 18:03:46 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 3 is 164 bytes
15/12/13 18:03:46 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 3 to 10.111.21.67:57226
15/12/13 18:03:48 INFO BlockManagerInfo: Added rdd_208_0 in memory on 10.111.21.67:52391 (size: 58.5 MB, free: 12.9 GB)
15/12/13 18:03:48 INFO TaskSetManager: Finished task 0.0 in stage 31.0 (TID 52) in 1670 ms on 10.111.21.67 (1/2)
15/12/13 18:03:48 INFO BlockManagerInfo: Added rdd_208_1 in memory on 10.111.21.81:38534 (size: 58.5 MB, free: 12.9 GB)
15/12/13 18:03:48 INFO TaskSetManager: Finished task 1.0 in stage 31.0 (TID 53) in 1695 ms on 10.111.21.81 (2/2)
15/12/13 18:03:48 INFO DAGScheduler: ResultStage 31 (count at ALS.scala:263) finished in 1.696 s
15/12/13 18:03:48 INFO TaskSchedulerImpl: Removed TaskSet 31.0, whose tasks have all completed, from pool
15/12/13 18:03:48 INFO DAGScheduler: Job 2 finished: count at ALS.scala:263, took 28.911732 s
15/12/13 18:03:48 INFO SparkContext: Starting job: count at ALS.scala:264
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 1 is 153 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 2 is 161 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 0 is 164 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 23 is 164 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 22 is 161 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 21 is 164 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 20 is 161 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 19 is 164 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 18 is 161 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 17 is 164 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 16 is 161 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 15 is 164 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 14 is 161 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 13 is 164 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 12 is 161 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 11 is 164 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 10 is 161 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 9 is 164 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 8 is 161 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 7 is 164 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 6 is 161 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 5 is 164 bytes
15/12/13 18:03:48 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 4 is 161 bytes
15/12/13 18:03:48 INFO DAGScheduler: Got job 3 (count at ALS.scala:264) with 2 output partitions
15/12/13 18:03:48 INFO DAGScheduler: Final stage: ResultStage 56(count at ALS.scala:264)
15/12/13 18:03:48 INFO DAGScheduler: Parents of final stage: List(ShuffleMapStage 33, ShuffleMapStage 55)
15/12/13 18:03:48 INFO DAGScheduler: Missing parents: List()
15/12/13 18:03:48 INFO DAGScheduler: Submitting ResultStage 56 (products MapPartitionsRDD[209] at mapValues at ALS.scala:259), which has no missing parents
15/12/13 18:03:48 INFO MemoryStore: ensureFreeSpace(25680) called with curMem=717587, maxMem=2223023063
15/12/13 18:03:48 INFO MemoryStore: Block broadcast_28 stored as values in memory (estimated size 25.1 KB, free 2.1 GB)
15/12/13 18:03:48 INFO MemoryStore: ensureFreeSpace(7589) called with curMem=743267, maxMem=2223023063
15/12/13 18:03:48 INFO MemoryStore: Block broadcast_28_piece0 stored as bytes in memory (estimated size 7.4 KB, free 2.1 GB)
15/12/13 18:03:48 INFO BlockManagerInfo: Added broadcast_28_piece0 in memory on 10.112.21.66:47648 (size: 7.4 KB, free: 2.1 GB)
15/12/13 18:03:48 INFO SparkContext: Created broadcast 28 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:48 INFO DAGScheduler: Submitting 2 missing tasks from ResultStage 56 (products MapPartitionsRDD[209] at mapValues at ALS.scala:259)
15/12/13 18:03:48 INFO TaskSchedulerImpl: Adding task set 56.0 with 2 tasks
15/12/13 18:03:48 INFO TaskSetManager: Starting task 1.0 in stage 56.0 (TID 54, 10.111.21.67, PROCESS_LOCAL, 2308 bytes)
15/12/13 18:03:48 INFO TaskSetManager: Starting task 0.0 in stage 56.0 (TID 55, 10.111.21.81, PROCESS_LOCAL, 2308 bytes)
15/12/13 18:03:48 INFO BlockManagerInfo: Added broadcast_28_piece0 in memory on 10.111.21.67:52391 (size: 7.4 KB, free: 12.9 GB)
15/12/13 18:03:48 INFO BlockManagerInfo: Added broadcast_28_piece0 in memory on 10.111.21.81:38534 (size: 7.4 KB, free: 12.9 GB)
15/12/13 18:03:48 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 4 to 10.111.21.67:57226
15/12/13 18:03:48 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 4 to 10.111.21.81:58038
15/12/13 18:03:49 INFO BlockManagerInfo: Added rdd_209_1 in memory on 10.111.21.67:52391 (size: 2.9 KB, free: 12.9 GB)
15/12/13 18:03:49 INFO TaskSetManager: Finished task 1.0 in stage 56.0 (TID 54) in 509 ms on 10.111.21.67 (1/2)
15/12/13 18:03:49 INFO BlockManagerInfo: Added rdd_209_0 in memory on 10.111.21.81:38534 (size: 3.0 KB, free: 12.9 GB)
15/12/13 18:03:49 INFO TaskSetManager: Finished task 0.0 in stage 56.0 (TID 55) in 906 ms on 10.111.21.81 (2/2)
15/12/13 18:03:49 INFO TaskSchedulerImpl: Removed TaskSet 56.0, whose tasks have all completed, from pool
15/12/13 18:03:49 INFO DAGScheduler: ResultStage 56 (count at ALS.scala:264) finished in 0.907 s
15/12/13 18:03:49 INFO DAGScheduler: Job 3 finished: count at ALS.scala:264, took 0.952347 s
15/12/13 18:03:49 INFO SparkContext: Starting job: first at MatrixFactorizationModel.scala:67
15/12/13 18:03:49 INFO DAGScheduler: Got job 4 (first at MatrixFactorizationModel.scala:67) with 1 output partitions
15/12/13 18:03:49 INFO DAGScheduler: Final stage: ResultStage 82(first at MatrixFactorizationModel.scala:67)
15/12/13 18:03:49 INFO DAGScheduler: Parents of final stage: List(ShuffleMapStage 81, ShuffleMapStage 60)
15/12/13 18:03:49 INFO DAGScheduler: Missing parents: List()
15/12/13 18:03:49 INFO DAGScheduler: Submitting ResultStage 82 (users MapPartitionsRDD[208] at mapValues at ALS.scala:255), which has no missing parents
15/12/13 18:03:49 INFO MemoryStore: ensureFreeSpace(26688) called with curMem=750856, maxMem=2223023063
15/12/13 18:03:49 INFO MemoryStore: Block broadcast_29 stored as values in memory (estimated size 26.1 KB, free 2.1 GB)
15/12/13 18:03:49 INFO MemoryStore: ensureFreeSpace(7855) called with curMem=777544, maxMem=2223023063
15/12/13 18:03:49 INFO MemoryStore: Block broadcast_29_piece0 stored as bytes in memory (estimated size 7.7 KB, free 2.1 GB)
15/12/13 18:03:49 INFO BlockManagerInfo: Added broadcast_29_piece0 in memory on 10.112.21.66:47648 (size: 7.7 KB, free: 2.1 GB)
15/12/13 18:03:49 INFO SparkContext: Created broadcast 29 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:49 INFO DAGScheduler: Submitting 1 missing tasks from ResultStage 82 (users MapPartitionsRDD[208] at mapValues at ALS.scala:255)
15/12/13 18:03:49 INFO TaskSchedulerImpl: Adding task set 82.0 with 1 tasks
15/12/13 18:03:49 INFO TaskSetManager: Starting task 0.0 in stage 82.0 (TID 56, 10.111.21.67, PROCESS_LOCAL, 2308 bytes)
15/12/13 18:03:49 INFO BlockManagerInfo: Added broadcast_29_piece0 in memory on 10.111.21.67:52391 (size: 7.7 KB, free: 12.9 GB)
15/12/13 18:03:49 INFO TaskSetManager: Finished task 0.0 in stage 82.0 (TID 56) in 27 ms on 10.111.21.67 (1/1)
15/12/13 18:03:49 INFO TaskSchedulerImpl: Removed TaskSet 82.0, whose tasks have all completed, from pool
15/12/13 18:03:49 INFO DAGScheduler: ResultStage 82 (first at MatrixFactorizationModel.scala:67) finished in 0.028 s
15/12/13 18:03:49 INFO DAGScheduler: Job 4 finished: first at MatrixFactorizationModel.scala:67, took 0.061054 s
15/12/13 18:03:49 INFO SparkContext: Starting job: first at MatrixFactorizationModel.scala:67
15/12/13 18:03:49 INFO DAGScheduler: Got job 5 (first at MatrixFactorizationModel.scala:67) with 1 output partitions
15/12/13 18:03:49 INFO DAGScheduler: Final stage: ResultStage 107(first at MatrixFactorizationModel.scala:67)
15/12/13 18:03:49 INFO DAGScheduler: Parents of final stage: List(ShuffleMapStage 84, ShuffleMapStage 106)
15/12/13 18:03:49 INFO DAGScheduler: Missing parents: List()
15/12/13 18:03:49 INFO DAGScheduler: Submitting ResultStage 107 (products MapPartitionsRDD[209] at mapValues at ALS.scala:259), which has no missing parents
15/12/13 18:03:49 INFO MemoryStore: ensureFreeSpace(25848) called with curMem=785399, maxMem=2223023063
15/12/13 18:03:49 INFO MemoryStore: Block broadcast_30 stored as values in memory (estimated size 25.2 KB, free 2.1 GB)
15/12/13 18:03:49 INFO MemoryStore: ensureFreeSpace(7657) called with curMem=811247, maxMem=2223023063
15/12/13 18:03:49 INFO MemoryStore: Block broadcast_30_piece0 stored as bytes in memory (estimated size 7.5 KB, free 2.1 GB)
15/12/13 18:03:49 INFO BlockManagerInfo: Added broadcast_30_piece0 in memory on 10.112.21.66:47648 (size: 7.5 KB, free: 2.1 GB)
15/12/13 18:03:49 INFO SparkContext: Created broadcast 30 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:49 INFO DAGScheduler: Submitting 1 missing tasks from ResultStage 107 (products MapPartitionsRDD[209] at mapValues at ALS.scala:259)
15/12/13 18:03:49 INFO TaskSchedulerImpl: Adding task set 107.0 with 1 tasks
15/12/13 18:03:49 INFO TaskSetManager: Starting task 0.0 in stage 107.0 (TID 57, 10.111.21.81, PROCESS_LOCAL, 2308 bytes)
15/12/13 18:03:49 INFO BlockManagerInfo: Added broadcast_30_piece0 in memory on 10.111.21.81:38534 (size: 7.5 KB, free: 12.9 GB)
15/12/13 18:03:49 INFO TaskSetManager: Finished task 0.0 in stage 107.0 (TID 57) in 28 ms on 10.111.21.81 (1/1)
15/12/13 18:03:49 INFO TaskSchedulerImpl: Removed TaskSet 107.0, whose tasks have all completed, from pool
15/12/13 18:03:49 INFO DAGScheduler: ResultStage 107 (first at MatrixFactorizationModel.scala:67) finished in 0.028 s
15/12/13 18:03:49 INFO DAGScheduler: Job 5 finished: first at MatrixFactorizationModel.scala:67, took 0.059956 s
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_10_piece0 on 10.112.21.66:47648 in memory (size: 4.6 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_10_piece0 on 10.111.21.67:52391 in memory (size: 4.6 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_10_piece0 on 10.111.21.81:38534 in memory (size: 4.6 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_30_piece0 on 10.112.21.66:47648 in memory (size: 7.5 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_30_piece0 on 10.111.21.81:38534 in memory (size: 7.5 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 30
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_29_piece0 on 10.112.21.66:47648 in memory (size: 7.7 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_29_piece0 on 10.111.21.67:52391 in memory (size: 7.7 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 29
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_28_piece0 on 10.112.21.66:47648 in memory (size: 7.4 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_28_piece0 on 10.111.21.81:38534 in memory (size: 7.4 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_28_piece0 on 10.111.21.67:52391 in memory (size: 7.4 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 28
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_27_piece0 on 10.112.21.66:47648 in memory (size: 7.6 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_27_piece0 on 10.111.21.67:52391 in memory (size: 7.6 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_27_piece0 on 10.111.21.81:38534 in memory (size: 7.6 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 27
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_26_piece0 on 10.112.21.66:47648 in memory (size: 7.3 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_26_piece0 on 10.111.21.81:38534 in memory (size: 7.3 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_26_piece0 on 10.111.21.67:52391 in memory (size: 7.3 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 26
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_25_piece0 on 10.112.21.66:47648 in memory (size: 7.2 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_25_piece0 on 10.111.21.67:52391 in memory (size: 7.2 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_25_piece0 on 10.111.21.81:38534 in memory (size: 7.2 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 25
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_24_piece0 on 10.112.21.66:47648 in memory (size: 7.0 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_24_piece0 on 10.111.21.67:52391 in memory (size: 7.0 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_24_piece0 on 10.111.21.81:38534 in memory (size: 7.0 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 24
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_23_piece0 on 10.112.21.66:47648 in memory (size: 6.8 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_23_piece0 on 10.111.21.81:38534 in memory (size: 6.8 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_23_piece0 on 10.111.21.67:52391 in memory (size: 6.8 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 23
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_22_piece0 on 10.112.21.66:47648 in memory (size: 6.7 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_22_piece0 on 10.111.21.67:52391 in memory (size: 6.7 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_22_piece0 on 10.111.21.81:38534 in memory (size: 6.7 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 22
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_21_piece0 on 10.112.21.66:47648 in memory (size: 6.5 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_21_piece0 on 10.111.21.81:38534 in memory (size: 6.5 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_21_piece0 on 10.111.21.67:52391 in memory (size: 6.5 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 21
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_20_piece0 on 10.112.21.66:47648 in memory (size: 6.3 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_20_piece0 on 10.111.21.81:38534 in memory (size: 6.3 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_20_piece0 on 10.111.21.67:52391 in memory (size: 6.3 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 20
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_19_piece0 on 10.112.21.66:47648 in memory (size: 6.2 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_19_piece0 on 10.111.21.67:52391 in memory (size: 6.2 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_19_piece0 on 10.111.21.81:38534 in memory (size: 6.2 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 19
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_18_piece0 on 10.112.21.66:47648 in memory (size: 6.0 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_18_piece0 on 10.111.21.67:52391 in memory (size: 6.0 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_18_piece0 on 10.111.21.81:38534 in memory (size: 6.0 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 18
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_17_piece0 on 10.112.21.66:47648 in memory (size: 5.8 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_17_piece0 on 10.111.21.81:38534 in memory (size: 5.8 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_17_piece0 on 10.111.21.67:52391 in memory (size: 5.8 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 17
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_16_piece0 on 10.112.21.66:47648 in memory (size: 5.7 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_16_piece0 on 10.111.21.67:52391 in memory (size: 5.7 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_16_piece0 on 10.111.21.81:38534 in memory (size: 5.7 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 16
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_15_piece0 on 10.112.21.66:47648 in memory (size: 5.5 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_15_piece0 on 10.111.21.81:38534 in memory (size: 5.5 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_15_piece0 on 10.111.21.67:52391 in memory (size: 5.5 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 15
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_14_piece0 on 10.112.21.66:47648 in memory (size: 5.3 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_14_piece0 on 10.111.21.81:38534 in memory (size: 5.3 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_14_piece0 on 10.111.21.67:52391 in memory (size: 5.3 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 14
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_13_piece0 on 10.112.21.66:47648 in memory (size: 5.2 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_13_piece0 on 10.111.21.81:38534 in memory (size: 5.2 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_13_piece0 on 10.111.21.67:52391 in memory (size: 5.2 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 13
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_12_piece0 on 10.112.21.66:47648 in memory (size: 5.0 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_12_piece0 on 10.111.21.67:52391 in memory (size: 5.0 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_12_piece0 on 10.111.21.81:38534 in memory (size: 5.0 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 12
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_11_piece0 on 10.112.21.66:47648 in memory (size: 4.8 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_11_piece0 on 10.111.21.81:38534 in memory (size: 4.8 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_11_piece0 on 10.111.21.67:52391 in memory (size: 4.8 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 11
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 10
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_9_piece0 on 10.112.21.66:47648 in memory (size: 4.5 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_9_piece0 on 10.111.21.67:52391 in memory (size: 4.5 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_9_piece0 on 10.111.21.81:38534 in memory (size: 4.5 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 9
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_8_piece0 on 10.112.21.66:47648 in memory (size: 4.3 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_8_piece0 on 10.111.21.67:52391 in memory (size: 4.3 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_8_piece0 on 10.111.21.81:38534 in memory (size: 4.3 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 8
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_7_piece0 on 10.112.21.66:47648 in memory (size: 3.6 KB, free: 2.1 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_7_piece0 on 10.111.21.81:38534 in memory (size: 3.6 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO BlockManagerInfo: Removed broadcast_7_piece0 on 10.111.21.67:52391 in memory (size: 3.6 KB, free: 12.9 GB)
15/12/13 18:03:50 INFO ContextCleaner: Cleaned accumulator 7
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_6_piece0 on 10.112.21.66:47648 in memory (size: 3.4 KB, free: 2.1 GB)
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_6_piece0 on 10.111.21.81:38534 in memory (size: 3.4 KB, free: 12.9 GB)
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_6_piece0 on 10.111.21.67:52391 in memory (size: 3.4 KB, free: 12.9 GB)
15/12/13 18:03:51 INFO ContextCleaner: Cleaned accumulator 6
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_5_piece0 on 10.112.21.66:47648 in memory (size: 3.4 KB, free: 2.1 GB)
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_5_piece0 on 10.111.21.67:52391 in memory (size: 3.4 KB, free: 12.9 GB)
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_5_piece0 on 10.111.21.81:38534 in memory (size: 3.4 KB, free: 12.9 GB)
15/12/13 18:03:51 INFO ContextCleaner: Cleaned accumulator 5
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_4_piece0 on 10.112.21.66:47648 in memory (size: 3.2 KB, free: 2.1 GB)
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_4_piece0 on 10.111.21.81:38534 in memory (size: 3.2 KB, free: 12.9 GB)
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_4_piece0 on 10.111.21.68:43411 in memory (size: 3.2 KB, free: 12.9 GB)
15/12/13 18:03:51 INFO ContextCleaner: Cleaned accumulator 4
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_3_piece0 on 10.112.21.66:47648 in memory (size: 3.4 KB, free: 2.1 GB)
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_3_piece0 on 10.111.21.67:52391 in memory (size: 3.4 KB, free: 12.9 GB)
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_3_piece0 on 10.111.21.81:38534 in memory (size: 3.4 KB, free: 12.9 GB)
15/12/13 18:03:51 INFO ContextCleaner: Cleaned accumulator 3
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_2_piece0 on 10.112.21.66:47648 in memory (size: 3.2 KB, free: 2.1 GB)
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_2_piece0 on 10.111.21.81:38534 in memory (size: 3.2 KB, free: 12.9 GB)
15/12/13 18:03:51 INFO BlockManagerInfo: Removed broadcast_2_piece0 on 10.111.21.68:43411 in memory (size: 3.2 KB, free: 12.9 GB)
15/12/13 18:03:51 INFO ContextCleaner: Cleaned accumulator 2
15/12/13 18:03:51 INFO ContextCleaner: Cleaned accumulator 1
15/12/13 18:03:55 INFO SparkContext: Starting job: aggregate at MatrixFactorizationModel.scala:96
15/12/13 18:03:55 INFO DAGScheduler: Got job 6 (aggregate at MatrixFactorizationModel.scala:96) with 18 output partitions
15/12/13 18:03:55 INFO DAGScheduler: Final stage: ResultStage 108(aggregate at MatrixFactorizationModel.scala:96)
15/12/13 18:03:55 INFO DAGScheduler: Parents of final stage: List()
15/12/13 18:03:55 INFO DAGScheduler: Missing parents: List()
15/12/13 18:03:55 INFO DAGScheduler: Submitting ResultStage 108 (ParallelCollectionRDD[210] at parallelize at prediction_save.scala:43), which has no missing parents
15/12/13 18:03:55 INFO MemoryStore: ensureFreeSpace(1696) called with curMem=171524, maxMem=2223023063
15/12/13 18:03:55 INFO MemoryStore: Block broadcast_31 stored as values in memory (estimated size 1696.0 B, free 2.1 GB)
15/12/13 18:03:55 INFO MemoryStore: ensureFreeSpace(1066) called with curMem=173220, maxMem=2223023063
15/12/13 18:03:55 INFO MemoryStore: Block broadcast_31_piece0 stored as bytes in memory (estimated size 1066.0 B, free 2.1 GB)
15/12/13 18:03:55 INFO BlockManagerInfo: Added broadcast_31_piece0 in memory on 10.112.21.66:47648 (size: 1066.0 B, free: 2.1 GB)
15/12/13 18:03:55 INFO SparkContext: Created broadcast 31 from broadcast at DAGScheduler.scala:861
15/12/13 18:03:55 INFO DAGScheduler: Submitting 18 missing tasks from ResultStage 108 (ParallelCollectionRDD[210] at parallelize at prediction_save.scala:43)
15/12/13 18:03:55 INFO TaskSchedulerImpl: Adding task set 108.0 with 18 tasks
15/12/13 18:03:57 WARN TaskSetManager: Stage 108 contains a task of very large size (32708 KB). The maximum recommended task size is 100 KB.
15/12/13 18:03:57 INFO TaskSetManager: Starting task 0.0 in stage 108.0 (TID 58, 10.111.21.67, PROCESS_LOCAL, 33493584 bytes)
15/12/13 18:03:59 INFO TaskSetManager: Starting task 1.0 in stage 108.0 (TID 59, 10.111.21.68, PROCESS_LOCAL, 33493600 bytes)
15/12/13 18:04:01 INFO TaskSetManager: Starting task 2.0 in stage 108.0 (TID 60, 10.111.21.81, PROCESS_LOCAL, 33493584 bytes)
15/12/13 18:04:02 INFO TaskSetManager: Starting task 3.0 in stage 108.0 (TID 61, 10.111.21.67, PROCESS_LOCAL, 33493600 bytes)
15/12/13 18:04:04 INFO TaskSetManager: Starting task 4.0 in stage 108.0 (TID 62, 10.111.21.68, PROCESS_LOCAL, 33493584 bytes)
15/12/13 18:04:06 INFO TaskSetManager: Starting task 5.0 in stage 108.0 (TID 63, 10.111.21.81, PROCESS_LOCAL, 33493600 bytes)
15/12/13 18:04:08 INFO TaskSetManager: Starting task 6.0 in stage 108.0 (TID 64, 10.111.21.67, PROCESS_LOCAL, 33493584 bytes)
^@15/12/13 18:04:10 INFO TaskSetManager: Starting task 7.0 in stage 108.0 (TID 65, 10.111.21.68, PROCESS_LOCAL, 33493600 bytes)
15/12/13 18:04:11 INFO TaskSetManager: Starting task 8.0 in stage 108.0 (TID 66, 10.111.21.81, PROCESS_LOCAL, 33493600 bytes)
15/12/13 18:04:13 INFO TaskSetManager: Starting task 9.0 in stage 108.0 (TID 67, 10.111.21.67, PROCESS_LOCAL, 33493584 bytes)
15/12/13 18:04:15 INFO TaskSetManager: Starting task 10.0 in stage 108.0 (TID 68, 10.111.21.68, PROCESS_LOCAL, 33493600 bytes)
15/12/13 18:04:17 INFO TaskSetManager: Starting task 11.0 in stage 108.0 (TID 69, 10.111.21.81, PROCESS_LOCAL, 33493584 bytes)
15/12/13 18:04:18 INFO TaskSetManager: Starting task 12.0 in stage 108.0 (TID 70, 10.111.21.67, PROCESS_LOCAL, 33493600 bytes)
15/12/13 18:04:20 INFO TaskSetManager: Starting task 13.0 in stage 108.0 (TID 71, 10.111.21.68, PROCESS_LOCAL, 33493584 bytes)
15/12/13 18:04:22 INFO TaskSetManager: Starting task 14.0 in stage 108.0 (TID 72, 10.111.21.81, PROCESS_LOCAL, 33493600 bytes)
15/12/13 18:04:24 INFO TaskSetManager: Starting task 15.0 in stage 108.0 (TID 73, 10.111.21.67, PROCESS_LOCAL, 33493584 bytes)
15/12/13 18:04:25 INFO TaskSetManager: Starting task 16.0 in stage 108.0 (TID 74, 10.111.21.68, PROCESS_LOCAL, 33493600 bytes)
15/12/13 18:04:27 INFO TaskSetManager: Starting task 17.0 in stage 108.0 (TID 75, 10.111.21.81, PROCESS_LOCAL, 33493600 bytes)
15/12/13 18:04:56 INFO BlockManagerInfo: Added broadcast_31_piece0 in memory on 10.111.21.67:52391 (size: 1066.0 B, free: 12.9 GB)
15/12/13 18:04:57 INFO TaskSetManager: Finished task 0.0 in stage 108.0 (TID 58) in 61200 ms on 10.111.21.67 (1/18)
15/12/13 18:04:57 INFO TaskSetManager: Finished task 6.0 in stage 108.0 (TID 64) in 50576 ms on 10.111.21.67 (2/18)
15/12/13 18:04:57 INFO TaskSetManager: Finished task 12.0 in stage 108.0 (TID 70) in 40086 ms on 10.111.21.67 (3/18)
15/12/13 18:04:57 INFO TaskSetManager: Finished task 9.0 in stage 108.0 (TID 67) in 45293 ms on 10.111.21.67 (4/18)
15/12/13 18:04:57 INFO TaskSetManager: Finished task 3.0 in stage 108.0 (TID 61) in 55979 ms on 10.111.21.67 (5/18)
15/12/13 18:04:57 INFO BlockManagerInfo: Added broadcast_31_piece0 in memory on 10.111.21.68:43411 (size: 1066.0 B, free: 12.9 GB)
15/12/13 18:04:57 INFO TaskSetManager: Finished task 15.0 in stage 108.0 (TID 73) in 35589 ms on 10.111.21.67 (6/18)
15/12/13 18:04:58 INFO BlockManagerInfo: Added broadcast_31_piece0 in memory on 10.111.21.81:38534 (size: 1066.0 B, free: 12.9 GB)
15/12/13 18:04:58 INFO TaskSetManager: Finished task 7.0 in stage 108.0 (TID 65) in 50406 ms on 10.111.21.68 (7/18)
15/12/13 18:04:58 INFO TaskSetManager: Finished task 4.0 in stage 108.0 (TID 62) in 55881 ms on 10.111.21.68 (8/18)
15/12/13 18:04:58 INFO TaskSetManager: Finished task 1.0 in stage 108.0 (TID 59) in 61174 ms on 10.111.21.68 (9/18)
15/12/13 18:04:58 INFO TaskSetManager: Finished task 10.0 in stage 108.0 (TID 68) in 45218 ms on 10.111.21.68 (10/18)
15/12/13 18:04:58 INFO TaskSetManager: Finished task 8.0 in stage 108.0 (TID 66) in 48759 ms on 10.111.21.81 (11/18)
15/12/13 18:04:58 INFO TaskSetManager: Finished task 2.0 in stage 108.0 (TID 60) in 59367 ms on 10.111.21.81 (12/18)
15/12/13 18:04:58 INFO TaskSetManager: Finished task 5.0 in stage 108.0 (TID 63) in 54158 ms on 10.111.21.81 (13/18)
15/12/13 18:04:59 INFO TaskSetManager: Finished task 11.0 in stage 108.0 (TID 69) in 43600 ms on 10.111.21.81 (14/18)
15/12/13 18:04:59 INFO TaskSetManager: Finished task 13.0 in stage 108.0 (TID 71) in 40320 ms on 10.111.21.68 (15/18)
15/12/13 18:04:59 INFO TaskSetManager: Finished task 14.0 in stage 108.0 (TID 72) in 38757 ms on 10.111.21.81 (16/18)
15/12/13 18:04:59 INFO TaskSetManager: Finished task 16.0 in stage 108.0 (TID 74) in 35445 ms on 10.111.21.68 (17/18)
15/12/13 18:04:59 INFO TaskSetManager: Finished task 17.0 in stage 108.0 (TID 75) in 33691 ms on 10.111.21.81 (18/18)
15/12/13 18:04:59 INFO DAGScheduler: ResultStage 108 (aggregate at MatrixFactorizationModel.scala:96) finished in 63.592 s
15/12/13 18:04:59 INFO TaskSchedulerImpl: Removed TaskSet 108.0, whose tasks have all completed, from pool
15/12/13 18:04:59 INFO DAGScheduler: Job 6 finished: aggregate at MatrixFactorizationModel.scala:96, took 63.601825 s
15/12/13 18:04:59 INFO deprecation: mapred.tip.id is deprecated. Instead, use mapreduce.task.id
15/12/13 18:04:59 INFO deprecation: mapred.task.id is deprecated. Instead, use mapreduce.task.attempt.id
15/12/13 18:04:59 INFO deprecation: mapred.task.is.map is deprecated. Instead, use mapreduce.task.ismap
15/12/13 18:04:59 INFO deprecation: mapred.task.partition is deprecated. Instead, use mapreduce.task.partition
15/12/13 18:04:59 INFO deprecation: mapred.job.id is deprecated. Instead, use mapreduce.job.id
15/12/13 18:04:59 INFO SparkContext: Starting job: saveAsTextFile at prediction_save.scala:47
15/12/13 18:04:59 INFO DAGScheduler: Registering RDD 211 (map at MatrixFactorizationModel.scala:137)
15/12/13 18:04:59 INFO DAGScheduler: Registering RDD 215 (map at MatrixFactorizationModel.scala:137)
15/12/13 18:04:59 INFO DAGScheduler: Got job 7 (saveAsTextFile at prediction_save.scala:47) with 2 output partitions
15/12/13 18:04:59 INFO DAGScheduler: Final stage: ResultStage 136(saveAsTextFile at prediction_save.scala:47)
15/12/13 18:04:59 INFO DAGScheduler: Parents of final stage: List(ShuffleMapStage 135, ShuffleMapStage 112, ShuffleMapStage 134)
15/12/13 18:04:59 INFO DAGScheduler: Missing parents: List(ShuffleMapStage 134)
15/12/13 18:04:59 INFO DAGScheduler: Submitting ShuffleMapStage 133 (MapPartitionsRDD[211] at map at MatrixFactorizationModel.scala:137), which has no missing parents
15/12/13 18:04:59 INFO MemoryStore: ensureFreeSpace(2224) called with curMem=174286, maxMem=2223023063
15/12/13 18:04:59 INFO MemoryStore: Block broadcast_32 stored as values in memory (estimated size 2.2 KB, free 2.1 GB)
15/12/13 18:04:59 INFO MemoryStore: ensureFreeSpace(1382) called with curMem=176510, maxMem=2223023063
15/12/13 18:04:59 INFO MemoryStore: Block broadcast_32_piece0 stored as bytes in memory (estimated size 1382.0 B, free 2.1 GB)
15/12/13 18:04:59 INFO BlockManagerInfo: Added broadcast_32_piece0 in memory on 10.112.21.66:47648 (size: 1382.0 B, free: 2.1 GB)
15/12/13 18:04:59 INFO SparkContext: Created broadcast 32 from broadcast at DAGScheduler.scala:861
15/12/13 18:04:59 INFO DAGScheduler: Submitting 18 missing tasks from ShuffleMapStage 133 (MapPartitionsRDD[211] at map at MatrixFactorizationModel.scala:137)
15/12/13 18:04:59 INFO TaskSchedulerImpl: Adding task set 133.0 with 18 tasks
15/12/13 18:05:01 WARN TaskSetManager: Stage 133 contains a task of very large size (32708 KB). The maximum recommended task size is 100 KB.
15/12/13 18:05:01 INFO TaskSetManager: Starting task 0.0 in stage 133.0 (TID 76, 10.111.21.81, PROCESS_LOCAL, 33493573 bytes)
15/12/13 18:05:03 INFO TaskSetManager: Starting task 1.0 in stage 133.0 (TID 77, 10.111.21.67, PROCESS_LOCAL, 33493589 bytes)
15/12/13 18:05:04 INFO TaskSetManager: Starting task 2.0 in stage 133.0 (TID 78, 10.111.21.68, PROCESS_LOCAL, 33493573 bytes)
15/12/13 18:05:06 INFO TaskSetManager: Starting task 3.0 in stage 133.0 (TID 79, 10.111.21.81, PROCESS_LOCAL, 33493589 bytes)
15/12/13 18:05:08 INFO TaskSetManager: Starting task 4.0 in stage 133.0 (TID 80, 10.111.21.67, PROCESS_LOCAL, 33493573 bytes)
^@15/12/13 18:05:09 INFO TaskSetManager: Starting task 5.0 in stage 133.0 (TID 81, 10.111.21.68, PROCESS_LOCAL, 33493589 bytes)
15/12/13 18:05:11 INFO TaskSetManager: Starting task 6.0 in stage 133.0 (TID 82, 10.111.21.81, PROCESS_LOCAL, 33493573 bytes)
15/12/13 18:05:12 INFO TaskSetManager: Starting task 7.0 in stage 133.0 (TID 83, 10.111.21.67, PROCESS_LOCAL, 33493589 bytes)
15/12/13 18:05:13 INFO TaskSetManager: Starting task 8.0 in stage 133.0 (TID 84, 10.111.21.68, PROCESS_LOCAL, 33493589 bytes)
15/12/13 18:05:15 INFO TaskSetManager: Starting task 9.0 in stage 133.0 (TID 85, 10.111.21.81, PROCESS_LOCAL, 33493573 bytes)
15/12/13 18:05:16 INFO TaskSetManager: Starting task 10.0 in stage 133.0 (TID 86, 10.111.21.67, PROCESS_LOCAL, 33493589 bytes)
15/12/13 18:05:18 INFO TaskSetManager: Starting task 11.0 in stage 133.0 (TID 87, 10.111.21.68, PROCESS_LOCAL, 33493573 bytes)
15/12/13 18:05:19 INFO TaskSetManager: Starting task 12.0 in stage 133.0 (TID 88, 10.111.21.81, PROCESS_LOCAL, 33493589 bytes)
15/12/13 18:05:21 INFO TaskSetManager: Starting task 13.0 in stage 133.0 (TID 89, 10.111.21.67, PROCESS_LOCAL, 33493573 bytes)
15/12/13 18:05:24 INFO BlockManagerInfo: Removed broadcast_31_piece0 on 10.112.21.66:47648 in memory (size: 1066.0 B, free: 2.1 GB)
15/12/13 18:05:24 INFO BlockManagerInfo: Removed broadcast_31_piece0 on 10.111.21.81:38534 in memory (size: 1066.0 B, free: 12.9 GB)
15/12/13 18:05:24 INFO BlockManagerInfo: Removed broadcast_31_piece0 on 10.111.21.68:43411 in memory (size: 1066.0 B, free: 12.9 GB)
15/12/13 18:05:24 INFO BlockManagerInfo: Removed broadcast_31_piece0 on 10.111.21.67:52391 in memory (size: 1066.0 B, free: 12.9 GB)
15/12/13 18:05:24 INFO TaskSetManager: Starting task 14.0 in stage 133.0 (TID 90, 10.111.21.68, PROCESS_LOCAL, 33493589 bytes)
15/12/13 18:05:24 INFO ContextCleaner: Cleaned accumulator 31
15/12/13 18:05:25 INFO TaskSetManager: Starting task 15.0 in stage 133.0 (TID 91, 10.111.21.81, PROCESS_LOCAL, 33493573 bytes)
15/12/13 18:05:27 INFO TaskSetManager: Starting task 16.0 in stage 133.0 (TID 92, 10.111.21.67, PROCESS_LOCAL, 33493589 bytes)
15/12/13 18:05:28 INFO TaskSetManager: Starting task 17.0 in stage 133.0 (TID 93, 10.111.21.68, PROCESS_LOCAL, 33493589 bytes)
15/12/13 18:05:48 INFO BlockManagerInfo: Added broadcast_32_piece0 in memory on 10.111.21.67:52391 (size: 1382.0 B, free: 12.9 GB)
15/12/13 18:05:48 INFO BlockManagerInfo: Added broadcast_32_piece0 in memory on 10.111.21.81:38534 (size: 1382.0 B, free: 12.9 GB)
15/12/13 18:05:49 INFO BlockManagerInfo: Added broadcast_32_piece0 in memory on 10.111.21.68:43411 (size: 1382.0 B, free: 12.9 GB)
15/12/13 18:05:52 INFO TaskSetManager: Finished task 6.0 in stage 133.0 (TID 82) in 42851 ms on 10.111.21.81 (1/18)
15/12/13 18:05:52 INFO TaskSetManager: Finished task 0.0 in stage 133.0 (TID 76) in 52845 ms on 10.111.21.81 (2/18)
15/12/13 18:05:52 INFO TaskSetManager: Finished task 12.0 in stage 133.0 (TID 88) in 34534 ms on 10.111.21.81 (3/18)
15/12/13 18:05:52 INFO TaskSetManager: Finished task 9.0 in stage 133.0 (TID 85) in 38854 ms on 10.111.21.81 (4/18)
15/12/13 18:05:52 INFO TaskSetManager: Finished task 1.0 in stage 133.0 (TID 77) in 51250 ms on 10.111.21.67 (5/18)
15/12/13 18:05:52 INFO TaskSetManager: Finished task 3.0 in stage 133.0 (TID 79) in 47844 ms on 10.111.21.81 (6/18)
15/12/13 18:05:52 INFO TaskSetManager: Finished task 10.0 in stage 133.0 (TID 86) in 37674 ms on 10.111.21.67 (7/18)
15/12/13 18:05:52 INFO TaskSetManager: Finished task 4.0 in stage 133.0 (TID 80) in 46330 ms on 10.111.21.67 (8/18)
15/12/13 18:05:53 INFO TaskSetManager: Finished task 13.0 in stage 133.0 (TID 89) in 33740 ms on 10.111.21.67 (9/18)
15/12/13 18:05:53 INFO TaskSetManager: Finished task 15.0 in stage 133.0 (TID 91) in 29522 ms on 10.111.21.81 (10/18)
15/12/13 18:05:53 INFO TaskSetManager: Finished task 8.0 in stage 133.0 (TID 84) in 41442 ms on 10.111.21.68 (11/18)
15/12/13 18:05:53 INFO TaskSetManager: Finished task 2.0 in stage 133.0 (TID 78) in 50844 ms on 10.111.21.68 (12/18)
15/12/13 18:05:54 INFO TaskSetManager: Finished task 7.0 in stage 133.0 (TID 83) in 42985 ms on 10.111.21.67 (13/18)
15/12/13 18:05:54 INFO TaskSetManager: Finished task 11.0 in stage 133.0 (TID 87) in 37604 ms on 10.111.21.68 (14/18)
15/12/13 18:05:54 INFO TaskSetManager: Finished task 14.0 in stage 133.0 (TID 90) in 32924 ms on 10.111.21.68 (15/18)
15/12/13 18:05:54 INFO TaskSetManager: Finished task 5.0 in stage 133.0 (TID 81) in 45986 ms on 10.111.21.68 (16/18)
15/12/13 18:05:54 INFO TaskSetManager: Finished task 16.0 in stage 133.0 (TID 92) in 28807 ms on 10.111.21.67 (17/18)
15/12/13 18:05:54 INFO TaskSetManager: Finished task 17.0 in stage 133.0 (TID 93) in 27746 ms on 10.111.21.68 (18/18)
15/12/13 18:05:54 INFO DAGScheduler: ShuffleMapStage 133 (map at MatrixFactorizationModel.scala:137) finished in 55.024 s
15/12/13 18:05:54 INFO TaskSchedulerImpl: Removed TaskSet 133.0, whose tasks have all completed, from pool
15/12/13 18:05:54 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:05:54 INFO DAGScheduler: running: Set()
15/12/13 18:05:54 INFO DAGScheduler: waiting: Set(ShuffleMapStage 134, ResultStage 136)
15/12/13 18:05:54 INFO DAGScheduler: failed: Set()
15/12/13 18:05:54 INFO DAGScheduler: Missing parents for ShuffleMapStage 134: List()
15/12/13 18:05:54 INFO DAGScheduler: Missing parents for ResultStage 136: List(ShuffleMapStage 134)
15/12/13 18:05:54 INFO DAGScheduler: Submitting ShuffleMapStage 134 (MapPartitionsRDD[215] at map at MatrixFactorizationModel.scala:137), which is now runnable
15/12/13 18:05:54 INFO MemoryStore: ensureFreeSpace(26016) called with curMem=175130, maxMem=2223023063
15/12/13 18:05:54 INFO MemoryStore: Block broadcast_33 stored as values in memory (estimated size 25.4 KB, free 2.1 GB)
15/12/13 18:05:54 INFO MemoryStore: ensureFreeSpace(7669) called with curMem=201146, maxMem=2223023063
15/12/13 18:05:54 INFO MemoryStore: Block broadcast_33_piece0 stored as bytes in memory (estimated size 7.5 KB, free 2.1 GB)
15/12/13 18:05:54 INFO BlockManagerInfo: Added broadcast_33_piece0 in memory on 10.112.21.66:47648 (size: 7.5 KB, free: 2.1 GB)
15/12/13 18:05:54 INFO SparkContext: Created broadcast 33 from broadcast at DAGScheduler.scala:861
15/12/13 18:05:54 INFO DAGScheduler: Submitting 2 missing tasks from ShuffleMapStage 134 (MapPartitionsRDD[215] at map at MatrixFactorizationModel.scala:137)
15/12/13 18:05:54 INFO TaskSchedulerImpl: Adding task set 134.0 with 2 tasks
15/12/13 18:05:54 INFO TaskSetManager: Starting task 1.0 in stage 134.0 (TID 94, 10.111.21.67, PROCESS_LOCAL, 2339 bytes)
15/12/13 18:05:54 INFO TaskSetManager: Starting task 0.0 in stage 134.0 (TID 95, 10.111.21.81, PROCESS_LOCAL, 2339 bytes)
15/12/13 18:05:54 INFO BlockManagerInfo: Added broadcast_33_piece0 in memory on 10.111.21.81:38534 (size: 7.5 KB, free: 12.9 GB)
15/12/13 18:05:54 INFO BlockManagerInfo: Added broadcast_33_piece0 in memory on 10.111.21.67:52391 (size: 7.5 KB, free: 12.9 GB)
15/12/13 18:05:54 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 24 to 10.111.21.81:58038
15/12/13 18:05:54 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 24 is 180 bytes
15/12/13 18:05:54 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 24 to 10.111.21.67:57226
^@^@15/12/13 18:07:10 INFO TaskSetManager: Finished task 1.0 in stage 134.0 (TID 94) in 75830 ms on 10.111.21.67 (1/2)
15/12/13 18:07:12 INFO TaskSetManager: Finished task 0.0 in stage 134.0 (TID 95) in 78144 ms on 10.111.21.81 (2/2)
15/12/13 18:07:12 INFO TaskSchedulerImpl: Removed TaskSet 134.0, whose tasks have all completed, from pool
15/12/13 18:07:12 INFO DAGScheduler: ShuffleMapStage 134 (map at MatrixFactorizationModel.scala:137) finished in 78.146 s
15/12/13 18:07:12 INFO DAGScheduler: looking for newly runnable stages
15/12/13 18:07:12 INFO DAGScheduler: running: Set()
15/12/13 18:07:12 INFO DAGScheduler: waiting: Set(ResultStage 136)
15/12/13 18:07:12 INFO DAGScheduler: failed: Set()
15/12/13 18:07:12 INFO DAGScheduler: Missing parents for ResultStage 136: List()
15/12/13 18:07:12 INFO DAGScheduler: Submitting ResultStage 136 (MapPartitionsRDD[221] at saveAsTextFile at prediction_save.scala:47), which is now runnable
15/12/13 18:07:13 INFO MemoryStore: ensureFreeSpace(151952) called with curMem=208815, maxMem=2223023063
15/12/13 18:07:13 INFO MemoryStore: Block broadcast_34 stored as values in memory (estimated size 148.4 KB, free 2.1 GB)
15/12/13 18:07:13 INFO MemoryStore: ensureFreeSpace(49764) called with curMem=360767, maxMem=2223023063
15/12/13 18:07:13 INFO MemoryStore: Block broadcast_34_piece0 stored as bytes in memory (estimated size 48.6 KB, free 2.1 GB)
15/12/13 18:07:13 INFO BlockManagerInfo: Added broadcast_34_piece0 in memory on 10.112.21.66:47648 (size: 48.6 KB, free: 2.1 GB)
15/12/13 18:07:13 INFO SparkContext: Created broadcast 34 from broadcast at DAGScheduler.scala:861
15/12/13 18:07:13 INFO DAGScheduler: Submitting 2 missing tasks from ResultStage 136 (MapPartitionsRDD[221] at saveAsTextFile at prediction_save.scala:47)
15/12/13 18:07:13 INFO TaskSchedulerImpl: Adding task set 136.0 with 2 tasks
15/12/13 18:07:13 INFO TaskSetManager: Starting task 1.0 in stage 136.0 (TID 96, 10.111.21.81, PROCESS_LOCAL, 2350 bytes)
15/12/13 18:07:13 INFO TaskSetManager: Starting task 0.0 in stage 136.0 (TID 97, 10.111.21.67, PROCESS_LOCAL, 2350 bytes)
15/12/13 18:07:13 INFO BlockManagerInfo: Added broadcast_34_piece0 in memory on 10.111.21.81:38534 (size: 48.6 KB, free: 12.9 GB)
15/12/13 18:07:13 INFO BlockManagerInfo: Added broadcast_34_piece0 in memory on 10.111.21.67:52391 (size: 48.6 KB, free: 12.9 GB)
15/12/13 18:07:13 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 25 to 10.111.21.67:57226
15/12/13 18:07:13 INFO MapOutputTrackerMaster: Size of output statuses for shuffle 25 is 161 bytes
15/12/13 18:07:13 INFO MapOutputTrackerMasterEndpoint: Asked to send map output locations for shuffle 25 to 10.111.21.81:58038
^@15/12/13 18:08:25 INFO BlockManagerInfo: Removed broadcast_33_piece0 on 10.112.21.66:47648 in memory (size: 7.5 KB, free: 2.1 GB)
15/12/13 18:08:25 INFO BlockManagerInfo: Removed broadcast_33_piece0 on 10.111.21.67:52391 in memory (size: 7.5 KB, free: 12.9 GB)
15/12/13 18:08:25 INFO BlockManagerInfo: Removed broadcast_33_piece0 on 10.111.21.81:38534 in memory (size: 7.5 KB, free: 12.9 GB)
15/12/13 18:08:37 INFO TaskSetManager: Finished task 1.0 in stage 136.0 (TID 96) in 84926 ms on 10.111.21.81 (1/2)
15/12/13 18:08:42 INFO TaskSetManager: Finished task 0.0 in stage 136.0 (TID 97) in 88953 ms on 10.111.21.67 (2/2)
15/12/13 18:08:42 INFO TaskSchedulerImpl: Removed TaskSet 136.0, whose tasks have all completed, from pool
15/12/13 18:08:42 INFO DAGScheduler: ResultStage 136 (saveAsTextFile at prediction_save.scala:47) finished in 88.954 s
15/12/13 18:08:42 INFO DAGScheduler: Job 7 finished: saveAsTextFile at prediction_save.scala:47, took 222.325605 s
15/12/13 18:08:42 INFO SparkUI: Stopped Spark web UI at http://10.112.21.66:4040
15/12/13 18:08:42 INFO DAGScheduler: Stopping DAGScheduler
15/12/13 18:08:42 INFO SparkDeploySchedulerBackend: Shutting down all executors
15/12/13 18:08:42 INFO SparkDeploySchedulerBackend: Asking each executor to shut down
15/12/13 18:08:42 INFO MapOutputTrackerMasterEndpoint: MapOutputTrackerMasterEndpoint stopped!
15/12/13 18:08:42 INFO MemoryStore: MemoryStore cleared
15/12/13 18:08:42 INFO BlockManager: BlockManager stopped
15/12/13 18:08:42 INFO BlockManagerMaster: BlockManagerMaster stopped
15/12/13 18:08:42 INFO SparkContext: Successfully stopped SparkContext
15/12/13 18:08:42 INFO OutputCommitCoordinator$OutputCommitCoordinatorEndpoint: OutputCommitCoordinator stopped!
15/12/13 18:08:42 INFO ShutdownHookManager: Shutdown hook called
15/12/13 18:08:42 INFO RemoteActorRefProvider$RemotingTerminator: Shutting down remote daemon.
15/12/13 18:08:42 INFO ShutdownHookManager: Deleting directory /tmp/spark-94e9ef51-824a-49f8-931b-81025f5ad6c1
15/12/13 18:08:42 INFO RemoteActorRefProvider$RemotingTerminator: Remote daemon shut down; proceeding with flushing remote transports.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.