You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@spark.apache.org by András Kolbert <ko...@gmail.com> on 2022/10/22 18:16:16 UTC
unexplainable delay in a few executors' task execution time (logs attached)
Good evening community,
We are facing a rather unexplainable behaviour in Spark.
Some facts:
- The spark streaming is running for hours without any issues.
- All of sudden, a particular section of the code starts to take longer
(data size has not increased)
- When we look into the execution, we noticed that the delay is due to a
few executors where the processing takes a multiple folds longer than on
all the other
(the data per task is the same, no GC increase according to Spark UI)
- See the logs below. If we compare a 'normal' executor log with a
'stuck' executor log we can see that two log lines take a minute longer
than on a normal one
- Version PySpark 2.4.4.
Spark Streaming.
Attached are a few logs below.
We are really lost, and can't figure out what's going on.
Does anyone have any suggestions?
Thanks
Andras
Log example:
'Normal'
[image: image.png]
'stuck':
[image: image.png]
[image: image.png]
[image: image.png]
[image: image.png]
[image: image.png]
[image: image.png]
[image: image.png]
[image: image.png]
Re: unexplainable delay in a few executors' task execution time (logs attached)
Posted by Artemis User <ar...@dtechspace.com>.
Andras, regarding your questions, both Spark executor cores and executor
memory sizes are soft-bound and not tied to the physical CPU cores and
RAM at the OS level (the term of executor core is also misleading since
they are not CPU cores but JVM instances). So you can indeed assigning
more cores and memory than what your OS has. I have a Spark cluster
with 6 workers with a total of 18 cores and 60 GB running on a VM with
only 8 CPU cores and 24 GB. All resource allocations (CPU cores and
memory) at the application level are by default soft-bound, so the OS
schedule them based on FIFO policy or their priority. Therefore, it is
most likely your problem is due to uneven resource allocation. Some
early-birds (i.e. executors) get enough resources allocated than late
owls, especially when you executors and memory allocations exceed what
the OS offers. This could also happen when your containers/virtual
machines for hosting your workers, aren't getting resources evenly
distributed since most VMs and containers are soft-bound by default as well.
It is unlikely spill or skew be the case here since your partition and
tasks of your streaming job is evenly distributed across all executors
(your log file indicates the executor still has plenty of memory left
and the troubled one spends less memory than the normal one). I could
be wrong but just can't think of any other explanations. Because Spark
managed its own spill/serialization functions, it doesn't know where the
physical memory ends where the virtual begins. You may get data written
into SWAP space without any indication of a spill showing on the Spark
UI. Only an OS-level resource monitor can help..
On 10/23/22 4:19 AM, András Kolbert wrote:
> Hi All
>
> Thank you for your inputs .
>
> Artemis, very useful suggestions I will take it up with the DevOps
> person who is currently working on adding additional application
> levele monitoring to each application. One thing that is bizarre, that
> all the other 4 streaming applications are not affected! So it must be
> on a container/application level (plus a simple restart solves the
> problem)
> Your third point, how is it possible to assign more memory than what's
> available?
> 4th point, other applications are isolated on a memory and CPU level,
> aren't they?
>
> Sean, regarding spill. Each task has the same amount of spill
> (according to spark ui). What else can I check to validate your theory?
>
> Tufan: that's indeed happening after we observe this task level delay.
> Prior the application 's processing time is around 2-2.3 mins average.
> Versioning, yes we will be upgrading once the downstream systems are
> updated (Kafka). Similar to Sean, what makes you think that there is a
> skew? Task level number of records seems to be uniformly distributed.
>
> Thanks
> Andras
>
>
>
>
> On Sun, 23 Oct 2022, 06:49 Tufan Rakshit, <tu...@gmail.com> wrote:
>
> Hi Andras ,
>
> A few points you are running the job are Micro batches of 3
> minutes and the final delivery per batch currently from your
> Screenshot is 10 min , So generally you have a huge lag in
> Scheduling and processing .
> you are using a really old version of Spark 2.4 , please upgrade
> Spark to 3.3.0 , it comes with a Tons of New development in
> Structured Streaming .
> Please check in the config what kind of Scheduler please enable
> FAIR scheduling .
> Please use Machines with SSD , this will make the processing much
> faster that HDD based Machines ,this should also solve the problem
> with Spill .
> Each batch is also taking on Avg 2 min to process the data that is
> arriving which also can be used if you use i5 generation Machines .
> In the Current scenario one particular partition is big , So try
> to mitigate the Skew by adding a dummy key with more even
> distribution .
> And please please convert the code to scala when it comes to do
> real hard work in Streaming in Big data please don't use Python .
>
> Best
> Tufan
>
> On Sun, 23 Oct 2022 at 04:06, Sean Owen <sr...@gmail.com> wrote:
>
> This just looks like spill? one partition of a batch is
> unusually large?
>
> On Sat, Oct 22, 2022 at 8:57 PM Artemis User
> <ar...@dtechspace.com> wrote:
>
> The log file doesn't reveal where the problem might be
> since no error occurred. You may have a bottleneck
> somewhere at the OS level beyond Spark. Couple of
> suggestions for your consideration:
>
> 1. The data sink of your streaming pipeline might be full
> or congested (e.g., disk drive out of space).
> 2. Log file/directory is full or nearly full.
> 3. Worker/executors run out of physical memory so the
> SWAP has to kick in, especially when Spark is
> configured to have more memory assigned to executors
> than the total available RAM.
> 4. Some other applications are running on the same
> machine and compete with OS resources, e.g., CPU cores.
>
> There are also other possibilities. You may want to
> check/monitor the resource consumption status on your OS
> to get a better idea where the bottleneck might be...
>
>
> On 10/22/22 2:16 PM, András Kolbert wrote:
>> Good evening community,
>>
>> We are facing a rather unexplainable behaviour in Spark.
>>
>> Some facts:
>>
>> * The spark streaming is running for hours without any
>> issues.
>> * All of sudden, a particular section of the code
>> starts to take longer
>> (data size has not increased)
>> * When we look into the execution, we noticed that the
>> delay is due to a few executors where the processing
>> takes a multiple folds longer than on all the other
>> (the data per task is the same, no GC increase
>> according to Spark UI)
>> * See the logs below. If we compare a 'normal' executor
>> log with a 'stuck' executor log we can see that two
>> log lines take a minute longer than on a normal one
>> *
>> Version PySpark 2.4.4.
>> Spark Streaming.
>>
>>
>> Attached are a few logs below.
>>
>> We are really lost, and can't figure out what's going on.
>> Does anyone have any suggestions?
>>
>> Thanks
>> Andras
>>
>>
>>
>> Log example:
>> 'Normal'
>> image.png
>> 'stuck':
>> image.png
>>
>>
>>
>> image.png
>>
>>
>>
>>
>>
>> image.png
>> image.png
>> image.png
>> image.png
>> image.png
>>
>> image.png
>>
>>
>>
>
Re: unexplainable delay in a few executors' task execution time (logs attached)
Posted by András Kolbert <ko...@gmail.com>.
Hi All
Thank you for your inputs .
Artemis, very useful suggestions I will take it up with the DevOps person
who is currently working on adding additional application levele monitoring
to each application. One thing that is bizarre, that all the other 4
streaming applications are not affected! So it must be on a
container/application level (plus a simple restart solves the problem)
Your third point, how is it possible to assign more memory than what's
available?
4th point, other applications are isolated on a memory and CPU level,
aren't they?
Sean, regarding spill. Each task has the same amount of spill (according to
spark ui). What else can I check to validate your theory?
Tufan: that's indeed happening after we observe this task level delay.
Prior the application 's processing time is around 2-2.3 mins average.
Versioning, yes we will be upgrading once the downstream systems are
updated (Kafka). Similar to Sean, what makes you think that there is a
skew? Task level number of records seems to be uniformly distributed.
Thanks
Andras
On Sun, 23 Oct 2022, 06:49 Tufan Rakshit, <tu...@gmail.com> wrote:
> Hi Andras ,
>
> A few points you are running the job are Micro batches of 3 minutes and
> the final delivery per batch currently from your Screenshot is 10 min , So
> generally you have a huge lag in Scheduling and processing .
> you are using a really old version of Spark 2.4 , please upgrade Spark to
> 3.3.0 , it comes with a Tons of New development in Structured Streaming .
> Please check in the config what kind of Scheduler please enable FAIR
> scheduling .
> Please use Machines with SSD , this will make the processing much faster
> that HDD based Machines ,this should also solve the problem with Spill .
> Each batch is also taking on Avg 2 min to process the data that is
> arriving which also can be used if you use i5 generation Machines .
> In the Current scenario one particular partition is big , So try to
> mitigate the Skew by adding a dummy key with more even distribution .
> And please please convert the code to scala when it comes to do real hard
> work in Streaming in Big data please don't use Python .
>
> Best
> Tufan
>
> On Sun, 23 Oct 2022 at 04:06, Sean Owen <sr...@gmail.com> wrote:
>
>> This just looks like spill? one partition of a batch is unusually large?
>>
>> On Sat, Oct 22, 2022 at 8:57 PM Artemis User <ar...@dtechspace.com>
>> wrote:
>>
>>> The log file doesn't reveal where the problem might be since no error
>>> occurred. You may have a bottleneck somewhere at the OS level beyond
>>> Spark. Couple of suggestions for your consideration:
>>>
>>> 1. The data sink of your streaming pipeline might be full or
>>> congested (e.g., disk drive out of space).
>>> 2. Log file/directory is full or nearly full.
>>> 3. Worker/executors run out of physical memory so the SWAP has to
>>> kick in, especially when Spark is configured to have more memory assigned
>>> to executors than the total available RAM.
>>> 4. Some other applications are running on the same machine and
>>> compete with OS resources, e.g., CPU cores.
>>>
>>> There are also other possibilities. You may want to check/monitor the
>>> resource consumption status on your OS to get a better idea where the
>>> bottleneck might be...
>>>
>>> On 10/22/22 2:16 PM, András Kolbert wrote:
>>>
>>> Good evening community,
>>>
>>> We are facing a rather unexplainable behaviour in Spark.
>>>
>>> Some facts:
>>>
>>> - The spark streaming is running for hours without any issues.
>>> - All of sudden, a particular section of the code starts to take
>>> longer
>>> (data size has not increased)
>>> - When we look into the execution, we noticed that the delay is due
>>> to a few executors where the processing takes a multiple folds longer than
>>> on all the other
>>> (the data per task is the same, no GC increase according to Spark UI)
>>> - See the logs below. If we compare a 'normal' executor log with a
>>> 'stuck' executor log we can see that two log lines take a minute longer
>>> than on a normal one
>>> - Version PySpark 2.4.4.
>>> Spark Streaming.
>>>
>>>
>>> Attached are a few logs below.
>>>
>>> We are really lost, and can't figure out what's going on.
>>> Does anyone have any suggestions?
>>>
>>> Thanks
>>> Andras
>>>
>>>
>>>
>>> Log example:
>>> 'Normal'
>>> [image: image.png]
>>> 'stuck':
>>> [image: image.png]
>>>
>>>
>>>
>>> [image: image.png]
>>>
>>>
>>>
>>>
>>>
>>> [image: image.png]
>>> [image: image.png]
>>> [image: image.png]
>>> [image: image.png]
>>> [image: image.png]
>>>
>>> [image: image.png]
>>>
>>>
>>>
>>>
>>>
Re: unexplainable delay in a few executors' task execution time (logs attached)
Posted by Tufan Rakshit <tu...@gmail.com>.
Hi Andras ,
A few points you are running the job are Micro batches of 3 minutes and the
final delivery per batch currently from your Screenshot is 10 min , So
generally you have a huge lag in Scheduling and processing .
you are using a really old version of Spark 2.4 , please upgrade Spark to
3.3.0 , it comes with a Tons of New development in Structured Streaming .
Please check in the config what kind of Scheduler please enable FAIR
scheduling .
Please use Machines with SSD , this will make the processing much faster
that HDD based Machines ,this should also solve the problem with Spill .
Each batch is also taking on Avg 2 min to process the data that is arriving
which also can be used if you use i5 generation Machines .
In the Current scenario one particular partition is big , So try to
mitigate the Skew by adding a dummy key with more even distribution .
And please please convert the code to scala when it comes to do real hard
work in Streaming in Big data please don't use Python .
Best
Tufan
On Sun, 23 Oct 2022 at 04:06, Sean Owen <sr...@gmail.com> wrote:
> This just looks like spill? one partition of a batch is unusually large?
>
> On Sat, Oct 22, 2022 at 8:57 PM Artemis User <ar...@dtechspace.com>
> wrote:
>
>> The log file doesn't reveal where the problem might be since no error
>> occurred. You may have a bottleneck somewhere at the OS level beyond
>> Spark. Couple of suggestions for your consideration:
>>
>> 1. The data sink of your streaming pipeline might be full or
>> congested (e.g., disk drive out of space).
>> 2. Log file/directory is full or nearly full.
>> 3. Worker/executors run out of physical memory so the SWAP has to
>> kick in, especially when Spark is configured to have more memory assigned
>> to executors than the total available RAM.
>> 4. Some other applications are running on the same machine and
>> compete with OS resources, e.g., CPU cores.
>>
>> There are also other possibilities. You may want to check/monitor the
>> resource consumption status on your OS to get a better idea where the
>> bottleneck might be...
>>
>> On 10/22/22 2:16 PM, András Kolbert wrote:
>>
>> Good evening community,
>>
>> We are facing a rather unexplainable behaviour in Spark.
>>
>> Some facts:
>>
>> - The spark streaming is running for hours without any issues.
>> - All of sudden, a particular section of the code starts to take
>> longer
>> (data size has not increased)
>> - When we look into the execution, we noticed that the delay is due
>> to a few executors where the processing takes a multiple folds longer than
>> on all the other
>> (the data per task is the same, no GC increase according to Spark UI)
>> - See the logs below. If we compare a 'normal' executor log with a
>> 'stuck' executor log we can see that two log lines take a minute longer
>> than on a normal one
>> - Version PySpark 2.4.4.
>> Spark Streaming.
>>
>>
>> Attached are a few logs below.
>>
>> We are really lost, and can't figure out what's going on.
>> Does anyone have any suggestions?
>>
>> Thanks
>> Andras
>>
>>
>>
>> Log example:
>> 'Normal'
>> [image: image.png]
>> 'stuck':
>> [image: image.png]
>>
>>
>>
>> [image: image.png]
>>
>>
>>
>>
>>
>> [image: image.png]
>> [image: image.png]
>> [image: image.png]
>> [image: image.png]
>> [image: image.png]
>>
>> [image: image.png]
>>
>>
>>
>>
>>
Re: unexplainable delay in a few executors' task execution time (logs attached)
Posted by Sean Owen <sr...@gmail.com>.
This just looks like spill? one partition of a batch is unusually large?
On Sat, Oct 22, 2022 at 8:57 PM Artemis User <ar...@dtechspace.com> wrote:
> The log file doesn't reveal where the problem might be since no error
> occurred. You may have a bottleneck somewhere at the OS level beyond
> Spark. Couple of suggestions for your consideration:
>
> 1. The data sink of your streaming pipeline might be full or congested
> (e.g., disk drive out of space).
> 2. Log file/directory is full or nearly full.
> 3. Worker/executors run out of physical memory so the SWAP has to kick
> in, especially when Spark is configured to have more memory assigned to
> executors than the total available RAM.
> 4. Some other applications are running on the same machine and compete
> with OS resources, e.g., CPU cores.
>
> There are also other possibilities. You may want to check/monitor the
> resource consumption status on your OS to get a better idea where the
> bottleneck might be...
>
> On 10/22/22 2:16 PM, András Kolbert wrote:
>
> Good evening community,
>
> We are facing a rather unexplainable behaviour in Spark.
>
> Some facts:
>
> - The spark streaming is running for hours without any issues.
> - All of sudden, a particular section of the code starts to take longer
> (data size has not increased)
> - When we look into the execution, we noticed that the delay is due to
> a few executors where the processing takes a multiple folds longer than on
> all the other
> (the data per task is the same, no GC increase according to Spark UI)
> - See the logs below. If we compare a 'normal' executor log with a
> 'stuck' executor log we can see that two log lines take a minute longer
> than on a normal one
> - Version PySpark 2.4.4.
> Spark Streaming.
>
>
> Attached are a few logs below.
>
> We are really lost, and can't figure out what's going on.
> Does anyone have any suggestions?
>
> Thanks
> Andras
>
>
>
> Log example:
> 'Normal'
> [image: image.png]
> 'stuck':
> [image: image.png]
>
>
>
> [image: image.png]
>
>
>
>
>
> [image: image.png]
> [image: image.png]
> [image: image.png]
> [image: image.png]
> [image: image.png]
>
> [image: image.png]
>
>
>
>
>
Re: unexplainable delay in a few executors' task execution time (logs attached)
Posted by Artemis User <ar...@dtechspace.com>.
The log file doesn't reveal where the problem might be since no error
occurred. You may have a bottleneck somewhere at the OS level beyond
Spark. Couple of suggestions for your consideration:
1. The data sink of your streaming pipeline might be full or congested
(e.g., disk drive out of space).
2. Log file/directory is full or nearly full.
3. Worker/executors run out of physical memory so the SWAP has to kick
in, especially when Spark is configured to have more memory assigned
to executors than the total available RAM.
4. Some other applications are running on the same machine and compete
with OS resources, e.g., CPU cores.
There are also other possibilities. You may want to check/monitor the
resource consumption status on your OS to get a better idea where the
bottleneck might be...
On 10/22/22 2:16 PM, András Kolbert wrote:
> Good evening community,
>
> We are facing a rather unexplainable behaviour in Spark.
>
> Some facts:
>
> * The spark streaming is running for hours without any issues.
> * All of sudden, a particular section of the code starts to take longer
> (data size has not increased)
> * When we look into the execution, we noticed that the delay is due
> to a few executors where the processing takes a multiple folds
> longer than on all the other
> (the data per task is the same, no GC increase according to Spark UI)
> * See the logs below. If we compare a 'normal' executor log with a
> 'stuck' executor log we can see that two log lines take a minute
> longer than on a normal one
> *
> Version PySpark 2.4.4.
> Spark Streaming.
>
>
> Attached are a few logs below.
>
> We are really lost, and can't figure out what's going on.
> Does anyone have any suggestions?
>
> Thanks
> Andras
>
>
>
> Log example:
> 'Normal'
> image.png
> 'stuck':
> image.png
>
>
>
> image.png
>
>
>
>
>
> image.png
> image.png
> image.png
> image.png
> image.png
>
> image.png
>
>
>