sony / nmos-cpp

An NMOS (Networked Media Open Specifications) Registry and Node in C++ (IS-04, IS-05)
Apache License 2.0
144 stars 80 forks source link

Problems with updating node registrations #19

Open billt-hlit opened 6 years ago

billt-hlit commented 6 years ago

I started using node-cpp-registry instead of the BBC's registry and am running into problems with node reregistrations not working. In short, I get a "409 Conflict" error when I try to update the node's registration.

I'll attach detailed logs of some sample changes I made to the node's main.cpp to demonstrate the problem and the output of both the node and the registry. I didn't have this problem when working against the BBC registry in Wuppertal last month.

Any suggestions? I'm not able to use the BBC registry here because I can't run it on the machine that the node is running on, and can't get the registry to be exposed to the LAN.

billt-hlit commented 6 years ago

I can't get attachments to work, so I'm going to have to paste them into comments. This is the patch I used.


diff --git Development/nmos-cpp-node/main.cpp Development/nmos-cpp-node/main.cpp
index 33cf1f6..85a377c 100644
--- Development/nmos-cpp-node/main.cpp
+++ Development/nmos-cpp-node/main.cpp
@@ -155,6 +155,19 @@ int main(int argc, char* argv[])

         slog::log<slog::severities::info>(gate, SLOG_FLF) << "Ready for connections";

+        sleep(1);
+
+        const auto& seed_id = nmos::experimental::fields::seed_id(node_model.settings);
+        auto node_id = nmos::make_repeatable_id(seed_id, U("/x-nmos/node/self"));
+        web::json::value clock;
+        clock["name"] = web::json::value{"clk0"};
+        clock["ref_type"] = web::json::value{"internal"};
+        nmos::modify_resource(node_model.resources, node_id, [&] (nmos::resource &node)
+        {
+            push_back(node.data["clocks"], clock);
+        });
+        node_condition.notify_all();
+
         // Wait for a process termination signal
         nmos::details::wait_term_signal();```
billt-hlit commented 6 years ago

This is the node's output

$ ./nmos-cpp-node '{"logging_level":-24, "seed_id": "8b2caf6f-5850-509f-8c47-c009ccb8d90d", "hostname": "D13-04284"}' < 1port 
2018-08-03 20:15:41.646: info: 140119400593600: Starting nmos-cpp node
2018-08-03 20:15:41.649: info: 140119400593600: Process ID: 91456
2018-08-03 20:15:41.649: info: 140119400593600: Initial settings: {"host_address":"10.10.138.104","host_addresses":["10.10.138.104","172.31.0.1","172.31.1.1"],"hostname":"D13-04284","logging_level":-24,"seed_id":"8b2caf6f-5850-509f-8c47-c009ccb8d90d"}
2018-08-03 20:15:41.649: info: 140119400593600: Configuring nmos-cpp node with its primary Node API at: 10.10.138.104:3212
2018-08-03 20:15:41.671: info: 140119400593600: Preparing for connections
2018-08-03 20:15:41.677: info: 140119400593600: Ready for connections
*** WARNING *** The program 'nmos-cpp-node' uses the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=nmos-cpp-node>
2018-08-03 20:15:41.682: info: 140118920644352: Registered advertisement for: nmos-cpp_node_10-10-138-104:3212._nmos-node._tcp
2018-08-03 20:15:41.686: info: 140118920644352: Attempting discovery of a Registration API
2018-08-03 20:15:41.686: more info: 140118920644352: DNSServiceBrowse for regtype: _nmos-registration._tcp domain:  on interface: 0
2018-08-03 20:15:41.693: more info: 140118920644352: After DNSServiceBrowse, DNSServiceBrowseReply got service: nmos-cpp_registration_10-10-138-98:3210 for regtype: _nmos-registration._tcp. domain: local. on interface: 4
2018-08-03 20:15:41.695: more info: 140118920644352: DNSServiceResolve for name: nmos-cpp_registration_10-10-138-98:3210 regtype: _nmos-registration._tcp. domain: local. on interface: 4
2018-08-03 20:15:41.698: more info: 140118920644352: After DNSServiceResolve, DNSServiceResolveReply got host: hbv-bld1.local. port: 3210
2018-08-03 20:15:41.700: more info: 140118920644352: After DNSServiceResolve, got 1 address(es) for hostname: hbv-bld1.local.
2018-08-03 20:15:41.700: info: 140118920644352: Discovered 1 Registration API(s)
2018-08-03 20:15:41.700: info: 140118920644352: Attempting initial registration
2018-08-03 20:15:41.701: info: 140118920644352: Registering nmos-cpp node with the Registration API at: 10.10.138.98:3210
2018-08-03 20:15:41.701: info: 140118920644352: Requesting registration creation for node: 85f7cadf-32bb-5c3d-97d4-443daa2d42ae
2018-08-03 20:15:41.843: more info: 140119214388992: Registration created for node: 85f7cadf-32bb-5c3d-97d4-443daa2d42ae
2018-08-03 20:15:41.844: info: 140118920644352: Adopting registered operation
2018-08-03 20:15:41.851: info: 140118920644352: Requesting registration creation for device: 61a50d6e-3af5-5818-bdb2-705a33fbb339
2018-08-03 20:15:41.904: more info: 140118979393280: Registration created for device: 61a50d6e-3af5-5818-bdb2-705a33fbb339
2018-08-03 20:15:41.904: info: 140118920644352: Requesting registration creation for source: 4b80cca8-e029-5562-8ae3-b39ec85f121f
2018-08-03 20:15:42.008: more info: 140118979393280: Registration created for source: 4b80cca8-e029-5562-8ae3-b39ec85f121f
2018-08-03 20:15:42.008: info: 140118920644352: Requesting registration creation for flow: de4486e1-769f-5950-947a-3a28e5e21dff
2018-08-03 20:15:42.081: more info: 140118979393280: Registration created for flow: de4486e1-769f-5950-947a-3a28e5e21dff
2018-08-03 20:15:42.081: info: 140118920644352: Requesting registration creation for sender: b0ec9bcf-d46d-5539-adc5-421bd4757166
2018-08-03 20:15:42.186: more info: 140118979393280: Registration created for sender: b0ec9bcf-d46d-5539-adc5-421bd4757166
2018-08-03 20:15:42.186: info: 140118920644352: Requesting registration creation for receiver: 1e6ee63a-3d30-5788-b0c2-07e97d77e375
2018-08-03 20:15:42.258: more info: 140118979393280: Registration created for receiver: 1e6ee63a-3d30-5788-b0c2-07e97d77e375
2018-08-03 20:15:42.677: info: 140118920644352: Requesting registration update for node: 85f7cadf-32bb-5c3d-97d4-443daa2d42ae
2018-08-03 20:15:42.807: error: 140118979393280: Registration update error: 409 Conflict
2018-08-03 20:15:51.571: info: 140119400593600: Closing connections
2018-08-03 20:15:51.574: info: 140119400593600: Stopping nmos-cpp node
: [xenial]bt@Bill-D13_04284:/root/git/nmos-cpp/Development/build; ./nmos-cpp-node '{"logging_level":-24, "seed_id": "8b2caf6f-5850-509f-8c47-c009ccb8d90d", "hostname": "D13-04284"}' < 1port 
2018-08-03 20:16:21.342: info: 139916453460160: Starting nmos-cpp node
2018-08-03 20:16:21.344: info: 139916453460160: Process ID: 92190
2018-08-03 20:16:21.344: info: 139916453460160: Initial settings: {"host_address":"10.10.138.104","host_addresses":["10.10.138.104","172.31.0.1","172.31.1.1"],"hostname":"D13-04284","logging_level":-24,"seed_id":"8b2caf6f-5850-509f-8c47-c009ccb8d90d"}
2018-08-03 20:16:21.344: info: 139916453460160: Configuring nmos-cpp node with its primary Node API at: 10.10.138.104:3212
2018-08-03 20:16:21.364: info: 139916453460160: Preparing for connections
2018-08-03 20:16:21.372: info: 139916453460160: Ready for connections
*** WARNING *** The program 'nmos-cpp-node' uses the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=nmos-cpp-node>
2018-08-03 20:16:21.376: info: 139915966654208: Registered advertisement for: nmos-cpp_node_10-10-138-104:3212._nmos-node._tcp
2018-08-03 20:16:21.383: info: 139915966654208: Attempting discovery of a Registration API
2018-08-03 20:16:21.385: more info: 139915966654208: DNSServiceBrowse for regtype: _nmos-registration._tcp domain:  on interface: 0
2018-08-03 20:16:21.389: more info: 139915966654208: After DNSServiceBrowse, DNSServiceBrowseReply got service: nmos-cpp_registration_10-10-138-98:3210 for regtype: _nmos-registration._tcp. domain: local. on interface: 4
2018-08-03 20:16:21.391: more info: 139915966654208: DNSServiceResolve for name: nmos-cpp_registration_10-10-138-98:3210 regtype: _nmos-registration._tcp. domain: local. on interface: 4
2018-08-03 20:16:21.396: more info: 139915966654208: After DNSServiceResolve, DNSServiceResolveReply got host: hbv-bld1.local. port: 3210
2018-08-03 20:16:21.399: more info: 139915966654208: After DNSServiceResolve, got 1 address(es) for hostname: hbv-bld1.local.
2018-08-03 20:16:21.399: info: 139915966654208: Discovered 1 Registration API(s)
2018-08-03 20:16:21.399: info: 139915966654208: Attempting initial registration
2018-08-03 20:16:21.400: info: 139915966654208: Registering nmos-cpp node with the Registration API at: 10.10.138.98:3210
2018-08-03 20:16:21.400: info: 139915966654208: Requesting registration creation for node: 85f7cadf-32bb-5c3d-97d4-443daa2d42ae
2018-08-03 20:16:21.542: more info: 139916260398848: Registration created for node: 85f7cadf-32bb-5c3d-97d4-443daa2d42ae
2018-08-03 20:16:21.543: info: 139915966654208: Adopting registered operation
2018-08-03 20:16:21.551: info: 139915966654208: Requesting registration creation for device: 61a50d6e-3af5-5818-bdb2-705a33fbb339
2018-08-03 20:16:21.627: more info: 139916226828032: Registration created for device: 61a50d6e-3af5-5818-bdb2-705a33fbb339
2018-08-03 20:16:21.627: info: 139915966654208: Requesting registration creation for source: 4b80cca8-e029-5562-8ae3-b39ec85f121f
2018-08-03 20:16:21.701: more info: 139916226828032: Registration created for source: 4b80cca8-e029-5562-8ae3-b39ec85f121f
2018-08-03 20:16:21.701: info: 139915966654208: Requesting registration creation for flow: de4486e1-769f-5950-947a-3a28e5e21dff
2018-08-03 20:16:21.824: more info: 139916017010432: Registration created for flow: de4486e1-769f-5950-947a-3a28e5e21dff
2018-08-03 20:16:21.824: info: 139915966654208: Requesting registration creation for sender: b0ec9bcf-d46d-5539-adc5-421bd4757166
2018-08-03 20:16:21.886: more info: 139916017010432: Registration created for sender: b0ec9bcf-d46d-5539-adc5-421bd4757166
2018-08-03 20:16:21.886: info: 139915966654208: Requesting registration creation for receiver: 1e6ee63a-3d30-5788-b0c2-07e97d77e375
2018-08-03 20:16:21.975: more info: 139916017010432: Registration created for receiver: 1e6ee63a-3d30-5788-b0c2-07e97d77e375
2018-08-03 20:16:22.372: info: 139915966654208: Requesting registration update for node: 85f7cadf-32bb-5c3d-97d4-443daa2d42ae
2018-08-03 20:16:22.502: error: 139916360828672: Registration update error: 409 Conflict
billt-hlit commented 6 years ago

This is the registry's output (no command-line options):

2018-08-03 20:16:21.539: info: 139976104589056: Registration requested for node: 85f7cadf-32bb-5c3d-97d4-443daa2d42ae
2018-08-03 20:16:21.540: more info: 139976104589056: At 1533327381:539461510, the registry contains 2 resources (2 nodes, 0 devices, 0 sources, 0 flows, 0 senders, 0 receivers, 0 subscriptions, 0 grains), most recent update: 1533327381:539422214, least health: 1533327381, 0 non-extant resources
2018-08-03 20:16:21.540: more info: 139976087803648: access: Sending response
2018-08-03 20:16:21.550: more info: 139976171730688: access: Sending response
2018-08-03 20:16:21.624: info: 139976272443136: Registration requested for device: 61a50d6e-3af5-5818-bdb2-705a33fbb339 on node: 85f7cadf-32bb-5c3d-97d4-443daa2d42ae
2018-08-03 20:16:21.624: warning: 139976272443136: Registration requested for device: 61a50d6e-3af5-5818-bdb2-705a33fbb339 with unknown sender: b0ec9bcf-d46d-5539-adc5-421bd4757166
2018-08-03 20:16:21.624: warning: 139976272443136: Registration requested for device: 61a50d6e-3af5-5818-bdb2-705a33fbb339 with unknown receiver: 1e6ee63a-3d30-5788-b0c2-07e97d77e375
2018-08-03 20:16:21.625: more info: 139976272443136: At 1533327381:624618850, the registry contains 3 resources (2 nodes, 1 devices, 0 sources, 0 flows, 0 senders, 0 receivers, 0 subscriptions, 0 grains), most recent update: 1533327381:624571391, least health: 1533327381, 0 non-extant resources
2018-08-03 20:16:21.625: more info: 139976196908800: access: Sending response
2018-08-03 20:16:21.699: info: 139976297621248: Registration requested for source: 4b80cca8-e029-5562-8ae3-b39ec85f121f on device: 61a50d6e-3af5-5818-bdb2-705a33fbb339
2018-08-03 20:16:21.699: more info: 139976297621248: At 1533327381:699209380, the registry contains 4 resources (2 nodes, 1 devices, 1 sources, 0 flows, 0 senders, 0 receivers, 0 subscriptions, 0 grains), most recent update: 1533327381:699180629, least health: 1533327381, 0 non-extant resources
2018-08-03 20:16:21.699: more info: 139976331192064: access: Sending response
2018-08-03 20:16:21.822: info: 139976381548288: Registration requested for flow: de4486e1-769f-5950-947a-3a28e5e21dff on source: 4b80cca8-e029-5562-8ae3-b39ec85f121f
2018-08-03 20:16:21.822: more info: 139976381548288: At 1533327381:822335771, the registry contains 5 resources (2 nodes, 1 devices, 1 sources, 1 flows, 0 senders, 0 receivers, 0 subscriptions, 0 grains), most recent update: 1533327381:822300355, least health: 1533327381, 0 non-extant resources
2018-08-03 20:16:21.823: more info: 139976071018240: access: Sending response
2018-08-03 20:16:21.884: info: 139976171730688: Registration requested for sender: b0ec9bcf-d46d-5539-adc5-421bd4757166 on device: 61a50d6e-3af5-5818-bdb2-705a33fbb339
2018-08-03 20:16:21.884: more info: 139976171730688: Registration requested for sender: b0ec9bcf-d46d-5539-adc5-421bd4757166 of flow: de4486e1-769f-5950-947a-3a28e5e21dff
2018-08-03 20:16:21.884: more info: 139976171730688: Registration requested for sender: b0ec9bcf-d46d-5539-adc5-421bd4757166 subscribed to receiver: null
2018-08-03 20:16:21.884: more info: 139976171730688: At 1533327381:884298684, the registry contains 6 resources (2 nodes, 1 devices, 1 sources, 1 flows, 1 senders, 0 receivers, 0 subscriptions, 0 grains), most recent update: 1533327381:884272008, least health: 1533327381, 0 non-extant resources
2018-08-03 20:16:21.885: more info: 139976079410944: access: Sending response
2018-08-03 20:16:21.974: info: 139976213694208: Registration requested for receiver: 1e6ee63a-3d30-5788-b0c2-07e97d77e375 on device: 61a50d6e-3af5-5818-bdb2-705a33fbb339
2018-08-03 20:16:21.974: more info: 139976213694208: Registration requested for receiver: 1e6ee63a-3d30-5788-b0c2-07e97d77e375 subscribed to sender: null
2018-08-03 20:16:21.974: more info: 139976213694208: At 1533327381:974001123, the registry contains 7 resources (2 nodes, 1 devices, 1 sources, 1 flows, 1 senders, 1 receivers, 0 subscriptions, 0 grains), most recent update: 1533327381:973965631, least health: 1533327381, 0 non-extant resources
2018-08-03 20:16:21.974: more info: 139976196908800: access: Sending response
2018-08-03 20:16:22.501: error: 139976364762880: Registration requested for node: 85f7cadf-32bb-5c3d-97d4-443daa2d42ae with invalid version
2018-08-03 20:16:22.501: more info: 139976331192064: access: Sending response
2018-08-03 20:16:25.000: more info: 139976406726400: At 1533327385:114197, the registry contains 7 resources (2 nodes, 1 devices, 1 sources, 1 flows, 1 senders, 1 receivers, 0 subscriptions, 0 grains), most recent update: 1533327381:973965631, least health: 1533327381, 0 non-extant resources
garethsb commented 6 years ago

The key is the "invalid version" error message. When you update any of a resource's properties you also have to update the version property. Something like node.data["version"] = nmos::make_version();

I'll ask @andrewbonney whether he agrees modifying other properties without modifying the version timestamp ought to be picked up by a registry. (Whether this particular semantic error ought to be a plain 400, a 409, or something else, is a conversation we started in Wuppertal but didn't finish.)

billt-hlit commented 6 years ago

OK, I see. Would it make sense for modify_resource to update the version rather than relying on the modifier function to do so?

Thanks.

garethsb commented 6 years ago

Good question. It could be an idea to have that behaviour as a default if the specified modifier function hasn't updated it. (And similar logic in replace_resource; and add one if not specified in insert_resource.)

The difference between the version property and the resource attributes that are already updated automatically is that the version is part of the JSON which isn't currently validated at all at this level, whereas the created/updated timestamps, etc. are not part of the JSON, but are used in the nmos::resources indices. Therefore just needs a bit of thought to decide whether partial validation/modification of the JSON is appropriate/not confusing.