[ https://issues.apache.org/jira/browse/SPARK-15813?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Peter Ableda updated SPARK-15813: --------------------------------- Description: *Driver requested* message is logged before the *Canceling* message but has the updated executor number. The messages are misleading. See log snippet: {code} 16/06/07 18:53:48 INFO yarn.YarnAllocator: Driver requested a total number of 619 executor(s). 16/06/07 18:53:48 INFO yarn.YarnAllocator: Canceling requests for 4 executor containers 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 382.0 in stage 0.0 (TID 382) in 22 ms on lava-2.vpc.cloudera.com (382/1000) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 383.0 in stage 0.0 (TID 383, lava-2.vpc.cloudera.com, partition 383,PROCESS_LOCAL, 1980 bytes) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 383.0 in stage 0.0 (TID 383) in 24 ms on lava-2.vpc.cloudera.com (383/1000) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 384.0 in stage 0.0 (TID 384, lava-2.vpc.cloudera.com, partition 384,PROCESS_LOCAL, 1980 bytes) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 384.0 in stage 0.0 (TID 384) in 19 ms on lava-2.vpc.cloudera.com (384/1000) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 385.0 in stage 0.0 (TID 385, lava-2.vpc.cloudera.com, partition 385,PROCESS_LOCAL, 1980 bytes) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 385.0 in stage 0.0 (TID 385) in 22 ms on lava-2.vpc.cloudera.com (385/1000) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 386.0 in stage 0.0 (TID 386, lava-2.vpc.cloudera.com, partition 386,PROCESS_LOCAL, 1980 bytes) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 386.0 in stage 0.0 (TID 386) in 20 ms on lava-2.vpc.cloudera.com (386/1000) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 387.0 in stage 0.0 (TID 387, lava-2.vpc.cloudera.com, partition 387,PROCESS_LOCAL, 1980 bytes) 16/06/07 18:53:48 INFO yarn.YarnAllocator: Driver requested a total number of 614 executor(s). 16/06/07 18:53:48 INFO yarn.YarnAllocator: Canceling requests for 5 executor containers 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 388.0 in stage 0.0 (TID 388, lava-4.vpc.cloudera.com, partition 388,PROCESS_LOCAL, 1980 bytes) {code} The easy solution is to update the message to use past tense. This is consistent with the other messages there. *Canceled requests for 5 executor container(s).* was: *Driver requested* message is logged before the *Canceling* message but has the updated executor number. The messages are misleading. See log snippet: {code} 16/06/07 18:53:48 INFO yarn.YarnAllocator: Driver requested a total number of 619 executor(s). 16/06/07 18:53:48 INFO yarn.YarnAllocator: Canceling requests for 4 executor containers 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 382.0 in stage 0.0 (TID 382) in 22 ms on lava-2.vpc.cloudera.com (382/1000) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 383.0 in stage 0.0 (TID 383, lava-2.vpc.cloudera.com, partition 383,PROCESS_LOCAL, 1980 bytes) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 383.0 in stage 0.0 (TID 383) in 24 ms on lava-2.vpc.cloudera.com (383/1000) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 384.0 in stage 0.0 (TID 384, lava-2.vpc.cloudera.com, partition 384,PROCESS_LOCAL, 1980 bytes) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 384.0 in stage 0.0 (TID 384) in 19 ms on lava-2.vpc.cloudera.com (384/1000) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 385.0 in stage 0.0 (TID 385, lava-2.vpc.cloudera.com, partition 385,PROCESS_LOCAL, 1980 bytes) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 385.0 in stage 0.0 (TID 385) in 22 ms on lava-2.vpc.cloudera.com (385/1000) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 386.0 in stage 0.0 (TID 386, lava-2.vpc.cloudera.com, partition 386,PROCESS_LOCAL, 1980 bytes) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 386.0 in stage 0.0 (TID 386) in 20 ms on lava-2.vpc.cloudera.com (386/1000) 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 387.0 in stage 0.0 (TID 387, lava-2.vpc.cloudera.com, partition 387,PROCESS_LOCAL, 1980 bytes) 16/06/07 18:53:48 INFO yarn.YarnAllocator: Driver requested a total number of 614 executor(s). 16/06/07 18:53:48 INFO yarn.YarnAllocator: Canceling requests for 5 executor containers 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 388.0 in stage 0.0 (TID 388, lava-4.vpc.cloudera.com, partition 388,PROCESS_LOCAL, 1980 bytes) {code} The easy solution is to update the message to use past sentence. This is consistent with the other messages there. *Canceled requests for 5 executor container(s).* > Spark Dyn Allocation Cancel log message misleading > -------------------------------------------------- > > Key: SPARK-15813 > URL: https://issues.apache.org/jira/browse/SPARK-15813 > Project: Spark > Issue Type: Bug > Reporter: Peter Ableda > Priority: Trivial > > *Driver requested* message is logged before the *Canceling* message but has > the updated executor number. The messages are misleading. > See log snippet: > {code} > 16/06/07 18:53:48 INFO yarn.YarnAllocator: Driver requested a total number of > 619 executor(s). > 16/06/07 18:53:48 INFO yarn.YarnAllocator: Canceling requests for 4 executor > containers > 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 382.0 in stage > 0.0 (TID 382) in 22 ms on lava-2.vpc.cloudera.com (382/1000) > 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 383.0 in stage > 0.0 (TID 383, lava-2.vpc.cloudera.com, partition 383,PROCESS_LOCAL, 1980 > bytes) > 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 383.0 in stage > 0.0 (TID 383) in 24 ms on lava-2.vpc.cloudera.com (383/1000) > 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 384.0 in stage > 0.0 (TID 384, lava-2.vpc.cloudera.com, partition 384,PROCESS_LOCAL, 1980 > bytes) > 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 384.0 in stage > 0.0 (TID 384) in 19 ms on lava-2.vpc.cloudera.com (384/1000) > 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 385.0 in stage > 0.0 (TID 385, lava-2.vpc.cloudera.com, partition 385,PROCESS_LOCAL, 1980 > bytes) > 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 385.0 in stage > 0.0 (TID 385) in 22 ms on lava-2.vpc.cloudera.com (385/1000) > 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 386.0 in stage > 0.0 (TID 386, lava-2.vpc.cloudera.com, partition 386,PROCESS_LOCAL, 1980 > bytes) > 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Finished task 386.0 in stage > 0.0 (TID 386) in 20 ms on lava-2.vpc.cloudera.com (386/1000) > 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 387.0 in stage > 0.0 (TID 387, lava-2.vpc.cloudera.com, partition 387,PROCESS_LOCAL, 1980 > bytes) > 16/06/07 18:53:48 INFO yarn.YarnAllocator: Driver requested a total number of > 614 executor(s). > 16/06/07 18:53:48 INFO yarn.YarnAllocator: Canceling requests for 5 executor > containers > 16/06/07 18:53:48 INFO scheduler.TaskSetManager: Starting task 388.0 in stage > 0.0 (TID 388, lava-4.vpc.cloudera.com, partition 388,PROCESS_LOCAL, 1980 > bytes) > {code} > The easy solution is to update the message to use past tense. This is > consistent with the other messages there. > *Canceled requests for 5 executor container(s).* -- This message was sent by Atlassian JIRA (v6.3.4#6332) --------------------------------------------------------------------- To unsubscribe, e-mail: issues-unsubscr...@spark.apache.org For additional commands, e-mail: issues-h...@spark.apache.org