Do you use the same version of spark for zeppelin 0.7 & 0.8 ? What kind of
job do you run ? Is it easy to reproduce it ?
Sebastian Albrecht <albrecht.sebast...@googlemail.com> 于2020年3月24日周二
下午4:24写道：
> Hi,
> i just upgraded from zeppelin 0.7.3 to 0.8.2. I am using zeppelin for
> spark in local mode and 0.8.2 came with spark updated to 2.2.1. I now
> experience slower spark job executions. I can show it in these log
> snippets: task executions with 0.7.3: milliseconds, 0.8.2: seconds
>
> 0.7.3
> INFO [2020-03-12 00:01:22,105] ({Executor task launch worker-2}
> Logging.scala[logInfo]:54) - Code generated in 24.742647 ms
> INFO [2020-03-12 00:01:22,139] ({Executor task launch worker-2}
> Logging.scala[logInfo]:54) - Code generated in 23.640976 ms
> INFO [2020-03-12 00:01:22,174] ({Executor task launch worker-2}
> Logging.scala[logInfo]:54) - Code generated in 11.667064 ms
> INFO [2020-03-12 00:01:22,193] ({Executor task launch worker-0}
> Logging.scala[logInfo]:54) - Code generated in 14.959374 ms
> INFO [2020-03-12 00:01:22,872] ({Executor task launch worker-6}
> Logging.scala[logInfo]:54) - Finished task 6.0 in stage 8.0 (TID 14). 2593
> bytes result sent to driver
> INFO [2020-03-12 00:01:22,873] ({dispatcher-event-loop-2}
> Logging.scala[logInfo]:54) - Starting task 8.0 in stage 8.0 (TID 16,
> localhost, executor driver, partition 8, NODE_LOCAL, 9086 bytes)
> INFO [2020-03-12 00:01:22,875] ({Executor task launch worker-6}
> Logging.scala[logInfo]:54) - Running task 8.0 in stage 8.0 (TID 16)
> INFO [2020-03-12 00:01:22,876] ({task-result-getter-0}
> Logging.scala[logInfo]:54) - Finished task 6.0 in stage 8.0 (TID 14) in
> 2061 ms on localhost (executor driver) (1/97)
> INFO [2020-03-12 00:01:22,938] ({Executor task launch worker-2}
> Logging.scala[logInfo]:54) - Finished task 2.0 in stage 8.0 (TID 10). 2593
> bytes result sent to driver
> INFO [2020-03-12 00:01:22,939] ({dispatcher-event-loop-7}
> Logging.scala[logInfo]:54) - Starting task 9.0 in stage 8.0 (TID 17,
> localhost, executor driver, partition 9, NODE_LOCAL, 8838 bytes)
> INFO [2020-03-12 00:01:22,946] ({task-result-getter-1}
> Logging.scala[logInfo]:54) - Finished task 2.0 in stage 8.0 (TID 10) in
> 2135 ms on localhost (executor driver) (2/97)
> INFO [2020-03-12 00:01:22,962] ({Executor task launch worker-8}
> Logging.scala[logInfo]:54) - Running task 9.0 in stage 8.0 (TID 17)
> INFO [2020-03-12 00:01:22,983] ({Executor task launch worker-3}
> Logging.scala[logInfo]:54) - Finished task 3.0 in stage 8.0 (TID 11). 2506
> bytes result sent to driver
> INFO [2020-03-12 00:01:22,984] ({dispatcher-event-loop-3}
> Logging.scala[logInfo]:54) - Starting task 10.0 in stage 8.0 (TID 18,
> localhost, executor driver, partition 10, NODE_LOCAL, 8839 bytes)
> INFO [2020-03-12 00:01:22,985] ({task-result-getter-2}
> Logging.scala[logInfo]:54) - Finished task 3.0 in stage 8.0 (TID 11) in
> 2173 ms on localhost (executor driver) (3/97)
> INFO [2020-03-12 00:01:22,986] ({Executor task launch worker-2}
> Logging.scala[logInfo]:54) - Running task 10.0 in stage 8.0 (TID 18)
> INFO [2020-03-12 00:01:23,068] ({Executor task launch worker-0}
> Logging.scala[logInfo]:54) - Finished task 0.0 in stage 8.0 (TID 8). 2506
> bytes result sent to driver
> INFO [2020-03-12 00:01:23,069] ({dispatcher-event-loop-6}
> Logging.scala[logInfo]:54) - Starting task 11.0 in stage 8.0 (TID 19,
> localhost, executor driver, partition 11, NODE_LOCAL, 9333 bytes)
> INFO [2020-03-12 00:01:23,070] ({Executor task launch worker-3}
> Logging.scala[logInfo]:54) - Running task 11.0 in stage 8.0 (TID 19)
> INFO [2020-03-12 00:01:23,070] ({task-result-getter-3}
> Logging.scala[logInfo]:54) - Finished task 0.0 in stage 8.0 (TID 8) in 2262
> ms on localhost (executor driver) (4/97)
> INFO [2020-03-12 00:01:23,088] ({Executor task launch worker-7}
> Logging.scala[logInfo]:54) - Finished task 7.0 in stage 8.0 (TID 15). 2506
> bytes result sent to driver
> INFO [2020-03-12 00:01:23,089] ({dispatcher-event-loop-2}
> Logging.scala[logInfo]:54) - Starting task 12.0 in stage 8.0 (TID 20,
> localhost, executor driver, partition 12, NODE_LOCAL, 8591 bytes)
> INFO [2020-03-12 00:01:23,090] ({task-result-getter-0}
> Logging.scala[logInfo]:54) - Finished task 7.0 in stage 8.0 (TID 15) in
> 2275 ms on localhost (executor driver) (5/97)
> INFO [2020-03-12 00:01:23,090] ({Executor task launch worker-7}
> Logging.scala[logInfo]:54) - Running task 12.0 in stage 8.0 (TID 20)
> INFO [2020-03-12 00:01:23,266] ({Executor task launch worker-1}
> Logging.scala[logInfo]:54) - Finished task 1.0 in stage 8.0 (TID 9). 2506
> bytes result sent to driver
> INFO [2020-03-12 00:01:23,267] ({dispatcher-event-loop-7}
> Logging.scala[logInfo]:54) - Starting task 13.0 in stage 8.0 (TID 21,
> localhost, executor driver, partition 13, NODE_LOCAL, 9458 bytes)
> INFO [2020-03-12 00:01:23,268] ({task-result-getter-1}
> Logging.scala[logInfo]:54) - Finished task 1.0 in stage 8.0 (TID 9) in 2457
> ms on localhost (executor driver) (6/97)
> INFO [2020-03-12 00:01:23,269] ({Executor task launch worker-1}
> Logging.scala[logInfo]:54) - Running task 13.0 in stage 8.0 (TID 21)
> INFO [2020-03-12 00:01:23,278] ({Executor task launch worker-4}
> Logging.scala[logInfo]:54) - Finished task 4.0 in stage 8.0 (TID 12). 2506
> bytes result sent to driver
> INFO [2020-03-12 00:01:23,279] ({dispatcher-event-loop-3}
> Logging.scala[logInfo]:54) - Starting task 14.0 in stage 8.0 (TID 22,
> localhost, executor driver, partition 14, NODE_LOCAL, 9086 bytes)
> INFO [2020-03-12 00:01:23,279] ({Executor task launch worker-0}
> Logging.scala[logInfo]:54) - Running task 14.0 in stage 8.0 (TID 22)
> INFO [2020-03-12 00:01:23,280] ({task-result-getter-2}
> Logging.scala[logInfo]:54) - Finished task 4.0 in stage 8.0 (TID 12) in
> 2467 ms on localhost (executor driver) (7/97)
> INFO [2020-03-12 00:01:23,773] ({Executor task launch worker-5}
> Logging.scala[logInfo]:54) - Finished task 5.0 in stage 8.0 (TID 13). 2506
> bytes result sent to driver
> INFO [2020-03-12 00:01:23,775] ({dispatcher-event-loop-6}
> Logging.scala[logInfo]:54) - Starting task 15.0 in stage 8.0 (TID 23,
> localhost, executor driver, partition 15, NODE_LOCAL, 8962 bytes)
> INFO [2020-03-12 00:01:23,775] ({Executor task launch worker-5}
> Logging.scala[logInfo]:54) - Running task 15.0 in stage 8.0 (TID 23)
> INFO [2020-03-12 00:01:23,775] ({task-result-getter-3}
> Logging.scala[logInfo]:54) - Finished task 5.0 in stage 8.0 (TID 13) in
> 2961 ms on localhost (executor driver) (8/97)
> INFO [2020-03-12 00:01:24,026] ({Executor task launch worker-2}
> Logging.scala[logInfo]:54) - Finished task 10.0 in stage 8.0 (TID 18). 2506
> bytes result sent to driver
> INFO [2020-03-12 00:01:24,028] ({dispatcher-event-loop-2}
> Logging.scala[logInfo]:54) - Starting task 16.0 in stage 8.0 (TID 24,
> localhost, executor driver, partition 16, NODE_LOCAL, 8963 bytes)
>
> 0.8.2
>
> INFO [2020-03-17 15:39:14,699] ({Executor task launch worker for task 410}
> Logging.scala[logInfo]:54) - Code generated in 7.739789 ms
> INFO [2020-03-17 15:39:14,715] ({Executor task launch worker for task
> 410} Logging.scala[logInfo]:54) - Code generated in 14.050658 ms
> INFO [2020-03-17 15:39:14,921] ({Executor task launch worker for task
> 410} Logging.scala[logInfo]:54) - Finished task 0.0 in stage 7.0 (TID 410).
> 2055 bytes result sent to driver
> INFO [2020-03-17 15:39:14,922] ({dispatcher-event-loop-3}
> Logging.scala[logInfo]:54) - Starting task 1.0 in stage 7.0 (TID 411,
> localhost, executor driver, partition 1, NODE_LOCAL, 7296 bytes)
> INFO [2020-03-17 15:39:14,922] ({Executor task launch worker for task
> 411} Logging.scala[logInfo]:54) - Running task 1.0 in stage 7.0 (TID 411)
> INFO [2020-03-17 15:39:14,922] ({task-result-getter-2}
> Logging.scala[logInfo]:54) - Finished task 0.0 in stage 7.0 (TID 410) in
> 1171 ms on localhost (executor driver) (1/113)
> INFO [2020-03-17 15:39:16,679] ({Executor task launch worker for task
> 411} Logging.scala[logInfo]:54) - Finished task 1.0 in stage 7.0 (TID 411).
> 2012 bytes result sent to driver
> INFO [2020-03-17 15:39:16,680] ({dispatcher-event-loop-1}
> Logging.scala[logInfo]:54) - Starting task 2.0 in stage 7.0 (TID 412,
> localhost, executor driver, partition 2, NODE_LOCAL, 6923 bytes)
> INFO [2020-03-17 15:39:16,680] ({Executor task launch worker for task
> 412} Logging.scala[logInfo]:54) - Running task 2.0 in stage 7.0 (TID 412)
> INFO [2020-03-17 15:39:16,680] ({task-result-getter-3}
> Logging.scala[logInfo]:54) - Finished task 1.0 in stage 7.0 (TID 411) in
> 1758 ms on localhost (executor driver) (2/113)
> INFO [2020-03-17 15:39:17,584] ({Executor task launch worker for task
> 412} Logging.scala[logInfo]:54) - Finished task 2.0 in stage 7.0 (TID 412).
> 2012 bytes result sent to driver
> INFO [2020-03-17 15:39:17,585] ({dispatcher-event-loop-7}
> Logging.scala[logInfo]:54) - Starting task 3.0 in stage 7.0 (TID 413,
> localhost, executor driver, partition 3, NODE_LOCAL, 7171 bytes)
> INFO [2020-03-17 15:39:17,585] ({Executor task launch worker for task
> 413} Logging.scala[logInfo]:54) - Running task 3.0 in stage 7.0 (TID 413)
> INFO [2020-03-17 15:39:17,585] ({task-result-getter-0}
> Logging.scala[logInfo]:54) - Finished task 2.0 in stage 7.0 (TID 412) in
> 906 ms on localhost (executor driver) (3/113)
> INFO [2020-03-17 15:39:18,811] ({Executor task launch worker for task
> 413} Logging.scala[logInfo]:54) - Finished task 3.0 in stage 7.0 (TID 413).
> 2012 bytes result sent to driver
> INFO [2020-03-17 15:39:18,811] ({dispatcher-event-loop-6}
> Logging.scala[logInfo]:54) - Starting task 4.0 in stage 7.0 (TID 414,
> localhost, executor driver, partition 4, NODE_LOCAL, 6924 bytes)
> INFO [2020-03-17 15:39:18,812] ({Executor task launch worker for task
> 414} Logging.scala[logInfo]:54) - Running task 4.0 in stage 7.0 (TID 414)
> INFO [2020-03-17 15:39:18,812] ({task-result-getter-1}
> Logging.scala[logInfo]:54) - Finished task 3.0 in stage 7.0 (TID 413) in
> 1228 ms on localhost (executor driver) (4/113)
> INFO [2020-03-17 15:39:19,459] ({Executor task launch worker for task
> 414} Logging.scala[logInfo]:54) - Finished task 4.0 in stage 7.0 (TID 414).
> 2012 bytes result sent to driver
> INFO [2020-03-17 15:39:19,460] ({dispatcher-event-loop-5}
> Logging.scala[logInfo]:54) - Starting task 5.0 in stage 7.0 (TID 415,
> localhost, executor driver, partition 5, NODE_LOCAL, 6923 bytes)
> INFO [2020-03-17 15:39:19,460] ({Executor task launch worker for task
> 415} Logging.scala[logInfo]:54) - Running task 5.0 in stage 7.0 (TID 415)
> INFO [2020-03-17 15:39:19,460] ({task-result-getter-2}
> Logging.scala[logInfo]:54) - Finished task 4.0 in stage 7.0 (TID 414) in
> 649 ms on localhost (executor driver) (5/113)
> INFO [2020-03-17 15:39:21,712] ({Executor task launch worker for task
> 415} Logging.scala[logInfo]:54) - Finished task 5.0 in stage 7.0 (TID 415).
> 2055 bytes result sent to driver
> INFO [2020-03-17 15:39:21,712] ({dispatcher-event-loop-4}
> Logging.scala[logInfo]:54) - Starting task 6.0 in stage 7.0 (TID 416,
> localhost, executor driver, partition 6, NODE_LOCAL, 7915 bytes)
> INFO [2020-03-17 15:39:21,712] ({Executor task launch worker for task
> 416} Logging.scala[logInfo]:54) - Running task 6.0 in stage 7.0 (TID 416)
> INFO [2020-03-17 15:39:21,712] ({task-result-getter-3}
> Logging.scala[logInfo]:54) - Finished task 5.0 in stage 7.0 (TID 415) in
> 2252 ms on localhost (executor driver) (6/113)
> INFO [2020-03-17 15:39:22,406] ({Executor task launch worker for task
> 416} Logging.scala[logInfo]:54) - Finished task 6.0 in stage 7.0 (TID 416).
> 2012 bytes result sent to driver
> INFO [2020-03-17 15:39:22,406] ({dispatcher-event-loop-6}
> Logging.scala[logInfo]:54) - Starting task 7.0 in stage 7.0 (TID 417,
> localhost, executor driver, partition 7, NODE_LOCAL, 7171 bytes)
> INFO [2020-03-17 15:39:22,406] ({Executor task launch worker for task
> 417} Logging.scala[logInfo]:54) - Running task 7.0 in stage 7.0 (TID 417)
> INFO [2020-03-17 15:39:22,406] ({task-result-getter-0}
> Logging.scala[logInfo]:54) - Finished task 6.0 in stage 7.0 (TID 416) in
> 694 ms on localhost (executor driver) (7/113)
> INFO [2020-03-17 15:39:23,407] ({Executor task launch worker for task
> 417} Logging.scala[logInfo]:54) - Finished task 7.0 in stage 7.0 (TID 417).
> 2012 bytes result sent to driver
> INFO [2020-03-17 15:39:23,407] ({dispatcher-event-loop-5}
> Logging.scala[logInfo]:54) - Starting task 8.0 in stage 7.0 (TID 418,
> localhost, executor driver, partition 8, NODE_LOCAL, 7047 bytes)
> INFO [2020-03-17 15:39:23,407] ({Executor task launch worker for task
> 418} Logging.scala[logInfo]:54) - Running task 8.0 in stage 7.0 (TID 418)
> INFO [2020-03-17 15:39:23,407] ({task-result-getter-1}
> Logging.scala[logInfo]:54) - Finished task 7.0 in stage 7.0 (TID 417) in
> 1001 ms on localhost (executor driver) (8/113)
> INFO [2020-03-17 15:39:24,450] ({Executor task launch worker for task
> 418} Logging.scala[logInfo]:54) - Finished task 8.0 in stage 7.0 (TID 418).
> 2012 bytes result sent to driver
> INFO [2020-03-17 15:39:24,450] ({dispatcher-event-loop-2}
> Logging.scala[logInfo]:54) - Starting task 9.0 in stage 7.0 (TID 419,
> localhost, executor driver, partition 9, NODE_LOCAL, 6924 bytes)
>
> I already gave zeppelin itself as well as the spark interpreter more Xmx.
> Is this a spark only issue or what would you recommend to narrow down the
> possible source for that performance fall.
>
> Thanks + BR,
> Sebastian.
>
>
--
Best Regards
Jeff Zhang
