How to investigate Oban jobs stuck in 'available' state, across all queues?

[linusdm]

Hi!

This weekend I experienced jobs accumulating in a state available across all queues. We run a two-node setup. One of them was the leader while jobs were accumulating (checking with Oban.Peer.leader?/1), and none of the queues were paused (checking with Oban.check_queue/2). All Oban config is fairly default (the :peer option is not set, two plugins: Cron and Pruner).

Unfortunately I had no time to investigate. Respawning two new nodes (we’re on k8s) solved the issue and jobs were being processed again.

I want to prevent this in the future, but I’m not sure what I can do next time to get to the bottom of this. I checked the troubleshooting guide, but I don’t think there is something in there for this situation (I’m not using PgBouncer for example). I read something about the Stager modes (local vs global), but I’m not sure how to query for that (and if it’s useful information at all).

[sorentwo]

@linusdm

Unfortunately I had no time to investigate. Respawning two new nodes (we’re on k8s) solved the issue and jobs were being processed again.

Without a running instance it’s difficult to say what the problem may have been. The fact that restarting got things running again points to an ephemeral issue, rather than something with the jobs table itself.

@linusdm

I read something about the Stager modes (local vs global), but I’m not sure how to query for that (and if it’s useful information at all).

That would be useful information because it would indicate whether the nodes were able to communicate with eachother, and whether the stager “thought” it was notifying queues about available jobs. Staging events are included in the default logger (and is recommended as part of the Ready for Production guide).

[linusdm]

@sorentwo

Staging events are included in the default logger (and is recommended as part of the Ready for Production guide).

We only log job-related events right now, so we’re missing out on other events. That’s something actionable I can fix. Thanks for the suggestion!

My first idea was to attach handlers for all events that end with :exception, but that might be a bit too much. I’ll start with the ones that are listed in the default logger. Are there any other events you think of that might be of interest for this exact use-case?

[sorentwo]

@linusdm

Are there any other events you think of that might be of interest for this exact use-case?

The peer, notifier, and stager events are all helpful for diagnosing whatever happened in your use-case.

[linusdm]

After adding the handlers for for more Oban events, I got to see these sequence of events (I took the log messages from the default implementation in Oban.Telemetry):

• Oban notifier only receiving messages from its own node, functionality may be degraded
• Oban staging switched to local mode. Local mode polls for jobs for every queue.
• Oban notifier is receiving messages from other nodes
• Oban staging switched back to global mode

(this sequence happened twice with only a few seconds in between)

Nothing bad happened, and it only happened once today. So I’m not worried. But it raises some questions about how to interpret this.

Is this expected? Or could this be a hint that network is flaky or that the underlying Erlang Distribution is not stable? Or is the database network connection going bad when this happens?

[sorentwo]

@linusdm

Is this expected? Or could this be a hint that network is flaky or that the underlying Erlang Distribution is not stable? Or is the database network connection going bad when this happens?

That is normal if the network or database connection is flaky. Really, that’s why the events exist and why the stager switches modes. If you’re using the Postgres notifier, then we recommend switching to the PG notifier if possible (Scaling Applications — Oban v2.18.3).

[madclaws]

@sorentwo We also faced exact issue sometime ago, and we too had to restart the server for jobs to move into executing state. But we have only single node. Any idea on how can we monitor/debug issue like this.

We can see in this image that these jobs were in available state for 4hrs…

Also once we restarted there was big cpu spike (as expected) due to all these pending jobs moving to exectuing state at once.

[sorentwo]

@madclaws

We also faced exact issue sometime ago, and we too had to restart the server for jobs to move into executing state. But we have only single node.

This seems like an issue with postgres pubsub. A disconnect error in versions prior to v0.20 would leave the Oban.Notifier in an undetectable disconnected state. The node would keep emitting notifications about available jobs, but they wouldn’t broadcast.

@madclaws

Any idea on how can we monitor/debug issue like this.

There are several ways you could monitor this:

1. Use checkins in a tracker like sentry or honeybadger. Send an from a cron job every minute and get alerted if they stop running.
2. Use cron monitors in sentry, which have native support for oban in recent versions.
3. Poll jobs and send it to an external tool like grafana, datadog, etc. and set up alerts on those. If you’re using the PG notifier, then Oban.Met.latest/2 is a good option. Otherwise, query the actual database every minute or so.

[madclaws]

Thanks will try these.

[thousandsofthem]

Try to change notifier -
https://hexdocs.pm/oban/Oban.Notifiers.PG.html

I got this issue before. For some reason no one mentions it

config :app, Oban,
  notifier: Oban.Notifiers.PG

[sorentwo]

@thousandsofthem

For some reason no one mentions it

It’s suggested in the scaling guide, and in the web installation guide, but it could be highlighted more prominently.

[thousandsofthem]

Oban.Notifiers.PG works like a charm on single machine, unlike default config. So, i think, guide doesn’t explain it clearly. I think nice improvement would be "if you’re getting these errors, likely cause is notifier and you could try alternative implementation "

[madclaws]

But doc clearly says if its not clustered, then use Postgres notifier

[thousandsofthem]

If you have multiple machines, that is.

[quatermain]

We have similar issue where we have only one queue doesn’t process jobs. 3 nodes, new and old jobs are still in available state. See config:

 %Oban.Config{
      dispatch_cooldown: 5,
      engine: Oban.Pro.Engines.Smart,
      get_dynamic_repo: nil,
      insert_trigger: true,
      log: false,
      name: Oban,
      node: "production@123:0:4567:890:1a7:6bde:b5e4:2",
      notifier: {Oban.Notifiers.Postgres, []},
      peer: {Oban.Peers.Database, []},
      plugins: [
        {Oban.Plugins.Cron,
         [
           crontab: [],
           timezone: "America/New_York"
         ]},
        {Oban.Pro.Plugins.DynamicPruner,
         [
           state_overrides: [
             completed: {:max_age, {30, :day}},
             cancelled: {:max_age, {12, :month}},
             discarded: {:max_age, {12, :month}}
           ],
           limit: 25000,
           timeout: 60000,
           schedule: "0 * * * *"
         ]},
        {Oban.Plugins.Lifeline, [rescue_after: 14_400_000, interval: 14_400_000]},
        {Oban.Pro.Plugins.DynamicPrioritizer, []}
      ],
      prefix: "public",
      queues: [
        retroactive_sync: [
          local_limit: 1,
          global_limit: 3,
          rate_limit: [allowed: 1, partition: [args: [:partner_id]], period: 2]
        ]
      ],
      shutdown_grace_period: 15000,
      stage_interval: 1000,
      testing: :disabled
    }

I removed other queues and cron config and some other not related values. Any suggestions how to debug it please?

[quatermain]

I found this in logs, not sure if it’s related but we recently introduce some other jobs in other queue which can have big text in params:

Ecto query error:
Query: SELECT pg_notify($1, payload) FROM json_array_elements_text($2::json) AS payload
Params: ["public.oban_handoff", ["H4sIAAAA........" <> ...]]
Reason: %Postgrex.Error{
      message: nil,
      postgres: %{
        code: :invalid_parameter_value,
        line: "655",
        message: "payload string too long",
        file: "async.c",
        unknown: "ERROR",
        severity: "ERROR",
        pg_code: "22023",
        routine: "Async_Notify"
      },
      connection_id: 15572,
      query: nil
    }

[sorentwo]

@quatermain

I found this in logs, not sure if it’s related but we recently introduce some other jobs in other queue which can have big text in params:

That’s from oban_met and entirely unrelated to job processing, but it’s not ideal. The Postgres payload limit is the primary reason we suggest switching to the PG notifier in the Web installation guide.

[quatermain]

Thanks @sorentwo . We switched to PG notifier yesterday. It didn’t help, but how you suggested via email support, we disabled Global and Rate limit from Oban Web and it started processing.

But still something weird happen. We have 3 nodes, local limit is 1. So it should process 3 jobs at same time. But it was processing only 2, one node was always resting. Not specific node, just randomly switched.

[sorentwo]

@quatermain

We have 3 nodes, local limit is 1. So it should process 3 jobs at same time. But it was processing only 2, one node was always resting. Not specific node, just randomly switched.

Did it remain this way after the app restarted? If it is still that way, will you please share the output of Oban.check_queue/1 for that queue on each of the nodes?

[quatermain]

Well, we changed config in code and release until we figure out how to fix it. Before we restarted app and it was still not processing. But now when we revert changes and go back with original config it works like it should and how it worked before. So no idea what could happen. Is it possible that something in meta which is used by global and rate limiting was broken? See only changes what we did: