Bug #23132
closed
arvados-ws crash
Description
This was observed happening in a production cluster running Arvados 3.1.2
Aug 26 13:54:35 server arvados-ws[3449862]: {"ClusterID":"zzzzz","PID":3449862,"RequestID":"req-7018jwqvf9a5vc3ofqnc","level":"info","msg":"request","remoteAddr":"127.0.0.1:48358","reqBytes":0,"reqForwardedFor":"172.25.132.80","reqHost":"ws.zzzzz.example.com","reqMethod":"GET","reqPath":"websocket","reqQuery":"api_token=v2/zzzzz-gj3su-xxxxxxxxx/yyyyuyyyyy","time":"2025-08-26T13:54:35.977205443Z"}
Aug 26 13:54:38 server arvados-ws[3449862]: panic: runtime error: invalid memory address or nil pointer dereference
Aug 26 13:54:38 server arvados-ws[3449862]: [signal SIGSEGV: segmentation violation code=0x1 addr=0xe0 pc=0x2193aa5]
Aug 26 13:54:38 server arvados-ws[3449862]: goroutine 52002435 [running]:
Aug 26 13:54:38 server arvados-ws[3449862]: git.arvados.org/arvados.git/services/ws.(*event).Detail(0xc0013f2780)
Aug 26 13:54:38 server arvados-ws[3449862]: /arvados/services/ws/event.go:67 +0x4e5
Aug 26 13:54:38 server arvados-ws[3449862]: git.arvados.org/arvados.git/services/ws.(*v0subscribe).match(0xc000d94f50, 0xc00093e500, 0xc0013f2780)
Aug 26 13:54:38 server arvados-ws[3449862]: /arvados/services/ws/session_v0.go:263 +0x89
Aug 26 13:54:38 server arvados-ws[3449862]: git.arvados.org/arvados.git/services/ws.(*v0subscribe).sendOldEvents(0xc000d94f50, 0xc00093e500)
Aug 26 13:54:38 server arvados-ws[3449862]: /arvados/services/ws/session_v0.go:241 +0x52b
Aug 26 13:54:38 server arvados-ws[3449862]: git.arvados.org/arvados.git/services/ws.(*v0session).Receive(0xc00093e500, {0xc001c8a000, 0x75, 0x200000})
Aug 26 13:54:38 server arvados-ws[3449862]: /arvados/services/ws/session_v0.go:90 +0x317
Aug 26 13:54:38 server arvados-ws[3449862]: git.arvados.org/arvados.git/services/ws.(*handler).Handle.func2()
Aug 26 13:54:38 server arvados-ws[3449862]: /arvados/services/ws/handler.go:81 +0x227
Aug 26 13:54:38 server arvados-ws[3449862]: created by git.arvados.org/arvados.git/services/ws.(*handler).Handle in goroutine 52002415
Aug 26 13:54:38 server arvados-ws[3449862]: /arvados/services/ws/handler.go:59 +0x345
Aug 26 13:54:38 server systemd[1]: arvados-ws.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Aug 26 13:54:38 server systemd[1]: arvados-ws.service: Failed with result 'exit-code'.
Aug 26 13:54:38 server systemd[1]: arvados-ws.service: Consumed 2d 11h 42min 48.818s CPU time.
<pre>
Updated by Tom Clegg 7 months ago
- Target version changed from Future to Development 2025-09-03
- Assigned To set to Tom Clegg
- Status changed from New to In Progress
23132-ws-error-panic @ 3a037b236abf9f07d6dc384e94e2a6e5e8053e57 -- developer-run-tests: #4863
Fix nil pointer dereference when trying to log "yaml decode failed" on the properties attribute of a log table row.
Also, don't log anything if the properties column is blank. The rest of the arvados-ws code already accommodates logs with empty properties.
Updated by Lucas Di Pentima 7 months ago
The fix LGTM, but I'm wondering if it would be useful to have a test for this?
Updated by Tom Clegg 7 months ago
23132-ws-error-panic @ 94e27383f31cddfb95ce0ac32a78f8439ef2061c -- developer-run-tests: #4864
Add test for blank and invalid properties.
This doesn't actually test that Logger is non-nil when set up by session_v0, but at least it exercises the "yaml decode failed" log.
START: event_test.go:37: eventSuite.TestDetail_Properties
time="2025-08-27T14:08:56.870381647-04:00" level=error msg="yaml decode failed" LogID=1627 error="error unmarshaling JSON: json: cannot unmarshal string into Go value of type map[string]interface {}"
PASS: event_test.go:37: eventSuite.TestDetail_Properties 0.072s
Updated by Tom Clegg 7 months ago
- Status changed from In Progress to Resolved
Applied in changeset arvados|370b70b5aa5fd745c5840dbcd51c6ef4df7097e0.
Updated by