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.
