shimmeringbee / zstack

Implementation of a ZNP and support code designed to interface with Texas Instruments Z-Stack, written in Go.
https://shimmeringbee.io/
Apache License 2.0
27 stars 8 forks source link

Initialize() fails when config is changed (or just generated), but works on second try #21

Closed joonas-fi closed 3 years ago

joonas-fi commented 3 years ago

Given this code:

netCfg, err := zigbee.GenerateNetworkConfiguration()
if err != nil {
    return err
}

if err := zigbeeComms.Initialise(ctx, netCfg); err != nil {
    return err
}

.. Initialize() fails every time.

If I take what GenerateNetworkConfiguration() gives and type it as static config, Initialize() fails for the first time my process runs (when it notices that some config inside the stick doesn't match what I was given), but if I run my process again, it now starts working. So I guess it has something to do with this branch: https://github.com/shimmeringbee/zstack/blob/35282bb53c92a80a38d24212abbb7db8cc738517/adapter_initialise.go#L31

IIRC the error message I got was adapter rejected permit join state change: state ... (sorry I don't have the dynamic part of that error message written down..) from here https://github.com/shimmeringbee/zstack/blob/35282bb53c92a80a38d24212abbb7db8cc738517/joining.go#L33

My hardware/firmware is documented in #20

pwood commented 3 years ago

Issue replicated on a CC2532.

2021/01/13 16:36:41 [INFO] "Shimmering Bee: Controller - Copyright 2019-2020 Shimmering Bee Contributors - Starting..." {}
2021/01/13 16:36:41 [INFO] "Directory enumeration complete." {"directories":{"Config":"C:\\Users\\peter\\AppData\\Roaming\\shimmeringbee\\controller\\config","Data":"C:\\Users\\peter\\AppData\\Roaming\\shimmeringbee\\controller\\data","Log":"C:\\Users\\peter\\AppData\\Roaming\\shimmeringbee\\controller\\log"}}
2021/01/13 16:36:41 [INFO] "Initialising device organiser." {}
2021/01/13 16:36:41 [INFO] "Loaded gateway configurations." {"configCount":1}
2021/01/13 16:36:41 [INFO] "Linking device organiser to mux." {}
2021/01/13 16:36:41 [INFO] "Starting interfaces." {}
2021/01/13 16:36:41 [INFO] "Starting gateways." {}
2021/01/13 16:36:41 [INFO] "Adapter Initialise." {"segment":"start","segmentID":1}
2021/01/13 16:36:41 [INFO] "Restarting adapter." {"segmentID":1}
2021/01/13 16:36:42 [INFO] "Verifying existing network configuration." {"segmentID":1}
2021/01/13 16:36:42 [WARN] "Adapter network configuration is invalid, resetting adapter." {"segmentID":1}
2021/01/13 16:36:43 [INFO] "Setting adapter to coordinator." {"segmentID":1}
2021/01/13 16:36:44 [INFO] "Configuring adapter." {"segmentID":1}
2021/01/13 16:36:44 [INFO] "Starting Zigbee stack." {"segmentID":1}
2021/01/13 16:36:45 [INFO] "Fetching adapter IEEE and Network addresses." {"segmentID":1}
2021/01/13 16:36:45 [INFO] "Enforcing denial of network joins." {"segmentID":1}
2021/01/13 16:36:45 [INFO] "Adapter Initialise." {"segment":"end","segmentID":1}
2021/01/13 16:36:45 [FATAL] "Failed to start gateways." {"err":"failed to start gateway 'cc2531': failed to start zigbee provider: failed to initialise zstack: adapter rejected permit join state change: state=194"}
pwood commented 3 years ago

So interestingly the device does actually start after the initialisation - the lights show the start up pattern of the zigbee application on the device.

It appears that it's not waiting for the application to have started. I suspect this broke when support for the CC26X2R1 was introduced. I'll need to go back and see if I can find where it used to pause on network initalisation.

So when PermitJoin is requested, the application isn't ready yet, hence the return code of 194 (ZNwkInvalidRequest).

joonas-fi commented 3 years ago

Nice work!