Search code examples
jrubybackground-process

Jruby-rack-worker not starting on WebLogic

I have a Jruby project that is using background processes that need to be run every x minutes. I am using Jruby-rack-worker + delayed_cron_job library. I have followed the jruby-rack-worker instructions as follow:

  1. Copy the jruby-rack-worker.jar file under lib folder

  2. my web.xml located under config folder:

    enter image description here

  3. my worker rb file:

enter image description here

  1. my GEM file:

    gem 'jruby-rack-worker', :platform => :jruby, :require => nil
    gem 'delayed_cron_job'

After the deployment of the WAR file on WebLogic, I have checked the log file and I can see that after the completion of deployment, It is trying to start the Worker but nothing happening: 

####<Jul 7, 2017, 6:48:00,489 PM SGT> <Info> <CONCURRENCY> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000020> <1499424480489> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-2162600> <Creating ManagedThreadFactory "DefaultManagedThreadFactory" (partition="DOMAIN", module="null", application="myrubyapp")> 
####<Jul 7, 2017, 6:48:00,489 PM SGT> <Info> <CONCURRENCY> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000020> <1499424480489> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-2162610> <Creating ManagedExecutorService "DefaultManagedExecutorService" (partition="DOMAIN", module="null", application="myrubyapp", workmanager="default")> 
####<Jul 7, 2017, 6:48:00,490 PM SGT> <Info> <CONCURRENCY> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000020> <1499424480490> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-2162611> <Creating ManagedScheduledExecutorService "DefaultManagedScheduledExecutorService" (partition="DOMAIN", module="null", application="myrubyapp", workmanager="default")> 
####<Jul 7, 2017, 6:48:00,490 PM SGT> <Info> <Deployer> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000020> <1499424480490> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-149059> <Module myrubyapp.war of application myrubyapp is transitioning from STATE_NEW to STATE_PREPARED on server AdminServer.> 
####<Jul 7, 2017, 6:48:02,884 PM SGT> <Info> <Deployer> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000020> <1499424482884> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-149060> <Module myrubyapp.war of application myrubyapp successfully transitioned from STATE_NEW to STATE_PREPARED on server AdminServer.> 
####<Jul 7, 2017, 6:48:02,911 PM SGT> <Info> <Deployer> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424482911> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-149059> <Module myrubyapp.war of application myrubyapp is transitioning from STATE_PREPARED to STATE_ADMIN on server AdminServer.> 
####<Jul 7, 2017, 6:48:02,927 PM SGT> <Info> <Deployer> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424482927> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-149060> <Module myrubyapp.war of application myrubyapp successfully transitioned from STATE_PREPARED to STATE_ADMIN on server AdminServer.> 
####<Jul 7, 2017, 6:48:03,96 PM SGT> <Info> <ServletContext-/myrubyapp> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <weblogic> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424483096> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-000000> <INFO: jruby 9.1.5.0 (2.3.1) 2016-09-07 036ce39 Java HotSpot(TM) 64-Bit Server VM 25.131-b11 on 1.8.0_131-b11 +jit [mswin32-x86_64]> 
####<Jul 7, 2017, 6:48:03,97 PM SGT> <Info> <ServletContext-/myrubyapp> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <weblogic> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424483097> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-000000> <INFO: using a shared (threadsafe!) runtime> 
####<Jul 7, 2017, 6:48:24,321 PM SGT> <Info> <ServletContext-/myrubyapp> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <weblogic> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424504321> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-000000> <I, [2017-07-07T10:48:24.309000 #9420]  INFO -- : [ActiveJob] [CronJobs] [859cb101-2c4b-4995-ad08-d453c7f26b35] Performing CronJobs from Inline(default)
> 
####<Jul 7, 2017, 6:48:24,705 PM SGT> <Info> <Common> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <weblogic> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424504705> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-000628> <Created "1" resources for pool "myapp-staging-ds", out of which "1" are available and "0" are unavailable.> 
####<Jul 7, 2017, 6:48:28,253 PM SGT> <Info> <ServletContext-/myrubyapp> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <weblogic> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424508253> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-000000> <I, [2017-07-07T10:48:28.253000 #9420]  INFO -- : [ActiveJob] [CronJobs] [859cb101-2c4b-4995-ad08-d453c7f26b35] Performed CronJobs from Inline(default) in 3930.0ms
> 
####<Jul 7, 2017, 6:48:28,255 PM SGT> <Info> <ServletContext-/myrubyapp> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <weblogic> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424508255> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-000000> <I, [2017-07-07T10:48:28.255000 #9420]  INFO -- : [ActiveJob] Enqueued CronJobs (Job ID: 859cb101-2c4b-4995-ad08-d453c7f26b35) to Inline(default)
> 
####<Jul 7, 2017, 6:48:30,292 PM SGT> <Info> <ServletContext-/myrubyapp> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <weblogic> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424510292> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-000000> <INFO: [org.kares.jruby.rack.DefaultWorkerManager] started 1 worker(s)> 
####<Jul 7, 2017, 6:48:30,356 PM SGT> <Info> <Deployer> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424510356> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-149059> <Module myrubyapp.war of application myrubyapp is transitioning from STATE_ADMIN to STATE_ACTIVE on server AdminServer.> 
####<Jul 7, 2017, 6:48:30,356 PM SGT> <Info> <Deployer> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424510356> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-149060> <Module myrubyapp.war of application myrubyapp successfully transitioned from STATE_ADMIN to STATE_ACTIVE on server AdminServer.> 
####<Jul 7, 2017, 6:48:30,377 PM SGT> <Info> <Deployer> <voldemort-PC> <AdminServer> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000022> <1499424510377> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <BEA-149074> <Successfully completed deployment task: [Deployer:149026]deploy application myrubyapp on AdminServer..> 
####<Jul 7, 2017, 6:48:30,404 PM SGT> <Info> <ServletContext-/myrubyapp> <voldemort-PC> <AdminServer> <jruby-rack-worker#1> <weblogic> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424510404> <[severity-value: 64] [rid: 0:3] [partition-id: 0] [partition-name: DOMAIN] > <BEA-000000> <I, [2017-07-07T10:48:30.401000 #9420]  INFO -- : 2017-07-07T10:48:30+0000: [Worker(host:voldemort-PC pid:9420 thread:jruby-rack-worker#1)] Starting job worker
> 
####<Jul 7, 2017, 6:48:34,991 PM SGT> <Info> <Health> <voldemort-PC> <AdminServer> <weblogic.GCMonitor> <<anonymous>> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000006> <1499424514991> <[severity-value: 64] [rid: 0:1] [partition-id: 0] [partition-name: DOMAIN] > <BEA-310002> <21% of the total memory in the server is free.> 
####<Jul 7, 2017, 6:50:34,994 PM SGT> <Info> <Health> <voldemort-PC> <AdminServer> <weblogic.GCMonitor> <<anonymous>> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000006> <1499424634994> <[severity-value: 64] [rid: 0:1] [partition-id: 0] [partition-name: DOMAIN] > <BEA-310002> <35% of the total memory in the server is free.>

What is missing here and how can I know if the JobWorker started successfully or why it didn't start ?

Solution

  • you have it right and your log output confirms the worker started, fine!

    ####<Jul 7, 2017, 6:48:30,404 PM SGT> <Info> <ServletContext-/myrubyapp> <voldemort-PC> <AdminServer> <jruby-rack-worker#1> <weblogic> <> <ef7dc28a-6fde-4131-b1b0-41f2bd3db01b-00000021> <1499424510404> <[severity-value: 64] [rid: 0:3] [partition-id: 0] [partition-name: DOMAIN] > <BEA-000000> <I, [2017-07-07T10:48:30.401000 #9420]  INFO -- : 2017-07-07T10:48:30+0000: [Worker(host:voldemort-PC pid:9420 thread:jruby-rack-worker#1)] Starting job worker

    you probably did not put anything on DJ's queue ... thus not seeing any work getting done.

    delayed_cron_job won't auto-magically start - likely your worker rb file isn't being loaded by anything. you should trigger the loading of such worker files although be careful on restarts as you might need to remove the previous schedules.