Intermittent crash with "panic: reflect: call of reflect.Value.FieldByName on zero Value"

[twystd]

Hi,

meshtastic-go intermittently crashes with the following panic:

./meshtastic-go --port /dev/cu.usbserial-02036308 prefs set --key GpsUpdateInterval --value 0 
panic: reflect: call of reflect.Value.FieldByName on zero Value

goroutine 1 [running]:
reflect.flag.mustBe(...)
	/usr/local/go/src/reflect/value.go:221
reflect.Value.FieldByName(0x0, 0x0, 0x0, 0x7ffeefbff8ca, 0x11, 0x0, 0x0, 0x0)
	/usr/local/go/src/reflect/value.go:903 +0x25a
github.com/lmatte7/gomesh.(*Radio).SetUserPreferences(0xc00019f8f0, 0x7ffeefbff8ca, 0x11, 0x7ffeefbff8e4, 0x1, 0x0, 0x0)
	/usr/local/var/go/pkg/mod/github.com/lmatte7/gomesh@v0.1.4-0.20210628235629-3dcee19ec7a4/radio.go:738 +0x1e5
main.setPref(0xc000022dc0, 0x0, 0x0)
	..../meshtastic-go/pref.go:18 +0x165
github.com/urfave/cli/v2.(*Command).Run(0xc00014d9e0, 0xc000022b80, 0x0, 0x0)
	/usr/local/var/go/pkg/mod/github.com/urfave/cli/v2@v2.3.0/command.go:163 +0x4dd
github.com/urfave/cli/v2.(*App).RunAsSubcommand(0xc000103520, 0xc000022ac0, 0x0, 0x0)
	/usr/local/var/go/pkg/mod/github.com/urfave/cli/v2@v2.3.0/app.go:434 +0xa49
github.com/urfave/cli/v2.(*Command).startApp(0xc00014d8c0, 0xc000022ac0, 0x7ffeefbff8ba, 0x5)
	/usr/local/var/go/pkg/mod/github.com/urfave/cli/v2@v2.3.0/command.go:278 +0x69b
github.com/urfave/cli/v2.(*Command).Run(0xc00014d8c0, 0xc000022ac0, 0x0, 0x0)
	/usr/local/var/go/pkg/mod/github.com/urfave/cli/v2@v2.3.0/command.go:94 +0x98d
github.com/urfave/cli/v2.(*App).RunContext(0xc000103380, 0x1381418, 0xc0000180e0, 0xc000012090, 0x9, 0x9, 0x0, 0x0)
	/usr/local/var/go/pkg/mod/github.com/urfave/cli/v2@v2.3.0/app.go:313 +0x810
github.com/urfave/cli/v2.(*App).Run(...)
	/usr/local/var/go/pkg/mod/github.com/urfave/cli/v2@v2.3.0/app.go:224
main.Init()
	.../meshtastic-go/cli.go:278 +0x1be5
main.main()
	.../meshtastic-go/main.go:6 +0x25

It's an intermittent fault and little difficult to reliably reproduce - but happens most often when sending commands in rapid'ish succession. The root cause is probably in the meshtastic device code somewhere (it occasionally responds with the incorrect reply) but the immediate cause of the crash is in goMesh::radio.go:

        channelResponses, err := r.ReadResponse()
	if err != nil {
		return pb.AdminMessage{}, err
	}
         var channelPacket []byte
	for _, response := range channelResponses {
		if packet, ok := response.GetPayloadVariant().(*pb.FromRadio_Packet); ok {
			if packet.Packet.GetDecoded().GetPortnum() == pb.PortNum_ADMIN_APP {
				channelPacket = packet.Packet.GetDecoded().GetPayload()
			}
		}
	}

	if err := proto.Unmarshal(channelPacket, &radioPreferences); err != nil {
		return pb.AdminMessage{}, err
	}

If the returned channelResponses do not contain a reply to the request, thenchannelPacket is not initialised with a packet and proto.Unmarshal(...) unmarshals the empty channelPacket without an error as an unexpected nil preferences value in the returned AdminMessage.

[twystd]

Oh, and there's what looks like a related crash in the info command handler:

./meshtastic-go --port /dev/cu.usbserial-0001 info

Radio Preferences:
PositionBroadcastSecs:   panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x28 pc=0x128f88d]

goroutine 1 [running]:
main.printRadioPreferences(0x1380f20, 0xc0000b80f8, 0x0, 0x0, 0x0, 0x0, 0x8)
	.../meshtastic-go/pref.go:54 +0x30d
main.getRadioInfo(0x1380f20, 0xc0000b80f8, 0x0, 0x0, 0x0, 0x13222f1, 0x1381488)
	.../meshtastic-go/info.go:118 +0x427
main.showAllRadioInfo(0xc0000bcc00, 0x0, 0x0)
	.../meshtastic-go/info.go:45 +0xe7
github.com/urfave/cli/v2.(*App).RunAsSubcommand(0xc0000a1380, 0xc0000bca80, 0x0, 0x0)
	/usr/local/var/go/pkg/mod/github.com/urfave/cli/v2@v2.3.0/app.go:439 +0x970
github.com/urfave/cli/v2.(*Command).startApp(0xc0000feea0, 0xc0000bca80, 0x7ffeefbff8fe, 0x4)
	/usr/local/var/go/pkg/mod/github.com/urfave/cli/v2@v2.3.0/command.go:278 +0x69b
github.com/urfave/cli/v2.(*Command).Run(0xc0000feea0, 0xc0000bca80, 0x0, 0x0)
	/usr/local/var/go/pkg/mod/github.com/urfave/cli/v2@v2.3.0/command.go:94 +0x98d
github.com/urfave/cli/v2.(*App).RunContext(0xc0000a11e0, 0x1381418, 0xc0000b4060, 0xc0000bc000, 0x4, 0x4, 0x0, 0x0)
	/usr/local/var/go/pkg/mod/github.com/urfave/cli/v2@v2.3.0/app.go:313 +0x810
github.com/urfave/cli/v2.(*App).Run(...)
	/usr/local/var/go/pkg/mod/github.com/urfave/cli/v2@v2.3.0/app.go:224
main.Init()
	.../meshtastic-go/cli.go:278 +0x1be5
main.main()
	.../meshtastic-go/main.go:6 +0x25

[lmatte7]

Thanks for brining up this bug. I'm still looking into it, but a fix should be published with the next release.

[twystd]

I've done a little more debugging on this and the meshtastic device is occasionally returning either a my_info and/or a ROUTING_APP reply to an AdminPlugin message. Retrying the request in a loop doesn't seem to work particularly well (or actually at all) so it looks like the device FSM is possibly getting stuck in a weird state and recovering after a timeout.