gNMI Set on new "unconnected" device never completes

Describe the bug When a Set() operation is done on an unconnected device that has not previously been created in the system, the Set() hangs

To Reproduce

Use the onit tool to create a new cluster - does not matter if simulators are present

Run the following gNMI Set() command on the system

Use 'onit onos-cli' to get access to the gnmi_cli too on the command line

gnmi_cli -address onos-config:5150 -set \
-proto "update: <path: <target: 'my-td', elem: <name: 'cont1a'> elem: <name: 'cont2a'> elem: <name: 'leaf2a'>> val: <uint_val: 12>> extension: <registered_ext: <id: 100, msg:'update_devicesim-1'>> extension: <registered_ext: <id: 101, msg:'1.0.0'>> extension: <registered_ext: <id: 102, msg:'TestDevice'>>" \
-timeout 5s -alsologtostderr -client_crt /etc/ssl/certs/client1.crt -client_key /etc/ssl/certs/client1.key -ca_crt /etc/ssl/certs/onfca.crt

Expected behavior The Set() should return and the Device Change should be marked as COMPLETE. The system is meant to be able to take new configurations even though there's no device my-td created in the Topology system.

Logs, text or screenshots

I1106 13:47:51.083427       1 set.go:62] gNMI Set Requestupdate:<path:<elem:<name:"cont1a" > elem:<name:"cont2a" > elem:<name:"leaf2a" > target:"my-td" > val:<uint_val:12 > > extension:<registered_ext:<id:100 msg:"update_devicesim-1" > > extension:<registered_ext:<id:101 msg:"1.0.0" > > extension:<registered_ext:<id:102 msg:"TestDevice" > > 
I1106 13:47:51.083559       1 set.go:236] Set called with extensions; 100: update_devicesim-1, 101: , 102: 
I1106 13:47:51.083569       1 set.go:236] Set called with extensions; 100: update_devicesim-1, 101: 1.0.0, 102: 
I1106 13:47:51.083573       1 set.go:236] Set called with extensions; 100: update_devicesim-1, 101: 1.0.0, 102: TestDevice
I1106 13:47:51.085648       1 manager.go:243] Device my-td not found in topo store
I1106 13:47:51.087490       1 set.go:421] Validating change my-td:TestDevice:1.0.0
I1106 13:47:51.089292       1 setconfig.go:66] New Configuration for my-td, with version 1.0.0 and type TestDevice, is Valid according to model TestDevice-1.0.0
I1106 13:47:51.089306       1 set.go:429] Validating change my-td:TestDevice:1.0.0 DONE
I1106 13:47:51.089314       1 set.go:330] Testing /cont1a/cont2a/leaf2a for read only
I1106 13:47:51.089366       1 setconfig.go:108] Appending device change device_id:"my-td" device_version:"1.0.0" device_type:"TestDevice" values:<path:"/cont1a/cont2a/leaf2a" value:<bytes:"\014\000\000\000\000\000\000\000" type:UINT > > 
I1106 13:47:51.096094       1 controller.go:137] Creating DeviceChange network_change:<id:"update_devicesim-1" index:1 > change:<device_id:"my-td" device_version:"1.0.0" device_type:"TestDevice" values:<path:"/cont1a/cont2a/leaf2a" value:<bytes:"\014\000\000\000\000\000\000\000" type:UINT > > > status:<> created:<seconds:-62135596800 > updated:<seconds:-62135596800 > 
I1106 13:47:51.098934       1 set.go:365] Received notification for change ID update_devicesim-1, phase CHANGE, state PENDING
I1106 13:47:51.101388       1 controller.go:105] Running NetworkChange id:"update_devicesim-1" index:1 revision:213 status:<state:RUNNING > created:<seconds:1573048071 nanos:90256603 > updated:<seconds:1573048071 nanos:98241848 > changes:<device_id:"my-td" device_version:"1.0.0" device_type:"TestDevice" values:<path:"/cont1a/cont2a/leaf2a" value:<bytes:"\014\000\000\000\000\000\000\000" type:UINT > > > refs:<device_change_id:"update_devicesim-1:my-td:1.0.0" > 
I1106 13:47:51.102964       1 set.go:365] Received notification for change ID update_devicesim-1, phase CHANGE, state RUNNING
I1106 13:47:51.105759       1 controller.go:236] Running DeviceChange id:"update_devicesim-1:my-td:1.0.0" index:1 revision:177 network_change:<id:"update_devicesim-1" index:1 > change:<device_id:"my-td" device_version:"1.0.0" device_type:"TestDevice" values:<path:"/cont1a/cont2a/leaf2a" value:<bytes:"\014\000\000\000\000\000\000\000" type:UINT > > > status:<state:RUNNING > created:<seconds:1573048071 nanos:96935412 > updated:<seconds:1573048071 nanos:96935412 >

Running the onos CLI in another windows I can see that the Network Change and the Device Change are present, but the Device Change is not complete.

~ $ onos config get network-changes
CHANGE                          INDEX  REVISION  PHASE    STATE     REASON   MESSAGE
update_devicesim-1              1       214      CHANGE   RUNNING   NONE     
    Device: my-td (1.0.0)

~ $ onos config get device-changes my-td
CHANGE                          INDEX  REVISION  PHASE    STATE     REASON   MESSAGE
update_devicesim-1:my-td:1.0.0  1       178      CHANGE   RUNNING   NONE     
    update_devicesim-1  1   my-td   1.0.0
    |/cont1a/cont2a/leaf2a                             |(UINT) 12                               |false  |

~ $

Additional context I would expect translateAndSendChange() and doChange() to be called in the device/controller.go but nothing from its logs show up.

onosproject / onos-config

gNMI Set on new "unconnected" device never completes #866