Apache Ignite .Net node would not start when a Spring configuration file is used

3/28/2019

I'm using Apache Ignite .Net v2.7. While resolving another issue (How to use TcpDiscoveryKubernetesIpFinder in Apache Ignite .Net) I've added a sprint configuration file where the Kubernetes configuration is specified. All other configuration goes in the C# code.

The content of the config file is below (taken from the docs):

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xmlns:util="http://www.springframework.org/schema/util"
       xsi:schemaLocation="
        http://www.springframework.org/schema/beans
        http://www.springframework.org/schema/beans/spring-beans.xsd
        http://www.springframework.org/schema/util
        http://www.springframework.org/schema/util/spring-util.xsd">

  <bean class="org.apache.ignite.configuration.IgniteConfiguration">
    <property name="discoverySpi">
      <bean class="org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi">
        <property name="ipFinder">
          <bean class="org.apache.ignite.spi.discovery.tcp.ipfinder.kubernetes.TcpDiscoveryKubernetesIpFinder">
            <property name="namespace" value="ignite"/>
          </bean>
        </property>
      </bean>
    </property>
  </bean>
</beans>

The C# code which references the file is as follows:

var igniteConfig = new IgniteConfiguration
        {
            SpringConfigUrl = "./kubernetes.config",
            JvmClasspath = string.Join(";",
                new string[] {
                    "ignite-kubernetes-2.7.0.jar",
                    "jackson-core-2.9.6.jar",
                    "jackson-databind-2.9.6.jar"
                }
                .Select(c => System.IO.Path.Combine(Environment.CurrentDirectory, "Libs", c)))}

The Ignite node starts fine locally but when deployed to a Kubernetes cluster, it fails with this error:

    INFO: Loading XML bean definitions from URL [file:/app/./kubernetes.config]
Mar 28, 2019 10:43:55 PM org.springframework.context.support.AbstractApplicationContext prepareRefresh
INFO: Refreshing org.springframework.context.support.GenericApplicationContext@1bc6a36e: startup date [Thu Mar 28 22:43:55 UTC 2019]; root of context hierarchy

Unhandled Exception: Apache.Ignite.Core.Common.IgniteException: Java exception occurred [class=java.lang.NoSuchFieldError, message=logger] ---> Apache.Ignite.Core.Com
mon.JavaException: java.lang.NoSuchFieldError: logger
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:727)
        at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:867)
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:543)
        at org.apache.ignite.internal.util.spring.IgniteSpringHelperImpl.applicationContext(IgniteSpringHelperImpl.java:381)
        at org.apache.ignite.internal.util.spring.IgniteSpringHelperImpl.loadConfigurations(IgniteSpringHelperImpl.java:104)
        at org.apache.ignite.internal.util.spring.IgniteSpringHelperImpl.loadConfigurations(IgniteSpringHelperImpl.java:98)
        at org.apache.ignite.internal.IgnitionEx.loadConfigurations(IgnitionEx.java:751)
        at org.apache.ignite.internal.IgnitionEx.loadConfiguration(IgnitionEx.java:809)
        at org.apache.ignite.internal.processors.platform.PlatformIgnition.configuration(PlatformIgnition.java:153)
        at org.apache.ignite.internal.processors.platform.PlatformIgnition.start(PlatformIgnition.java:68)

   at Apache.Ignite.Core.Impl.Unmanaged.Jni.Env.ExceptionCheck()
   at Apache.Ignite.Core.Impl.Unmanaged.UnmanagedUtils.IgnitionStart(Env env, String cfgPath, String gridName, Boolean clientMode, Boolean userLogger, Int64 igniteId,
 Boolean redirectConsole)
   at Apache.Ignite.Core.Ignition.Start(IgniteConfiguration cfg)
   --- End of inner exception stack trace ---
   at Apache.Ignite.Core.Ignition.Start(IgniteConfiguration cfg)
   at UtilityClick.ProductService.Initializer.<>c__DisplayClass0_0.<Init>b__1(IServiceProvider sp) in /src/ProductService/Initializer.cs:line 102
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitFactory(FactoryCallSite factoryCallSite, ServiceProviderEngineScope scope)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(IServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitScoped(ScopedCallSite scopedCallSite, ServiceProviderEngineScope scope)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitSingleton(SingletonCallSite singletonCallSite, ServiceProviderEngineScope sc
ope)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(IServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.DynamicServiceProviderEngine.<>c__DisplayClass1_0.<RealizeService>b__0(ServiceProviderEngineScope scope)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.ServiceProviderEngine.GetService(Type serviceType, ServiceProviderEngineScope serviceProviderEngineScope)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.ServiceProviderEngine.GetService(Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.GetService(Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetService[T](IServiceProvider provider)
   at UtilityClick.ProductService.Initializer.Init(IServiceCollection serviceCollection) in /src/ProductService/Initializer.cs:line 123
   at UtilityClick.ProductService.ApiStartup.ConfigureServices(IServiceCollection services) in /src/ProductService/ApiStartup.cs:line 50
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Hosting.ConventionBasedStartup.ConfigureServices(IServiceCollection services)
   at Microsoft.AspNetCore.Hosting.Internal.WebHost.EnsureApplicationServices()
   at Microsoft.AspNetCore.Hosting.Internal.WebHost.Initialize()
   at Microsoft.AspNetCore.Hosting.WebHostBuilder.Build()
   at UtilityClick.ProductService.Program.Main(String[] args) in /src/ProductService/Program.cs:line 14

Do you have any idea why it might happen? Which logger is it complaining about?

Kubernetes is running Linux containers, locally I'm using Windows 10.

Two more observations:

  1. When I specify the config file name as kubernetes.config, the node launches successfully on local but in Kubernetes it fails with an error which suggests that the URL "kubernetes.config" is missing the schema part.

  2. JvmClasspath: I have to add "ignite-kubernetes-2.7.0.jar", otherwise the JAR is not found although it is located in the same dir as the rest of the Ignite classes. Adding the next two entries does not make any difference.

-- Alex Avrutin
ignite
kubernetes

2 Answers

4/9/2019

After reviewing your corrected logs it seems that you have stumbled on IGNITE-10577 issue. Indeed you will have to copy this dependency manually. I still wonder why you were seeing that error instead of the correct one:

SEVERE: Got exception while starting (will rollback startup routine).
java.lang.NoClassDefFoundError: com/fasterxml/jackson/annotation/JsonView
   at com.fasterxml.jackson.databind.introspect.JacksonAnnotationIntrospector.<clinit>(JacksonAnnotationIntrospector.java:37)
   at com.fasterxml.jackson.databind.ObjectMapper.<clinit>(ObjectMapper.java:291)
   at org.apache.ignite.spi.discovery.tcp.ipfinder.kubernetes.TcpDiscoveryKubernetesIpFinder.getRegisteredAddresses(TcpDiscoveryKubrnetesIpFinder.java:151)
-- alamar
Source: StackOverflow

3/29/2019

It looks like you have different versions of spring-core and spring-beans in your Java classpath for some reason. There's no reason for them to not match exactly. I think it should print full classpath somewhere, you can look it up.

In 2.7 Apache Ignite ships differing version of Spring libs in ignite-spring-data_2.0 submodule. Maybe it got into your classpath by accident? Please remove that dir for good - you'll not need it when using .Net.

UPD: With your reproducer project, it looks like I'm starting successfully:

Directories in the working directory:
/home/gridgain/w/ignitenet-kubernetes-example/ApacheIgniteNetKubernetesExample/bin/Debug/netcoreapp2.2/libs

Files in the working directory:
/home/gridgain/w/ignitenet-kubernetes-example/ApacheIgniteNetKubernetesExample/bin/Debug/netcoreapp2.2/ApacheIgniteNetKubernetesExample.dll
/home/gridgain/w/ignitenet-kubernetes-example/ApacheIgniteNetKubernetesExample/bin/Debug/netcoreapp2.2/log4net.config
/home/gridgain/w/ignitenet-kubernetes-example/ApacheIgniteNetKubernetesExample/bin/Debug/netcoreapp2.2/ApacheIgniteNetKubernetesExample.deps.json
/home/gridgain/w/ignitenet-kubernetes-example/ApacheIgniteNetKubernetesExample/bin/Debug/netcoreapp2.2/ApacheIgniteNetKubernetesExample.pdb
/home/gridgain/w/ignitenet-kubernetes-example/ApacheIgniteNetKubernetesExample/bin/Debug/netcoreapp2.2/ApacheIgniteNetKubernetesExample.runtimeconfig.dev.json
/home/gridgain/w/ignitenet-kubernetes-example/ApacheIgniteNetKubernetesExample/bin/Debug/netcoreapp2.2/appsettings.json
/home/gridgain/w/ignitenet-kubernetes-example/ApacheIgniteNetKubernetesExample/bin/Debug/netcoreapp2.2/ApacheIgniteNetKubernetesExample.runtimeconfig.json
/home/gridgain/w/ignitenet-kubernetes-example/ApacheIgniteNetKubernetesExample/bin/Debug/netcoreapp2.2/appsettings.development.json

log4j:WARN No appenders could be found for logger (org.springframework.core.env.StandardEnvironment).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
[2019-04-03 17:29:02,095][INFO ][main][IgniteKernal] 

>>>    __________  ________________  
>>>   /  _/ ___/ |/ /  _/_  __/ __/  
>>>  _/ // (7 7    // /  / / / _/    
>>> /___/\___/_/|_/___/ /_/ /___/   
>>> 
>>> ver. 2.7.0#20181130-sha1:256ae401
>>> 2018 Copyright(C) Apache Software Foundation
>>> 
>>> Ignite documentation: http://ignite.apache.org

[2019-04-03 17:29:02,096][INFO ][main][IgniteKernal] Config URL: n/a
[2019-04-03 17:29:02,110][INFO ][main][IgniteKernal] IgniteConfiguration [igniteInstanceName=null, pubPoolSize=8, svcPoolSize=8, callbackPoolSize=8, stripedPoolSize=8, sysPoolSize=8, mgmtPoolSize=4, igfsPoolSize=8, dataStreamerPoolSize=8, utilityCachePoolSize=8, utilityCacheKeepAliveTime=60000, p2pPoolSize=2, qryPoolSize=8, igniteHome=/home/gridgain/Downloads/apache-ignite-2.7.0-bin, igniteWorkDir=/home/gridgain/Downloads/apache-ignite-2.7.0-bin/work, mbeanSrv=com.sun.jmx.mbeanserver.JmxMBeanServer@3e58a80e, nodeId=f5a4c49b-82c9-44df-ba8b-5ff97cad0a1f, marsh=BinaryMarshaller [], marshLocJobs=false, daemon=false, p2pEnabled=false, netTimeout=5000, sndRetryDelay=1000, sndRetryCnt=3, metricsHistSize=10000, metricsUpdateFreq=2000, metricsExpTime=9223372036854775807, discoSpi=TcpDiscoverySpi [addrRslvr=null, sockTimeout=0, ackTimeout=0, marsh=null, reconCnt=10, reconDelay=2000, maxAckTimeout=600000, forceSrvMode=false, clientReconnectDisabled=false, internalLsnr=null], segPlc=STOP, segResolveAttempts=2, waitForSegOnStart=true, allResolversPassReq=true, segChkFreq=10000, commSpi=TcpCommunicationSpi [connectGate=null, connPlc=org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$FirstConnectionPolicy@4cc8eb05, enableForcibleNodeKill=false, enableTroubleshootingLog=false, locAddr=null, locHost=null, locPort=47100, locPortRange=100, shmemPort=-1, directBuf=true, directSndBuf=false, idleConnTimeout=600000, connTimeout=5000, maxConnTimeout=600000, reconCnt=10, sockSndBuf=32768, sockRcvBuf=32768, msgQueueLimit=0, slowClientQueueLimit=0, nioSrvr=null, shmemSrv=null, usePairedConnections=false, connectionsPerNode=1, tcpNoDelay=true, filterReachableAddresses=false, ackSndThreshold=32, unackedMsgsBufSize=0, sockWriteTimeout=2000, boundTcpPort=-1, boundTcpShmemPort=-1, selectorsCnt=4, selectorSpins=0, addrRslvr=null, ctxInitLatch=java.util.concurrent.CountDownLatch@51f116b8[Count = 1], stopping=false], evtSpi=org.apache.ignite.spi.eventstorage.NoopEventStorageSpi@19d481b, colSpi=NoopCollisionSpi [], deploySpi=LocalDeploymentSpi [], indexingSpi=org.apache.ignite.spi.indexing.noop.NoopIndexingSpi@7690781, addrRslvr=null, encryptionSpi=org.apache.ignite.spi.encryption.noop.NoopEncryptionSpi@77eca502, clientMode=false, rebalanceThreadPoolSize=1, txCfg=TransactionConfiguration [txSerEnabled=false, dfltIsolation=REPEATABLE_READ, dfltConcurrency=PESSIMISTIC, dfltTxTimeout=0, txTimeoutOnPartitionMapExchange=0, pessimisticTxLogSize=0, pessimisticTxLogLinger=10000, tmLookupClsName=null, txManagerFactory=null, useJtaSync=false], cacheSanityCheckEnabled=true, discoStartupDelay=60000, deployMode=SHARED, p2pMissedCacheSize=100, locHost=null, timeSrvPortBase=31100, timeSrvPortRange=100, failureDetectionTimeout=10000, sysWorkerBlockedTimeout=null, clientFailureDetectionTimeout=30000, metricsLogFreq=60000, hadoopCfg=null, connectorCfg=ConnectorConfiguration [jettyPath=null, host=null, port=11211, noDelay=true, directBuf=false, sndBufSize=32768, rcvBufSize=32768, idleQryCurTimeout=600000, idleQryCurCheckFreq=60000, sndQueueLimit=0, selectorCnt=4, idleTimeout=7000, sslEnabled=false, sslClientAuth=false, sslCtxFactory=null, sslFactory=null, portRange=100, threadPoolSize=8, msgInterceptor=null], odbcCfg=null, warmupClos=null, atomicCfg=AtomicConfiguration [seqReserveSize=1000, cacheMode=PARTITIONED, backups=1, aff=null, grpName=null], classLdr=null, sslCtxFactory=null, platformCfg=PlatformDotNetConfiguration [binaryCfg=null], binaryCfg=null, memCfg=null, pstCfg=null, dsCfg=DataStorageConfiguration [sysRegionInitSize=41943040, sysRegionMaxSize=104857600, pageSize=0, concLvl=0, dfltDataRegConf=DataRegionConfiguration [name=default, maxSize=6720133529, initSize=268435456, swapPath=null, pageEvictionMode=DISABLED, evictionThreshold=0.9, emptyPagesPoolSize=100, metricsEnabled=false, metricsSubIntervalCount=5, metricsRateTimeInterval=60000, persistenceEnabled=false, checkpointPageBufSize=0], dataRegions=null, storagePath=null, checkpointFreq=180000, lockWaitTime=10000, checkpointThreads=4, checkpointWriteOrder=SEQUENTIAL, walHistSize=20, maxWalArchiveSize=1073741824, walSegments=10, walSegmentSize=67108864, walPath=db/wal, walArchivePath=db/wal/archive, metricsEnabled=false, walMode=LOG_ONLY, walTlbSize=131072, walBuffSize=0, walFlushFreq=2000, walFsyncDelay=1000, walRecordIterBuffSize=67108864, alwaysWriteFullPages=false, fileIOFactory=org.apache.ignite.internal.processors.cache.persistence.file.AsyncFileIOFactory@59af0466, metricsSubIntervalCnt=5, metricsRateTimeInterval=60000, walAutoArchiveAfterInactivity=-1, writeThrottlingEnabled=false, walCompactionEnabled=false, walCompactionLevel=1, checkpointReadLockTimeout=null], activeOnStart=true, autoActivation=true, longQryWarnTimeout=3000, sqlConnCfg=null, cliConnCfg=ClientConnectorConfiguration [host=null, port=10800, portRange=100, sockSndBufSize=0, sockRcvBufSize=0, tcpNoDelay=true, maxOpenCursorsPerConn=128, threadPoolSize=8, idleTimeout=0, jdbcEnabled=true, odbcEnabled=true, thinCliEnabled=true, sslEnabled=false, useIgniteSslCtxFactory=true, sslClientAuth=false, sslCtxFactory=null], mvccVacuumThreadCnt=2, mvccVacuumFreq=5000, authEnabled=false, failureHnd=null, commFailureRslvr=null]
[2019-04-03 17:29:02,110][INFO ][main][IgniteKernal] Daemon mode: off
[2019-04-03 17:29:02,110][INFO ][main][IgniteKernal] OS: Linux 4.15.0-46-generic amd64
[2019-04-03 17:29:02,110][INFO ][main][IgniteKernal] OS user: gridgain
[2019-04-03 17:29:02,111][INFO ][main][IgniteKernal] PID: 8539
[2019-04-03 17:29:02,111][INFO ][main][IgniteKernal] Language runtime: Java Platform API Specification ver. 1.8
[2019-04-03 17:29:02,111][INFO ][main][IgniteKernal] VM information: Java(TM) SE Runtime Environment 1.8.0_144-b01 Oracle Corporation Java HotSpot(TM) 64-Bit Server VM 25.144-b01
[2019-04-03 17:29:02,112][INFO ][main][IgniteKernal] VM total memory: 0.48GB
[2019-04-03 17:29:02,112][INFO ][main][IgniteKernal] Remote Management [restart: off, REST: on, JMX (remote: off)]
[2019-04-03 17:29:02,113][INFO ][main][IgniteKernal] Logger: Log4JLogger [quiet=false, config=/home/gridgain/Downloads/apache-ignite-2.7.0-bin/config/ignite-log4j.xml]
[2019-04-03 17:29:02,113][INFO ][main][IgniteKernal] IGNITE_HOME=/home/gridgain/Downloads/apache-ignite-2.7.0-bin
[2019-04-03 17:29:02,113][INFO ][main][IgniteKernal] VM arguments: [-Djava.net.preferIPv4Stack=true, -Xms512m, -Xmx512m, -DIGNITE_PERFORMANCE_SUGGESTIONS_DISABLED=true, -DIGNITE_QUIET=false]
[2019-04-03 17:29:02,113][INFO ][main][IgniteKernal] System cache's DataRegion size is configured to 40 MB. Use DataStorageConfiguration.systemRegionInitialSize property to change the setting.
[2019-04-03 17:29:02,119][INFO ][main][IgniteKernal] Configured caches [in 'sysMemPlc' dataRegion: ['ignite-sys-cache']]
[2019-04-03 17:29:02,122][INFO ][main][IgniteKernal] 3-rd party licenses can be found at: /home/gridgain/Downloads/apache-ignite-2.7.0-bin/libs/licenses
[2019-04-03 17:29:02,123][INFO ][main][IgniteKernal] Local node user attribute [service=ProductService]
[2019-04-03 17:29:02,157][INFO ][main][IgnitePluginProcessor] Configured plugins:
[2019-04-03 17:29:02,157][INFO ][main][IgnitePluginProcessor]   ^-- None
[2019-04-03 17:29:02,157][INFO ][main][IgnitePluginProcessor] 
[2019-04-03 17:29:02,158][INFO ][main][FailureProcessor] Configured failure handler: [hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0, super=AbstractFailureHandler [ignoredFailureTypes=[SYSTEM_WORKER_BLOCKED]]]]
[2019-04-03 17:29:02,186][INFO ][main][TcpCommunicationSpi] Successfully bound communication NIO server to TCP port [port=47100, locHost=0.0.0.0/0.0.0.0, selectorsCnt=4, selectorSpins=0, pairedConn=false]
[2019-04-03 17:29:07,195][WARN ][main][TcpCommunicationSpi] Message queue limit is set to 0 which may lead to potential OOMEs when running cache operations in FULL_ASYNC or PRIMARY_SYNC modes due to message queues growth on sender and receiver sides.
[2019-04-03 17:29:07,232][WARN ][main][NoopCheckpointSpi] Checkpoints are disabled (to enable configure any GridCheckpointSpi implementation)
[2019-04-03 17:29:07,254][WARN ][main][GridCollisionManager] Collision resolution is disabled (all jobs will be activated upon arrival).
[2019-04-03 17:29:07,293][INFO ][main][IgniteKernal] Security status [authentication=off, tls/ssl=off]
[2019-04-03 17:29:07,430][WARN ][main][IgniteCacheDatabaseSharedManager] DataRegionConfiguration.maxWalArchiveSize instead DataRegionConfiguration.walHistorySize would be used for removing old archive wal files
[2019-04-03 17:29:07,444][INFO ][main][PartitionsEvictManager] Evict partition permits=2
[2019-04-03 17:29:07,593][INFO ][main][ClientListenerProcessor] Client connector processor has started on TCP port 10800
[2019-04-03 17:29:07,624][INFO ][main][GridTcpRestProtocol] Command protocol successfully started [name=TCP binary, host=0.0.0.0/0.0.0.0, port=11211]
[2019-04-03 17:29:07,643][WARN ][main][PlatformProcessorImpl] Marshaller is automatically set to o.a.i.i.binary.BinaryMarshaller (other nodes must have the same marshaller type).
[2019-04-03 17:29:07,675][INFO ][main][IgniteKernal] Non-loopback local IPs: 172.17.0.1, 172.25.4.188
[2019-04-03 17:29:07,675][INFO ][main][IgniteKernal] Enabled local MACs: 0242929A3D04, D481D72208BB
[2019-04-03 17:29:07,700][INFO ][main][TcpDiscoverySpi] Connection check threshold is calculated: 10000
[2019-04-03 17:29:07,702][INFO ][main][TcpDiscoverySpi] Successfully bound to TCP port [port=47500, localHost=0.0.0.0/0.0.0.0, locNodeId=f5a4c49b-82c9-44df-ba8b-5ff97cad0a1f]
[2019-04-03 17:29:07,844][ERROR][main][TcpDiscoverySpi] Failed to get registered addresses from IP finder on start (retrying every 2000ms; change 'reconnectDelay' to configure the frequency of retries).
class org.apache.ignite.spi.IgniteSpiException: Failed to retrieve Ignite pods IP addresses.
    at org.apache.ignite.spi.discovery.tcp.ipfinder.kubernetes.TcpDiscoveryKubernetesIpFinder.getRegisteredAddresses(TcpDiscoveryKubernetesIpFinder.java:172)

(but that's expected)

Have you tried to moving ignite-kubernetes from libs/optional/ to libs/ instead of manually adding its JARs to classpath? Do you have anything else in your libs/?

-- alamar
Source: StackOverflow