You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
{{ message }}
Repository navigation
On erasing NMOS resources, HTTP DELETE messages are not getting generated #372
While, NMOS shutting down, I'm calling following functions to delete all the nmos resources before exiting:
nmos::erase_resource(model.node_resources, res_id, true); // res_id is of node
model.notify();
While erasing the resources, in Wireshark, I was expecting HTTP DELETE messages going out to Registry and controller(e.g., Riedel). However, I don't see any of these messages in wireshark.
Could you please help, am I missing something in the above code?
2024-02-16 18:49:15 User.Warning 10.110.60.75 Feb 16 13:19:26 10.100.50.2 NMOS[1812]: Unable to lock to current reference source
2024-02-16 18:49:15 Daemon.Info 10.110.60.75 Feb 16 13:19:27 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:27.191: error: 2657059808: Eraced resources count = 62
2024-02-16 18:49:15 Daemon.Info 10.110.60.75 Feb 16 13:19:27 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:27.196: warning: 2673845216: System global configuration is not discoverable
2024-02-16 18:49:15 Daemon.Info 10.110.60.75 Feb 16 13:19:27 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:27.199: warning: 2715808736: Stopped registered operation
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.557: info: 3069259792: Closing connections
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.561: info: 2648667104: Error getting remote endpoint: system:9 (Bad file descriptor)
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.561: warning: 2648667104: WebSocket Connection Unknown - "" - 0 websocketpp:26 Operation canceled
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.561: info: 2648667104: asio async_shutdown error: system:9 (Bad file descriptor)
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.561: info: 2648667104: handle_accept error: Operation canceled
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.561: info: 2648667104: Stopping acceptance of new connections because the underlying transport is no longer listening.
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.572: info: 3069259792: Stopping nmos-cpp node
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 systemd[1]: Stopping Sony Nmos Daemon....
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 systemd[1]: nmos.service: Succeeded.
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 systemd[1]: Stopped Sony Nmos Daemon..
You could see, my log while erasing 62 NMOS resources at second line: 2024-02-16 13:19:27.191:
After about 4s, that is 5th line in the logs, at 2024-02-16 13:19:31.557: we see Closing connections.
I was expecting following logs in the sys-logs which is in the node_behavior thread, with the deregistration logic just after the regular registration logic::
slog::logslog::severities::info(gate, SLOG_FLF) << "Requesting registration deletion for " << id_type;
The HTTP DELETE requests are sent to the registry asynchronously with the call to nmos::erase_resource, by the node behaviour thread.
If you erase the resources from the model after a controlled shutdown is initiated, the node behaviour thread probably already exited, so the requests won't be sent.
If you erase a resource any time before a controlled shutdown, the DELETE requests will be sent. (Obviously you also have to release the model lock for long enough for the node behaviour thread to get the lock.)
Hope that makes sense. If you want to implement the recommended (but not required) controlled unregistration behaviour then erase the resources before calling model.controlled_shutdown() (or destroying the server).
I have created a separate thread named "ShutDownThread" that runs in parallel with the "node_implementation_thread." This thread is responsible for monitoring for shutdown conditions within my application. Upon receiving a shutdown signal, the thread erases the node, subsequently erasing all its child resources. After the erasure is complete, it calls the model.controlled_shutdown() function.
To ensure data integrity during this process, I have implemented a write lock using auto write_lock = model.write_lock(); before initiating the erase operation. The lock is then released after the erasure is complete using write_lock.unlock();.
However, despite these steps, HTTP DELETE messages are not being sent as expected.
I would appreciate your assistance in understanding why these messages are not being triggered and troubleshooting any potential issues. Any insights or suggestions you can provide would be greatly helpful.
I think this just still doesn't leave a long enough gap for the Node behaviour thread to empty the queue of events to send to the Registry between 3 and 4.
The simplest change to confirm this would be to put a std::this_thread::sleep_for there.
The other approach would be to use a conditional wait on the "grain" containing the queue of events to be empty. It's created by the Node behaviour thread itself but you could find it in the model.
Activity
gsbnmos commentedon Feb 17, 2024
Below is the sys-logs captured while exiting:
2024-02-16 18:49:15 User.Warning 10.110.60.75 Feb 16 13:19:26 10.100.50.2 NMOS[1812]: Unable to lock to current reference source
2024-02-16 18:49:15 Daemon.Info 10.110.60.75 Feb 16 13:19:27 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:27.191: error: 2657059808: Eraced resources count = 62
2024-02-16 18:49:15 Daemon.Info 10.110.60.75 Feb 16 13:19:27 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:27.196: warning: 2673845216: System global configuration is not discoverable
2024-02-16 18:49:15 Daemon.Info 10.110.60.75 Feb 16 13:19:27 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:27.199: warning: 2715808736: Stopped registered operation
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.557: info: 3069259792: Closing connections
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.561: info: 2648667104: Error getting remote endpoint: system:9 (Bad file descriptor)
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.561: warning: 2648667104: WebSocket Connection Unknown - "" - 0 websocketpp:26 Operation canceled
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.561: info: 2648667104: asio async_shutdown error: system:9 (Bad file descriptor)
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.561: info: 2648667104: handle_accept error: Operation canceled
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.561: info: 2648667104: Stopping acceptance of new connections because the underlying transport is no longer listening.
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 nmos-cpp-node[6039]: 2024-02-16 13:19:31.572: info: 3069259792: Stopping nmos-cpp node
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 systemd[1]: Stopping Sony Nmos Daemon....
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 systemd[1]: nmos.service: Succeeded.
2024-02-16 18:49:20 Daemon.Info 10.110.60.75 Feb 16 13:19:31 10.100.50.2 systemd[1]: Stopped Sony Nmos Daemon..
You could see, my log while erasing 62 NMOS resources at second line: 2024-02-16 13:19:27.191:
After about 4s, that is 5th line in the logs, at 2024-02-16 13:19:31.557: we see Closing connections.
I was expecting following logs in the sys-logs which is in the node_behavior thread, with the deregistration logic just after the regular registration logic::
slog::logslog::severities::info(gate, SLOG_FLF) << "Requesting registration deletion for " << id_type;
garethsb commentedon Feb 20, 2024
It depends when you erase the resources.
The
HTTP DELETErequests are sent to the registry asynchronously with the call tonmos::erase_resource, by the node behaviour thread.DELETErequests will be sent. (Obviously you also have to release the model lock for long enough for the node behaviour thread to get the lock.)Hope that makes sense. If you want to implement the recommended (but not required) controlled unregistration behaviour then erase the resources before calling
model.controlled_shutdown()(or destroying theserver).suddheerA commentedon Feb 21, 2024
Dear Gareth (@garethsb),
Thank you for your response.
I have created a separate thread named "ShutDownThread" that runs in parallel with the "node_implementation_thread." This thread is responsible for monitoring for shutdown conditions within my application. Upon receiving a shutdown signal, the thread erases the node, subsequently erasing all its child resources. After the erasure is complete, it calls the model.controlled_shutdown() function.
To ensure data integrity during this process, I have implemented a write lock using auto write_lock = model.write_lock(); before initiating the erase operation. The lock is then released after the erasure is complete using write_lock.unlock();.
However, despite these steps, HTTP DELETE messages are not being sent as expected.
I would appreciate your assistance in understanding why these messages are not being triggered and troubleshooting any potential issues. Any insights or suggestions you can provide would be greatly helpful.
Thank you for your time and support.
Sincerely,
garethsb commentedon Feb 21, 2024
I understand you're doing something like this...
I think this just still doesn't leave a long enough gap for the Node behaviour thread to empty the queue of events to send to the Registry between 3 and 4.
The simplest change to confirm this would be to put a
std::this_thread::sleep_forthere.The other approach would be to use a conditional wait on the "grain" containing the queue of events to be empty. It's created by the Node behaviour thread itself but you could find it in the model.
nmos-cpp/Development/nmos/node_behaviour.cpp
Line 126 in 62a9165
gsbnmos commentedon Apr 5, 2024
Hi Garethsb,
Apologies for the delayed reply.
Thanks for the suggestions. This works!
Best regards,