bug? seemingly random job abortion

Twice today, I saw a job aborted for no readily apparent reason, and the associated worker failed.

The first occurrence was with v2.3.1 and the second was after upgrading the dogfood cluster to v2.4.0-rc.2.

Here's the data I gathered from the second occurrence:

```
$ brig event get -i 61a4332c-c26e-4fa8-a3a0-4c5bd16cc107

ID PROJECT SOURCE TYPE AGE WORKER PHASE
61a4332c-c26e-4fa8-a3a0-4c5bd16cc107 brigade brigade.sh/github ci:pipeline_requested 1h FAILED

Event "61a4332c-c26e-4fa8-a3a0-4c5bd16cc107" jobs:

NAME STARTED ENDED PHASE
test-unit-js 1h 1h SUCCEEDED
yarn-audit 1h 1h SUCCEEDED
lint-chart 1h 1h SUCCEEDED
validate-examples 1h 1h SUCCEEDED
lint-js PENDING
validate-schemas 1h 1h SUCCEEDED
style-check-js 1h 1h SUCCEEDED
test-unit-go 1h ABORTED
lint-go PENDING
```

Worker logs reveal this:

```
...

2022-03-30T23:54:23.354Z ERROR: Error creating job "test-unit-js": An internal server error occurred.
/var/brigade-worker/worker/dist/prestart.js:204
throw new Error(`error executing node brigade.js:\n\n${e.output}`);
^

...
```

An internal server error by the API server should have been logged, so I looked there next:

```
2022/03/30 23:54:23 error scheduling event "61a4332c-c26e-4fa8-a3a0-4c5bd16cc107" job "test-unit-js" on the substrate: error submitting execution task for event "61a4332c-c26e-4fa8-a3a0-4c5bd16cc107" job "test-unit-js": error sending amqp message for queue "jobs.brigade": unexpected frame: &amqp.performAttach{Name:"mwYiuAiQm58ubLB3bQ77krRjFxXwde2eDQTkYl1RObbAOV6rvi73nw", Handle:0x0, Role:true, SenderSettleMode:(*amqp.SenderSettleMode)(0xc0009a4610), ReceiverSettleMode:(*amqp.ReceiverSettleMode)(0xc0009a4611), Source:(*amqp.source)(nil), Target:(*amqp.target)(0xc00008dd10), Unsettled:amqp.unsettled(nil), IncompleteUnsettled:false, InitialDeliveryCount:0x0, MaxMessageSize:0x0, OfferedCapabilities:amqp.multiSymbol(nil), DesiredCapabilities:amqp.multiSymbol(nil), Properties:map[amqp.symbol]interface {}(nil)}
2022/03/30 23:54:23 error scheduling event "61a4332c-c26e-4fa8-a3a0-4c5bd16cc107" job "validate-schemas" on the substrate: error submitting execution task for event "61a4332c-c26e-4fa8-a3a0-4c5bd16cc107" job "validate-schemas": error sending amqp message for queue "jobs.brigade": unexpected frame: &amqp.performAttach{Name:"mwYiuAiQm58ubLB3bQ77krRjFxXwde2eDQTkYl1RObbAOV6rvi73nw", Handle:0x0, Role:true, SenderSettleMode:(*amqp.SenderSettleMode)(0xc0009a4610), ReceiverSettleMode:(*amqp.ReceiverSettleMode)(0xc0009a4611), Source:(*amqp.source)(nil), Target:(*amqp.target)(0xc00008dd10), Unsettled:amqp.unsettled(nil), IncompleteUnsettled:false, InitialDeliveryCount:0x0, MaxMessageSize:0x0, OfferedCapabilities:amqp.multiSymbol(nil), DesiredCapabilities:amqp.multiSymbol(nil), Properties:map[amqp.symbol]interface {}(nil)}
2022/03/30 23:54:23 error scheduling event "61a4332c-c26e-4fa8-a3a0-4c5bd16cc107" job "test-unit-go" on the substrate: error submitting execution task for event "61a4332c-c26e-4fa8-a3a0-4c5bd16cc107" job "test-unit-go": error sending amqp message for queue "jobs.brigade": unexpected frame: &amqp.performAttach{Name:"mwYiuAiQm58ubLB3bQ77krRjFxXwde2eDQTkYl1RObbAOV6rvi73nw", Handle:0x0, Role:true, SenderSettleMode:(*amqp.SenderSettleMode)(0xc0009a4610), ReceiverSettleMode:(*amqp.ReceiverSettleMode)(0xc0009a4611), Source:(*amqp.source)(nil), Target:(*amqp.target)(0xc00008dd10), Unsettled:amqp.unsettled(nil), IncompleteUnsettled:false, InitialDeliveryCount:0x0, MaxMessageSize:0x0, OfferedCapabilities:amqp.multiSymbol(nil), DesiredCapabilities:amqp.multiSymbol(nil), Properties:map[amqp.symbol]interface {}(nil)}
2022/03/30 23:54:24 http: panic serving 10.240.0.104:39214: runtime error: invalid memory address or nil pointer dereference
goroutine 128736 [running]:
net/http.(*conn).serve.func1()
/usr/local/go/src/net/http/server.go:1825 +0xbf
panic({0x1704b20, 0x2788530})
/usr/local/go/src/runtime/panic.go:844 +0x258
github.com/Azure/go-amqp.(*Sender).Close(0xc000952660?, {0x1c0ea80?, 0xc000114008?})
/go/pkg/mod/github.com/!azure/go-amqp@v0.13.1/client.go:458 +0x1e
github.com/brigadecore/brigade/v2/apiserver/internal/lib/queue/amqp.(*writerFactory).NewWriter.func1()
/src/v2/apiserver/internal/lib/queue/amqp/writer.go:109 +0x79
github.com/brigadecore/brigade-foundations/retries.ManageRetries({0x1c0ea80, 0xc000114000}, {0x191f5b3, 0xd}, 0xa, 0x0?, 0xc0007e00c0)
/go/pkg/mod/github.com/brigadecore/brigade-foundations@v0.3.0/retries/retries.go:50 +0x79
github.com/brigadecore/brigade/v2/apiserver/internal/lib/queue/amqp.(*writerFactory).NewWriter(0xc00008d950, {0xc00059c6d0, 0xc})
/src/v2/apiserver/internal/lib/queue/amqp/writer.go:100 +0x24a
github.com/brigadecore/brigade/v2/apiserver/internal/api/kubernetes.(*substrate).ScheduleJob(_, {_, _}, {{{0xc00059c5f6, 0x7}, 0xc0009a8f60}, {0xc000a43fa0, 0x1f}, {{0xc0002e8bd0, 0x2, ...}, ...}, ...}, ...)
/src/v2/apiserver/internal/api/kubernetes/substrate.go:569 +0xec
github.com/brigadecore/brigade/v2/apiserver/internal/api.(*jobsService).Create(0xc00008dea0, {0x1c0eaf0, 0xc0003e9a70}, {0xc00047c7e0, _}, {{0xc000873828, 0x7}, 0xc0009a88d0, {{{{...}, {...}, ...}, ...}, ...}, ...})
/src/v2/apiserver/internal/api/jobs.go:504 +0xeaf
github.com/brigadecore/brigade/v2/apiserver/internal/api/rest.(*JobsEndpoints).create.func1()
/src/v2/apiserver/internal/api/rest/jobs_endpoints.go:76 +0xef
github.com/brigadecore/brigade/v2/apiserver/internal/lib/restmachinery.ServeRequest({{0x1c0e0e8, 0xc0006f2ee0}, 0xc0009e4000, {0x1c0ecb0, 0xc00003a7a0}, {0x16ce580, 0xc00051d040}, 0xc00003ba00, 0xc9})
/src/v2/apiserver/internal/lib/restmachinery/endpoints.go:123 +0xb6
github.com/brigadecore/brigade/v2/apiserver/internal/api/rest.(*JobsEndpoints).create(0xc0000aba80, {0x1c0e0e8, 0xc0006f2ee0}, 0xc0009e4000)
/src/v2/apiserver/internal/api/rest/jobs_endpoints.go:69 +0x194
github.com/brigadecore/brigade/v2/apiserver/internal/api/rest.(*tokenAuthFilter).Decorate.func1({0x1c0e0e8, 0xc0006f2ee0}, 0xc00096ef00)
/src/v2/apiserver/internal/api/rest/token_auth_filter.go:154 +0xa6b
net/http.HandlerFunc.ServeHTTP(0xc00096ed00?, {0x1c0e0e8?, 0xc0006f2ee0?}, 0xb50000c0007cd740?)
/usr/local/go/src/net/http/server.go:2084 +0x2f
github.com/gorilla/mux.(*Router).ServeHTTP(0xc0000c5200, {0x1c0e0e8, 0xc0006f2ee0}, 0xc00096ec00)
/go/pkg/mod/github.com/gorilla/mux@v1.8.0/mux.go:210 +0x1cf
github.com/rs/cors.(*Cors).Handler.func1({0x1c0e0e8, 0xc0006f2ee0}, 0xc00096ec00)
/go/pkg/mod/github.com/rs/cors@v1.7.0/cors.go:219 +0x1bd
net/http.HandlerFunc.ServeHTTP(0x40d687?, {0x1c0e0e8?, 0xc0006f2ee0?}, 0x4f1001?)
/usr/local/go/src/net/http/server.go:2084 +0x2f
github.com/brigadecore/brigade/v2/apiserver/internal/lib/restmachinery.(*requestContextFilter).Decorate.func1({0x1c0e0e8, 0xc0006f2ee0}, 0xc00096eb00)
/src/v2/apiserver/internal/lib/restmachinery/request_context_filter.go:38 +0x288
net/http.HandlerFunc.ServeHTTP(0x0?, {0x1c0e0e8?, 0xc0006f2ee0?}, 0x40d325?)
/usr/local/go/src/net/http/server.go:2084 +0x2f
net/http.serverHandler.ServeHTTP({0x1c024f8?}, {0x1c0e0e8, 0xc0006f2ee0}, 0xc00096eb00)
/usr/local/go/src/net/http/server.go:2916 +0x43b
net/http.(*conn).serve(0xc00040c1e0, {0x1c0eaf0, 0xc000263e30})
/usr/local/go/src/net/http/server.go:1966 +0x5d7
created by net/http.(*Server).Serve
/usr/local/go/src/net/http/server.go:3071 +0x4db
2022/03/30 23:54:27 http: panic serving 10.240.0.104:39216: runtime error: invalid memory address or nil pointer dereference
goroutine 128753 [running]:
net/http.(*conn).serve.func1()
/usr/local/go/src/net/http/server.go:1825 +0xbf
panic({0x1704b20, 0x2788530})
/usr/local/go/src/runtime/panic.go:844 +0x258
github.com/Azure/go-amqp.(*Session).Close(0x0, {0x1c0ea80, 0xc000114008})
/go/pkg/mod/github.com/!azure/go-amqp@v0.13.1/client.go:256 +0x30
github.com/brigadecore/brigade/v2/internal/amqp.(*session).Close(0xc0006b4cc0?, {0x1c0ea80?, 0xc000114008?})
/src/v2/internal/amqp/session.go:38 +0x26
github.com/brigadecore/brigade/v2/apiserver/internal/lib/queue/amqp.(*writerFactory).NewWriter.func1()
/src/v2/apiserver/internal/lib/queue/amqp/writer.go:112 +0xbc
github.com/brigadecore/brigade-foundations/retries.ManageRetries({0x1c0ea80, 0xc000114000}, {0x191f5b3, 0xd}, 0xa, 0x0?, 0xc0007440c0)
/go/pkg/mod/github.com/brigadecore/brigade-foundations@v0.3.0/retries/retries.go:50 +0x79
github.com/brigadecore/brigade/v2/apiserver/internal/lib/queue/amqp.(*writerFactory).NewWriter(0xc00008d950, {0xc0009a43c0, 0xc})
/src/v2/apiserver/internal/lib/queue/amqp/writer.go:100 +0x24a
github.com/brigadecore/brigade/v2/apiserver/internal/api/kubernetes.(*substrate).ScheduleJob(_, {_, _}, {{{0xc000109502, 0x7}, 0xc0005a6210}, {0xc000a9c920, 0x1f}, {{0xc0001e7500, 0x2, ...}, ...}, ...}, ...)
/src/v2/apiserver/internal/api/kubernetes/substrate.go:569 +0xec
github.com/brigadecore/brigade/v2/apiserver/internal/api.(*jobsService).Create(0xc00008dea0, {0x1c0eaf0, 0xc00061c210}, {0xc00047c600, _}, {{0xc00052d598, 0x7}, 0xc000a73668, {{{{...}, {...}, ...}, ...}, ...}, ...})
/src/v2/apiserver/internal/api/jobs.go:504 +0xeaf
github.com/brigadecore/brigade/v2/apiserver/internal/api/rest.(*JobsEndpoints).create.func1()
/src/v2/apiserver/internal/api/rest/jobs_endpoints.go:76 +0xef
github.com/brigadecore/brigade/v2/apiserver/internal/lib/restmachinery.ServeRequest({{0x1c0e0e8, 0xc0006f2d20}, 0xc000b17c00, {0x1c0ecb0, 0xc00003a7a0}, {0x16ce580, 0xc000110a90}, 0xc0008edf40, 0xc9})
/src/v2/apiserver/internal/lib/restmachinery/endpoints.go:123 +0xb6
github.com/brigadecore/brigade/v2/apiserver/internal/api/rest.(*JobsEndpoints).create(0xc0000aba80, {0x1c0e0e8, 0xc0006f2d20}, 0xc000b17c00)
/src/v2/apiserver/internal/api/rest/jobs_endpoints.go:69 +0x194
github.com/brigadecore/brigade/v2/apiserver/internal/api/rest.(*tokenAuthFilter).Decorate.func1({0x1c0e0e8, 0xc0006f2d20}, 0xc00096e600)
/src/v2/apiserver/internal/api/rest/token_auth_filter.go:154 +0xa6b
net/http.HandlerFunc.ServeHTTP(0xc00096e500?, {0x1c0e0e8?, 0xc0006f2d20?}, 0x190000c0007cd3c0?)
/usr/local/go/src/net/http/server.go:2084 +0x2f
github.com/gorilla/mux.(*Router).ServeHTTP(0xc0000c5200, {0x1c0e0e8, 0xc0006f2d20}, 0xc00096e400)
/go/pkg/mod/github.com/gorilla/mux@v1.8.0/mux.go:210 +0x1cf
github.com/rs/cors.(*Cors).Handler.func1({0x1c0e0e8, 0xc0006f2d20}, 0xc00096e400)
/go/pkg/mod/github.com/rs/cors@v1.7.0/cors.go:219 +0x1bd
net/http.HandlerFunc.ServeHTTP(0x40d687?, {0x1c0e0e8?, 0xc0006f2d20?}, 0x4f1001?)
/usr/local/go/src/net/http/server.go:2084 +0x2f
github.com/brigadecore/brigade/v2/apiserver/internal/lib/restmachinery.(*requestContextFilter).Decorate.func1({0x1c0e0e8, 0xc0006f2d20}, 0xc00096e300)
/src/v2/apiserver/internal/lib/restmachinery/request_context_filter.go:38 +0x288
net/http.HandlerFunc.ServeHTTP(0x0?, {0x1c0e0e8?, 0xc0006f2d20?}, 0x40d325?)
/usr/local/go/src/net/http/server.go:2084 +0x2f
net/http.serverHandler.ServeHTTP({0x1c024f8?}, {0x1c0e0e8, 0xc0006f2d20}, 0xc00096e300)
/usr/local/go/src/net/http/server.go:2916 +0x43b
net/http.(*conn).serve(0xc00040c320, {0x1c0eaf0, 0xc000263e30})
/usr/local/go/src/net/http/server.go:1966 +0x5d7
created by net/http.(*Server).Serve
/usr/local/go/src/net/http/server.go:3071 +0x4db
```

This has the appearance of the job _failing to be placed on the queue_, for reasons I cannot yet diagnose.

_However_, if I look at the logs for that job, they exist. The job ran. In fact, it executed hundreds of unit tests before it was forcefully terminated. This means the job _did_ make it onto the queue after all... and this explains a lot...

After the worker failed (or so it thought) to create a new job, the worker exited non-zero. The observer recorded this correctly as a worker failure. Eventual worker cleanup forcefully killed the running job, which actually _was_ created.

There's more to investigate here, but the fundamental question is probably one of how we ended up with an error that makes it appear as though the job never made it onto the queue event though it very clearly did.