Execution exited abnormally

data123data123 Member Posts: 23 Maven
edited December 2018 in Product Feedback - Resolved

I repeatedly get this "Execution exited abnormally" error when i run a process in server.  Any clues?

 

2018-01-26 16:43:21.820 INFO 15135 --- [main] c.r.execution.jobcontainer.Application : Starting Application on sn1ycpx2n0012.pdc.yes with PID 15135 (/opt/RapidMiner/rapidminer-server-installer-8.0.1/job-agent/engine/rapidminer-jobcontainer-0.1.0.jar started by root in /opt/RapidMiner/rapidminer-server-installer-8.0.1/bin)
2018-01-26 16:43:21.822 INFO 15135 --- [main] c.r.execution.jobcontainer.Application : No active profile set, falling back to default profiles: default
2018-01-26 16:43:21.969 INFO 15135 --- [main] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@78691363: startup date [Fri Jan 26 16:43:21 MYT 2018]; root of context hierarchy
2018-01-26 16:43:22.904 INFO 15135 --- [main] o.s.s.c.ThreadPoolTaskScheduler : Initializing ExecutorService 'taskScheduler'
2018-01-26 16:43:23.396 INFO 15135 --- [main] o.s.j.e.a.AnnotationMBeanExporter : Registering beans for JMX exposure on startup
2018-01-26 16:43:23.401 INFO 15135 --- [main] o.s.c.support.DefaultLifecycleProcessor : Starting beans in phase 0
2018-01-26 16:43:23.446 INFO 15135 --- [taskScheduler-2] c.r.e.j.service.RemoteRepositoryService : Trying to update JWT token from auth properties.
2018-01-26 16:43:23.446 INFO 15135 --- [taskScheduler-2] c.r.e.j.service.RemoteRepositoryService : Updated JWT token from auth properties file.
2018-01-26 16:43:23.448 INFO 15135 --- [main] c.r.e.j.s.RapidMinerInitializerService : Changing 'user.home' system property to '/opt/RapidMiner/rapidminer-server-installer-8.0.1/job-agent/jobs/1d00fff9-4acf-40f5-9a8f-5be091aa98a5'
2018-01-26 16:43:23.449 INFO 15135 --- [main] c.r.e.j.s.RapidMinerInitializerService : Generating new in-memory cipher key
2018-01-26 16:43:23.458 INFO 15135 --- [main] c.r.e.j.s.RapidMinerInitializerService : Loading JDBC properties
2018-01-26 16:43:23.597 INFO 15135 --- [main] c.r.e.j.s.RapidMinerInitializerService : Setting pre-defined system properties for Job Container
2018-01-26 16:43:23.598 INFO 15135 --- [main] c.r.e.j.s.RapidMinerInitializerService : Initializing the RapidMiner Core
2018-01-26 16:43:23.598 INFO 15135 --- [main] c.r.e.j.s.RapidMinerInitializerService : Setting execution mode to 'APPSERVER'
2018-01-26 16:43:23.598 INFO 15135 --- [main] c.r.e.j.s.RapidMinerInitializerService : Loading extensions from '/opt/RapidMiner/rapidminer-server-installer-8.0.1/job-agent/extensions'
2018-01-26 16:43:23.605 INFO 15135 --- [main] com.rapidminer : Performing upgrade to version 8.0.000
2018-01-26 16:43:23.606 INFO 15135 --- [main] com.rapidminer : Set locale to en.
2018-01-26 16:43:23.634 INFO 15135 --- [main] PlatformUtilities : rapidminer.home is '/opt/RapidMiner/rapidminer-server-installer-8.0.1/job-agent/engine'.
2018-01-26 16:43:23.672 INFO 15135 --- [main] com.rapidminer : Initializing license manager.
2018-01-26 16:43:23.761 INFO 15135 --- [main] com.rapidminer : Cannot access file system in execution mode APPSERVER. Not loading repositories.
2018-01-26 16:43:23.941 INFO 15135 --- [main] com.rapidminer : Register plugin: Legacy Result Access
2018-01-26 16:43:23.941 INFO 15135 --- [main] com.rapidminer : Register plugin: H2O
2018-01-26 16:43:23.941 INFO 15135 --- [main] com.rapidminer : Register plugin: Social Media
2018-01-26 16:43:23.941 INFO 15135 --- [main] com.rapidminer : Register plugin: Process Scheduling
2018-01-26 16:43:23.941 INFO 15135 --- [main] com.rapidminer : Register plugin: Concurrency
2018-01-26 16:43:23.941 INFO 15135 --- [main] com.rapidminer : Register plugin: JDBC Connectors
2018-01-26 16:43:23.941 INFO 15135 --- [main] com.rapidminer : Register plugin: Remote Repository
2018-01-26 16:43:23.941 INFO 15135 --- [main] com.rapidminer : Register plugin: Professional
2018-01-26 16:43:23.941 INFO 15135 --- [main] com.rapidminer : Register plugin: PMML
2018-01-26 16:43:23.942 INFO 15135 --- [main] com.rapidminer : Register plugin: Advanced File Connectors
2018-01-26 16:43:23.942 INFO 15135 --- [main] com.rapidminer : Register plugin: Productivity
2018-01-26 16:43:23.942 INFO 15135 --- [main] com.rapidminer : Register plugin: Cloud Connectivity
2018-01-26 16:43:24.334 INFO 15135 --- [main] com.rapidminer : Registered configurator Twitter Connection.
2018-01-26 16:43:24.499 INFO 15135 --- [main] com.rapidminer : Registered configurator Salesforce Connection.
2018-01-26 16:43:24.499 INFO 15135 --- [main] com.rapidminer : Registered configurator Amazon S3 Connection.
2018-01-26 16:43:24.499 INFO 15135 --- [main] com.rapidminer : Registered configurator Azure Blob Storage Connection.
2018-01-26 16:43:24.500 INFO 15135 --- [main] com.rapidminer : Registered configurator Dropbox Connection.
2018-01-26 16:43:25.046 WARN 15135 --- [main] com.rapidminer : Missing database driver class name for ODBC Bridge (e.g. Access)
2018-01-26 16:43:25.046 WARN 15135 --- [main] com.rapidminer : Missing database driver class name for Ingres
2018-01-26 16:43:25.673 INFO 15135 --- [main] com.rapidminer : Extension PMML was loaded in 4ms.
2018-01-26 16:43:25.674 INFO 15135 --- [main] com.rapidminer : Extension Process Scheduling was loaded in 93ms.
2018-01-26 16:43:25.674 INFO 15135 --- [main] com.rapidminer : Extension Productivity was loaded in 97ms.
2018-01-26 16:43:25.674 INFO 15135 --- [main] com.rapidminer : Extension Concurrency was loaded in 100ms.
2018-01-26 16:43:25.674 INFO 15135 --- [main] com.rapidminer : Extension Remote Repository was loaded in 100ms.
2018-01-26 16:43:25.674 INFO 15135 --- [main] com.rapidminer : Extension Social Media was loaded in 109ms.
2018-01-26 16:43:25.674 INFO 15135 --- [main] com.rapidminer : Extension Professional was loaded in 149ms.
2018-01-26 16:43:25.674 INFO 15135 --- [main] com.rapidminer : Extension Advanced File Connectors was loaded in 161ms.
2018-01-26 16:43:25.674 INFO 15135 --- [main] com.rapidminer : Extension Legacy Result Access was loaded in 170ms.
2018-01-26 16:43:25.674 INFO 15135 --- [main] com.rapidminer : Extension Cloud Connectivity was loaded in 215ms.
2018-01-26 16:43:25.674 INFO 15135 --- [main] com.rapidminer : Extension JDBC Connectors was loaded in 219ms.
2018-01-26 16:43:25.675 INFO 15135 --- [main] com.rapidminer : Extension H2O was loaded in 311ms.
2018-01-26 16:43:28.733 INFO 15135 --- [main] com.rapidminer : Cannot access file system in execution mode APPSERVER. Not loading repositories.
2018-01-26 16:43:28.746 INFO 15135 --- [main] com.rapidminer : Load configuration for Amazon S3 Connection.
2018-01-26 16:43:28.746 INFO 15135 --- [main] com.rapidminer : No configuration file found for Amazon S3 Connection
2018-01-26 16:43:28.746 INFO 15135 --- [main] com.rapidminer : Loaded configurations for 0 objects of type Amazon S3 Connection.
2018-01-26 16:43:28.746 INFO 15135 --- [main] com.rapidminer : Load configuration for Azure Blob Storage Connection.
2018-01-26 16:43:28.747 INFO 15135 --- [main] com.rapidminer : No configuration file found for Azure Blob Storage Connection
2018-01-26 16:43:28.747 INFO 15135 --- [main] com.rapidminer : Loaded configurations for 0 objects of type Azure Blob Storage Connection.
2018-01-26 16:43:28.747 INFO 15135 --- [main] com.rapidminer : Load configuration for Dropbox Connection.
2018-01-26 16:43:28.747 INFO 15135 --- [main] com.rapidminer : No configuration file found for Dropbox Connection
2018-01-26 16:43:28.747 INFO 15135 --- [main] com.rapidminer : Loaded configurations for 0 objects of type Dropbox Connection.
2018-01-26 16:43:28.747 INFO 15135 --- [main] com.rapidminer : Load configuration for Salesforce Connection.
2018-01-26 16:43:28.747 INFO 15135 --- [main] com.rapidminer : No configuration file found for Salesforce Connection
2018-01-26 16:43:28.747 INFO 15135 --- [main] com.rapidminer : Loaded configurations for 0 objects of type Salesforce Connection.
2018-01-26 16:43:28.748 INFO 15135 --- [main] com.rapidminer : Load configuration for Twitter Connection.
2018-01-26 16:43:28.748 INFO 15135 --- [main] com.rapidminer : No configuration file found for Twitter Connection
2018-01-26 16:43:28.748 INFO 15135 --- [main] com.rapidminer : Loaded configurations for 0 objects of type Twitter Connection.
2018-01-26 16:43:28.801 INFO 15135 --- [main] c.r.e.j.s.RapidMinerInitializerService : License framework initialized. Current active license edition is 'non-commercial'. The license expires on '2018-12-26'.
2018-01-26 16:43:28.801 INFO 15135 --- [main] c.r.execution.jobcontainer.EngineRunner : Starting execution of process
2018-01-26 16:43:28.801 INFO 15135 --- [main] c.r.e.j.service.RemoteRepositoryService : Executed process is stored in '/home/STORE_TEST_OFCS1'.
2018-01-26 16:43:28.802 INFO 15135 --- [main] c.r.e.j.service.RemoteRepositoryService : Trying to update JWT token from auth properties.
2018-01-26 16:43:28.803 INFO 15135 --- [main] c.r.e.j.service.RemoteRepositoryService : Skipped updating the JWT token as old one equals the new one.
2018-01-26 16:43:28.803 INFO 15135 --- [main] c.r.e.j.service.RemoteRepositoryService : Initializing the connection to RapidMiner Server. Using protocol 'http', host 'sn1ycpx2n0012.pdc.yes', and port '8080'
2018-01-26 16:43:28.830 INFO 15135 --- [main] com.rapidminer : Loading 0 configurations of type Amazon S3 Connection from RapidMiner Server _LOCAL
2018-01-26 16:43:28.833 INFO 15135 --- [main] com.rapidminer : Loading 0 configurations of type Azure Blob Storage Connection from RapidMiner Server _LOCAL
2018-01-26 16:43:28.836 INFO 15135 --- [main] com.rapidminer : Loading 0 configurations of type Dropbox Connection from RapidMiner Server _LOCAL
2018-01-26 16:43:28.840 INFO 15135 --- [main] com.rapidminer : Loading 0 configurations of type Salesforce Connection from RapidMiner Server _LOCAL
2018-01-26 16:43:28.843 INFO 15135 --- [main] com.rapidminer : Loading 0 configurations of type Twitter Connection from RapidMiner Server _LOCAL
2018-01-26 16:43:29.072 INFO 15135 --- [main] com.rapidminer : Loading 0 configurations of type Amazon S3 Connection from RapidMiner Server _LOCAL
2018-01-26 16:43:29.116 INFO 15135 --- [main] com.rapidminer : Loading 0 configurations of type Azure Blob Storage Connection from RapidMiner Server _LOCAL
2018-01-26 16:43:29.134 INFO 15135 --- [main] com.rapidminer : Loading 0 configurations of type Dropbox Connection from RapidMiner Server _LOCAL
2018-01-26 16:43:29.150 INFO 15135 --- [main] com.rapidminer : Loading 0 configurations of type Salesforce Connection from RapidMiner Server _LOCAL
2018-01-26 16:43:29.153 INFO 15135 --- [main] com.rapidminer : Loading 0 configurations of type Twitter Connection from RapidMiner Server _LOCAL
2018-01-26 16:44:09.253 ERROR 15135 --- [main] c.r.execution.jobcontainer.EngineRunner : Exception during repository access

com.rapidminer.repository.RepositoryException: Cannot connect to RapidMiner Server repository 'javax.xml.ws.WebServiceException: java.net.SocketTimeoutException: Read timed out'.
at com.rapidminer.extension.remote.repository.remote.DefaultRemoteRepository.handleExceptionsForService(DefaultRemoteRepository.java:960)
at com.rapidminer.extension.remote.repository.remote.RepositoryServiceFacade.handleException(RepositoryServiceFacade.java:64)
at com.rapidminer.extension.remote.repository.remote.RepositoryServiceFacade.getFolderContents(RepositoryServiceFacade.java:153)
at com.rapidminer.extension.remote.repository.remote.DefaultRemoteFolder.ensureLoaded(DefaultRemoteFolder.java:159)
at com.rapidminer.extension.remote.repository.remote.DefaultRemoteFolder.refresh(DefaultRemoteFolder.java:234)
at com.rapidminer.extension.remote.repository.remote.DefaultRemoteRepository.refresh(DefaultRemoteRepository.java:1174)
at com.rapidminer.execution.jobcontainer.service.RemoteRepositoryService.initializeProcessRepository(RemoteRepositoryService.java:79)
at com.rapidminer.execution.jobcontainer.EngineRunner.onApplicationEvent(EngineRunner.java:60)
at com.rapidminer.execution.jobcontainer.EngineRunner.onApplicationEvent(EngineRunner.java:28)
at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:167)
at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:393)
at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:347)
at org.springframework.boot.context.event.EventPublishingRunListener.finished(EventPublishingRunListener.java:101)
at org.springframework.boot.SpringApplicationRunListeners.callFinishedListener(SpringApplicationRunListeners.java:79)
at org.springframework.boot.SpringApplicationRunListeners.finished(SpringApplicationRunListeners.java:72)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:305)
at com.rapidminer.execution.jobcontainer.Application.main(Application.java:43)

2018-01-26 16:44:09.254 INFO 15135 --- [main] c.r.execution.jobcontainer.EngineRunner : Execution finished with exit code 'ABNORMAL'
2018-01-26 16:44:09.254 INFO 15135 --- [main] c.r.e.j.service.ShutdownService : Job Container exits with status code 'ABNORMAL'
2018-01-26 16:44:09.255 INFO 15135 --- [Thread-2] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@78691363: startup date [Fri Jan 26 16:43:21 MYT 2018]; root of context hierarchy
2018-01-26 16:44:09.258 INFO 15135 --- [Thread-2] o.s.c.support.DefaultLifecycleProcessor : Stopping beans in phase 0
2018-01-26 16:44:09.259 INFO 15135 --- [Thread-2] o.s.j.e.a.AnnotationMBeanExporter : Unregistering JMX-exposed beans on shutdown
2018-01-26 16:44:09.259 INFO 15135 --- [Thread-2] o.s.s.c.ThreadPoolTaskScheduler : Shutting down ExecutorService 'taskScheduler'

Tagged:
0
0 votes

Fixed and Released · Last Updated

Comments

  • MartinLiebigMartinLiebig Administrator, Moderator, Employee, RapidMiner Certified Analyst, RapidMiner Certified Expert, University Professor Posts: 3,503 RM Data Scientist

    Hi,

     

    looks like your JA cannot connect to the RM Server DB. Can you check the availabilty of

    Using protocol 'http', host 'sn1ycpx2n0012.pdc.yes', and port '8080'

    from the JA?

     

    Best,

    Martin

    - Sr. Director Data Solutions, Altair RapidMiner -
    Dortmund, Germany
  • landland RapidMiner Certified Analyst, RapidMiner Certified Expert, Member Posts: 2,531 Unicorn

    Hi,

    we experience the same problem when running processor and memory intensive jobs. I believe the following happens:

    1. Your Job agent starts a new container

    2. The container runs and get's into a garbage collection pause, longer than 15 seconds. They regularly occur on large jobs. It just takes time to sort out > 64 GB of memory...

    3. The Job agent thinks the container is dead and kills it

     

    Another possibility is, as we regularly see that happen when results are written, the RM Server itself gets into Garbage Collection mode, what causes the abnormal termination when writing as it doesn't responde.

    Our Jackhammer Extension has a handle Exception operator that allows for retries in case of error with a delay. We tried to store to repository several times with a larger delay, to help it to get unstuck again, but it didn't help. Same error, just three times before it failed completely. Maybe the Server is simply stuck with writing the data to repository too long.


    Unfortunately to my knowledge there's nothing we can do, as there seems to be no setting for the timeout we could increment.

    We decided to stay with RM 7.6 until RM can resolve that in future versions.

    Greetings,
    Sebastian

     

  • data123data123 Member Posts: 23 Maven

    Yes. This captures my situation exactly. I was hoping the issue would be resolvd in the new server release but unfortuantely I'm still having the same issue with 8.1.

  • sgenzersgenzer Administrator, Moderator, Employee, RapidMiner Certified Analyst, Community Manager, Member, University Professor, PM Moderator Posts: 2,959 Community Manager

    tagging @jpuente and @zprekopcsak

     

    Scott

     

  • jpuentejpuente Employee, Member Posts: 53 RM Product Management

    Hi. I'll check with our Engineering. We'll look into it and I'll get back to you.

  • sgenzersgenzer Administrator, Moderator, Employee, RapidMiner Certified Analyst, Community Manager, Member, University Professor, PM Moderator Posts: 2,959 Community Manager

    Pushing to Product Feedback.

     

    Scott

     

     

  • sgenzersgenzer Administrator, Moderator, Employee, RapidMiner Certified Analyst, Community Manager, Member, University Professor, PM Moderator Posts: 2,959 Community Manager
  • data123data123 Member Posts: 23 Maven

    10 out of 12 processes failed in succession. I've either had to wait at least 8mins (after a failed process) or restart the server for a process to run succesfully. 

    Rm_Server Failure.png

  • jpuentejpuente Employee, Member Posts: 53 RM Product Management

    Hi. We have analyzed the log. This could happen because of 1) network issues or 2) the Server being overloaded. Do you think any of those would apply to your case? We are thinking how to overcome the issue in both cases.

  • Nils_WoehlerNils_Woehler Member Posts: 463 Maven

    Hi @data123,

     

    did all of the 10 processes fail with the following error?

     

    2018-01-26 16:44:09.253 ERROR 15135 --- [main] c.r.execution.jobcontainer.EngineRunner : Exception during repository access

    com.rapidminer.repository.RepositoryException: Cannot connect to RapidMiner Server repository 'javax.xml.ws.WebServiceException: java.net.SocketTimeoutException: Read timed out'.

    Thanks!

  • data123data123 Member Posts: 23 Maven

    Hi Nils_Woehler no it didnt fail due to lost connectivity. Network connection is perfectly ok.

    Hi  jpuente there is no network connectivity issue and the server is dedicated solely to RM Server. I think  

    @land articulated the issue perfectly. This is an issue that has been happening with 8.0 and now 8.1. The process fails and you have to wait for about 8-10mins to run it again or it'll continue to fail.
     

    Execution exited abnormally

    Could not retrieve error log for job '4df7eb8e-f7cc-430d-8c8f-5bec489e5def'. Ask your administrator to look into job running on Job Agent 'agent-bundled' (402ca44d-4ca2-490c-b87b-f63440784e77)

    com.rapidminer.execution.jobagent.service.exception.ServiceException: Could not retrieve error log for job '4df7eb8e-f7cc-430d-8c8f-5bec489e5def'. Ask your administrator to look into job running on Job Agent 'agent-bundled' (402ca44d-4ca2-490c-b87b-f63440784e77)

Sign In or Register to comment.