Hi,
sob., 25 sty 2020 o 01:44 Brian Gix <brian.gix@xxxxxxxxx> napisał(a):
>
> Version 2: Fix path construction code when first reading RPL from NVM
>
>
> An oversight led to losing our Replay Protection List with every
> re-boot. This patch-set makes a number of Replay Protect List
> modifications that culminate in adding rpl.c/h, which stores the latest
> iv_index/sequence values for each node that handles an incoming packet.
>
> The first 4 patches, does some maintenance required to handle RPL
> according the the Mesh Specification.
While testing this patch set I've come across the following problem:
After importing and attaching new node to the daemon I tried to
configure new application key by sending dev key message
ConfigOpcode.APPKEY_ADD to self.
This previously resulted in DevKeyMessageReceived reply.
16:40:24.045 MESHD.stderr INFO 2020-01-27 16:40:24.045
mesh.c:622 attach_call mesh/mesh.c:attach_call()
Attach
16:40:24.045 DBUS.in DEBUG /
org.freedesktop.DBus.ObjectManager::GetManagedObjects()
16:40:24.046 MESHD.stderr INFO 2020-01-27 16:40:24.046
node.c:1311 get_app_properties
mesh/node.c:get_app_properties() path /com/silvair/application
16:40:24.046 MESHD.stderr INFO 2020-01-27 16:40:24.046
node.c:1158 get_element_properties
mesh/node.c:get_element_properties() path
/com/silvair/application/element0
16:40:24.048 MESHD.stderr INFO 2020-01-27 16:40:24.046
node.c:1797 build_element_config
mesh/node.c:build_element_config() Element 0
16:40:24.048 DBUS.out DEBUG /org/bluez/mesh
org.bluez.mesh.Network1::Attach('/', 1141961045074800157) =
('/org/bluez/mesh/node83bf3b46810345a28bcce70d8d0b46d3', [[0, []]])
16:40:24.054 DBUS.out DEBUG
/org/bluez/mesh/node83bf3b46810345a28bcce70d8d0b46d3
org.freedesktop.DBus.Properties::Get('org.bluez.mesh.Node1',
'Addresses') = (<dbus_next.signature.Variant object at
0x7f11eaece150>,)
16:40:24.054 APPLICATION INFO Attached to node
/org/bluez/mesh/node83bf3b46810345a28bcce70d8d0b46d3, address: 05f2,
configuration: {0: {}}
16:40:24.056 MESHD.stderr INFO 2020-01-27 16:40:24.055
keyring.c:209 keyring_put_remote_dev_key
mesh/keyring.c:keyring_put_remote_dev_key() Put Dev Key
/tmp/pytest-of-ragajda/pytest-74/test_rpl_persistence_after_res0/config/83bf3b46810345a28bcce70d8d0b46d3/dev_keys/05f2
16:40:24.057 DBUS.out DEBUG
/org/bluez/mesh/node83bf3b46810345a28bcce70d8d0b46d3
org.bluez.mesh.Management1::ImportRemoteNode(1522, 1,
b'\x9dm\xd0\xe9n\xb2]\xc1\x9a@\xed\x99\x14\xf8\xf0?') = ()
16:40:24.060 APPLICATION.Element0.ConfigClient DEBUG Sending:
/com/silvair/application/element0 -> 05f2 [remote True, net_index 0]
ConfigOpcode.APPKEY_ADD Container(app_key_index=0, net_key_index=0,
app_key=b'c\x96GqsO\xbdv\xe3\xb4\x05\x19\xd1\xd9JH')
16:40:24.060 APPLICATION.Element0.ConfigClient DEBUG Sending:
/com/silvair/application/element0 - > 0001 [remote 1522, net_index 0]
0000000063964771734fbd76e3b40519d1d94a48
16:40:24.063 MESHD.stderr INFO 2020-01-27 16:40:24.062
node.c:1891 dev_key_send_call mesh/node.c:dev_key_send_call()
DevKeySend
16:40:24.064 MESHD.stderr INFO 2020-01-27 16:40:24.063
model.c:604 msg_send mesh/model.c:msg_send() (6fff)
0x7ffffffa9fa0
16:40:24.064 MESHD.stderr INFO 2020-01-27 16:40:24.063
model.c:605 msg_send mesh/model.c:msg_send()
net_idx 0
16:40:24.064 MESHD.stderr INFO 2020-01-27 16:40:24.063
model.c:957 mesh_model_rx mesh/model.c:mesh_model_rx()
iv_index 00000000 key_aid = 00
16:40:24.064 MESHD.stderr INFO 2020-01-27 16:40:24.063
util.c:46 print_packet mesh/util.c:print_packet()
39624.063 Clr Rx: 0000000063964771734fbd76e3b40519d1d94a48
16:40:24.065 MESHD.stderr INFO 2020-01-27 16:40:24.063
model.c:370 forward_model mesh/model.c:forward_model()
model ffff0000 with idx 7fff
16:40:24.065 MESHD.stderr INFO 2020-01-27 16:40:24.063
cfgmod-server.c:783 cfg_srv_pkt
mesh/cfgmod-server.c:cfg_srv_pkt() CONFIG-SRV-opcode 0x0 size 19 idx
000
16:40:24.065 MESHD.stderr INFO 2020-01-27 16:40:24.065
cfgmod-server.c:1036 cfg_srv_pkt
mesh/cfgmod-server.c:cfg_srv_pkt() Add/Update AppKey success: Net_Idx
000, App_Idx 000
16:40:24.065 MESHD.stderr INFO 2020-01-27 16:40:24.065
model.c:604 msg_send mesh/model.c:msg_send() (7fff)
0x5564327d323c
16:40:24.066 MESHD.stderr INFO 2020-01-27 16:40:24.065
model.c:605 msg_send mesh/model.c:msg_send()
net_idx 0
16:40:24.066 MESHD.stderr INFO 2020-01-27 16:40:24.065
model.c:957 mesh_model_rx mesh/model.c:mesh_model_rx()
iv_index 00000000 key_aid = 00
16:40:24.066 MESHD.stderr INFO 2020-01-27 16:40:24.065
util.c:46 print_packet mesh/util.c:print_packet()
39624.065 Clr Rx: 800300000000
16:40:24.066 MESHD.stderr INFO 2020-01-27 16:40:24.065
cfgmod-server.c:783 cfg_srv_pkt
mesh/cfgmod-server.c:cfg_srv_pkt() CONFIG-SRV-opcode 0x8003 size 4 idx
000
16:40:24.067 MESHD.stderr INFO 2020-01-27 16:40:24.065
model.c:871 send_dev_key_msg_rcvd
mesh/model.c:send_dev_key_msg_rcvd() Send "DevKeyMessageReceived"
16:40:24.067 MESHD.stderr INFO 2020-01-27 16:40:24.065
mesh-config-json.c:2111 mesh_config_write_seq_number
mesh/mesh-config-json.c:mesh_config_write_seq_number() Seq Cache: 1 ->
14286
After applying the patch set the same procedure results in:
16:41:04.102 MESHD.stderr INFO mesh/mesh.c:attach_call() Attach
16:41:04.103 DBUS.in DEBUG /
org.freedesktop.DBus.ObjectManager::GetManagedObjects()
16:41:04.103 MESHD.stderr INFO
mesh/node.c:get_app_properties() path /com/silvair/application
16:41:04.104 MESHD.stderr INFO
mesh/node.c:get_element_properties() path
/com/silvair/application/element0
16:41:04.105 MESHD.stderr INFO
mesh/node.c:build_element_config() Element 0
16:41:04.105 DBUS.out DEBUG /org/bluez/mesh
org.bluez.mesh.Network1::Attach('/', 11095264700132944744) =
('/org/bluez/mesh/node83bf3b46810345a28bcce70d8d0b46d3', [[0, []]])
16:41:04.110 DBUS.out DEBUG
/org/bluez/mesh/node83bf3b46810345a28bcce70d8d0b46d3
org.freedesktop.DBus.Properties::Get('org.bluez.mesh.Node1',
'Addresses') = (<dbus_next.signature.Variant object at
0x7f27613a2990>,)
16:41:04.110 APPLICATION INFO Attached to node
/org/bluez/mesh/node83bf3b46810345a28bcce70d8d0b46d3, address: 05f2,
configuration: {0: {}}
16:41:04.111 MESHD.stderr INFO
mesh/keyring.c:keyring_put_remote_dev_key() Put Dev Key
/tmp/pytest-of-ragajda/pytest-75/test_rpl_persistence_after_res0/config/83bf3b46810345a28bcce70d8d0b46d3/dev_keys/05f2
16:41:04.112 DBUS.out DEBUG
/org/bluez/mesh/node83bf3b46810345a28bcce70d8d0b46d3
org.bluez.mesh.Management1::ImportRemoteNode(1522, 1,
b'\x9dm\xd0\xe9n\xb2]\xc1\x9a@\xed\x99\x14\xf8\xf0?') = ()
16:41:04.113 APPLICATION.Element0.ConfigClient DEBUG Sending:
/com/silvair/application/element0 -> 05f2 [remote True, net_index 0]
ConfigOpcode.APPKEY_ADD Container(app_key_index=0, net_key_index=0,
app_key=b'c\x96GqsO\xbdv\xe3\xb4\x05\x19\xd1\xd9JH')
16:41:04.113 APPLICATION.Element0.ConfigClient DEBUG Sending:
/com/silvair/application/element0 - > 0001 [remote 1522, net_index 0]
0000000063964771734fbd76e3b40519d1d94a48
16:41:04.113 MESHD.stderr INFO
mesh/node.c:dev_key_send_call() DevKeySend
16:41:04.114 MESHD.stderr INFO mesh/model.c:msg_send() (6fff)
0x7ffffce69290
16:41:04.114 MESHD.stderr INFO mesh/model.c:msg_send() net_idx 0
16:41:04.114 MESHD.stderr INFO
mesh/mesh-config-json.c:mesh_config_write_seq_number() Seq Cache: 1 ->
25001
16:41:04.114 MESHD.stderr INFO mesh/model.c:mesh_model_rx()
iv_index 00000000 key_aid = 00
16:41:04.115 MESHD.stderr INFO
mesh/net.c:net_msg_in_replay_cache() Test Replay src: 05f2 seq: 000001
iv: 00000000
16:41:04.115 MESHD.stderr INFO
mesh/net.c:net_msg_in_replay_cache() New Entry for 05f2
16:41:04.115 MESHD.stderr INFO mesh/util.c:print_packet()
39664.115 Clr Rx: 0000000063964771734fbd76e3b40519d1d94a48
16:41:04.115 MESHD.stderr INFO mesh/model.c:forward_model()
model ffff0000 with idx 7fff
16:41:04.115 MESHD.stderr INFO
mesh/cfgmod-server.c:cfg_srv_pkt() CONFIG-SRV-opcode 0x0 size 19 idx
000
16:41:04.115 MESHD.stderr INFO
mesh/cfgmod-server.c:cfg_srv_pkt() Add/Update AppKey success: Net_Idx
000, App_Idx 000
16:41:04.115 MESHD.stderr INFO mesh/model.c:msg_send() (7fff)
0x55639ab9c8ec
16:41:04.115 MESHD.stderr INFO mesh/model.c:msg_send() net_idx 0
16:41:04.116 MESHD.stderr INFO mesh/model.c:mesh_model_rx()
iv_index 00000000 key_aid = 00
16:41:04.116 MESHD.stderr INFO
mesh/net.c:net_msg_in_replay_cache() Test Replay src: 05f2 seq: 000001
iv: 00000000
16:41:04.116 MESHD.stderr INFO
mesh/net.c:net_msg_in_replay_cache() Message already processed
(duplicate)
It looks like sequence number is correctly incremented when calling
DevKeySend but it isn't incremented at all when ConfigModel sends the
reply back.
--
Rafał Gajda
Silvair Sp. z o.o.
