jondot / sneakers

A fast background processing framework for Ruby and RabbitMQ
https://github.com/jondot/sneakers
MIT License
2.24k stars 333 forks source link

Workers terminating with signal SIGABRT when attempting post request inside worker #386

Closed alilland closed 5 years ago

alilland commented 5 years ago

I get the following errors when my worker tries to make a post request, and sneakers just fails on the same message continually spinning up new workers and failing, where do I go from here?

$ bundle exec ruby sneakers.rb
2019-03-05T01:09:44Z p-70615 t-owz1459k0 WARN: Loading runner configuration...
2019-03-05T01:09:44Z p-70615 t-owz1459k0 DEBUG: New configuration: #<Sneakers::Configuration:0x007fdb96cdd150 @hash={:error_reporters=>[#<Sneakers::ErrorReporter::DefaultLogger:0x007fdb9703d070>], :runner_config_file=>nil, :metrics=>nil, :daemonize=>false, :start_worker_delay=>0.2, :workers=>4, :log=>#<IO:<STDOUT>>, :pid_path=>"sneakers.pid", :amqp_heartbeat=>30, :prefetch=>10, :threads=>10, :share_threads=>false, :ack=>true, :heartbeat=>30, :hooks=>{}, :exchange=>"sneakers", :exchange_options=>{:type=>:direct, :durable=>true, :auto_delete=>false, :arguments=>{}}, :queue_options=>{:durable=>true, :auto_delete=>false, :exclusive=>false, :arguments=>{}}, :amqp=>"amqp:/<redacted>@localhost:5672", :vhost=>"/", :handler=>Sneakers::Handlers::Oneshot, :logger=>#<ServerEngine::DaemonLogger:0x007fdb96cdec08 @rotate_age=5, @rotate_size=1048576, @file_dev=nil, @level=0, @progname=nil, @default_formatter=#<Logger::Formatter:0x007fdb96cdea78 @datetime_format=nil>, @formatter=Sneakers::Support::ProductionFormatter, @logdev=#<IO:<STDOUT>>>, :log_level=>0, :worker_type=>"process", :worker_classes=>[Workers::FieldWorkOrder], :log_stdout=>false, :log_stderr=>false}>
2019-03-05T01:09:44Z p-70615 t-owz1459k0 WARN: Loading runner configuration...
2019-03-05T01:09:44Z p-70615 t-owz1459k0 DEBUG: New configuration: #<Sneakers::Configuration:0x007fdb96cd5dd8 @hash={:error_reporters=>[#<Sneakers::ErrorReporter::DefaultLogger:0x007fdb9703d070>], :runner_config_file=>nil, :metrics=>nil, :daemonize=>false, :start_worker_delay=>0.2, :workers=>4, :log=>#<IO:<STDOUT>>, :pid_path=>"sneakers.pid", :amqp_heartbeat=>30, :prefetch=>10, :threads=>10, :share_threads=>false, :ack=>true, :heartbeat=>30, :hooks=>{}, :exchange=>"sneakers", :exchange_options=>{:type=>:direct, :durable=>true, :auto_delete=>false, :arguments=>{}}, :queue_options=>{:durable=>true, :auto_delete=>false, :exclusive=>false, :arguments=>{}}, :amqp=>"amqp:/<redacted>@localhost:5672", :vhost=>"/", :handler=>Sneakers::Handlers::Oneshot, :logger=>#<ServerEngine::DaemonLogger:0x007fdb96cdec08 @rotate_age=5, @rotate_size=1048576, @file_dev=nil, @level=0, @progname=nil, @default_formatter=#<Logger::Formatter:0x007fdb96cdea78 @datetime_format=nil>, @formatter=Sneakers::Support::ProductionFormatter, @logdev=#<IO:<STDOUT>>>, :log_level=>0, :worker_type=>"process", :worker_classes=>[Workers::FieldWorkOrder], :log_stdout=>false, :log_stderr=>false}>
2019-03-05T01:09:44Z p-70615 t-owz1459k0 WARN: Loading runner configuration...
2019-03-05T01:09:44Z p-70615 t-owz1459k0 DEBUG: New configuration: #<Sneakers::Configuration:0x007fdb96cce380 @hash={:error_reporters=>[#<Sneakers::ErrorReporter::DefaultLogger:0x007fdb9703d070>], :runner_config_file=>nil, :metrics=>nil, :daemonize=>false, :start_worker_delay=>0.2, :workers=>4, :log=>#<IO:<STDOUT>>, :pid_path=>"sneakers.pid", :amqp_heartbeat=>30, :prefetch=>10, :threads=>10, :share_threads=>false, :ack=>true, :heartbeat=>30, :hooks=>{}, :exchange=>"sneakers", :exchange_options=>{:type=>:direct, :durable=>true, :auto_delete=>false, :arguments=>{}}, :queue_options=>{:durable=>true, :auto_delete=>false, :exclusive=>false, :arguments=>{}}, :amqp=>"amqp:/<redacted>@localhost:5672", :vhost=>"/", :handler=>Sneakers::Handlers::Oneshot, :logger=>#<ServerEngine::DaemonLogger:0x007fdb96cdec08 @rotate_age=5, @rotate_size=1048576, @file_dev=nil, @level=0, @progname=nil, @default_formatter=#<Logger::Formatter:0x007fdb96cdea78 @datetime_format=nil>, @formatter=Sneakers::Support::ProductionFormatter, @logdev=#<IO:<STDOUT>>>, :log_level=>0, :worker_type=>"process", :worker_classes=>[Workers::FieldWorkOrder], :log_stdout=>false, :log_stderr=>false}>
2019-03-05T01:09:44Z p-70624 t-owz1459k0 DEBUG: [worker-jobdata_fwo:1:ygrx8k][#<Thread:0x007fdb96082f40>][jobdata_fwo][#<Sneakers::Configuration:0x007fdb96cc50f0>] New worker: subscribing.
2019-03-05T01:09:44Z p-70624 t-owz1459k0 DEBUG: Sent protocol preamble
2019-03-05T01:09:44Z p-70624 t-owz1459k0 DEBUG: Sent connection.start-ok
2019-03-05T01:09:44Z p-70624 t-owz1459k0 DEBUG: Heartbeat interval negotiation: client = 30, server = 60, result = 30
2019-03-05T01:09:44Z p-70624 t-owz1459k0 INFO: Heartbeat interval used (in seconds): 30
2019-03-05T01:09:44Z p-70624 t-owz1459k0 DEBUG: Will use socket read timeout of 66 seconds
2019-03-05T01:09:44Z p-70624 t-owz1459k0 DEBUG: Initializing channel ID allocator with channel_max = 2047
2019-03-05T01:09:44Z p-70624 t-owz1459k0 DEBUG: Sent connection.tune-ok with heartbeat interval = 30, frame_max = 131072, channel_max = 2047
2019-03-05T01:09:44Z p-70624 t-owz1459k0 DEBUG: Sent connection.open with vhost = /
2019-03-05T01:09:44Z p-70624 t-owz1459k0 DEBUG: Initializing heartbeat sender...
2019-03-05T01:09:44Z p-70624 t-owz1459k0 DEBUG: Allocated channel id: 1
2019-03-05T01:09:44Z p-70624 t-owz17xy7c DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Channel::OpenOk:0x007fdb96ca6c40 @channel_id="">
2019-03-05T01:09:44Z p-70624 t-owz17xy7c DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Basic::QosOk:0x007fdb96ca5778>
2019-03-05T01:09:44Z p-70624 t-owz17xy7c DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Basic::QosOk:0x007fdb96ca5778>
2019-03-05T01:09:44Z p-70624 t-owz17xy7c DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Exchange::DeclareOk:0x007fdb96c93f78>
2019-03-05T01:09:44Z p-70624 t-owz17xy7c DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Exchange::DeclareOk:0x007fdb96c93f78>
2019-03-05T01:09:44Z p-70624 t-owz17xy7c DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Queue::DeclareOk:0x007fdb96c92178 @queue="jobdata_fwo", @message_count=0, @consumer_count=0>
2019-03-05T01:09:44Z p-70624 t-owz17xy7c DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Queue::DeclareOk:0x007fdb96c92178 @queue="jobdata_fwo", @message_count=0, @consumer_count=0>
2019-03-05T01:09:44Z p-70624 t-owz17xy7c DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Queue::BindOk:0x007fdb96c90bc0>
2019-03-05T01:09:44Z p-70624 t-owz17xy7c DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Queue::BindOk:0x007fdb96c90bc0>
2019-03-05T01:09:44Z p-70624 t-owz17xy7c DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Basic::ConsumeOk:0x007fdb96c8abd0 @consumer_tag="bunny-1551748184000-475301131963">
2019-03-05T01:09:44Z p-70624 t-owz17xy7c DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Basic::ConsumeOk:0x007fdb96c8abd0 @consumer_tag="bunny-1551748184000-475301131963">
2019-03-05T01:09:44Z p-70624 t-owz1459k0 DEBUG: [worker-jobdata_fwo:1:ygrx8k][#<Thread:0x007fdb96082f40>][jobdata_fwo][#<Sneakers::Configuration:0x007fdb96cc50f0>] New worker: I'm alive.
2019-03-05T01:09:44Z p-70625 t-owz1459k0 DEBUG: [worker-jobdata_fwo:1:55nivl][#<Thread:0x007fdb96082f40>][jobdata_fwo][#<Sneakers::Configuration:0x007fdb96cc4bc8>] New worker: subscribing.
2019-03-05T01:09:44Z p-70626 t-owz1459k0 DEBUG: [worker-jobdata_fwo:1:np1y18][#<Thread:0x007fdb96082f40>][jobdata_fwo][#<Sneakers::Configuration:0x007fdb96cc4740>] New worker: subscribing.
2019-03-05T01:09:44Z p-70625 t-owz1459k0 DEBUG: Sent protocol preamble
2019-03-05T01:09:44Z p-70626 t-owz1459k0 DEBUG: Sent protocol preamble
2019-03-05T01:09:44Z p-70626 t-owz1459k0 DEBUG: Sent connection.start-ok
2019-03-05T01:09:44Z p-70625 t-owz1459k0 DEBUG: Sent connection.start-ok
2019-03-05T01:09:44Z p-70625 t-owz1459k0 DEBUG: Heartbeat interval negotiation: client = 30, server = 60, result = 30
2019-03-05T01:09:44Z p-70626 t-owz1459k0 DEBUG: Heartbeat interval negotiation: client = 30, server = 60, result = 30
2019-03-05T01:09:44Z p-70625 t-owz1459k0 INFO: Heartbeat interval used (in seconds): 30
2019-03-05T01:09:44Z p-70626 t-owz1459k0 INFO: Heartbeat interval used (in seconds): 30
2019-03-05T01:09:44Z p-70625 t-owz1459k0 DEBUG: Will use socket read timeout of 66 seconds
2019-03-05T01:09:44Z p-70626 t-owz1459k0 DEBUG: Will use socket read timeout of 66 seconds
2019-03-05T01:09:44Z p-70626 t-owz1459k0 DEBUG: Initializing channel ID allocator with channel_max = 2047
2019-03-05T01:09:44Z p-70625 t-owz1459k0 DEBUG: Initializing channel ID allocator with channel_max = 2047
2019-03-05T01:09:44Z p-70626 t-owz1459k0 DEBUG: Sent connection.tune-ok with heartbeat interval = 30, frame_max = 131072, channel_max = 2047
2019-03-05T01:09:44Z p-70625 t-owz1459k0 DEBUG: Sent connection.tune-ok with heartbeat interval = 30, frame_max = 131072, channel_max = 2047
2019-03-05T01:09:44Z p-70626 t-owz1459k0 DEBUG: Sent connection.open with vhost = /
2019-03-05T01:09:44Z p-70625 t-owz1459k0 DEBUG: Sent connection.open with vhost = /
2019-03-05T01:09:44Z p-70626 t-owz1459k0 DEBUG: Initializing heartbeat sender...
2019-03-05T01:09:44Z p-70625 t-owz1459k0 DEBUG: Initializing heartbeat sender...
2019-03-05T01:09:44Z p-70626 t-owz1459k0 DEBUG: Allocated channel id: 1
2019-03-05T01:09:44Z p-70625 t-owz1459k0 DEBUG: Allocated channel id: 1
2019-03-05T01:09:44Z p-70625 t-owz17xxk0 DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Channel::OpenOk:0x007fdb96ca6718 @channel_id="">
2019-03-05T01:09:44Z p-70626 t-owz17xqh0 DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Channel::OpenOk:0x007fdb96ca5fc0 @channel_id="">
2019-03-05T01:09:44Z p-70625 t-owz17xxk0 DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Basic::QosOk:0x007fdb96ca5110>
2019-03-05T01:09:44Z p-70626 t-owz17xqh0 DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Basic::QosOk:0x007fdb96ca4bc0>
2019-03-05T01:09:44Z p-70625 t-owz17xxk0 DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Basic::QosOk:0x007fdb96ca5110>
2019-03-05T01:09:44Z p-70626 t-owz17xqh0 DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Basic::QosOk:0x007fdb96ca4bc0>
2019-03-05T01:09:44Z p-70626 t-owz17xqh0 DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Exchange::DeclareOk:0x007fdb96c92e20>
2019-03-05T01:09:44Z p-70625 t-owz17xxk0 DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Exchange::DeclareOk:0x007fdb96c933c0>
2019-03-05T01:09:44Z p-70626 t-owz17xqh0 DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Exchange::DeclareOk:0x007fdb96c92e20>
2019-03-05T01:09:44Z p-70625 t-owz17xxk0 DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Exchange::DeclareOk:0x007fdb96c933c0>
2019-03-05T01:09:44Z p-70626 t-owz17xqh0 DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Queue::DeclareOk:0x007fdb96c916d8 @queue="jobdata_fwo", @message_count=0, @consumer_count=1>
2019-03-05T01:09:44Z p-70625 t-owz17xxk0 DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Queue::DeclareOk:0x007fdb96c91bb0 @queue="jobdata_fwo", @message_count=0, @consumer_count=1>
2019-03-05T01:09:44Z p-70626 t-owz17xqh0 DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Queue::DeclareOk:0x007fdb96c916d8 @queue="jobdata_fwo", @message_count=0, @consumer_count=1>
2019-03-05T01:09:44Z p-70625 t-owz17xxk0 DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Queue::DeclareOk:0x007fdb96c91bb0 @queue="jobdata_fwo", @message_count=0, @consumer_count=1>
2019-03-05T01:09:44Z p-70625 t-owz17xxk0 DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Queue::BindOk:0x007fdb96c90530>
2019-03-05T01:09:44Z p-70626 t-owz17xqh0 DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Queue::BindOk:0x007fdb96c90008>
2019-03-05T01:09:44Z p-70625 t-owz17xxk0 DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Queue::BindOk:0x007fdb96c90530>
2019-03-05T01:09:44Z p-70626 t-owz17xqh0 DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Queue::BindOk:0x007fdb96c90008>
2019-03-05T01:09:44Z p-70625 t-owz17xxk0 DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Basic::ConsumeOk:0x007fdb96c8a450 @consumer_tag="bunny-1551748184000-997715587181">
2019-03-05T01:09:44Z p-70626 t-owz17xqh0 DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Basic::ConsumeOk:0x007fdb96c89ca8 @consumer_tag="bunny-1551748184000-710213382410">
2019-03-05T01:09:44Z p-70625 t-owz17xxk0 DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Basic::ConsumeOk:0x007fdb96c8a450 @consumer_tag="bunny-1551748184000-997715587181">
2019-03-05T01:09:44Z p-70626 t-owz17xqh0 DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Basic::ConsumeOk:0x007fdb96c89ca8 @consumer_tag="bunny-1551748184000-710213382410">
2019-03-05T01:09:44Z p-70625 t-owz1459k0 DEBUG: [worker-jobdata_fwo:1:55nivl][#<Thread:0x007fdb96082f40>][jobdata_fwo][#<Sneakers::Configuration:0x007fdb96cc4bc8>] New worker: I'm alive.
2019-03-05T01:09:44Z p-70626 t-owz1459k0 DEBUG: [worker-jobdata_fwo:1:np1y18][#<Thread:0x007fdb96082f40>][jobdata_fwo][#<Sneakers::Configuration:0x007fdb96cc4740>] New worker: I'm alive.
2019-03-05T01:09:44Z p-70627 t-owz1459k0 DEBUG: [worker-jobdata_fwo:1:ybq0fg][#<Thread:0x007fdb96082f40>][jobdata_fwo][#<Sneakers::Configuration:0x007fdb96cc4308>] New worker: subscribing.
2019-03-05T01:09:44Z p-70627 t-owz1459k0 DEBUG: Sent protocol preamble
2019-03-05T01:09:44Z p-70627 t-owz1459k0 DEBUG: Sent connection.start-ok
2019-03-05T01:09:44Z p-70627 t-owz1459k0 DEBUG: Heartbeat interval negotiation: client = 30, server = 60, result = 30
2019-03-05T01:09:44Z p-70627 t-owz1459k0 INFO: Heartbeat interval used (in seconds): 30
2019-03-05T01:09:44Z p-70627 t-owz1459k0 DEBUG: Will use socket read timeout of 66 seconds
2019-03-05T01:09:44Z p-70627 t-owz1459k0 DEBUG: Initializing channel ID allocator with channel_max = 2047
2019-03-05T01:09:44Z p-70627 t-owz1459k0 DEBUG: Sent connection.tune-ok with heartbeat interval = 30, frame_max = 131072, channel_max = 2047
2019-03-05T01:09:44Z p-70627 t-owz1459k0 DEBUG: Sent connection.open with vhost = /
2019-03-05T01:09:44Z p-70627 t-owz1459k0 DEBUG: Initializing heartbeat sender...
2019-03-05T01:09:44Z p-70627 t-owz1459k0 DEBUG: Allocated channel id: 1
2019-03-05T01:09:44Z p-70627 t-owz17xpsk DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Channel::OpenOk:0x007fdb96ca5958 @channel_id="">
2019-03-05T01:09:44Z p-70627 t-owz17xpsk DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Basic::QosOk:0x007fdb96ca4698>
2019-03-05T01:09:44Z p-70627 t-owz17xpsk DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Basic::QosOk:0x007fdb96ca4698>
2019-03-05T01:09:44Z p-70627 t-owz17xpsk DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Exchange::DeclareOk:0x007fdb96c92948>
2019-03-05T01:09:44Z p-70627 t-owz17xpsk DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Exchange::DeclareOk:0x007fdb96c92948>
2019-03-05T01:09:44Z p-70627 t-owz17xpsk DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Queue::DeclareOk:0x007fdb96c91138 @queue="jobdata_fwo", @message_count=0, @consumer_count=3>
2019-03-05T01:09:44Z p-70627 t-owz17xpsk DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Queue::DeclareOk:0x007fdb96c91138 @queue="jobdata_fwo", @message_count=0, @consumer_count=3>
2019-03-05T01:09:44Z p-70627 t-owz17xpsk DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Queue::BindOk:0x007fdb96c8baa8>
2019-03-05T01:09:44Z p-70627 t-owz17xpsk DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Queue::BindOk:0x007fdb96c8baa8>
2019-03-05T01:09:44Z p-70627 t-owz17xpsk DEBUG: Session#handle_frame on 1: #<AMQ::Protocol::Basic::ConsumeOk:0x007fdb96c89578 @consumer_tag="bunny-1551748184000-342786573669">
2019-03-05T01:09:44Z p-70627 t-owz17xpsk DEBUG: Channel#handle_frame on channel 1: #<AMQ::Protocol::Basic::ConsumeOk:0x007fdb96c89578 @consumer_tag="bunny-1551748184000-342786573669">
2019-03-05T01:09:44Z p-70627 t-owz1459k0 DEBUG: [worker-jobdata_fwo:1:ybq0fg][#<Thread:0x007fdb96082f40>][jobdata_fwo][#<Sneakers::Configuration:0x007fdb96cc4308>] New worker: I'm alive.
2019-03-05T01:09:58Z p-70624 t-owz17wprc DEBUG: [worker-jobdata_fwo:1:ygrx8k][#<Thread:0x007fdb96c90ad0>][jobdata_fwo][#<Sneakers::Configuration:0x007fdb96cc50f0>] Working off: "{\"cmd\":\"notify_pm\",\"payload\":{\"_id\":{\"$oid\":\"5c6f1b50670f6e31f27ddb08\"},\"ab_hours\":0.0,\"change_order\":null,\"change_order_details\":null,\"company_id\":{\"$oid\":\"5b58ff1af7e49c0726f35101\"},\"created_at\":\"2019-02-21T13:42:40.569-08:00\",\"ct_hours\":0.0,\"customer\":null,\"description\":\"asdfasdf\",\"fwo_date\":\"2019-03-06T00:00:00.000-08:00\",\"has_signature\":false,\"job_id\":{\"$oid\":\"5bef56f5f7e49c415e5410d8\"},\"job_number\":\"182669\",\"labor_details\":[],\"material_details\":[],\"order_number\":1,\"pl_hours\":0.0,\"pp_hours\":0.0,\"project_manager\":\"MARCUS TERRY\",\"record_changes\":[{\"_id\":{\"$oid\":\"5c6f1b50670f6e31f27ddb09\"},\"backbone_id\":\"5c631112670f6e640a4362a4\",\"changed_fields\":[{\"field\":null,\"from\":null,\"to\":null}],\"created_at\":\"2019-02-21T13:42:40.570-08:00\",\"updated_at\":\"2019-02-21T13:42:40.570-08:00\",\"username\":\"Brad Pettit\"},{\"_id\":{\"$oid\":\"5c7dc5e2670f6efcd00b1e7b\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"fwo_date\",\"from\":null,\"to\":\"2019-03-06T08:00:00.000Z\"},{\"field\":\"description\",\"from\":null,\"to\":\"asdfasdf\"},{\"field\":\"signature\",\"from\":[],\"to\":null}],\"created_at\":\"2019-03-04T16:42:10.461-08:00\",\"updated_at\":\"2019-03-04T16:42:10.461-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dc5e4670f6efcd00b1e7c\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"draft\",\"to\":\"submitted\"},{\"field\":\"signature\",\"from\":null,\"to\":[]}],\"created_at\":\"2019-03-04T16:42:12.076-08:00\",\"updated_at\":\"2019-03-04T16:42:12.076-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dc744670f6efcd00b1e7d\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"submitted\",\"to\":\"void\"}],\"created_at\":\"2019-03-04T16:48:04.022-08:00\",\"updated_at\":\"2019-03-04T16:48:04.022-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dc745670f6efcd00b1e7e\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"void\",\"to\":\"draft\"}],\"created_at\":\"2019-03-04T16:48:05.017-08:00\",\"updated_at\":\"2019-03-04T16:48:05.017-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dc746670f6efcd00b1e7f\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"draft\",\"to\":\"submitted\"}],\"created_at\":\"2019-03-04T16:48:06.162-08:00\",\"updated_at\":\"2019-03-04T16:48:06.162-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dc848670f6efcd00b1e80\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"submitted\",\"to\":\"void\"}],\"created_at\":\"2019-03-04T16:52:24.553-08:00\",\"updated_at\":\"2019-03-04T16:52:24.553-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dc84c670f6efcd00b1e81\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"void\",\"to\":\"draft\"}],\"created_at\":\"2019-03-04T16:52:28.163-08:00\",\"updated_at\":\"2019-03-04T16:52:28.163-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dc85e670f6e0555b43029\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"draft\",\"to\":\"submitted\"}],\"created_at\":\"2019-03-04T16:52:46.252-08:00\",\"updated_at\":\"2019-03-04T16:52:46.252-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dc8c8670f6e0555b4302a\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"submitted\",\"to\":\"void\"}],\"created_at\":\"2019-03-04T16:54:32.605-08:00\",\"updated_at\":\"2019-03-04T16:54:32.605-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dc8c9670f6e0555b4302b\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"void\",\"to\":\"draft\"}],\"created_at\":\"2019-03-04T16:54:33.860-08:00\",\"updated_at\":\"2019-03-04T16:54:33.860-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dc8cb670f6e0555b4302c\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"draft\",\"to\":\"submitted\"}],\"created_at\":\"2019-03-04T16:54:35.023-08:00\",\"updated_at\":\"2019-03-04T16:54:35.023-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dc9ff670f6e0b566a9c64\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"submitted\",\"to\":\"void\"}],\"created_at\":\"2019-03-04T16:59:43.238-08:00\",\"updated_at\":\"2019-03-04T16:59:43.238-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dca00670f6e0b566a9c65\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"void\",\"to\":\"draft\"}],\"created_at\":\"2019-03-04T16:59:44.122-08:00\",\"updated_at\":\"2019-03-04T16:59:44.122-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dca02670f6e0b566a9c66\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"draft\",\"to\":\"submitted\"}],\"created_at\":\"2019-03-04T16:59:46.125-08:00\",\"updated_at\":\"2019-03-04T16:59:46.125-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dcc62670f6e13fbff7be0\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"submitted\",\"to\":\"void\"}],\"created_at\":\"2019-03-04T17:09:54.826-08:00\",\"updated_at\":\"2019-03-04T17:09:54.826-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dcc64670f6e13fbff7be1\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"void\",\"to\":\"draft\"}],\"created_at\":\"2019-03-04T17:09:56.721-08:00\",\"updated_at\":\"2019-03-04T17:09:56.721-08:00\",\"username\":\"Aron Lilland\"},{\"_id\":{\"$oid\":\"5c7dcc66670f6e13fbff7be2\"},\"backbone_id\":\"5b11f8a6670f6e41796c39be\",\"changed_fields\":[{\"field\":\"status\",\"from\":\"draft\",\"to\":\"submitted\"}],\"created_at\":\"2019-03-04T17:09:58.289-08:00\",\"updated_at\":\"2019-03-04T17:09:58.289-08:00\",\"username\":\"Aron Lilland\"}],\"reject_reason\":null,\"signature\":[],\"signature_date\":null,\"sm_hours\":0.0,\"status\":\"submitted\",\"trade\":null,\"updated_at\":\"2019-03-04T17:09:58.291-08:00\"}}"
objc[70624]: +[__NSPlaceholderDictionary initialize] may have been in progress in another thread when fork() was called.
objc[70624]: +[__NSPlaceholderDictionary initialize] may have been in progress in another thread when fork() was called. We cannot safely call it or ignore it in the fork() child process. Crashing instead. Set a breakpoint on objc_initializeAfterForkError to debug.
2019-03-05T01:10:03Z p-70615 t-owz1459k0 INFO: Worker 0 finished unexpectedly with signal SIGABRT

Ruby Config / Launch file

./sneakers.rb

# frozen_string_literal: true

require 'rubygems'
require 'bundler'
require 'date'
require 'csv'
require 'pp'
require 'sneakers'
require 'sneakers/runner'

## Dependencies
Bundler.require :default
Dotenv.load("./.env.#{(ENV['RACK_ENV'] || 'development')}")

require './settings.rb'

## Application Configs
Dir.glob('./config/*.rb') { |file| load file }

## Libs
Dir.glob('./lib/*.rb') { |file| load file }
Dir.glob('./lib/*/*.rb') { |file| load file }

## Models
Dir.glob('./models/*.rb') { |file| load file }

## Workers
Dir.glob('./workers/*.rb') { |file| load file }

Sneakers.configure(
  heartbeat: 30,
  amqp: "amqp://#{ENV['RABBITMQ_USER']}:#{ENV['RABBITMQ_PASS']}@#{ENV['RABBITMQ_HOST']}",
  vhost: '/',
  exchange: 'sneakers',
  exchange_type: :direct
)
r = Sneakers::Runner.new([Workers::FieldWorkOrder])

## Startup Field Work Orders
r.run

My worker

./workers/field_work_order_worker.rb

# frozen_string_literal: true

##
module Workers
  ##
  class FieldWorkOrder
    ## RabbitMQ / Sneakers Configurations for this Model
    include Sneakers::Worker
    from_queue :jobdata_fwo

    def work(msg)
      obj = JSON.parse(msg)
      case obj['cmd']
      when 'notify_pm'
        ## -------------------------------------------------------------------------------
        ## Obtain as much details about the field work order as possible, then query
        ## around looking for the project manager, assistant, and any other relevant
        ## contacts to approve a FWO
        ## -------------------------------------------------------------------------------
        fwo = JOBDATA::FieldWorkOrder.find(obj['payload']['_id'])
        ## methods are in the model instead of the worker so they can be tested in tux &
        ## rake
        fwo.submitted if fwo.status == 'submitted'
        fwo.approved if fwo.status == 'approved'
        fwo.rejected if fwo.status == 'rejected'
        ## -------------------------------------------------------------------------------
        ## removes the published event from rabbitMQ so it doesnt keep getting done over
        ## and over again
        ## -------------------------------------------------------------------------------
        ack!
      end
    end
  end
end

relevent model

./models/field_work_orders/field_work_order_model.rb

# frozen_string_literal: true

module JOBDATA
  ##
  class FieldWorkOrder
    include Mongoid::Document
    include Mongoid::Timestamps

    # ...

    def approved
      # stuff
    end

    def submitted
      # stuff
    end

    def rejected
      # stuff
    end
  end
end
alilland commented 5 years ago

it appears that I am able to send simple GET requests with RestClient within the worker, but any post request is failing

michaelklishin commented 5 years ago

__NSPlaceholderDictionary is not a part of Sneakers, Bunny or any other dependency. In fact, the name strongly suggests this is a part of the Objective-C runtime/Foundation.

A quick search for the message (+[__NSPlaceholderDictionary initialize] may have been in progress in another thread when fork() was called. We cannot safely call it or ignore it in the fork() child process. Crashing instead.) leads to this post about a Mac OS-specific behavior introduced in High Sierra.

michaelklishin commented 5 years ago

According to the post above,

export OBJC_DISABLE_INITIALIZE_FORK_SAFETY=YES

disables the safety mechanism that prevents Ruby from successfully executing fork(2).

The problematic interplay between threads and fork(2) is nothing new (Passenger maintainers have written about it years ago). Their recommendation that

To guarantee that forking is safe, the application must not be running any threads at the point of fork (or the other threads must only be executing async-signal-safe code).

should generally true for Sneakers but only a thorough review can provide an informed answer. Those who feel interested in concurrency are welcome to conduct one. I personally have little time to dedicate to Sneakers and currently, it is best spent on pull request reviews and integration tests.