Calling finish, note etc in task code fails on macOS while communicating over TCP

[briandfoy]

I'm collecting info on this issue and I know that this report is incomplete. I'd like to record it here while I'm working on it. I think it's specific to macOS, but that's only a hunch. This might be a DBD::Pg issue rather than a Minion issue, too, but I haven't been able to reproduce it without Minion involved. If you've debugged this sort of thing before, I'd appreciate advice on what else I should investigate.

• Minion version: 10.04
• Perl version: 5.30.2
• Operating system: macOS Catalina 10.15.3

Darwin otter.local 19.3.0 Darwin Kernel Version 19.3.0: Thu Jan 9 20:58:23 PST 2020; root:xnu-6153.81.5~1/RELEASE_X86_64 x86_64

• local Postgresql is 12.2, from the precompiled package from EnterpriseDB. This is what the local DBD::Pg linked against.
• DBI: 1.643
• DBD::Pg: 3.11.1
• remote Postgresql is 12.2, from the precompiled package that ArchLinux installs. Note that ArchLinux treats the Postgres packages oddly because it's confused about the versioning.

Steps to reproduce the behavior

When I call a database-mutating method on the job object inside the task code, the subprocess exits with a failure. The parent process recovers and marks the job as failed. Here's the script I'm playing with:

use v5.30;
use Mojo::Base -strict, -signatures;
use Minion;
use Mojo::Util qw(dumper);

my $minion = Minion->new( Pg => 'postgresql://?service=remote-minion' );

$minion->add_task( sum => sub ( $job, @args ) {
	say "Sum: ARGS: @args";
	my $sum; $sum += $_ for @args;
	say "Sum: About to finish";
	$job->finish( { sum => $sum } );
	say "Sum: After finish";
	} );

my $jobs = 1;
foreach my $i ( 1 .. $jobs ) {
	my @args = map { int rand 100 } 2 .. 3 + int rand 5;
	say "ARGS: @args";
	my $id = $minion->enqueue( sum => \@args );
	say "Enqueued job ID <$id>";
	}

my $worker = $minion->repair->worker->register;

while(1) {
	my $job    = $worker->dequeue(0.5);
	last unless defined $job;

	say "Dequeueing Job id: <", $job->id,
		"> Args: <@{[ join ' ', $job->args->@* ]}>";

	$job->perform;
	last;
	}

$worker->unregister;

Here's the Pg service, with the hostaddr obscured. Nothing else (psql, other DBD::Pg programs) break using this service.

[remote-minion]
dbname=minion
hostaddr=w.x.y.z
port=5432
user=brian
sslmode=require

Now, here's the trick. This same program has no problems running against the same remote Pg server when I run it on an Ubuntu box. This script on the remote machine running against the remote Pg server works just fine.

So, I have another service for a Pg server running on the same laptop. Running this on my MacBook against the local Pg server over TCP fails (job fails because task child exits with an error), but connecting to the local socket works (job finishes normally).

[local-minion]
dbname=minion
host=localhost
user=postgres

[local-minion-socket]
dbname=minion
host=/tmp
user=postgres

Expected behavior

Calling finish, note, etc on the job object in the task code should not cause the subprocess to exit.

Actual behavior

Calling finish, note, etc on the job object in the task code fails somewhere around the code the attempts to make a connection to the database. I tracked the Perl code to a line in DBD::Pg, and this is what I think fails in the child process:

https://github.com/bucardo/dbdpg/blob/ef0f61fdcd5d2dec9271c722dac8bd75ce8def6e/Pg.pm#L258

While logging this in postgres, I do not see an attempt to connect (could be wrong, because there are a lot of connection attempts from Minion). I've traced this with DBI_TRACE=9, and have those very long logs.

I've also traced this with Devel::Trace to watch the Perl path. I think this is the general flow:

• Task calls $job->finish

• Minion::Job::finish() calls $self->minion->backend->finish_job($self->id, $self->retries, $result); (note and others have similar calls)

• Minion::Backend::Pg::finish_job calls Minion::Backend::Pg::_update

• Minion::Backend::Pg::_update calls $self->pg->db (Mojo::Pg::Database) (with an immediate call to ->query, but it never gets that far.

• Mojo::Pg::Database->db (Mojo::Pg::db) calls Mojo::Pg::Database->_prepare , which calls Mojo::Pg::Database->_dequeue, which calls DBI->connect(). The DBI options at this point seem right, and I think AutoInactiveDestroy is as it should be:

  {
  "AutoCommit" => 1,
  "AutoInactiveDestroy" => 1,
  "PrintError" => 0,
  "PrintWarn" => 0,
  "RaiseError" => 1
  }

• DBI->connect ends up in DBD::Pg, particularly DBD::Pg::db::_login, which is last Pure perl line of code executed in the child process. Somewhere in there it fails, which leads me to think that it might not be Minion's fault. However, trying to tickle this without Minion hasn't helped. I can't reproduce this by playing with DBD::Pg without Minion.

• At this point, the child process exits abnormally without DBI ever connecting. I see that the process gets the SEGV signal.

• The parent process sees the abnormal exit and switches from finish to fail.

[kraih]

Yea, doesn't look like a Minion problem. Maybe a broken DBD::Pg installation? Can you run the Minion tests against the database?

[briandfoy]

Oh, running the tests would have been a good idea a week ago. :) I'm strongly suspecting a problem with DBD::Pg too, but I'm still figuring out how to reproduce it without Minion.

$ echo $TEST_ONLINE
postgresql://?service=remote

Some of the tests fail in the same way I describe, then the test run hangs:

$ perl -Iblib t/pg.t
-- Emit connection in Mojo::Pg (0)
-- Emit connection in Mojo::Pg (0)
-- Emit connection in Mojo::Pg (0)
-- Emit worker in Minion (0)
ok 1 - 'has default application' isa 'Mojolicious'
ok 2 - active version is 20
ok 3 - active version is 0
ok 4 - active version is 20
ok 5 - has timestamp
ok 6 - has timestamp
ok 7 - same id
ok 8 - new timestamp
ok 9 - no information
ok 10 - right host
ok 11 - right pid
ok 12 - no information
-- Emit worker in Minion (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
ok 13 - same id
ok 14 - not finished
ok 15 - not failed
-- Emit finished in Minion::Job (0)
ok 16 - right result
ok 17 - right note
ok 18 - no more results
ok 19 - not failed
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
ok 20 - same id
-- Emit failed in Minion::Job (0)
ok 21 - not finished
ok 22 - right result
ok 23 - no more results
ok 24 - right result
ok 25 - right note
ok 26 - no more results
ok 27 - not failed
ok 28 - not finished
ok 29 - failed
ok 30 - job no longer exists
ok 31 - not failed
-- Emit worker in Minion (0)
ok 32 - new id
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
ok 33 - right id
ok 34 - right id
ok 35 - job is still active
ok 36 - is registered
-- Emit connection in Mojo::Pg (0)
ok 37 - not registered
ok 38 - has finished timestamp
ok 39 - job is no longer active
ok 40 - right result
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
ok 41 - right id
-- Emit connection in Mojo::Pg (0)
ok 42 - job is no longer active
ok 43 - right result
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
ok 44 - right id
ok 45 - job is still active
ok 46 - no result
-- Emit enqueue in Minion (0)
-- Emit enqueue in Minion (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
-- Emit spawn in Minion::Job (0)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (0)
-- Emit finish in Minion::Job (0)
-- Emit cleanup in Minion::Job (0)
-- Emit reap in Minion::Job (0)
-- Emit finished in Minion::Job (0)
-- Emit dequeue in Minion::Worker (0)
-- Emit spawn in Minion::Job (0)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (0)
-- Emit finish in Minion::Job (0)
-- Emit cleanup in Minion::Job (0)
-- Emit reap in Minion::Job (0)
-- Emit finished in Minion::Job (0)
-- Emit dequeue in Minion::Worker (0)
-- Emit spawn in Minion::Job (0)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (0)
-- Emit finish in Minion::Job (0)
-- Emit cleanup in Minion::Job (0)
-- Emit reap in Minion::Job (0)
-- Emit finished in Minion::Job (0)
ok 47 - job has not been cleaned up
ok 48 - job has been cleaned up
ok 49 - job has been cleaned up
-- Emit worker in Minion (0)
-- Emit worker in Minion (0)
ok 50 - two workers total
ok 51 - has id
ok 52 - right host
ok 53 - right pid
ok 54 - has timestamp
ok 55 - right host
ok 56 - right pid
ok 57 - no more results
ok 58 - two workers total
ok 59 - right id
ok 60 - right status
ok 61 - no more results
ok 62 - right status
ok 63 - right id
ok 64 - no more results
-- Emit worker in Minion (0)
-- Emit worker in Minion (0)
-- Emit worker in Minion (0)
-- Emit worker in Minion (0)
-- Emit worker in Minion (0)
ok 65 - no before
ok 66 - right status
ok 67 - before 4
ok 68 - right status
ok 69 - right status
ok 70 - before 2
ok 71 - right status
ok 72 - right status
ok 73 - before 1
ok 74 - no more results
ok 75 - no before
ok 76 - right status
ok 77 - before 1
ok 78 - right status
ok 79 - right status
ok 80 - no more results
ok 81 - right status
ok 82 - right status
ok 83 - five workers
ok 84 - right status
ok 85 - right status
ok 86 - no more results
ok 87 - four workers
ok 88 - two workers
ok 89 - locked
ok 90 - not locked again
ok 91 - unlocked
ok 92 - not unlocked again
ok 93 - locked
ok 94 - locked again
ok 95 - locked again
ok 96 - not locked again
ok 97 - not locked again
ok 98 - unlocked
ok 99 - not unlocked again
ok 100 - locked
ok 101 - not locked again
ok 102 - locked
ok 103 - locked again
ok 104 - locked again
ok 105 - locked again
ok 106 - not locked again
ok 107 - locked
ok 108 - unlocked
ok 109 - locked again
ok 110 - unlocked again
ok 111 - unlocked again
ok 112 - unlocked again
ok 113 - not unlocked again
ok 114 - unlocked
ok 115 - not unlocked again
ok 116 - one active lock
ok 117 - right name
ok 118 - expires
ok 119 - no more locks
ok 120 - one result
ok 121 - three active locks
ok 122 - right name
ok 123 - expires
ok 124 - no more locks
ok 125 - three results
ok 126 - right name
ok 127 - expires
ok 128 - right name
ok 129 - expires
ok 130 - no more locks
ok 131 - two results
ok 132 - no results
ok 133 - no results
ok 134 - locked
ok 135 - not locked again
ok 136 - locked
ok 137 - not locked again
ok 138 - locked again
ok 139 - locked again
ok 140 - locked
ok 141 - locked
ok 142 - locked
ok 143 - not locked again
-- Emit enqueue in Minion (0)
-- Emit worker in Minion (0)
ok 144 - jobs
ok 145 - locks
ok 146 - workers
ok 147 - jobs
ok 148 - no locks
ok 149 - workers
ok 150 - jobs
ok 151 - locks
ok 152 - workers
ok 153 - no jobs
ok 154 - no locks
ok 155 - no workers
ok 156 - no active workers
ok 157 - no inactive workers
ok 158 - no enqueued jobs
ok 159 - no active jobs
ok 160 - no failed jobs
ok 161 - no finished jobs
ok 162 - no inactive jobs
ok 163 - no delayed jobs
ok 164 - no active locks
ok 165 - has uptime
-- Emit worker in Minion (0)
ok 166 - one inactive worker
-- Emit enqueue in Minion (0)
ok 167 - one enqueued job
-- Emit enqueue in Minion (0)
ok 168 - two enqueued jobs
ok 169 - two inactive jobs
-- Emit dequeue in Minion::Worker (0)
ok 170 - one active worker
ok 171 - one active job
ok 172 - one inactive job
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
ok 173 - one active worker
ok 174 - two active jobs
ok 175 - one inactive job
-- Emit finished in Minion::Job (0)
ok 176 - job finished
-- Emit finished in Minion::Job (0)
ok 177 - job finished
ok 178 - two finished jobs
-- Emit dequeue in Minion::Worker (0)
-- Emit failed in Minion::Job (0)
ok 179 - job failed
ok 180 - one failed job
ok 181 - job retried
ok 182 - no failed jobs
-- Emit dequeue in Minion::Worker (0)
-- Emit finished in Minion::Job (0)
ok 183 - job finished
ok 184 - no active workers
ok 185 - no inactive workers
ok 186 - no active jobs
ok 187 - no failed jobs
ok 188 - three finished jobs
ok 189 - no inactive jobs
ok 190 - no delayed jobs
-- Emit enqueue in Minion (0)
-- Emit worker in Minion (0)
-- Emit dequeue in Minion::Worker (0)
-- Emit failed in Minion::Job (0)
ok 191 - job failed
ok 192 - data for 24 hours
ok 193 - one failed job in the last hour
ok 194 - three finished jobs in the last hour
ok 195 - no finished jobs 24 hours ago
ok 196 - no failed jobs 24 hours ago
ok 197 - has epoch value
ok 198 - has epoch value
ok 199 - has epoch value
ok 200 - has epoch value
-- Emit enqueue in Minion (0)
ok 201 - four total with offset and limit
ok 202 - four jobs total
ok 203 - has id
ok 204 - right task
ok 205 - right state
ok 206 - job has not been retried
ok 207 - has created timestamp
ok 208 - right task
ok 209 - right arguments
ok 210 - right metadata
ok 211 - right result
ok 212 - right state
ok 213 - right priority
ok 214 - right parents
ok 215 - right children
ok 216 - job has been retried
ok 217 - has created timestamp
ok 218 - has delayed timestamp
ok 219 - has finished timestamp
ok 220 - has retried timestamp
ok 221 - has started timestamp
ok 222 - right task
ok 223 - right state
ok 224 - job has not been retried
ok 225 - right task
ok 226 - right state
ok 227 - job has not been retried
ok 228 - no more results
ok 229 - right state
ok 230 - job has not been retried
ok 231 - no more results
ok 232 - right task
ok 233 - job has not been retried
ok 234 - no more results
ok 235 - right task
ok 236 - right task
ok 237 - right task
ok 238 - right task
ok 239 - no more results
ok 240 - right queue
ok 241 - right queue
ok 242 - right queue
ok 243 - right queue
ok 244 - no more results
-- Emit enqueue in Minion (0)
ok 245 - right task
ok 246 - no more results
ok 247 - job removed
ok 248 - no results
ok 249 - four jobs total
ok 250 - right state
ok 251 - job has not been retried
ok 252 - no more results
ok 253 - right state
ok 254 - job has been retried
ok 255 - no more results
ok 256 - right task
ok 257 - before 1
ok 258 - right task
ok 259 - right task
ok 260 - right task
ok 261 - no more results
ok 262 - four jobs
ok 263 - no before
ok 264 - right task
ok 265 - before 3
ok 266 - right task
ok 267 - before 3
ok 268 - right task
ok 269 - before 1
ok 270 - right task
ok 271 - before 1
ok 272 - no more results
ok 273 - four jobs
ok 274 - one job
ok 275 - right task
ok 276 - no more results
ok 277 - no more results
ok 278 - right task
ok 279 - four jobs
-- Emit enqueue in Minion (0)
ok 280 - right task
ok 281 - job removed
ok 282 - four jobs
ok 283 - right task
ok 284 - no more results
ok 285 - three jobs
ok 286 - job removed
ok 287 - job removed
ok 288 - job does not exist
-- Emit enqueue in Minion (0)
ok 289 - job does exist
ok 290 - right arguments
ok 291 - right priority
ok 292 - right state
-- Emit worker in Minion (0)
ok 293 - not registered
ok 294 - no started timestamp
-- Emit dequeue in Minion::Worker (0)
ok 295 - right job
ok 296 - has created timestamp
ok 297 - has started timestamp
ok 298 - has server time
ok 299 - right arguments
ok 300 - right state
ok 301 - right task
ok 302 - job has not been retried
ok 303 - right worker
ok 304 - no finished timestamp
-- Emit spawn in Minion::Job (0)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (0)
-- Emit reap in Minion::Job (0)
-- Emit failed in Minion::Job (0)
ok 305 - no jobs
ok 306 - has finished timestamp
not ok 307 - right result
#   Failed test 'right result'
#   at t/pg.t line 567.
#     Structures begin differing at:
#          $got = 'Non-zero exit status (0)'
#     $expected = HASH(0x7fa611f18828)
not ok 308 - right state
#   Failed test 'right state'
#   at t/pg.t line 568.
#          got: 'failed'
#     expected: 'finished'
ok 309 - right arguments
ok 310 - job has not been retried
not ok 311 - right state
#   Failed test 'right state'
#   at t/pg.t line 573.
#          got: 'failed'
#     expected: 'finished'
ok 312 - right task
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
ok 313 - job will be attempted once
ok 314 - job has not been retried
ok 315 - right id
-- Emit finished in Minion::Job (0)
ok 316 - job finished
ok 317 - no more jobs
ok 318 - no retried timestamp
-- Emit notification in Mojo::Pg::Database (0)
ok 319 - job retried
ok 320 - has retried timestamp
ok 321 - right state
ok 322 - job has been retried once
-- Emit dequeue in Minion::Worker (0)
ok 323 - job has been retried once
-- Emit notification in Mojo::Pg::Database (0)
ok 324 - job retried
ok 325 - right id
ok 326 - job has been retried twice
-- Emit dequeue in Minion::Worker (0)
ok 327 - right state
-- Emit finished in Minion::Job (0)
ok 328 - job finished
ok 329 - job has been removed
ok 330 - job not retried
ok 331 - no information
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
ok 332 - right state
ok 333 - job has not been retried
-- Emit notification in Mojo::Pg::Database (0)
ok 334 - job retried
ok 335 - right state
ok 336 - job has been retried once
-- Emit dequeue in Minion::Worker (0)
ok 337 - right id
-- Emit failed in Minion::Job (0)
ok 338 - job failed
ok 339 - job has been removed
ok 340 - no information
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
ok 341 - job has been removed
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
ok 342 - right id
ok 343 - right priority
-- Emit finished in Minion::Job (0)
ok 344 - job finished
-- Emit dequeue in Minion::Worker (0)
ok 345 - different id
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
ok 346 - right id
ok 347 - right priority
-- Emit finished in Minion::Job (0)
ok 348 - job finished
-- Emit notification in Mojo::Pg::Database (0)
ok 349 - job retried with higher priority
-- Emit dequeue in Minion::Worker (0)
ok 350 - right id
ok 351 - job has been retried once
ok 352 - high priority
-- Emit finished in Minion::Job (0)
ok 353 - job finished
-- Emit notification in Mojo::Pg::Database (0)
ok 354 - job retried with lower priority
-- Emit dequeue in Minion::Worker (0)
ok 355 - right id
ok 356 - job has been retried twice
ok 357 - low priority
-- Emit finished in Minion::Job (0)
ok 358 - job finished
-- Emit enqueue in Minion (0)
ok 359 - one delayed job
ok 360 - too early for job
ok 361 - delayed timestamp
-- Emit dequeue in Minion::Worker (0)
ok 362 - right id
ok 363 - has delayed timestamp
-- Emit finished in Minion::Job (0)
ok 364 - job finished
-- Emit notification in Mojo::Pg::Database (0)
ok 365 - job retried
ok 366 - no delayed timestamp
ok 367 - job removed
ok 368 - job not retried
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
ok 369 - no delayed timestamp
-- Emit failed in Minion::Job (0)
ok 370 - job failed
ok 371 - job retried with delay
ok 372 - job has been retried once
ok 373 - delayed timestamp
ok 374 - job has been removed
-- Emit worker in Minion (1)
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (1)
ok 375 - enqueue event has been emitted
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (1)
ok 376 - failed event has not been emitted
ok 377 - finished event has not been emitted
-- Emit finished in Minion::Job (2)
ok 378 - job finished
-- Emit spawn in Minion::Job (1)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (1)
-- Emit reap in Minion::Job (1)
ok 379 - right result
ok 380 - failed event has not been emitted
ok 381 - finished event has been emitted once
ok 382 - new process id
ok 383 - new process id
ok 384 - same process id
-- Emit dequeue in Minion::Worker (1)
-- Emit failed in Minion::Job (2)
ok 385 - right error
ok 386 - failed event has been emitted once
ok 387 - finished event has been emitted once
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (1)
-- Emit spawn in Minion::Job (1)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (1)
-- Emit reap in Minion::Job (1)
-- Emit failed in Minion::Job (1)
not ok 388 - right result
#   Failed test 'right result'
#   at t/pg.t line 744.
#     Structures begin differing at:
#          $got = 'Non-zero exit status (0)'
#     $expected = HASH(0x7fa613cd7ea8)
not ok 389 - finish event has been emitted once
#   Failed test 'finish event has been emitted once'
#   at t/pg.t line 745.
#          got: '0'
#     expected: '1'
not ok 390 - has a process id
#   Failed test 'has a process id'
#   at t/pg.t line 746.
ok 391 - different process id
ok 392 - value still exists
not ok 393 - cleanup event has been emitted once
#   Failed test 'cleanup event has been emitted once'
#   at t/pg.t line 749.
#          got: undef
#     expected: '2'
not ok 394 - has a process id
#   Failed test 'has a process id'
#   at t/pg.t line 750.
ok 395 - different process id
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
ok 396 - wrong queue
-- Emit dequeue in Minion::Worker (1)
ok 397 - right id
ok 398 - right queue
-- Emit finished in Minion::Job (1)
ok 399 - job finished
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
ok 400 - wrong queue
-- Emit dequeue in Minion::Worker (1)
ok 401 - right id
ok 402 - right queue
-- Emit finished in Minion::Job (1)
ok 403 - job finished
-- Emit notification in Mojo::Pg::Database (0)
ok 404 - job retried
-- Emit dequeue in Minion::Worker (1)
ok 405 - right id
ok 406 - right queue
-- Emit finished in Minion::Job (1)
ok 407 - job finished
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (1)
ok 408 - right id
ok 409 - no result
-- Emit failed in Minion::Job (1)
ok 410 - job failed
ok 411 - job not finished
ok 412 - right state
ok 413 - right result
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (1)
ok 414 - right id
-- Emit failed in Minion::Job (1)
ok 415 - job failed
ok 416 - right state
ok 417 - right result
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (1)
ok 418 - right id
-- Emit spawn in Minion::Job (1)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (1)
-- Emit reap in Minion::Job (1)
-- Emit failed in Minion::Job (1)
ok 419 - right state
not ok 420 - right result
#   Failed test 'right result'
#   at t/pg.t line 794.
#          got: 'Non-zero exit status (0)'
#     expected: 'Intentional failure!
# '
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (1)
-- Emit spawn in Minion::Job (1)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (1)
-- Emit reap in Minion::Job (1)
-- Emit failed in Minion::Job (1)
not ok 421 - right state
#   Failed test 'right state'
#   at t/pg.t line 813.
#          got: 'failed'
#     expected: 'finished'
ok 422 - added metadata
ok 423 - not added metadata
not ok 424 - right metadata
#   Failed test 'right metadata'
#   at t/pg.t line 822.
#     Structures begin differing at:
#          $got->{baz} = Does not exist
#     $expected->{baz} = 'yada'
not ok 425 - right structure
#   Failed test 'right structure'
#   at t/pg.t line 823.
#     Structures begin differing at:
#          $got = 'Non-zero exit status (0)'
#     $expected = ARRAY(0x7fa611f142b8)
ok 426 - removed metadata
not ok 427 - right metadata
#   Failed test 'right metadata'
#   at t/pg.t line 826.
#     Structures begin differing at:
#          $got->{baz} = Does not exist
#     $expected->{baz} = 'yada'
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit worker in Minion (0)
-- Emit dequeue in Minion::Worker (0)
-- Emit spawn in Minion::Job (0)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (0)
-- Emit reap in Minion::Job (0)
-- Emit failed in Minion::Job (0)
not ok 428 - right state
#   Failed test 'right state'
#   at t/pg.t line 832.
#          got: 'failed'
#     expected: 'finished'
not ok 429 - right result
#   Failed test 'right result'
#   at t/pg.t line 833.
#     Structures begin differing at:
#          $got = 'Non-zero exit status (0)'
#     $expected = HASH(0x7fa611f1e390)
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (1)
ok 430 - right id
-- Emit spawn in Minion::Job (1)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (1)
-- Emit reap in Minion::Job (1)
-- Emit failed in Minion::Job (1)
ok 431 - right state
ok 432 - right result
ok 433 - right result
ok 434 - right result
ok 435 - right result
ok 436 - right result
ok 437 - right result
ok 438 - right result
ok 439 - right result
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (1)
ok 440 - right id
ok 441 - job has not been retried
-- Emit spawn in Minion::Job (1)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (1)
-- Emit reap in Minion::Job (1)
-- Emit failed in Minion::Job (1)
ok 442 - job will be attempted twice
ok 443 - right state
ok 444 - right result
ok 445 - delayed timestamp
-- Emit dequeue in Minion::Worker (1)
ok 446 - right id
ok 447 - job has been retried once
-- Emit spawn in Minion::Job (1)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (1)
-- Emit reap in Minion::Job (1)
-- Emit failed in Minion::Job (1)
ok 448 - job will be attempted twice
ok 449 - right state
ok 450 - right result
-- Emit notification in Mojo::Pg::Database (0)
ok 451 - job retried
-- Emit dequeue in Minion::Worker (1)
ok 452 - right id
-- Emit spawn in Minion::Job (1)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (1)
-- Emit reap in Minion::Job (1)
-- Emit failed in Minion::Job (1)
ok 453 - job will be attempted three times
ok 454 - right state
ok 455 - right result
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (1)
ok 456 - right id
ok 457 - job has not been retried
ok 458 - job will be attempted twice
ok 459 - right state
-- Emit connection in Mojo::Pg (0)
ok 460 - right state
ok 461 - right result
ok 462 - delayed timestamp
-- Emit dequeue in Minion::Worker (1)
ok 463 - right id
ok 464 - job has been retried once
-- Emit connection in Mojo::Pg (0)
ok 465 - right state
ok 466 - right result
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (1)
ok 467 - right id
-- Emit finished in Minion::Job (1)
ok 468 - job finished
ok 469 - right state
-- Emit notification in Mojo::Pg::Database (0)
ok 470 - job retried
ok 471 - right state
-- Emit dequeue in Minion::Worker (1)
ok 472 - right state
ok 473 - job not finished
ok 474 - right state
ok 475 - right id
-- Emit finished in Minion::Job (1)
ok 476 - job finished
ok 477 - job not retried
ok 478 - right state
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit worker in Minion (0)
-- Emit dequeue in Minion::Worker (0)
-- Emit dequeue in Minion::Worker (0)
-- Emit dequeue in Minion::Worker (0)
-- Emit dequeue in Minion::Worker (0)
-- Emit spawn in Minion::Job (0)
-- Emit spawn in Minion::Job (0)
-- Emit reset in Mojo::IOLoop (0)
-- Emit spawn in Minion::Job (0)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (0)
-- Emit start in Minion::Job (0)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (0)
-- Emit finish in Minion::Job (0)
-- Emit cleanup in Minion::Job (0)
-- Emit spawn in Minion::Job (0)
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (0)
-- Emit reap in Minion::Job (0)
-- Emit failed in Minion::Job (0)
-- Emit reap in Minion::Job (0)
-- Emit failed in Minion::Job (0)
-- Emit reap in Minion::Job (0)
-- Emit finished in Minion::Job (0)
-- Emit reap in Minion::Job (0)
-- Emit failed in Minion::Job (0)
not ok 479 - right state
#   Failed test 'right state'
#   at t/pg.t line 944.
#          got: 'failed'
#     expected: 'finished'
not ok 480 - right result
#   Failed test 'right result'
#   at t/pg.t line 945.
#     Structures begin differing at:
#          $got = 'Non-zero exit status (0)'
#     $expected = HASH(0x7fa613cd9a88)
not ok 481 - right state
#   Failed test 'right state'
#   at t/pg.t line 946.
#          got: 'failed'
#     expected: 'finished'
not ok 482 - right result
#   Failed test 'right result'
#   at t/pg.t line 947.
#     Structures begin differing at:
#          $got = 'Non-zero exit status (0)'
#     $expected = HASH(0x7fa613cd7278)
ok 483 - right state
ok 484 - no result
ok 485 - right state
ok 486 - right result
-- Emit worker in Minion (0)
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
-- Emit spawn in Minion::Job (0)
-- Emit reset in Mojo::IOLoop (0)
ok 487 - has a process id
ok 488 - job is not finished
-- Emit reap in Minion::Job (0)
-- Emit failed in Minion::Job (0)
ok 489 - right state
ok 490 - right result
-- Emit notification in Mojo::Pg::Database (0)
-- Emit enqueue in Minion (0)
-- Emit dequeue in Minion::Worker (0)
-- Emit spawn in Minion::Job (0)
ok 491 - has a process id
ok 492 - job is not finished
-- Emit reset in Mojo::IOLoop (0)
-- Emit start in Minion::Job (0)

[kraih]

Btw. I just ran the tests on macOS without problems in a perlbrew environment.

[briandfoy]

Which Postgresql installation do you have and were you connecting to a remote machine? Maybe I should be using a different Postgres binary source.

I'm going to compile postgres from source and try everything again.

[kraih]

Local, Postgres.app 12.

[briandfoy]

I compiled Postgres 12.2 myself and recompiled DBD::Pg against it. No problems. Like, something I should have tried a week ago.

Thanks for paying attention though. This isn't a problem for me now, but if someone runs into the same situation, at least they can read this. I still learned a lot about Minion by going through the process, so it wasn't a total waste for me.