Slice index out of range in basicStateManager.ForceSave

[mlafeldt]

One of our logging searches just found this panic:

Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  panic: reflect: slice index out of range [recovered]
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  panic: reflect: slice index out of range [recovered]
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  panic: reflect: slice index out of range
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  goroutine 3846 [running]:
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  panic(0x8e12c0, 0xc8203854d0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/runtime/panic.go:481 +0x3e6
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*encodeState).marshal.func1(0xc820803bd8)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:269 +0x11f
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  panic(0x8e12c0, 0xc8203854c0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/runtime/panic.go:443 +0x4e9
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*encodeState).marshal.func1(0xc820803480)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:269 +0x11f
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  panic(0x8e12c0, 0xc8203854b0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/runtime/panic.go:443 +0x4e9
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  reflect.Value.Index(0x8c7a40, 0xc8205345d8, 0x197, 0x1, 0x0, 0x0, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/reflect/value.go:854 +0x151
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*arrayEncoder).encode(0xc820026250, 0xc8201b2b00, 0x8c7a40, 0xc8205345d8, 0x197, 0x59800)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:690 +0xd2
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*arrayEncoder).(encoding/json.encode)-fm(0xc8201b2b00, 0x8c7a40, 0xc8205345d8, 0x197, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:697 +0x51
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*sliceEncoder).encode(0xc820026258, 0xc8201b2b00, 0x8c7a40, 0xc8205345d8, 0x197, 0x59800)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:667 +0xb0
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*sliceEncoder).(encoding/json.encode)-fm(0xc8201b2b00, 0x8c7a40, 0xc8205345d8, 0x197, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:676 +0x51
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*structEncoder).encode(0xc82040d080, 0xc8201b2b00, 0xa92620, 0xc820534480, 0x199, 0x750f00)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:587 +0x2c4
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*structEncoder).(encoding/json.encode)-fm(0xc8201b2b00, 0xa92620, 0xc820534480, 0x199, 0xc820534400)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:601 +0x51
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*ptrEncoder).encode(0xc8200263b8, 0xc8201b2b00, 0xa665c0, 0xc820497790, 0x196, 0x59200)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:709 +0xea
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*ptrEncoder).(encoding/json.encode)-fm(0xc8201b2b00, 0xa665c0, 0xc820497790, 0x196, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:714 +0x51
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*structEncoder).encode(0xc82040dce0, 0xc8201b2b00, 0xa03a60, 0xc820497770, 0x199, 0x750f00)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:587 +0x2c4
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*structEncoder).(encoding/json.encode)-fm(0xc8201b2b00, 0xa03a60, 0xc820497770, 0x199, 0xc820497700)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:601 +0x51
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*ptrEncoder).encode(0xc820026478, 0xc8201b2b00, 0x9b6260, 0xc820497770, 0x16, 0x59100)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:709 +0xea
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*ptrEncoder).(encoding/json.encode)-fm(0xc8201b2b00, 0x9b6260, 0xc820497770, 0x16, 0xc820376900)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:714 +0x51
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*mapEncoder).encode(0xc820026480, 0xc8201b2b00, 0x8deac0, 0xc82012ded8, 0x95, 0x2f200)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:622 +0x344
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*mapEncoder).(encoding/json.encode)-fm(0xc8201b2b00, 0x8deac0, 0xc82012ded8, 0x95, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:632 +0x51
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*structEncoder).encode(0xc82040ce70, 0xc8201b2b00, 0xa1f6e0, 0xc82012dec0, 0x99, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:587 +0x2c4
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*structEncoder).(encoding/json.encode)-fm(0xc8201b2b00, 0xa1f6e0, 0xc82012dec0, 0x99, 0xc82012de00)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:601 +0x51
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*encodeState).reflectValue(0xc8201b2b00, 0xa1f6e0, 0xc82012dec0, 0x99)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:301 +0x6b
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*encodeState).marshal(0xc8201b2b00, 0xa1f6e0, 0xc82012dec0, 0x0, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:274 +0xa9
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.Marshal(0xa1f6e0, 0xc82012dec0, 0x0, 0x0, 0x0, 0x0, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:139 +0x84
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  github.com/aws/amazon-ecs-agent/agent/engine/dockerstate.(*DockerTaskEngineState).MarshalJSON(0xc8200fd040, 0x0, 0x0, 0x0, 0x0, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /go/src/github.com/aws/amazon-ecs-agent/agent/engine/dockerstate/json.go:43 +0x20d
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  github.com/aws/amazon-ecs-agent/agent/engine.(*DockerTaskEngine).MarshalJSON(0xc8200a87e0, 0x0, 0x0, 0x0, 0x0, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /go/src/github.com/aws/amazon-ecs-agent/agent/engine/docker_task_engine.go:128 +0x42
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.marshalerEncoder(0xc8201b2a50, 0xaa65a0, 0xc8200a87e0, 0x16, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:418 +0x159
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*encodeState).reflectValue(0xc8201b2a50, 0xaa65a0, 0xc8200a87e0, 0x16)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:301 +0x6b
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.interfaceEncoder(0xc8201b2a50, 0x8f03c0, 0xc820156500, 0x194, 0xc820156500)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:560 +0xd8
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*ptrEncoder).encode(0xc820026048, 0xc8201b2a50, 0x8b0c40, 0xc820156500, 0x16, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:709 +0xea
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*ptrEncoder).(encoding/json.encode)-fm(0xc8201b2a50, 0x8b0c40, 0xc820156500, 0x16, 0xc8203bd300)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:714 +0x51
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*mapEncoder).encode(0xc820026050, 0xc8201b2a50, 0x988f40, 0xc820156560, 0x195, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:622 +0x344
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*mapEncoder).(encoding/json.encode)-fm(0xc8201b2a50, 0x988f40, 0xc820156560, 0x195, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:632 +0x51
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*structEncoder).encode(0xc82040cd20, 0xc8201b2a50, 0x9f21c0, 0xc820156560, 0x199, 0xc800000000)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:587 +0x2c4
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*structEncoder).(encoding/json.encode)-fm(0xc8201b2a50, 0x9f21c0, 0xc820156560, 0x199, 0xc820156500)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:601 +0x51
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*ptrEncoder).encode(0xc820026060, 0xc8201b2a50, 0x8b0e80, 0xc820156560, 0x16, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:709 +0xea
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*ptrEncoder).(encoding/json.encode)-fm(0xc8201b2a50, 0x8b0e80, 0xc820156560, 0x16, 0xc820156500)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:714 +0x51
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*encodeState).reflectValue(0xc8201b2a50, 0x8b0e80, 0xc820156560, 0x16)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:301 +0x6b
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.(*encodeState).marshal(0xc8201b2a50, 0x8b0e80, 0xc820156560, 0x0, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:274 +0xa9
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  encoding/json.Marshal(0x8b0e80, 0xc820156560, 0x0, 0x0, 0x0, 0x0, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /usr/local/go/src/encoding/json/encode.go:139 +0x84
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  github.com/aws/amazon-ecs-agent/agent/statemanager.(*basicStateManager).ForceSave(0xc82012e600, 0x0, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /go/src/github.com/aws/amazon-ecs-agent/agent/statemanager/state_manager.go:198 +0x103
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  github.com/aws/amazon-ecs-agent/agent/statemanager.(*basicStateManager).Save(0xc82012e600, 0x0, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /go/src/github.com/aws/amazon-ecs-agent/agent/statemanager/state_manager.go:166 +0xef
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  github.com/aws/amazon-ecs-agent/agent/acs/handler.(*payloadRequestHandler).handleSingleMessage(0xc8202a1b00, 0xc8202eee40, 0x0, 0x0)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /go/src/github.com/aws/amazon-ecs-agent/agent/acs/handler/payload_handler.go:139 +0x336
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  github.com/aws/amazon-ecs-agent/agent/acs/handler.(*payloadRequestHandler).handleMessages(0xc8202a1b00)
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /go/src/github.com/aws/amazon-ecs-agent/agent/acs/handler/payload_handler.go:121 +0xd5
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  created by github.com/aws/amazon-ecs-agent/agent/acs/handler.(*payloadRequestHandler).start
Nov 07 09:47:41 ip-10-8-3-140.eu-west-1.compute.internal ecs-agent:  /go/src/github.com/aws/amazon-ecs-agent/agent/acs/handler/payload_handler.go:81 +0x35

The code in question:

amazon-ecs-agent/agent/statemanager/state_manager.go

Line 198 in aebcbca

data, err := json.Marshal(s)

[richardpen]

@mlafeldt thanks for your reporting, this is the same as #570. We are working on a fix now, please track that issue for the update.