diff --git a/adapter_initialise.go b/adapter_initialise.go index 78f352a..4c14ed2 100644 --- a/adapter_initialise.go +++ b/adapter_initialise.go @@ -4,6 +4,7 @@ import ( "context" "errors" "fmt" + "github.com/shimmeringbee/logwrap" "github.com/shimmeringbee/retry" "github.com/shimmeringbee/zigbee" "golang.org/x/sync/semaphore" @@ -137,21 +138,27 @@ func (z *ZStack) configureNetwork(ctx context.Context, version Version) error { if err := retryFunctions(ctx, []func(context.Context) error{ func(invokeCtx context.Context) error { + z.logger.LogDebug(ctx, "Adapater Initialisation: Enabling preconfigured keys.") return z.writeNVRAM(invokeCtx, ZCDNVPreCfgKeysEnable{Enabled: 1}) }, func(invokeCtx context.Context) error { + z.logger.LogDebug(ctx, "Adapater Initialisation: Configuring network key.") return z.writeNVRAM(invokeCtx, ZCDNVPreCfgKey{NetworkKey: z.NetworkProperties.NetworkKey}) }, func(invokeCtx context.Context) error { + z.logger.LogDebug(ctx, "Adapater Initialisation: Enable ZDO callbacks.") return z.writeNVRAM(invokeCtx, ZCDNVZDODirectCB{Enabled: 1}) }, func(invokeCtx context.Context) error { + z.logger.LogDebug(ctx, "Adapater Initialisation: Configuring network channel.") return z.writeNVRAM(invokeCtx, ZCDNVChanList{Channels: channelBits}) }, func(invokeCtx context.Context) error { + z.logger.LogDebug(ctx, "Adapater Initialisation: Configuring network PANID.") return z.writeNVRAM(invokeCtx, ZCDNVPANID{PANID: z.NetworkProperties.PANID}) }, func(invokeCtx context.Context) error { + z.logger.LogDebug(ctx, "Adapater Initialisation: Configuring network extended PANID.") return z.writeNVRAM(invokeCtx, ZCDNVExtPANID{ExtendedPANID: z.NetworkProperties.ExtendedPANID}) }, }); err != nil { @@ -159,12 +166,15 @@ func (z *ZStack) configureNetwork(ctx context.Context, version Version) error { } if !version.IsV3() { + z.logger.LogDebug(ctx, "Adapater Initialisation: Not Version 3.X.X.") /* Less than Z-Stack 3.X.X requires the Trust Centre key to be loaded. */ return retryFunctions(ctx, []func(context.Context) error{ func(invokeCtx context.Context) error { + z.logger.LogDebug(ctx, "Adapater Initialisation: Enable default trust center.") return z.writeNVRAM(invokeCtx, ZCDNVUseDefaultTCLK{Enabled: 1}) }, func(invokeCtx context.Context) error { + z.logger.LogDebug(ctx, "Adapater Initialisation: Configuring ZLL trust center key.") return z.writeNVRAM(invokeCtx, ZCDNVTCLKTableStart{ Address: zigbee.IEEEAddress(0xffffffffffffffff), NetworkKey: zigbee.TCLinkKey, @@ -175,26 +185,32 @@ func (z *ZStack) configureNetwork(ctx context.Context, version Version) error { }) } else { /* Z-Stack 3.X.X requires configuration of Base Device Behaviour. */ + z.logger.LogDebug(ctx, "Adapater Initialisation: Version 3.X.X.") if err := retryFunctions(ctx, []func(context.Context) error{ func(invokeCtx context.Context) error { + z.logger.LogDebug(ctx, "Adapater Initialisation: Configure primary channel.") return z.requestResponder.RequestResponse(ctx, APPCNFBDBSetChannelRequest{IsPrimary: true, Channel: channelBits}, &APPCNFBDBSetChannelRequestReply{}) }, func(invokeCtx context.Context) error { + z.logger.LogDebug(ctx, "Adapater Initialisation: Configure secondary channels.") return z.requestResponder.RequestResponse(ctx, APPCNFBDBSetChannelRequest{IsPrimary: false, Channel: [4]byte{}}, &APPCNFBDBSetChannelRequestReply{}) }, func(invokeCtx context.Context) error { + z.logger.LogDebug(ctx, "Adapater Initialisation: Request commissioning.") return z.requestResponder.RequestResponse(ctx, APPCNFBDBStartCommissioningRequest{Mode: 0x04}, &APPCNFBDBStartCommissioningRequestReply{}) }, }); err != nil { return err } + z.logger.LogDebug(ctx, "Adapater Initialisation: Waiting for coordinator to start.") if err := z.waitForCoordinatorStart(ctx); err != nil { return err } return retryFunctions(ctx, []func(context.Context) error{ func(invokeCtx context.Context) error { + z.logger.LogDebug(ctx, "Adapater Initialisation: Waiting for commissioning to complete.") return z.requestResponder.RequestResponse(ctx, APPCNFBDBStartCommissioningRequest{Mode: 0x02}, &APPCNFBDBStartCommissioningRequestReply{}) }, }) @@ -238,7 +254,7 @@ func (z *ZStack) startZigbeeStack(ctx context.Context, version Version) error { err, cancel := z.subscriber.Subscribe(&ZDOStateChangeInd{}, func(v interface{}) { stateChange := v.(*ZDOStateChangeInd) - + z.logger.LogDebug(ctx, "Waiting for zigbee stack to start, state change.", logwrap.Datum("State", stateChange.State), logwrap.Datum("DesiredState", DeviceZBCoordinator)) if stateChange.State == DeviceZBCoordinator { ch <- true } @@ -263,6 +279,7 @@ func (z *ZStack) waitForCoordinatorStart(ctx context.Context) error { err, cancel := z.subscriber.Subscribe(&ZDOStateChangeInd{}, func(v interface{}) { stateChange := v.(*ZDOStateChangeInd) + z.logger.LogDebug(ctx, "Waiting for coordinator start, state change.", logwrap.Datum("State", stateChange.State), logwrap.Datum("DesiredState", DeviceZBCoordinator)) if stateChange.State == DeviceZBCoordinator { ch <- true }