[sysrepo-devel] Appplication/plugin subscription problem

[fabio antonini]

Hi all
I'm facing a trivial problem, but I cannot fix it.
I have run sysrepod, then I run sysrepo-plugin that successfully tries 
to turing-machine.so
here below the extended output

*~ # sysrepo-plugind -d -l4*
[DBG] (sr_log_stderr:146) Setting log level for stderr logs to 4.
[DBG] (main:282) Sysrepo plugin daemon initialization started.
[DBG] (sr_connect:353) Connecting to Sysrepo Engine.
[DBG] (cl_socket_connect:357) Connecting to socket=/tmp/sysrepod.sock
[INF] (sr_connect:405) Connected to daemon Sysrepo Engine at 
socket=/tmp/sysrepod.sock
[DBG] (cl_request_process:401) Sending session-start request.
[DBG] (cl_request_process:423) session-start request sent, waiting for 
response.
[DBG] (cl_request_process:445) session-start response received, processing.
[DBG] (sr_pd_load_plugins:156) Loading plugins from '/etc/sysrepo/plugins'.
[DBG] (sr_pd_load_plugins:170) Loading plugin 'libturing-machine.so'.
[DBG] (cl_sm_init:1252) Client Subscription Manager init started.
[DBG] (cl_sm_event_loop_threaded:1234) Starting client subscription 
event loop.
[DBG] (cl_sm_init:1302) Client Subscription Manager initialized 
successfully.
[DBG] (cl_sm_server_init:1131) Initializing sysrepo subscription server 
at socket=/tmp/sysrepo-subscriptions/turing-machine/4646.XXXXXX.sock
[DBG] (cl_sm_server_ctx_change_cb:1200) Server context changed.
[DBG] (cl_request_process:401) Sending subscribe request.
[DBG] (cl_sm_server_watcher_cb:966) New connection on fd 14
[DBG] (cl_sm_fd_read_data:846) fd 14 readable
[DBG] (cl_sm_conn_buffer_expand:303) Input buffer for fd=14 expanded to 
1024 bytes.
[DBG] (cl_sm_fd_read_data:860) 101 bytes of data received on fd 14
[DBG] (cl_sm_fd_read_data:870) fd 14 would block
[DBG] (cl_sm_conn_in_buff_process:796) New message of size 97 bytes 
received.
[DBG] (cl_sm_notif_process:559) Received a notification for subscription 
id=449446738 (source address='/tmp/sysrepod.sock').
[DBG] (cl_sm_notif_process:627) HELLO notification received on 
subscription id=449446738.
[DBG] (cl_request_process:423) subscribe request sent, waiting for response.
[DBG] (cl_request_process:445) subscribe response received, processing.
[DBG] (cl_request_process:401) Sending subscribe request.
[DBG] (cl_sm_fd_read_data:846) fd 14 readable
[DBG] (cl_sm_fd_read_data:860) 101 bytes of data received on fd 14
[DBG] (cl_sm_fd_read_data:870) fd 14 would block
[DBG] (cl_sm_conn_in_buff_process:796) New message of size 97 bytes 
received.
[DBG] (cl_sm_notif_process:559) Received a notification for subscription 
id=389404451 (source address='/tmp/sysrepod.sock').
[DBG] (cl_sm_notif_process:627) HELLO notification received on 
subscription id=389404451.
[DBG] (cl_request_process:423) subscribe request sent, waiting for response.
[DBG] (cl_request_process:445) subscribe response received, processing.
[DBG] (cl_request_process:401) Sending subscribe request.
[DBG] (cl_sm_fd_read_data:846) fd 14 readable
[DBG] (cl_sm_fd_read_data:860) 101 bytes of data received on fd 14
[DBG] (cl_sm_fd_read_data:870) fd 14 would block
[DBG] (cl_sm_conn_in_buff_process:796) New message of size 97 bytes 
received.
[DBG] (cl_sm_notif_process:559) Received a notification for subscription 
id=911813965 (source address='/tmp/sysrepod.sock').
[DBG] (cl_sm_notif_process:627) HELLO notification received on 
subscription id=911813965.
[DBG] (cl_request_process:423) subscribe request sent, waiting for response.
[DBG] (cl_request_process:445) subscribe response received, processing.
turing-machine plugin initialized successfully
current turing-machine configuration:
[DBG] (cl_request_process:401) Sending get-items request.
[DBG] (cl_request_process:423) get-items request sent, waiting for response.
[DBG] (cl_request_process:445) get-items response received, processing.
*[ERR] (sr_get_items:756) Error by processing of the request.*
[INF] (main:306) Sysrepo plugin daemon initialized successfully.

The plugin seems has been successfully loaded but sr_get_items failed. I 
cannot see any data retrieved from sysrepod.

I have a similar problem when I run appliaction_example (subscribing 
ietf-interfaces).

*~ # application_example*


  ========== READING STARTUP CONFIG: ==========

*Error by sr_get_items: Item not found*

  ========== STARTUP CONFIG APPLIED AS RUNNING ==========


 From sysrepod traces I cannot see any problem. For instance when I run 
application_example I get the following traces from sysrepod output

[DBG] (cm_server_watcher_cb:1146) New client connection on fd 11
[DBG] (sm_connection_start:354) New connection started successfully, 
fd=11, conn ctx=0x449cb8.
[DBG] (cm_conn_read_cb:1019) fd 11 readable
[DBG] (cm_conn_buffer_expand:457) Input buffer for fd=11 expanded to 
1024 bytes.
[DBG] (cm_conn_read_cb:1032) 18 bytes of data received on fd 11
[DBG] (cm_conn_read_cb:1042) fd 11 would block
[DBG] (cm_conn_in_buff_process:971) New message of size 14 bytes received.
[DBG] (cm_session_start_req_process:630) Processing session_start 
request (conn=0x449cb8).
[DBG] (cm_session_start_internal:575) Starting a new session, options=0.
[INF] (sm_session_create:468) New session created successfully, real 
user=root, effective user=(null), session id=1730123485.
[DBG] (sr_cbuff_init:402) Initiating circular buffer for 2 elements.
[DBG] (rp_session_start:1818) RP session start, session id=1730123485.
[DBG] (cm_conn_buffer_expand:457) Output buffer for fd=11 expanded to 
1024 bytes.
[DBG] (cm_conn_out_buff_flush:485) Sending 26 bytes of data.
[DBG] (cm_conn_out_buff_flush:491) 26 bytes of data sent.
[DBG] (cm_conn_read_cb:1019) fd 11 readable
[DBG] (cm_conn_read_cb:1032) 42 bytes of data received on fd 11
[DBG] (cm_conn_read_cb:1042) fd 11 would block
[DBG] (cm_conn_in_buff_process:971) New message of size 38 bytes received.
[DBG] (sr_cbuff_enqueue:461) Circular buffer enqueue to position=1, 
current count=1.
[DBG] (rp_msg_process:1930) Threads: active=0/4, 1 requests in queue
[DBG] (rp_worker_thread_execute:1664) Thread id=2051 signaled.
[DBG] (sr_cbuff_dequeue:477) Circular buffer dequeue, new buffer head=2, 
count=0.
[DBG] (rp_get_items_req_process:378) Processing get_items request.
[INF] (rp_dt_get_values_wrapper:237) Get items request startup 
datastore, xpath: /ietf-interfaces:*//*
[WRN] (ac_check_file_access:132) File 
'/etc/sysrepo/data/ietf-interfaces.startup' cannot be found.
[WRN] (ac_check_module_node_permissions:285) Data file 
'/etc/sysrepo/data/ietf-interfaces.startup' not found, considering as 
authorized.
[DBG] (dm_load_data_tree:564) Data file 
/etc/sysrepo/data/ietf-interfaces.startup does not exist, creating empty 
data tree
[INF] (dm_load_data_tree_file:525) Data file 
/etc/sysrepo/data/ietf-interfaces.startup loaded successfully
[DBG] (dm_get_data_info:1355) Module ietf-interfaces has been loaded
[DBG] (sr_cbuff_enqueue:461) Circular buffer enqueue to position=5, 
current count=1.
[DBG] (rp_worker_thread_execute:1652) Thread id=2051 will wait.
[DBG] (cm_msg_enqueue_cb:1488) New message enqueued into CM message queue.
[DBG] (sr_cbuff_dequeue:477) Circular buffer dequeue, new buffer head=6, 
count=0.
[DBG] (cm_conn_out_buff_flush:485) Sending 21 bytes of data.
[DBG] (cm_conn_out_buff_flush:491) 21 bytes of data sent.
[DBG] (cm_conn_read_cb:1019) fd 11 readable
[DBG] (cm_conn_read_cb:1032) 111 bytes of data received on fd 11
[DBG] (cm_conn_read_cb:1042) fd 11 would block
[DBG] (cm_conn_in_buff_process:971) New message of size 107 bytes received.
[DBG] (sr_cbuff_enqueue:461) Circular buffer enqueue to position=2, 
current count=1.
[DBG] (rp_msg_process:1930) Threads: active=0/4, 1 requests in queue
[DBG] (rp_worker_thread_execute:1664) Thread id=3076 signaled.
[DBG] (sr_cbuff_dequeue:477) Circular buffer dequeue, new buffer head=3, 
count=0.
[DBG] (rp_subscribe_req_process:894) Processing subscribe request.
[DBG] (np_notification_subscribe:395) Notification subscribe: event=3, 
dst_address='/tmp/sysrepo-subscriptions/ietf-interfaces/4738.XXXXXX.sock', 
dst_id=411581119.
[DBG] (sr_locking_set_lock_fd:734) File 
/etc/sysrepo/data/ietf-interfaces.persist has been locked
[DBG] (pm_load_data_tree:180) Persist data successfully loaded from file 
'/etc/sysrepo/data/ietf-interfaces.persist'.
[DBG] (pm_save_data_tree:96) Persist data tree successfully saved.
[DBG] (pm_add_subscription:680) Subscription entry successfully added 
into 'ietf-interfaces' persist data tree.
[DBG] (sr_locking_set_unlock_close_fd:803) File 
/etc/sysrepo/data/ietf-interfaces.persist (fd = 12) has been unlocked
[DBG] (sr_cbuff_enqueue:461) Circular buffer enqueue to position=6, 
current count=1.
[DBG] (np_hello_notify:672) Sending HELLO notification to 
'/tmp/sysrepo-subscriptions/ietf-interfaces/4738.XXXXXX.sock' @ 411581119.
[DBG] (sr_cbuff_enqueue:461) Circular buffer enqueue to position=7, 
current count=2.
[DBG] (rp_worker_thread_execute:1652) Thread id=3076 will wait.
[DBG] (cm_msg_enqueue_cb:1488) New message enqueued into CM message queue.
[DBG] (sr_cbuff_dequeue:477) Circular buffer dequeue, new buffer head=7, 
count=1.
[DBG] (cm_conn_out_buff_flush:485) Sending 21 bytes of data.
[DBG] (cm_conn_out_buff_flush:491) 21 bytes of data sent.
[DBG] (sr_cbuff_dequeue:477) Circular buffer dequeue, new buffer head=8, 
count=0.
[DBG] (cm_out_notif_process:1290) Sending a notification to 
'/tmp/sysrepo-subscriptions/ietf-interfaces/4738.XXXXXX.sock'.
[DBG] (sm_connection_find_dst:574) Cannot find the connection with 
dst_address 
address='/tmp/sysrepo-subscriptions/ietf-interfaces/4738.XXXXXX.sock'.
[DBG] (cm_out_notif_process:1305) Creating a new connection for the 
notification destination 
'/tmp/sysrepo-subscriptions/ietf-interfaces/4738.XXXXXX.sock'
[DBG] (sm_connection_start:354) New connection started successfully, 
fd=12, conn ctx=0x4597b8.
[DBG] (cm_conn_buffer_expand:457) Output buffer for fd=12 expanded to 
1024 bytes.
[DBG] (cm_conn_out_buff_flush:485) Sending 102 bytes of data.
[DBG] (cm_conn_out_buff_flush:491) 102 bytes of data sent.


It sounds as sysrepod replies to the the subscription request but 
something goes wrong and application_example doesn't receive the current 
configuration
What can be the problem?
I'm sorry for this silly question but I must have sysrepo/netopeer2 up 
and running on my target as soon as possible because I have to port my 
freenetconfd plugins in the new world.
Any help will be greatly appreciated
with regards
fabio

-- 
Fabio Antonini (Ph.D)
Tiesse Spa
Via Corradini 80, 67051 Avezzano (Aq)
mobile: +39 3939261941
phone: +39 0863455830
fax: +39 0863455830
f.antonini at tiesse.com
  

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sysrepo.org/archives/sysrepo-devel/attachments/20160711/381410e8/attachment.html>