[JBoss JIRA] (ISPN-8822) Major performance hit when running Spark jobs

Friday, 16 February 2018

    [
https://issues.jboss.org/browse/ISPN-8822?page=com.atlassian.jira.plugin....
] 

Gustavo Fernandes edited comment on ISPN-8822 at 2/16/18 4:31 AM:
------------------------------------------------------------------

Looking at the logs during job execution:

Before
[1a7a54f07|https://github.com/infinispan/infinispan/commit/1a7a54f079b411f...]:

{noformat}
2018-02-16 09:03:48 [Executor task launch worker for task 2] INFO  InfinispanRDD:54 -
Computing partition InfinispanPartition(0, Location(localhost:11222), null,
org.infinispan.spark.config.ConnectorConfiguration@47c8fe85)
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG TcpTransportFactory:146
- Statically configured servers: [localhost:11222]
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG TcpTransportFactory:147
- Load balancer class:
org.infinispan.client.hotrod.impl.transport.tcp.RoundRobinBalancingStrategy
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG TcpTransportFactory:148
- Tcp no delay = true; client socket timeout = 60000 ms; connect timeout = 60000 ms
2018-02-16 09:03:48 [Executor task launch worker for task 2] INFO  RemoteCacheManager:229
- ISPN004021: Infinispan version: 9.2.0-SNAPSHOT
2018-02-16 09:03:48 [Executor task launch worker for task 2] INFO 
PreferredServerBalancingStrategy:23 - next server: localhost:11222
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG RemoteCacheImpl:425 -
Start called, nothing to do here(org.infinispan.spark.suites.NonClusteredSuite)
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:124 - Starting iteration with segments null
2018-02-16 09:03:48 [Executor task launch worker for task 2] INFO 
PreferredServerBalancingStrategy:23 - next server: localhost:11222
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:130 - ISPN004063: Transport
'TcpTransport{socket=Socket[addr=localhost/127.0.0.1,port=11222,localport=45034],
serverAddress=localhost:11222, id =11} ' obtained for iteration 'null'
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:134 - ISPN004062: Started iteration
'593afefe-ad31-4619-ad5c-0e90f13ba1cb'
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:72 - ISPN004046: Successfully closed remote iterator
'593afefe-ad31-4619-ad5c-0e90f13ba1cb'
2018-02-16 09:03:48 [Executor task launch worker for task 4] INFO  InfinispanRDD:54 -
Computing partition InfinispanPartition(0, Location(localhost:11222), null,
org.infinispan.spark.config.ConnectorConfiguration@6220d869)
{noformat}

After
[1a7a54f07|https://github.com/infinispan/infinispan/commit/1a7a54f079b411f...]:

{noformat}
2018-02-16 09:10:18 [Executor task launch worker for task 2] INFO  InfinispanRDD:54 -
Computing partition InfinispanPartition(0, Location(localhost:11222), null,
org.infinispan.spark.config.ConnectorConfiguration@423d4832)
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG ChannelFactory:134 -
Statically configured servers: [localhost:11222]
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG ChannelFactory:135 -
Load balancer class:
org.infinispan.client.hotrod.impl.transport.tcp.RoundRobinBalancingStrategy
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG ChannelFactory:136 -
Tcp no delay = true; client socket timeout = 60000 ms; connect timeout = 60000 ms
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG ChannelFactory:158 -
Creating new channel pool for localhost:11222
2018-02-16 09:10:18 [Executor task launch worker for task 2] INFO  RemoteCacheManager:228
- ISPN004021: Infinispan version: 9.2.0-SNAPSHOT
2018-02-16 09:10:18 [Executor task launch worker for task 2] INFO 
PreferredServerBalancingStrategy:23 - next server: localhost:11222
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG RemoteCacheImpl:382 -
Start called, nothing to do here(org.infinispan.spark.suites.NonClusteredSuite)
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:134 - Starting iteration with segments null
2018-02-16 09:10:18 [Executor task launch worker for task 2] INFO 
PreferredServerBalancingStrategy:23 - next server: localhost:11222
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:141 - ISPN004063: Channel to localhost/127.0.0.1:11222 obtained
for iteration '43bda100-a799-45f3-8a95-a65482b68fae'
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:142 - ISPN004062: Started iteration
'43bda100-a799-45f3-8a95-a65482b68fae'
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:76 - ISPN004046: Successfully closed remote iterator
'43bda100-a799-45f3-8a95-a65482b68fae'
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG NotificationManager:178
- Stopping org.infinispan.client.hotrod.counter.impl.NotificationManager@128e25f
(org.infinispan.commons.util.concurrent.NonReentrantLock@54441d56)*
2018-02-16 09:10:20 [Executor task launch worker for task 4] INFO  InfinispanRDD:54 -
Computing partition InfinispanPartition(0, Location(localhost:11222), null,
org.infinispan.spark.config.ConnectorConfiguration@6d29805e)
{noformat}

...
From the logs, there is a constant overhead of 2s when stopping the
RemoteCacheManager; iteration itself does not seem to be affected 

was (Author: gustavonalle):
Looking at the logs during job execution:

Before
[1a7a54f07|https://github.com/infinispan/infinispan/commit/1a7a54f079b411f...]:

{noformat}
2018-02-16 09:03:48 [Executor task launch worker for task 2] INFO  InfinispanRDD:54 -
Computing partition InfinispanPartition(0, Location(localhost:11222), null,
org.infinispan.spark.config.ConnectorConfiguration@47c8fe85)
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG TcpTransportFactory:146
- Statically configured servers: [localhost:11222]
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG TcpTransportFactory:147
- Load balancer class:
org.infinispan.client.hotrod.impl.transport.tcp.RoundRobinBalancingStrategy
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG TcpTransportFactory:148
- Tcp no delay = true; client socket timeout = 60000 ms; connect timeout = 60000 ms
2018-02-16 09:03:48 [Executor task launch worker for task 2] INFO  RemoteCacheManager:229
- ISPN004021: Infinispan version: 9.2.0-SNAPSHOT
2018-02-16 09:03:48 [Executor task launch worker for task 2] INFO 
PreferredServerBalancingStrategy:23 - next server: localhost:11222
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG RemoteCacheImpl:425 -
Start called, nothing to do here(org.infinispan.spark.suites.NonClusteredSuite)
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:124 - Starting iteration with segments null
2018-02-16 09:03:48 [Executor task launch worker for task 2] INFO 
PreferredServerBalancingStrategy:23 - next server: localhost:11222
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:130 - ISPN004063: Transport
'TcpTransport{socket=Socket[addr=localhost/127.0.0.1,port=11222,localport=45034],
serverAddress=localhost:11222, id =11} ' obtained for iteration 'null'
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:134 - ISPN004062: Started iteration
'593afefe-ad31-4619-ad5c-0e90f13ba1cb'
2018-02-16 09:03:48 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:72 - ISPN004046: Successfully closed remote iterator
'593afefe-ad31-4619-ad5c-0e90f13ba1cb'
{noformat}

After
[1a7a54f07|https://github.com/infinispan/infinispan/commit/1a7a54f079b411f...]:

{noformat}
2018-02-16 09:10:18 [Executor task launch worker for task 2] INFO  InfinispanRDD:54 -
Computing partition InfinispanPartition(0, Location(localhost:11222), null,
org.infinispan.spark.config.ConnectorConfiguration@423d4832)
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG ChannelFactory:134 -
Statically configured servers: [localhost:11222]
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG ChannelFactory:135 -
Load balancer class:
org.infinispan.client.hotrod.impl.transport.tcp.RoundRobinBalancingStrategy
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG ChannelFactory:136 -
Tcp no delay = true; client socket timeout = 60000 ms; connect timeout = 60000 ms
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG ChannelFactory:158 -
Creating new channel pool for localhost:11222
2018-02-16 09:10:18 [Executor task launch worker for task 2] INFO  RemoteCacheManager:228
- ISPN004021: Infinispan version: 9.2.0-SNAPSHOT
2018-02-16 09:10:18 [Executor task launch worker for task 2] INFO 
PreferredServerBalancingStrategy:23 - next server: localhost:11222
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG RemoteCacheImpl:382 -
Start called, nothing to do here(org.infinispan.spark.suites.NonClusteredSuite)
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:134 - Starting iteration with segments null
2018-02-16 09:10:18 [Executor task launch worker for task 2] INFO 
PreferredServerBalancingStrategy:23 - next server: localhost:11222
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:141 - ISPN004063: Channel to localhost/127.0.0.1:11222 obtained
for iteration '43bda100-a799-45f3-8a95-a65482b68fae'
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:142 - ISPN004062: Started iteration
'43bda100-a799-45f3-8a95-a65482b68fae'
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG
RemoteCloseableIterator:76 - ISPN004046: Successfully closed remote iterator
'43bda100-a799-45f3-8a95-a65482b68fae'
2018-02-16 09:10:18 [Executor task launch worker for task 2] DEBUG NotificationManager:178
- Stopping org.infinispan.client.hotrod.counter.impl.NotificationManager@128e25f
(org.infinispan.commons.util.concurrent.NonReentrantLock@54441d56)*
2018-02-16 09:10:20 [Executor task launch worker for task 4] INFO  InfinispanRDD:54 -
Computing partition InfinispanPartition(0, Location(localhost:11222), null,
org.infinispan.spark.config.ConnectorConfiguration@6d29805e)
{noformat}

...
From the logs, there is a constant overhead of 2s when stopping the
RemoteCacheManager; iteration itself does not seem to be affected 

...
 Major performance hit when running Spark jobs
 ---------------------------------------------

                 Key: ISPN-8822
                 URL: https://issues.jboss.org/browse/ISPN-8822
             Project: Infinispan
          Issue Type: Bug
          Components: Hot Rod
    Affects Versions: 9.2.0.CR2
            Reporter: Gustavo Fernandes
            Priority: Critical

 When trying to upgrade the [Spark connector
|https://github.com/infinispan/infinispan-spark/] to use Infinispan 9.2.0.CR2, the test
suite runs about 10x slower.  

--
This message was sent by Atlassian JIRA
(v7.5.0#75005)

2026

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009