Open shozayen opened 7 years ago
Hi @kares facing a weird issue with Weblogic + JNDI + jruby-rack-worker, even though the jndi config is present in warble.rb, get the error
####<11 Oct, 2017, 12:49:55,821 PM IST> <Info> <ServletContext-> <my-laptop-Latitude-3550> <myserver> <jruby-rack-worker#1> <userxx> <> <9d178067-b085-4f54-92eb-ff40a25fb461-00000018> <1507706395821> <[severity-value: 64] [rid: 0:3] [partition-id: 0] [partition-name: DOMAIN] > <BEA-000000> <E, [2017-10-11T07:19:55.813000 #17904] ERROR -- : undefined method `[]' for nil:NilClass (NoMethodError):
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/backend/base.rb:63:in `name'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:273:in `job_say'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:304:in `handle_failed_job'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:241:in `block in run'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:61:in `block in initialize'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:66:in `execute'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:40:in `run_callbacks'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:241:in `run'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:312:in `block in reserve_and_run_one_job'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:61:in `block in initialize'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:66:in `execute'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:40:in `run_callbacks'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:312:in `reserve_and_run_one_job'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:213:in `block in work_off'
org/jruby/RubyFixnum.java:299:in `times'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:212:in `work_off'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:175:in `block in start'
uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/benchmark.rb:308:in `realtime'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:174:in `block in start'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:61:in `block in initialize'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:66:in `execute'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:40:in `run_callbacks'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:173:in `block in start'
org/jruby/RubyKernel.java:1296:in `loop'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:172:in `block in start'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/plugins/clear_locks.rb:7:in `block in ClearLocks'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:79:in `block in add'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:61:in `block in initialize'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:79:in `block in add'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:66:in `execute'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:40:in `run_callbacks'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:171:in `start'
uri:classloader:/delayed/start_worker.rb:19:in `<main>'
org/jruby/RubyKernel.java:974:in `load'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/activesupport-4.2.7/lib/active_support/dependencies.rb:268:in `block in load'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/activesupport-4.2.7/lib/active_support/dependencies.rb:240:in `load_dependency'
/home/my-laptop/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo/pshkqt/war/WEB-INF/gems/gems/activesupport-4.2.7/lib/active_support/dependencies.rb:268:in `load'
<script>:1:in `<main>'
Generated web xml in the warfile is like below
<web-app xmlns="http://java.sun.com/xml/ns/javaee"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/web-app_3_0.xsd"
version="3.0">
<!--
<display-name>Uncomment and put name :here: for Tomcat Dashboard</display-name>-->
<context-param>
<param-name>public.root</param-name>
<param-value>/</param-value>
</context-param>
<context-param>
<param-name>rails.env</param-name>
<param-value>staging</param-value>
</context-param>
<context-param>
<param-name>jruby.min.runtimes</param-name>
<param-value>1</param-value>
</context-param>
<context-param>
<param-name>jruby.max.runtimes</param-name>
<param-value>1</param-value>
</context-param>
<context-param>
<param-name>jruby.worker</param-name>
<param-value>delayed_job</param-value>
</context-param>
<context-param>
<param-name>QUEUES</param-name>
<param-value>default,another-queue</param-value>
</context-param>
<context-param>
<param-name>INTERVAL</param-name>
<param-value>2.5</param-value>
</context-param>
<filter>
<filter-name>RackFilter</filter-name>
<filter-class>org.jruby.rack.RackFilter</filter-class>
<async-supported>false</async-supported>
</filter>
<filter-mapping>
<filter-name>RackFilter</filter-name>
<url-pattern>/*</url-pattern>
</filter-mapping>
<listener>
<listener-class>org.jruby.rack.rails.RailsServletContextListener</listener-class>
</listener>
<listener>
<listener-class>org.kares.jruby.rack.WorkerContextListener</listener-class>
</listener>
<resource-ref>
<res-ref-name>jdbc/local-ds</res-ref-name>
<res-type>javax.sql.DataSource</res-type>
<res-auth>Container</res-auth>
</resource-ref>
</web-app>
If I don't use JNDI, work fine. Am I missing someting?
Got into this too with Weblogic 12C, JNDI Datasource in web.xml, tried with JRuby 9.0.5.0, 9.1.5.0, 9.1.7.0, JDK 1.8.66
####<Oct 11, 2017, 2:54:13,282 PM UTC> <Info> <ServletContext-/rails_app>
<wls12c-r2-1.private> <managed_1> <jruby-rack-worker#1>
<<anonymous>> <> <c9906ea0-1ee7-4e49-92c9-b6f4e36e12c2-00000007><1507733653282>
<[severity-value: 64] [rid: 0:16] [partition-id: 0] [partition-name: DOMAIN] >
<BEA-000000> <E, [2017-10-11T14:54:13.282000 #19158] ERROR -- : undefined method `[]' for nil:NilClass (NoMethodError):
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/backend/base.rb:63:in `name'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:273:in `job_say'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:304:in `handle_failed_job'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:241:in `block in run'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:61:in `block in initialize'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:66:in `execute'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:40:in `run_callbacks'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:241:in `run'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:312:in `block in reserve_and_run_one_job'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:61:in `block in initialize'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:66:in `execute'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:40:in `run_callbacks'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:312:in `reserve_and_run_one_job'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:213:in `block in work_off'
org/jruby/RubyFixnum.java:299:in `times'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:212:in `work_off'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:175:in `block in start'
uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/benchmark.rb:308:in `realtime'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:174:in `block in start'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:61:in `block in initialize'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:66:in `execute'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:40:in `run_callbacks'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:173:in `block in start'
org/jruby/RubyKernel.java:1296:in `loop'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:172:in `block in start'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/plugins/clear_locks.rb:7:in `block in ClearLocks'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:79:in `block in add'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:61:in `block in initialize'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:79:in `block in add'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:66:in `execute'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:40:in `run_callbacks'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:171:in `start'
uri:classloader:/delayed/start_worker.rb:19:in `<main>'
org/jruby/RubyKernel.java:974:in `load'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/activesupport-4.2.7/lib/active_support/dependencies.rb:268:in `block in load'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/activesupport-4.2.7/lib/active_support/dependencies.rb:240:in `load_dependency'
/oracle/fmw12.2.1/config/Domains/production-base/servers/managed_1/tmp/_WL_user/rails_app/53cvdz/war/WEB-INF/gems/gems/activesupport-4.2.7/lib/active_support/dependencies.rb:268:in `load'
sounds/seems quite weird - would be great to get it sorted out esp. since there are multiple complainers. guess a good start would be for someone to patch in some puts/logging statement and compare the problematic line output with/without a JNDI data-source (from there figuring out why its different).
could help out from there - but otherwise not planning to look into setting up a WL deployment scenario pro-actively, atm.
Hi @kares appreciate your help! Please check the debugging info for a single job below, and let me know if this helps!
Debug code https://github.com/collectiveidea/delayed_job/blob/v4.1.3/lib/delayed/backend/base.rb#L63
def name
p "############ debug name #####################"
p payload_object.inspect
p "Respond to :display_name: #{payload_object.respond_to?(:display_name)}"
@name ||= payload_object.respond_to?(:display_name) ? payload_object.display_name : payload_object.class.name
rescue DeserializationError
p "############ debug name rescue #####################"
p handler.inspect
ParseObjectFromYaml.match(handler)[1]
end
def payload_object=(object)
@payload_object = object
self.handler = object.to_yaml
end
def payload_object
p "############ debug payload_object #####################"
p "handler: #{handler.inspect}"
@payload_object ||= YAML.load_dj(handler)
rescue TypeError, LoadError, NameError, ArgumentError, SyntaxError, Psych::SyntaxError => e
raise DeserializationError, "Job failed to load: #{e.message}. Handler: #{handler.inspect}"
end
Without JNDI
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"############ debug name #####################"
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"#<Delayed::PerformableMethod:0x733dca9b @object=Job(id: integer, pair_id: integer, company_id: integer, name: string, code: integer, location_id: integer, job_type_id: integer, restriction: binary, duration: integer, job_status_id: integer, sequence: integer, assigned_locked: integer, assigned_late: integer, created_at: integer, updated_at: integer, job_priority_id: integer, scheduled_date_time: integer, real_drive_start: integer, real_enforcement_start: integer, real_enforcement_end: integer, remark: string, deleted_at: integer, active_time_start1: string, active_time_end1: string, active_time_start2: string, active_time_end2: string, active_time_start3: string, active_time_end3: string, zone_id: integer, enforcement_date: string, driver_arrived_at: integer, distance: float), @args=[1709], @method_name=:debug_job>"
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"Respond to :display_name: true"
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"Successfully Ran"
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"############ debug name #####################"
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"#<Delayed::PerformableMethod:0x733dca9b @object=Job(id: integer, pair_id: integer, company_id: integer, name: string, code: integer, location_id: integer, job_type_id: integer, restriction: binary, duration: integer, job_status_id: integer, sequence: integer, assigned_locked: integer, assigned_late: integer, created_at: integer, updated_at: integer, job_priority_id: integer, scheduled_date_time: integer, real_drive_start: integer, real_enforcement_start: integer, real_enforcement_end: integer, remark: string, deleted_at: integer, active_time_start1: string, active_time_end1: string, active_time_start2: string, active_time_end2: string, active_time_start3: string, active_time_end3: string, zone_id: integer, enforcement_date: string, driver_arrived_at: integer, distance: float), @args=[1709], @method_name=:debug_job>"
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"Respond to :display_name: true"
With JNDI
"############ debug payload_object #####################"
"handler: \"--- !ruby/object:Delayed::PerformableMethod\\nobject: !ruby/class 'Job'\\nmethod_name: :debug_job\\nargs:\\n- 1709\\n\""
"############ debug name #####################"
"############ debug payload_object #####################"
"handler: nil"
"############ debug name rescue #####################"
"nil"
"############ debug name #####################"
"############ debug payload_object #####################"
"handler: nil"
"############ debug name rescue #####################"
"nil"
ah I see - not much there - a missed the part that its already in error handling code, so there's likely an error being raised that we do not see details logged, you could force JRuby to log all or try this patch :
class Delayed::Worker.class_eval do
alias_method :__handle_failed_job, :handle_failed_job
def handle_failed_job(job, error)
puts "ERR: job #{job.inspect rescue nil} failed #{error.inspect}\n #{error.backtrace.join("\n ")}"
__handle_failed_job(job, error) # PLS double check this is right - obviously did not try it out :)
end
end
Here goes the info:
ERR: job #<Delayed::Backend::ActiveRecord::Job id: 4931, priority: 0, attempts: 0, handler: nil, last_error: nil, run_at: "2017-10-13 09:56:48", locked_at: "2017-10-13 09:56:49", failed_at: nil, locked_by: "host:qi53-Latitude-3550 pid:5242 thread:jruby-rack...", queue: nil, created_at: "2017-10-13 09:56:48", updated_at: "2017-10-13 09:56:48"> failed #<NoMethodError: undefined method []' for nil:NilClass> /home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/backend/base.rb:63:in
name'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:273:in job_say'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:228:in
run'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:312:in block in reserve_and_run_one_job'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:61:in
block in initialize'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:66:in execute'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:40:in
run_callbacks'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:312:in reserve_and_run_one_job'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:213:in
block in work_off'\norg/jruby/RubyFixnum.java:299:in times'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:212:in
work_off'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:175:in block in start'\nuri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/benchmark.rb:308:in
realtime'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:174:in block in start'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:61:in
block in initialize'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:66:in execute'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:40:in
run_callbacks'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:173:in block in start'\norg/jruby/RubyKernel.java:1296:in
loop'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:172:in block in start'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/plugins/clear_locks.rb:7:in
block in ClearLocks'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:79:in block in add'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:61:in
block in initialize'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:79:in block in add'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:66:in
execute'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/lifecycle.rb:40:in run_callbacks'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/delayed_job-4.1.3/lib/delayed/worker.rb:171:in
start'\nuri:classloader:/delayed/start_worker.rb:19:in <main>'\norg/jruby/RubyKernel.java:974:in
load'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/activesupport-4.2.7/lib/active_support/dependencies.rb:268:in block in load'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/activesupport-4.2.7/lib/active_support/dependencies.rb:240:in
load_dependency'\n/home/qi53/Weblogic/fmw_12.2.1.2.0_wls_quick_Disk1_1of1/wls12212/domain/servers/myserver/tmp/_WL_user/demo_app/pshkqt/war/WEB-INF/gems/gems/activesupport-4.2.7/lib/active_support/dependencies.rb:268:in load'\n<script>:1:in
<
formatting :1st_place_medal: sorry, this is leading no where - but you guys should get the drill. so please try finding out if there's anything else - going on differently with the two setups.
@kares I managed to let this work in tomcat, the same war file in weblogic still throws the error though.
@kares finally found the issue. In JNDI + Weblogic + Oracle, AR object attributes having column type text
is becoming null. This is a very strange behavior which works perfectly in
To solve this, change the handler
, and last_error
to varchar, which has limit 4000 bytes in Oracle, should be good enough.
This is not only with the delayed_jobs
table, but with other tables as well. For more debugging, if someone is interested, my gemfile like this:
gem 'rails', '4.2.7'
gem 'activerecord-oracle_enhanced-adapter', '1.6.9'
gem 'warbler', '~> 2.0', '>= 2.0.3'
gem 'jruby-rack-worker', :platform => :jruby, :require => nil
gem 'delayed_job_recurring'
I feel this is not a jruby-rack-worker issue. Thanks for your help!
@skarmakar thanks but this seems to make little sense, do you have any backtrace details around?
also, could anyone share how the 'normal' database.yml setup looked and then for comparison the jndi:
version of database.yml ?
for it to make sense you guys must have been using adapter: jdbc
from JNDI instead of adapter: oracle
I'm using oracle_enhanced adapter.
database.yml
default: &default
adapter: oracle_enhanced
database: <%= ENV['ORACLE_DATABASE'] %> # xe
host: <%= ENV['ORACLE_DBHOST'] %> # 0.0.0.0
username: <%= ENV['ORACLE_USERNAME'] %> # system
password: <%= ENV['ORACLE_PASSWORD'] %> # oracle
port: <%= ENV['ORACLE_PORT'] %> # 1521
development:
<<: *default
test:
<<: *default
migration:
<<: *default
staging:
adapter: oracle_enhanced
jndi: jdbc/staging-ds
production:
adapter: oracle_enhanced
jndi: jdbc/production-ds
web.xml.erb
<web-app xmlns="http://java.sun.com/xml/ns/javaee"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/web-app_3_0.xsd"
version="3.0">
<%- webxml.context_params.each do |name, value| -%>
<context-param>
<param-name><%= name %></param-name>
<param-value><%= value %></param-value>
</context-param>
<%- end -%>
<filter>
<filter-name>RackFilter</filter-name>
<filter-class>org.jruby.rack.RackFilter</filter-class>
<async-supported>false</async-supported>
</filter>
<filter-mapping>
<filter-name>RackFilter</filter-name>
<url-pattern>/*</url-pattern>
</filter-mapping>
<listener>
<listener-class>org.jruby.rack.rails.RailsServletContextListener</listener-class>
</listener>
<listener>
<listener-class>org.kares.jruby.rack.WorkerContextListener</listener-class>
</listener>
</web-app>
warble.rb
Warbler::Config.new do |config|
config.gem_excludes = [/^(test|spec)\//]
config.jar_name = "mega"
config.jar_extension = "war"
config.webinf_files += FileList["config/weblogic.xml"]
config.public_html = FileList["public/**/*", "doc/**/*"]
config.webxml.rails.env = ENV['RAILS_ENV'] || 'production'
config.webxml.jruby.min.runtimes = 1
config.webxml.jruby.max.runtimes = 1
config.webxml.jruby.worker = 'delayed_job'
config.webxml.QUEUES = 'one,two,three'
config.webxml.INTERVAL = 2.5
end
@mskutin your configuration seems right ... I'm out of ideas ATM esp. if its Oracle :) oracle_enhanced seems to be the common denominator, should work but obviously wasn't ever tested
@skarmakar already posted a 'work-around' so I'm assuming its not really an issue with jruby-rack-worker ... its still weird how it behaved differently with/wout JNDI, so it might be smt going differently in adapter.
pls note that DJ likes to keep connections around so JNDI without some "enhancements" makes no sense ;(
Hi guys, I finally found the issue, and here goes the details and probable solution. FYI https://github.com/rsim/oracle-enhanced/issues/1549
Hi,
I have a Jruby project that has background processes that need to be run every x minutes. I am using Jruby-rack- worker + delayed_cron_job library. I have followed the instructions of jruby-rack-worker as follow:
<web-app xmlns="http://java.sun.com/xml/ns/javaee" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/web-app_3_0.xsd" version="3.0">
class CronJobs < ActiveJob::Base queue_as :default
def perform puts " - Inside worker at #{Time.now.to_s}" Code.create({ code: "test1", content: Time.now.to_s }) end end
puts "Before set" CronJobs.set(cron: ' *').perform_later puts "After set"
gem 'jruby-rack-worker', :platform => :jruby, :require => nil gem 'delayed_cron_job'
<Jul 7, 2017, 6:48:00,489 PM SGT> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <> <> <1499424480489> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <Creating ManagedThreadFactory "DefaultManagedThreadFactory" (partition="DOMAIN", module="null", application="myrubyapp")>
<Jul 7, 2017, 6:48:00,489 PM SGT> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <> <> <1499424480489> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <Creating ManagedExecutorService "DefaultManagedExecutorService" (partition="DOMAIN", module="null", application="myrubyapp", workmanager="default")>
<Jul 7, 2017, 6:48:00,490 PM SGT> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <> <> <1499424480490> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <Creating ManagedScheduledExecutorService "DefaultManagedScheduledExecutorService" (partition="DOMAIN", module="null", application="myrubyapp", workmanager="default")>
<Jul 7, 2017, 6:48:00,490 PM SGT> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <> <> <1499424480490> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] >
<Jul 7, 2017, 6:48:02,884 PM SGT> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <> <> <1499424482884> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] >
<Jul 7, 2017, 6:48:02,911 PM SGT> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <> <> <1499424482911> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] >
<Jul 7, 2017, 6:48:02,927 PM SGT> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <> <> <1499424482927> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] >
<Jul 7, 2017, 6:48:03,96 PM SGT> <ServletContext-/myrubyapp> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <> <1499424483096> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <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> <ServletContext-/myrubyapp> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <> <1499424483097> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <INFO: using a shared (threadsafe!) runtime>
<Jul 7, 2017, 6:48:24,321 PM SGT> <ServletContext-/myrubyapp> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <> <1499424504321> <[severity-value: 64] [rid: 0] [partition-id: 0] [partition-name: DOMAIN] > <I, [2017-07-07T10:48:24.309000 #9420] INFO -- : [ActiveJob] [CronJobs] [859cb101-2c4b-4995-ad08-d453c7f26b35] Performing CronJobs from Inline(default)
What is missing here and how can I know if the JobWorker started successfully or why it didn't start ?
I appreciate your reply,