2020-04-03 23:16:07

by Steve Brown

[permalink] [raw]
Subject: mesh: test/test-mesh fails to provision node

test/test-mesh can no longer provision a node.

mesh-cfgclient correctly provisions the same node.

In poking around with d-feet, the interface
org.freedesktop.DBus.Properties isn't created by test/test-mesh, but is
by mesh-cfgclient.

Steve

================

test/test-mesh fails with:

create
Creating with UUID 0e04050a0b090d0c0108060f0a020307
Created mesh network with token bb0f18f8901f3587
Attach mesh node to bluetooth-meshd daemon
Mesh app registered: /org/bluez/mesh/node0e04050a0b090d0c0108060f0a020307
scan
Scanning...
Scan procedure started
ScanResult >> RSSI: -34 UUID: acda451feca3903e4560f6a3a25a437a OOB Data: 0000
uuid
Enter 32-digit hex remote UUID:
acda451feca3903e4560f6a3a25a437a
add
Adding dev UUID acda451feca3903e4560f6a3a25a437a
AddNode procedure failed org.bluez.mesh.Error.Failed: Failed to start provisioning initiator

=====================================

syslog:

Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: mesh/manager.c:add_node_call() AddNode request
Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: mesh/manager.c:scan_cancel() scan_cancel
Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: Agent failed (org.freedesktop.DBus.Error.UnknownMethod), Traceback (most recent call last):
Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: File "/usr/lib/python3/dist-packages/dbus/service.py", line 658, in _message_cb
Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: (candidate_method, parent_method) = _method_lookup(self, method_name, interface_name)
Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: File "/usr/lib/python3/dist-packages/dbus/service.py", line 248, in _method_lookup
Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: raise UnknownMethodException('%s is not a valid method of interface %s' % (method_name, dbus_interface))
Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: dbus.exceptions.UnknownMethodException: org.freedesktop.DBus.Error.UnknownMethod: Unknown method: GetAll is not a valid method of interface org.

=============================================

dbus-monitor log:

method call time=1585918004.102388 sender=:1.409 -> destination=:1.301 serial=14 path=/org/bluez/mesh/node0a060d08020f03050b090c0a07010e04; interface=org.bluez.mesh.Management1; member=AddNode
array of bytes [
ac da 45 1f ec a3 90 3e 45 60 f6 a3 a2 5a 43 7a
]
array [
]
method call time=1585918004.104726 sender=:1.301 -> destination=:1.409 serial=307 path=/mesh/test/agent; interface=org.freedesktop.DBus.Properties; member=GetAll
string "org.bluez.mesh.ProvisionAgent1"
error time=1585918004.110353 sender=:1.409 -> destination=:1.301 error_name=org.freedesktop.DBus.Error.UnknownMethod reply_serial=307
string "Traceback (most recent call last):
File "/usr/lib/python3/dist-packages/dbus/service.py", line 658, in _message_cb
(candidate_method, parent_method) = _method_lookup(self, method_name, interface_name)
File "/usr/lib/python3/dist-packages/dbus/service.py", line 248, in _method_lookup
raise UnknownMethodException('%s is not a valid method of interface %s' % (method_name, dbus_interface))
dbus.exceptions.UnknownMethodException: org.freedesktop.DBus.Error.UnknownMethod: Unknown method: GetAll is not a valid method of interface org.freedesktop.DBus.Properties
"
error time=1585918004.112011 sender=:1.301 -> destination=:1.409 error_name=org.bluez.mesh.Error.Failed reply_serial=14
string "Failed to start provisioning initiator"


signal time=1585918441.305863 sender=:1.2 -> destination=(null destination) serial=176 path=/org/freedesktop/timesync1; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
string "org.freedesktop.timesync1.Manager"
array [
dict entry(



2020-04-03 23:31:21

by Gix, Brian

[permalink] [raw]
Subject: Re: mesh: test/test-mesh fails to provision node

Thanks Steve,

On Fri, 2020-04-03 at 19:05 -0400, Steve Brown wrote:
> test/test-mesh can no longer provision a node.
>
> mesh-cfgclient correctly provisions the same node.
>
> In poking around with d-feet, the interface
> org.freedesktop.DBus.Properties isn't created by test/test-mesh, but is
> by mesh-cfgclient.
>

Yeah, we now require anyone doing AddNode() to provide Provisioning Initiator agent
"Capabilities" Property. I need to enlist someone a bit more Python adept to add
that property to the test-mesh org.bluez.mesh.ProvisionAgent1 interface.


> Steve
>
> ================
>
> test/test-mesh fails with:
>
> create
> Creating with UUID 0e04050a0b090d0c0108060f0a020307
> Created mesh network with token bb0f18f8901f3587
> Attach mesh node to bluetooth-meshd daemon
> Mesh app registered: /org/bluez/mesh/node0e04050a0b090d0c0108060f0a020307
> scan
> Scanning...
> Scan procedure started
> ScanResult >> RSSI: -34 UUID: acda451feca3903e4560f6a3a25a437a OOB Data: 0000
> uuid
> Enter 32-digit hex remote UUID:
> acda451feca3903e4560f6a3a25a437a
> add
> Adding dev UUID acda451feca3903e4560f6a3a25a437a
> AddNode procedure failed org.bluez.mesh.Error.Failed: Failed to start provisioning initiator
>
> =====================================
>
> syslog:
>
> Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: mesh/manager.c:add_node_call() AddNode request
> Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: mesh/manager.c:scan_cancel() scan_cancel
> Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: Agent failed (org.freedesktop.DBus.Error.UnknownMethod),
> Traceback (most recent call last):
> Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: File "/usr/lib/python3/dist-packages/dbus/service.py", line
> 658, in _message_cb
> Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: (candidate_method, parent_method) = _method_lookup(self,
> method_name, interface_name)
> Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: File "/usr/lib/python3/dist-packages/dbus/service.py", line
> 248, in _method_lookup
> Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: raise UnknownMethodException('%s is not a valid method of
> interface %s' % (method_name, dbus_interface))
> Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: dbus.exceptions.UnknownMethodException:
> org.freedesktop.DBus.Error.UnknownMethod: Unknown method: GetAll is not a valid method of interface org.
>
> =============================================
>
> dbus-monitor log:
>
> method call time=1585918004.102388 sender=:1.409 -> destination=:1.301 serial=14
> path=/org/bluez/mesh/node0a060d08020f03050b090c0a07010e04; interface=org.bluez.mesh.Management1;
> member=AddNode
> array of bytes [
> ac da 45 1f ec a3 90 3e 45 60 f6 a3 a2 5a 43 7a
> ]
> array [
> ]
> method call time=1585918004.104726 sender=:1.301 -> destination=:1.409 serial=307 path=/mesh/test/agent;
> interface=org.freedesktop.DBus.Properties; member=GetAll
> string "org.bluez.mesh.ProvisionAgent1"
> error time=1585918004.110353 sender=:1.409 -> destination=:1.301
> error_name=org.freedesktop.DBus.Error.UnknownMethod reply_serial=307
> string "Traceback (most recent call last):
> File "/usr/lib/python3/dist-packages/dbus/service.py", line 658, in _message_cb
> (candidate_method, parent_method) = _method_lookup(self, method_name, interface_name)
> File "/usr/lib/python3/dist-packages/dbus/service.py", line 248, in _method_lookup
> raise UnknownMethodException('%s is not a valid method of interface %s' % (method_name, dbus_interface))
> dbus.exceptions.UnknownMethodException: org.freedesktop.DBus.Error.UnknownMethod: Unknown method: GetAll is
> not a valid method of interface org.freedesktop.DBus.Properties
> "
> error time=1585918004.112011 sender=:1.301 -> destination=:1.409 error_name=org.bluez.mesh.Error.Failed
> reply_serial=14
> string "Failed to start provisioning initiator"
>
>
> signal time=1585918441.305863 sender=:1.2 -> destination=(null destination) serial=176
> path=/org/freedesktop/timesync1; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
> string "org.freedesktop.timesync1.Manager"
> array [
> dict entry(
>
>

2020-04-04 00:32:43

by Gix, Brian

[permalink] [raw]
Subject: Re: mesh: test/test-mesh fails to provision node

On Fri, 2020-04-03 at 23:30 +0000, Gix, Brian wrote:
> Thanks Steve,
>
> On Fri, 2020-04-03 at 19:05 -0400, Steve Brown wrote:
> > test/test-mesh can no longer provision a node.
> >
> > mesh-cfgclient correctly provisions the same node.
> >
> > In poking around with d-feet, the interface
> > org.freedesktop.DBus.Properties isn't created by test/test-mesh, but is
> > by mesh-cfgclient.
> >
>
> Yeah, we now require anyone doing AddNode() to provide Provisioning Initiator agent
> "Capabilities" Property. I need to enlist someone a bit more Python adept to add
> that property to the test-mesh org.bluez.mesh.ProvisionAgent1 interface.

test-mesh was never intended to be more than a simple example demonstrating dbus API usage of the daemon with
Python. It was our first daemon "Client App", most of whose usefulness is superceded by tools/mesh-cfgclient.

It is still useful as a "Simple Node" app that implements On/Off Client and server, but it has never had the
ability to be a full fledged Configuration Client, without which Provision Initiator role doesn't make any
sense.

So we are inclined to remove the "add" and "create" commands altogether, while pointing people to mesh-
cfgclient for that functionality.

Because even when "add" and "create" *did* work, they only *sorta* worked.... and left behind unusable
unconfigured nodes.


>
>
> > Steve
> >
> > ================
> >
> > test/test-mesh fails with:
> >
> > create
> > Creating with UUID 0e04050a0b090d0c0108060f0a020307
> > Created mesh network with token bb0f18f8901f3587
> > Attach mesh node to bluetooth-meshd daemon
> > Mesh app registered: /org/bluez/mesh/node0e04050a0b090d0c0108060f0a020307
> > scan
> > Scanning...
> > Scan procedure started
> > ScanResult >> RSSI: -34 UUID: acda451feca3903e4560f6a3a25a437a OOB Data: 0000
> > uuid
> > Enter 32-digit hex remote UUID:
> > acda451feca3903e4560f6a3a25a437a
> > add
> > Adding dev UUID acda451feca3903e4560f6a3a25a437a
> > AddNode procedure failed org.bluez.mesh.Error.Failed: Failed to start provisioning initiator
> >
> > =====================================
> >
> > syslog:
> >
> > Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: mesh/manager.c:add_node_call() AddNode request
> > Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: mesh/manager.c:scan_cancel() scan_cancel
> > Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: Agent failed (org.freedesktop.DBus.Error.UnknownMethod),
> > Traceback (most recent call last):
> > Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: File "/usr/lib/python3/dist-packages/dbus/service.py", line
> > 658, in _message_cb
> > Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: (candidate_method, parent_method) = _method_lookup(self,
> > method_name, interface_name)
> > Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: File "/usr/lib/python3/dist-packages/dbus/service.py", line
> > 248, in _method_lookup
> > Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: raise UnknownMethodException('%s is not a valid method of
> > interface %s' % (method_name, dbus_interface))
> > Apr 3 18:41:10 mesh0 bluetooth-meshd[6648]: dbus.exceptions.UnknownMethodException:
> > org.freedesktop.DBus.Error.UnknownMethod: Unknown method: GetAll is not a valid method of interface org.
> >
> > =============================================
> >
> > dbus-monitor log:
> >
> > method call time=1585918004.102388 sender=:1.409 -> destination=:1.301 serial=14
> > path=/org/bluez/mesh/node0a060d08020f03050b090c0a07010e04; interface=org.bluez.mesh.Management1;
> > member=AddNode
> > array of bytes [
> > ac da 45 1f ec a3 90 3e 45 60 f6 a3 a2 5a 43 7a
> > ]
> > array [
> > ]
> > method call time=1585918004.104726 sender=:1.301 -> destination=:1.409 serial=307 path=/mesh/test/agent;
> > interface=org.freedesktop.DBus.Properties; member=GetAll
> > string "org.bluez.mesh.ProvisionAgent1"
> > error time=1585918004.110353 sender=:1.409 -> destination=:1.301
> > error_name=org.freedesktop.DBus.Error.UnknownMethod reply_serial=307
> > string "Traceback (most recent call last):
> > File "/usr/lib/python3/dist-packages/dbus/service.py", line 658, in _message_cb
> > (candidate_method, parent_method) = _method_lookup(self, method_name, interface_name)
> > File "/usr/lib/python3/dist-packages/dbus/service.py", line 248, in _method_lookup
> > raise UnknownMethodException('%s is not a valid method of interface %s' % (method_name,
> > dbus_interface))
> > dbus.exceptions.UnknownMethodException: org.freedesktop.DBus.Error.UnknownMethod: Unknown method: GetAll is
> > not a valid method of interface org.freedesktop.DBus.Properties
> > "
> > error time=1585918004.112011 sender=:1.301 -> destination=:1.409 error_name=org.bluez.mesh.Error.Failed
> > reply_serial=14
> > string "Failed to start provisioning initiator"
> >
> >
> > signal time=1585918441.305863 sender=:1.2 -> destination=(null destination) serial=176
> > path=/org/freedesktop/timesync1; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
> > string "org.freedesktop.timesync1.Manager"
> > array [
> > dict entry(
> >
> >