Networker 19.3 clone sessions to datadomain queuing

@MarcosCarraro, I recommend you test a saveset clone manually using the nsrclone command, This will give you a better error or log to go ahead.

@crazyrovThanks! I running manual the command and received follow debug.

180169:nsrclone: Step (1 of 16): NSRCLONE_INIT_PHASE_ONE: nsrclone has been started on host 'networker', with command '/usr/sbin/nsrclone -S a6eeb195-00000006-29236985-60236985-0fd85000-1b9d9556 -s networker.domain.local -b DR_DD6300B01 -J
networker -o -F -D5 '.
02/10/21 08:12:03.577123 ============== nsrcloneconfig parameters ===============================
02/10/21 08:12:03.577172 max_threads_per_client(0) is default value.
02/10/21 08:12:03.577178 max_savesets_per_thread(0) is default value.
02/10/21 08:12:03.577183 max_client_threads(0) is default value.
02/10/21 08:12:03.577188 mmd_reservation_timeout(0) is default value.
02/10/21 08:12:03.577193 disable_vsr(0) is default value.
02/10/21 08:12:03.577200 concurrent_clone_enabled(1) is default value.
02/10/21 08:12:03.577205 ams_enabled(0) is default value.
02/10/21 08:12:03.577210 ams_slice_size_factor(31) is default value.
02/10/21 08:12:03.577216 ams_preferred_slice_count(0) is default value.
02/10/21 08:12:03.577221 ams_min_concurrent_slice_count(1) is default value.
02/10/21 08:12:03.577226 ams_max_concurrent_slice_count(60) is default value.
02/10/21 08:12:03.577230 ams_force_multithreaded_slicecopies(0) is default value.
02/10/21 08:12:03.577236 co_use_ip_if(0) is default value.
02/10/21 08:12:03.577240 ========================================================================
180170:nsrclone: Step (2 of 16): NSRCLONE_INIT_PHASE_TWO: Obtaining nsrclone options.
02/10/21 08:12:03.577258 lg_inet_getaddrinfo(): ENTER
02/10/21 08:12:03.577265 lg_inet_getaddrinfo(): input host=networker
02/10/21 08:12:03.577270 lg_inet_getaddrinfo(): input service=NULL
02/10/21 08:12:03.577277 lg_inet_getaddrinfo(): input hints-flags=0x0002 AI_PASSIVE=0 AI_NUMERICHOST=0 AI_NUMERICSERV=0 AI_CANONNAME=1
02/10/21 08:12:03.577286 lg_inet_getaddrinfo(): pass-through ... calling external libc getaddrinfo() ...
02/10/21 08:12:03.577304 lg_inet_getaddrinfo(): output cannonname = networker
02/10/21 08:12:03.577310 lg_inet_getaddrinfo(): output addr = 192.168.1.140
02/10/21 08:12:03.577315 lg_inet_getaddrinfo(): EXIT rc=0
02/10/21 08:12:03.577320 This Networker environment is configured for IPV6.
02/10/21 08:12:03.577327 lg_inet_getnameinfo(): ENTER
02/10/21 08:12:03.577344 lg_inet_getnameinfo(): input sa=192.168.1.140
02/10/21 08:12:03.577351 lg_inet_getnameinfo(): input host buff=0x3845230 hostlen=1025
02/10/21 08:12:03.577356 lg_inet_getnameinfo(): input service buff=(nil) servicelen=0
02/10/21 08:12:03.577363 lg_inet_getnameinfo(): input flags=0x0008 NI_NAMEREQD=1 NI_NUMERICHOST=0 NI_NUMERICSERV=0 NI_NOFQDN=0
02/10/21 08:12:03.577368 lg_inet_getnameinfo(): pass-through ... calling external libc getnameinfo() ...
02/10/21 08:12:03.577388 lg_inet_getnameinfo(): output host str=networker
02/10/21 08:12:03.577395 lg_inet_getnameinfo(): output service str=null
02/10/21 08:12:03.577400 lg_inet_getnameinfo(): EXIT rc=0
02/10/21 08:12:03.577549 No access to file /usr/sbin/lcmap: No such file or directory
02/10/21 08:12:03.577586 DNS lookup failed for address fe80::250:56ff:fe95:9d1b. Please ensure that the hostname and its aliases are updated in the DNS server
02/10/21 08:12:03.578368 lg_inet_getaddrinfo(): ENTER
02/10/21 08:12:03.578390 lg_inet_getaddrinfo(): input host=networker.domain.local
02/10/21 08:12:03.578395 lg_inet_getaddrinfo(): input service=NULL
02/10/21 08:12:03.578400 lg_inet_getaddrinfo(): input hints-flags=0x0004 AI_PASSIVE=0 AI_NUMERICHOST=1 AI_NUMERICSERV=0 AI_CANONNAME=0
02/10/21 08:12:03.578404 lg_inet_getaddrinfo(): pass-through ... calling external libc getaddrinfo() ...
02/10/21 08:12:03.578409 lg_inet_getaddrinfo(): output cannonname = null
02/10/21 08:12:03.578413 lg_inet_getaddrinfo(): output addr = retval error
02/10/21 08:12:03.578416 lg_inet_getaddrinfo(): EXIT rc=-2
02/10/21 08:12:03.579055 lgto_auth: redirected to networker.domain.local prog 390103 vers 2
02/10/21 08:12:03.580874 lgto_auth for `nsrd' succeeded
02/10/21 08:12:03.583390 lgto_auth for `nsrd' succeeded
180171:nsrclone: Step (3 of 16): NSRCLONE_INIT_PHASE_THREE: Performing Recover P i p e to Save enabled cloning.
02/10/21 08:12:03.586061 lg_inet_getaddrinfo(): ENTER
02/10/21 08:12:03.586076 lg_inet_getaddrinfo(): input host=networker.domain.local
02/10/21 08:12:03.586081 lg_inet_getaddrinfo(): input service=NULL
02/10/21 08:12:03.586087 lg_inet_getaddrinfo(): input hints-flags=0x0000 AI_PASSIVE=0 AI_NUMERICHOST=0 AI_NUMERICSERV=0 AI_CANONNAME=0
02/10/21 08:12:03.586091 lg_inet_getaddrinfo(): pass-through ... calling external libc getaddrinfo() ...
02/10/21 08:12:03.586116 lg_inet_getaddrinfo(): output cannonname = null
02/10/21 08:12:03.586121 lg_inet_getaddrinfo(): output addr = 192.168.1.140
02/10/21 08:12:03.586125 lg_inet_getaddrinfo(): EXIT rc=0
02/10/21 08:12:03.586128 This Networker environment is configured for IPV6.
02/10/21 08:12:03.587011 lgto_auth: redirected to networker.domain.local prog 390103 vers 2
02/10/21 08:12:03.588059 lgto_auth for `nsrjobd' succeeded
02/10/21 08:12:03.588843 Registered session id:1, fd:6, idx:0, ssn_max_pollfd:1, 1(512)
02/10/21 08:12:03.589504 Job ID = 458089.
02/10/21 08:12:03.589573 This is not an action.
02/10/21 08:12:03.589581 Is_action_clone = 0
180173:nsrclone: Step (4 of 16): NSRCLONE_INIT_PHASE_FOUR: Validating the command line arguments.
02/10/21 08:12:03.590727 lgto_auth for `nsrd' succeeded
02/10/21 08:12:03.592366 Destination clone pool 'DR_DD6300B01' has a max parallelism of 0
02/10/21 08:12:03.592787 inserting cache entry for sn networker.domain.local
02/10/21 08:12:03.592795 inserting cache entry for sn networkersn.domain.local
02/10/21 08:12:03.593130 lgto_auth for `nsrmmdbd' succeeded
02/10/21 08:12:03.594377 Calling process_clone_....
180174:nsrclone: Step (5 of 16): NSRCLONE_PROCESSING_PHASE_ONE: Submitting all save sets for Recover P  i  p  e to Save processing.
180184:nsrclone: Step (6 of 16): NSRCLONE_PROCESSING_PHASE_TWO: List of save sets is requested for cloning.
a6eeb195-00000006-29236985-60236985-0fd85000-1b9d9556;
02/10/21 08:12:03.594725 get_ss_list successful after <0> retries
02/10/21 08:12:03.594741 Obtaining the snapshot save set list.
02/10/21 08:12:03.594752 Filtering snapshots from save set list
02/10/21 08:12:03.594760 sslst 0x38a0980, snap (nil)
02/10/21 08:12:03.595444 lgto_auth: redirected to networker.domain.local prog 390103 vers 2
02/10/21 08:12:03.596564 lgto_auth for `nsrd' succeeded
02/10/21 08:12:03.597740 init_clone_backend_jb_monitor(): ENTER02/10/21 08:12:03.597786 Thread 32139240275969 will have a stack size of 8388608.
02/10/21 08:12:03.597798 Thread 32139240275970 will have a stack size of 8388608.
02/10/21 08:12:03.597803 Thread 32139240275971 will have a stack size of 8388608.
02/10/21 08:12:03.597807 Thread 32139240275972 will have a stack size of 8388608.
02/10/21 08:12:03.597811 Thread 32139240275973 will have a stack size of 8388608.
02/10/21 08:12:03.598371 init_clone_parent_job(): ENTER02/10/21 08:12:03.598969 lgto_auth: redirected to networker.domain.local prog 390103 vers 2
02/10/21 08:12:03.600100 lgto_auth for `nsrjobd' succeeded
02/10/21 08:12:03.600859 Registered session id:2, fd:9, idx:1, ssn_max_pollfd:2, 2(512)
02/10/21 08:12:03.601920 init_clone_parent_job(): EXIT180206:nsrclone: Step (7 of 16): NSRCLONE_PROCESSING_PHASE_THREE: Sending the media reservation request for the current save set list.
02/10/21 08:12:03.601951 In group_ssids_per_client_and_retention
02/10/21 08:12:03.602170 get_ss_list successful after <0> retries
02/10/21 08:12:03.602187 Looking for the ssid [690186629] in the original input list
02/10/21 08:12:03.602196 Looking for the ssid long string [a6eeb195-00000006-29236985-60236985-0fd85000-1b9d9556]
02/10/21 08:12:03.602201 Found ssid/cloneid pair : [a6eeb195-00000006-29236985-60236985-0fd85000-1b9d9556]
02/10/21 08:12:03.602211 Thread 32139240275974 will have a stack size of 8388608.
02/10/21 08:12:03.602251 No callback registered on session channel 1 for user-defined message: (message type: 50, request type: 0)
02/10/21 08:12:03.602296 submit_reservations_in_background(): ENTER02/10/21 08:12:03.603289 lgto_auth: redirected to networker.domain.local prog 390103 vers 2
02/10/21 08:12:03.604589 lgto_auth for `nsrd' succeeded
02/10/21 08:12:03.606037 req_id: 297047
02/10/21 08:12:03.606054 session_key: 297048
02/10/21 08:12:03.606059 priority: 1
02/10/21 08:12:03.606064 request_type: REQ_TYPE_CLONE
02/10/21 08:12:03.606068 req_ststus: REQ_NOT_SET
02/10/21 08:12:03.606073 poll_interval: 150
02/10/21 08:12:03.606077 reseved_time: 600
02/10/21 08:12:03.606082 detail: NO_DETAIL
02/10/21 08:12:03.606086 cl_resp_info:
02/10/21 08:12:03.606259 Requested client (networker) with req_status (2)
02/10/21 08:12:03.606264 preprocess client_response has:
02/10/21 08:17:08.725990 last reservation success was at '1612955528', now it is '1612955828'; keep checkng for mmd reservation status for 30 mnts past 'last success' and 'last activity'
116284:nsrclone: Sending cancel broker request 298469
02/10/21 08:17:08.726013 cancel_br_request: mmd request 298469 is being canceled from host networker with reservation key ?
180876:nsrclone: Request 298469 was cancelled.
02/10/21 08:17:08.726395 sleep for 10 secs before retrying mmd request
02/10/21 08:17:13.630939 extend_br_request_timeout: extend reservation timeout for mmd request 297049 on host networker
116283:nsrclone: retrying mmd reservation request!!!
02/10/21 08:17:18.727491 req_id: 0
02/10/21 08:17:18.727520 session_key: 0
02/10/21 08:17:18.727526 priority: 0
02/10/21 08:17:18.727530 request_type: REQ_TYPE_NOT_SET
02/10/21 08:17:18.727542 req_ststus: REQ_NOT_READY
02/10/21 08:17:18.727547 poll_interval: 0
02/10/21 08:17:18.727553 reseved_time: 0
02/10/21 08:17:18.727556 detail: NO_DETAIL
02/10/21 08:17:18.727559 cl_resp_info:
02/10/21 08:17:28.728684 req_id: 298573
02/10/21 08:17:28.728721 session_key: 297048
02/10/21 08:17:28.728727 priority: 1
02/10/21 08:17:28.728731 request_type: REQ_TYPE_CLONE
02/10/21 08:17:28.728734 req_ststus: REQ_REJECTED
02/10/21 08:17:28.728738 poll_interval: 150
02/10/21 08:17:28.728741 reseved_time: 600
02/10/21 08:17:28.728745 detail: NO_DETAIL
02/10/21 08:17:28.728748 cl_resp_info:

------------- THIS EVENT STAY IN LOOP ------------------------------
02/10/21 08:17:28.728754 last reservation success was at '1612955528', now it is '1612955848'; keep checkng for mmd reservation status for 30 mnts past 'last success' and 'last activity'
116284:nsrclone: Sending cancel broker request 298573
02/10/21 08:17:28.728771 cancel_br_request: mmd request 298573 is being canceled from host networker with reservation key ?
180876:nsrclone: Request 298573 was cancelled.
02/10/21 08:17:28.729210 sleep for 10 secs before retrying mmd request
116283:nsrclone: retrying mmd reservation request!!!

199746:nsrclone: No more retries to check status of mmd reservation. Five retries done and then retried for 30 mnts past the 'last success' and 'last activity' without success!
124480:nsrclone: Quitting MMD reservation due to request status = REQ_REJECTED!!!
199803:nsrclone: Sending cancel broker request 305711 because the mmd reservation failed
02/10/21 08:42:09.117878 cancel_br_request: mmd request 305711 is being canceled from host networker with reservation key ?
180876:nsrclone: Request 305711 was cancelled.
114982:nsrclone: NSRCLONE being aborted since broker request for mmd reservation failed with nonretryable error.

02/10/21 08:42:09.118283 LGTHREAD_FAILURE: mmd reservation failure
02/10/21 08:42:09.755081 submit_reservations_in_background(): EXIT180208:nsrclone: Step (8 of 16): NSRCLONE_PROCESSING_PHASE_FOUR: Found the recover storage node 'networker' for source volume '4251731159'.
124479:nsrclone: Failed to reserve one of the mmd. Sending cancel broker request 297049
02/10/21 08:42:11.318052 cancel_br_request: mmd request 297049 is being canceled from host networker with reservation key 14650410646532
180882:nsrclone: Step (9 of 16): NSRCLONE_PROCESSING_PHASE_FIVE: Failed to receive the media multiplexor daemon reservations for both the source volume '4251731159' and destination volume '3306181042'. Removing the reservation ID 297049.
02/10/21 08:42:11.318568 Removing backend monitor reservation 0x7fbc8c019ee0 for volume pair <4251731159, 3306181042>
02/10/21 08:42:11.318590 remove_backend_monitor_mmdreservation: removing volume pair reference
02/10/21 08:42:11.318597 mmdreserv_data_free: req_id: 297049
02/10/21 08:42:11.318602 cancel_br_request: mmd request 297049 is being canceled from host networker with reservation key 14650410646532
No valid input savesets - check CLONE SKIPPED SAVESETS!
RPS CLONE RESULTS
[ORIGINAL REQUESTED SAVESETS]
a6eeb195-00000006-29236985-60236985-0fd85000-1b9d9556;
[CLONE SKIPPED SAVESETS]
690186629/1612933509;
02/10/21 08:42:14.322416 free_clone_backend_jb_monitor(): ENTER142778:nsrclone: NSRCLONE failed for one or more savesets.

02/10/21 08:42:14.323007 alldone(): ENTER
02/10/21 08:42:14.323306 report_job_completion has the following attrlist:
completion severity: 50;
completion status: failed;
saveset id: \
a6eeb195-00000006-29236985-60236985-0fd85000-1b9d9556;
skipped savesets: 690186629/1612933509;
02/10/21 08:42:14.323592 Unregistered session id:1, fd:6, idx:0, ssn_max_pollfd:2, 1(512)
02/10/21 08:42:14.323645 snode_units (nil)
02/10/21 08:42:14.323655 free_snode_units ENTER
02/10/21 08:42:14.323664 free_snode_units EXIT
02/10/21 08:42:14.323707 nsrclone, alldone(): EXIT
02/10/21 08:42:14.323754 Unregistered session id:2, fd:9, idx:1, ssn_max_pollfd:0, 0(512)

We do not see the whole command and your statement "netwroker storage node -> Clone backup from datadomain02 to LTO" does not really make sense.

I think that meanwhile - for whatever reason - too many nsrmmd processes are running in the storage nodes. These are the DDS. One very experienced admin could kill these guys. NW will start them as needed. But I do not recommend that - it is easier to restart NW or the NW server.

Then also make sure that the server option "disable RPS clone" is checked.

Then run a simple clone command for a single save set from the command line:

    nsrclone -S your_ssid -b your_clonepool

This should already do the job, assuming that media for the clone pool is only mounted on a device in DD 2.If the command is wrong NW will tell you.

Good luck.

After find into Knowledge Dell have this KB https://www.dell.com/support/kbdoc/pt-br/000050305/ccr-cloning-to-dr-data-domain-fails-with-mmd-reservation-error-messages-nsrclone-being-aborted-since-broker-request-for-mmd-reservation-failed-with-nonretryable-error corelation this logs.

180876:nsrclone: Request 412984 was cancelled.
114982:nsrclone: NSRCLONE being aborted since broker request for mmd reservation failed with nonretryable error.

02/11/21 09:27:17.755164 LGTHREAD_FAILURE: mmd reservation failure
02/11/21 09:27:18.708899 submit_reservations_in_background(): EXIT180208:nsrclone: Step (8 of 16): NSRCLONE_PROCESSING_PHASE_FOUR: Found the recover storage node 'networker' for source volume '4251731159'.
124479:nsrclone: Failed to reserve one of the mmd. Sending cancel broker request 409411

But the KB have date 20-NOV-2020 and the last release from Networker is 19.4 date 10-NOV-2020, don't have more recent updates for Networker.

Hello @bingo.1 .

"netwroker storage node -> Clone backup from datadomain02 to LTO" because "networker" is a virtual machine and don't have physical connection to LTO, therefore need "networker storage node" is a physical machine and have a connection with LTO.

The uptime and processos is a "normaly", not have a high process.

# ps aux | grep -i nsrmmd | wc -l
28

Command usage on example this thread is:

# /usr/sbin/nsrclone -S a6eeb195-00000006-29236985-60236985-0fd85000-1b9d9556 -s networker.domain.local -b DR_DD6300B01 -J networker -o -F -D5

Return for command:   nsrclone -S 639872682 -b DR_DD6300B01 -D5

180169:nsrclone: Step (1 of 16): NSRCLONE_INIT_PHASE_ONE: nsrclone has been started on host 'networker', with command 'nsrclone -S 639872682 -b DR_DD6300B01 -D5 '.
02/11/21 08:56:52.542017 ============== nsrcloneconfig parameters ===============================
02/11/21 08:56:52.542074 max_threads_per_client(0) is default value.
02/11/21 08:56:52.542083 max_savesets_per_thread(0) is default value.
02/11/21 08:56:52.542090 max_client_threads(0) is default value.
02/11/21 08:56:52.542098 mmd_reservation_timeout(0) is default value.
02/11/21 08:56:52.542110 disable_vsr(0) is default value.
02/11/21 08:56:52.542119 concurrent_clone_enabled(1) is default value.
02/11/21 08:56:52.542127 ams_enabled(0) is default value.
02/11/21 08:56:52.542136 ams_slice_size_factor(31) is default value.
02/11/21 08:56:52.542144 ams_preferred_slice_count(0) is default value.
02/11/21 08:56:52.542154 ams_min_concurrent_slice_count(1) is default value.
02/11/21 08:56:52.542165 ams_max_concurrent_slice_count(60) is default value.
02/11/21 08:56:52.542173 ams_force_multithreaded_slicecopies(0) is default value.
02/11/21 08:56:52.542183 co_use_ip_if(0) is default value.
02/11/21 08:56:52.542195 ========================================================================
180170:nsrclone: Step (2 of 16): NSRCLONE_INIT_PHASE_TWO: Obtaining nsrclone options.
02/11/21 08:56:52.542240 No access to file /usr/sbin/lcmap: No such file or directory
02/11/21 08:56:52.542442 lg_inet_getaddrinfo(): ENTER
02/11/21 08:56:52.542458 lg_inet_getaddrinfo(): input host=networker
02/11/21 08:56:52.542468 lg_inet_getaddrinfo(): input service=NULL
02/11/21 08:56:52.542479 lg_inet_getaddrinfo(): input hints-flags=0x0002 AI_PASSIVE=0 AI_NUMERICHOST=0 AI_NUMERICSERV=0 AI_CANONNAME=1
02/11/21 08:56:52.542489 lg_inet_getaddrinfo(): pass-through ... calling external libc getaddrinfo() ...
02/11/21 08:56:52.542512 lg_inet_getaddrinfo(): output cannonname = networker
02/11/21 08:56:52.542524 lg_inet_getaddrinfo(): output addr = 192.168.1.140
02/11/21 08:56:52.542532 lg_inet_getaddrinfo(): EXIT rc=0
02/11/21 08:56:52.542541 This Networker environment is configured for IPV6.
02/11/21 08:56:52.542552 lg_inet_getnameinfo(): ENTER
02/11/21 08:56:52.542563 lg_inet_getnameinfo(): input sa=192.168.1.140
02/11/21 08:56:52.542574 lg_inet_getnameinfo(): input host buff=0x4460d30 hostlen=1025
02/11/21 08:56:52.542583 lg_inet_getnameinfo(): input service buff=(nil) servicelen=0
02/11/21 08:56:52.542592 lg_inet_getnameinfo(): input flags=0x0008 NI_NAMEREQD=1 NI_NUMERICHOST=0 NI_NUMERICSERV=0 NI_NOFQDN=0
02/11/21 08:56:52.542604 lg_inet_getnameinfo(): pass-through ... calling external libc getnameinfo() ...
02/11/21 08:56:52.542626 lg_inet_getnameinfo(): output host str=networker
02/11/21 08:56:52.542639 lg_inet_getnameinfo(): output service str=null
02/11/21 08:56:52.542649 lg_inet_getnameinfo(): EXIT rc=0
02/11/21 08:56:52.542660 pathlist_set_hostname: host is NULL
02/11/21 08:56:52.542672 pathlist_set_hostname: host is NULL
02/11/21 08:56:52.542682 pathlist_set_hostname: host is NULL
02/11/21 08:56:52.542692 pathlist_set_hostname: host is NULL
02/11/21 08:56:52.542703 pathlist_set_hostname: host is NULL
02/11/21 08:56:52.542715 pathlist_set_hostname: host is NULL
02/11/21 08:56:52.542728 nsr_getserverhost(): returning clus_get_hostname() = networker
02/11/21 08:56:52.543421 lgto_auth: redirected to networker prog 390103 vers 2
02/11/21 08:56:52.544475 lgto_auth for `nsrd' succeeded
02/11/21 08:56:52.546706 lgto_auth for `nsrd' succeeded
180171:nsrclone: Step (3 of 16): NSRCLONE_INIT_PHASE_THREE: Performing Recover P i p e to Save enabled cloning.
02/11/21 08:56:52.549062 lg_inet_getaddrinfo(): ENTER
02/11/21 08:56:52.549084 lg_inet_getaddrinfo(): input host=localhost
02/11/21 08:56:52.549090 lg_inet_getaddrinfo(): input service=NULL
02/11/21 08:56:52.549099 lg_inet_getaddrinfo(): input hints-flags=0x0000 AI_PASSIVE=0 AI_NUMERICHOST=0 AI_NUMERICSERV=0 AI_CANONNAME=0
02/11/21 08:56:52.549104 lg_inet_getaddrinfo(): pass-through ... calling external libc getaddrinfo() ...
02/11/21 08:56:52.549175 lg_inet_getaddrinfo(): output cannonname = null
02/11/21 08:56:52.549183 lg_inet_getaddrinfo(): output addr = ::1
02/11/21 08:56:52.549188 lg_inet_getaddrinfo(): EXIT rc=0
02/11/21 08:56:52.549193 Attempting to resolve 'localhost'.
02/11/21 08:56:52.549198 This Networker environment is configured for IPV6.
02/11/21 08:56:52.549994 lgto_auth: redirected to networker prog 390103 vers 2
02/11/21 08:56:52.551014 lgto_auth for `nsrjobd' succeeded
02/11/21 08:56:52.551880 Registered session id:1, fd:6, idx:0, ssn_max_pollfd:1, 1(512)
02/11/21 08:56:52.552473 Job ID = 464589.
02/11/21 08:56:52.552546 This is not an action.
02/11/21 08:56:52.552555 Is_action_clone = 0
180173:nsrclone: Step (4 of 16): NSRCLONE_INIT_PHASE_FOUR: Validating the command line arguments.
02/11/21 08:56:52.553562 lgto_auth for `nsrd' succeeded
02/11/21 08:56:52.554808 Destination clone pool 'DR_DD6300B01' has a max parallelism of 0
02/11/21 08:56:52.555037 lgto_auth for `nsrmmdbd' succeeded
02/11/21 08:56:52.556054 Calling process_clone_....
180174:nsrclone: Step (5 of 16): NSRCLONE_PROCESSING_PHASE_ONE: Submitting all save sets for Recover P i p e to Save processing.
180184:nsrclone: Step (6 of 16): NSRCLONE_PROCESSING_PHASE_TWO: List of save sets is requested for cloning.
639872682;
02/11/21 08:56:52.556285 get_ss_list successful after <0> retries
02/11/21 08:56:52.556302 Obtaining the snapshot save set list.
02/11/21 08:56:52.556309 Filtering snapshots from save set list
02/11/21 08:56:52.556318 sslst 0x44c2120, snap (nil)
02/11/21 08:56:52.557000 lgto_auth: redirected to networker prog 390103 vers 2
02/11/21 08:56:52.557967 lgto_auth for `nsrd' succeeded
02/11/21 08:56:52.558982 init_clone_backend_jb_monitor(): ENTER02/11/21 08:56:52.559026 Thread 117600499531777 will have a stack size of 8388608.
02/11/21 08:56:52.559036 Thread 117600499531778 will have a stack size of 8388608.
02/11/21 08:56:52.559040 Thread 117600499531779 will have a stack size of 8388608.
02/11/21 08:56:52.559045 Thread 117600499531780 will have a stack size of 8388608.
02/11/21 08:56:52.559049 Thread 117600499531781 will have a stack size of 8388608.
02/11/21 08:56:52.559613 init_clone_parent_job(): ENTER02/11/21 08:56:52.560240 lgto_auth: redirected to networker prog 390103 vers 2
02/11/21 08:56:52.561204 lgto_auth for `nsrjobd' succeeded
02/11/21 08:56:52.561967 Registered session id:2, fd:9, idx:1, ssn_max_pollfd:2, 2(512)
02/11/21 08:56:52.562395 init_clone_parent_job(): EXIT180206:nsrclone: Step (7 of 16): NSRCLONE_PROCESSING_PHASE_THREE: Sending the media reservation request for the current save set list.
02/11/21 08:56:52.562424 In group_ssids_per_client_and_retention
02/11/21 08:56:52.562580 get_ss_list successful after <0> retries
02/11/21 08:56:52.562597 Looking for the ssid [639872682] in the original input list
02/11/21 08:56:52.562605 Found ssid/cloneid pair : [639872682]
02/11/21 08:56:52.562616 Thread 117600499531782 will have a stack size of 8388608.
02/11/21 08:56:52.562671 No callback registered on session channel 1 for user-defined message: (message type: 50, request type: 0)
02/11/21 08:56:52.562695 submit_reservations_in_background(): ENTER02/11/21 08:56:52.563346 lgto_auth: redirected to networker prog 390103 vers 2
02/11/21 08:56:52.564485 lgto_auth for `nsrd' succeeded
02/11/21 08:56:52.566239 req_id: 409409
02/11/21 08:56:52.566275 session_key: 409410
02/11/21 08:56:52.566287 priority: 1
02/11/21 08:56:52.566297 request_type: REQ_TYPE_CLONE
02/11/21 08:56:52.566309 req_ststus: REQ_NOT_SET
02/11/21 08:56:52.566321 poll_interval: 150
02/11/21 08:56:52.566417 reseved_time: 600
02/11/21 08:56:52.566436 detail: NO_DETAIL
02/11/21 08:56:52.566446 cl_resp_info:
02/11/21 08:56:52.566797 Requested client (networker) with req_status (2)
02/11/21 08:56:52.566819 preprocess client_response has:
02/11/21 08:56:52.566828 req_id: 0
02/11/21 08:56:52.566838 session_key: 0
02/11/21 08:56:52.566850 priority: 0
02/11/21 08:56:52.566860 request_type: REQ_TYPE_NOT_SET
02/11/21 08:56:52.566875 req_ststus: REQ_NOT_READY
02/11/21 08:56:52.566892 poll_interval: 0
02/11/21 08:56:52.566909 reseved_time: 0
02/11/21 08:56:52.566930 detail: NO_DETAIL
02/11/21 08:56:52.566948 cl_resp_info:
02/11/21 08:56:52.566967 end preprocess
02/11/21 08:56:52.566982 request status is not ready continue to wait
02/11/21 08:56:57.567438 Requested client (networker) with req_status (4)
02/11/21 08:56:57.567471 preprocess client_response has:
02/11/21 08:56:57.567478 req_id: 409411
02/11/21 08:56:57.567484 session_key: 409410
02/11/21 08:56:57.567490 priority: 0
02/11/21 08:56:57.567496 request_type: REQ_TYPE_CLONE
02/11/21 08:56:57.567502 req_ststus: REQ_READY
02/11/21 08:56:57.567508 poll_interval: 0
02/11/21 08:56:57.567516 reseved_time: 0
02/11/21 08:56:57.567521 detail: NO_DETAIL
02/11/21 08:56:57.567529 cl_resp_info:
02/11/21 08:56:57.567535 seq_no: 0
02/11/21 08:56:57.567540 rq_op: REQ_OP_READ
02/11/21 08:56:57.567545 res_status: RES_NOT_SET
02/11/21 08:56:57.567551 mmd_info:
02/11/21 08:56:57.567556 req_id: 409412
02/11/21 08:56:57.567561 session_key: 409410
02/11/21 08:56:57.567566 priority: 0
02/11/21 08:56:57.567571 request_type: REQ_TYPE_CLONE
02/11/21 08:56:57.567577 req_ststus: REQ_READY
02/11/21 08:56:57.567582 poll_interval: 0
02/11/21 08:56:57.567587 reseved_time: 0
02/11/21 08:56:57.567592 detail: NO_DETAIL
02/11/21 08:56:57.567597 cl_resp_info:
02/11/21 08:56:57.567601 seq_no: 0
02/11/21 08:56:57.567607 rq_op: REQ_OP_WRITE
02/11/21 08:56:57.567611 res_status: RES_NOT_SET
02/11/21 08:56:57.567615 mmd_info:
02/11/21 08:56:57.567618 end preprocess
02/11/21 08:56:57.567634 Creating reservation thread = 0, request id 409411, session key 409410
02/11/21 08:56:57.567657 Thread 117600499531783 will have a stack size of 8388608.
02/11/21 08:56:57.567702 Creating reservation thread = 1, request id 409412, session key 409410
02/11/21 08:56:57.567715 Thread 117600499531784 will have a stack size of 8388608.
02/11/21 08:56:57.568866 lgto_auth: redirected to networker prog 390103 vers 2
02/11/21 08:56:57.569266 lgto_auth: redirected to networker prog 390103 vers 2
02/11/21 08:56:57.570811 lgto_auth for `nsrd' succeeded
02/11/21 08:56:57.571518 lgto_auth for `nsrd' succeeded
02/11/21 08:56:57.573153 req_id: 409411
02/11/21 08:56:57.573177 session_key: 409410
02/11/21 08:56:57.573189 priority: 1
02/11/21 08:56:57.573197 request_type: REQ_TYPE_CLONE
02/11/21 08:56:57.573205 req_ststus: REQ_READY
02/11/21 08:56:57.573213 poll_interval: 150
02/11/21 08:56:57.573221 reseved_time: 600
02/11/21 08:56:57.573229 detail: DETAIL
02/11/21 08:56:57.573236 cl_resp_info:
02/11/21 08:56:57.573244 seq_no: 1
02/11/21 08:56:57.573252 rq_op: REQ_OP_READ
02/11/21 08:56:57.573260 res_status: RES_READY
02/11/21 08:56:57.573267 mmd_info:
02/11/21 08:56:57.573275 mmd_host: networker
02/11/21 08:56:57.573283 mmd_version: 305
02/11/21 08:56:57.573291 mmd_reserve_time: 600
02/11/21 08:56:57.573299 dev_interface: DEV_IF_DD_ANY
02/11/21 08:56:57.573327 Unable to find backend monitor reservation for volume pair <4251731159, 0>
02/11/21 08:56:57.573350 adding backend monitor reservation 0x7fee4801af80 for volume pair <4251731159, 0>
02/11/21 08:56:57.573752 req_id: 409412
02/11/21 08:56:57.573780 session_key: 409410
02/11/21 08:56:57.573791 priority: 1
02/11/21 08:56:57.573804 request_type: REQ_TYPE_CLONE
02/11/21 08:56:57.573813 req_ststus: REQ_REJECTED
02/11/21 08:56:57.573823 poll_interval: 150
02/11/21 08:56:57.573838 reseved_time: 600
02/11/21 08:56:57.573854 detail: NO_DETAIL
02/11/21 08:56:57.573868 cl_resp_info:
199745:nsrclone: Received reservation request status as 'rejected'. Retry check mmd-request status: count is 1(out of 5).
116284:nsrclone: Sending cancel broker request 409412
02/11/21 08:56:57.573924 cancel_br_request: mmd request 409412 is being canceled from host networker with reservation key ?
180876:nsrclone: Request 409412 was cancelled.
02/11/21 08:56:57.574277 sleep for 10 secs before retrying mmd request
116283:nsrclone: retrying mmd reservation request!!!
02/11/21 08:57:07.574999 req_id: 0
02/11/21 08:57:07.575031 session_key: 0
02/11/21 08:57:07.575038 priority: 0
02/11/21 08:57:07.575044 request_type: REQ_TYPE_NOT_SET
02/11/21 08:57:07.575050 req_ststus: REQ_NOT_READY
02/11/21 08:57:07.575056 poll_interval: 0
02/11/21 08:57:07.575062 reseved_time: 0
02/11/21 08:57:07.575067 detail: NO_DETAIL
02/11/21 08:57:07.575072 cl_resp_info:
02/11/21 08:57:17.575562 req_id: 409449
02/11/21 08:57:17.575603 session_key: 409410
02/11/21 08:57:17.575613 priority: 1
02/11/21 08:57:17.575622 request_type: REQ_TYPE_CLONE
02/11/21 08:57:17.575630 req_ststus: REQ_REJECTED
02/11/21 08:57:17.575637 poll_interval: 150
02/11/21 08:57:17.575645 reseved_time: 600
02/11/21 08:57:17.575653 detail: NO_DETAIL
02/11/21 08:57:17.575660 cl_resp_info:
199745:nsrclone: Received reservation request status as 'rejected'. Retry check mmd-request status: count is 2(out of 5).
116284:nsrclone: Sending cancel broker request 409449
02/11/21 08:57:17.575693 cancel_br_request: mmd request 409449 is being canceled from host networker with reservation key ?
180876:nsrclone: Request 409449 was cancelled.
02/11/21 08:57:17.576076 sleep for 10 secs before retrying mmd request

@bingo.1  after a long time, the command "nsrclone -S 639872682 -b DR_DD6300B01 -D5" reported error.

199746:nsrclone: No more retries to check status of mmd reservation. Five retries done and then retried for 30 mnts past the 'last success' and 'last activity' without success!
124480:nsrclone: Quitting MMD reservation due to request status = REQ_REJECTED!!!
199803:nsrclone: Sending cancel broker request 412984 because the mmd reservation failed
02/11/21 09:27:17.754757 cancel_br_request: mmd request 412984 is being canceled from host networker with reservation key ?
180876:nsrclone: Request 412984 was cancelled.
114982:nsrclone: NSRCLONE being aborted since broker request for mmd reservation failed with nonretryable error.

02/11/21 09:27:17.755164 LGTHREAD_FAILURE: mmd reservation failure
02/11/21 09:27:18.708899 submit_reservations_in_background(): EXIT180208:nsrclone: Step (8 of 16): NSRCLONE_PROCESSING_PHASE_FOUR: Found the recover storage node 'networker' for source volume '4251731159'.
124479:nsrclone: Failed to reserve one of the mmd. Sending cancel broker request 409411
02/11/21 09:27:21.271670 cancel_br_request: mmd request 409411 is being canceled from host networker with reservation key 21586782829571
180882:nsrclone: Step (9 of 16): NSRCLONE_PROCESSING_PHASE_FIVE: Failed to receive the media multiplexor daemon reservations for both the source volume '4251731159' and destination volume '0'. Removing the reservation ID 409411.
02/11/21 09:27:21.271976 Removing backend monitor reservation 0x7fee4801af80 for volume pair <4251731159, 0>
02/11/21 09:27:21.271987 remove_backend_monitor_mmdreservation: removing volume pair reference
02/11/21 09:27:21.271993 mmdreserv_data_free: req_id: 409411
02/11/21 09:27:21.271998 cancel_br_request: mmd request 409411 is being canceled from host networker with reservation key 21586782829571
No valid input savesets - check CLONE SKIPPED SAVESETS!
RPS CLONE RESULTS
[ORIGINAL REQUESTED SAVESETS]
639872682;
[CLONE SKIPPED SAVESETS]
639872682/1612951210;
02/11/21 09:27:24.275625 free_clone_backend_jb_monitor(): ENTER142778:nsrclone: NSRCLONE failed for one or more savesets.

02/11/21 09:27:24.275898 alldone(): ENTER
02/11/21 09:27:24.276003 report_job_completion has the following attrlist:
completion severity: 50;
completion status: failed;
saveset id: 639872682;
skipped savesets: 639872682/1612951210;
02/11/21 09:27:24.276407 Unregistered session id:1, fd:6, idx:0, ssn_max_pollfd:2, 1(512)
02/11/21 09:27:24.276451 snode_units (nil)
02/11/21 09:27:24.276458 free_snode_units ENTER
02/11/21 09:27:24.276462 free_snode_units EXIT
02/11/21 09:27:24.276510 nsrclone, alldone(): EXIT
02/11/21 09:27:24.276549 Unregistered session id:2, fd:9, idx:1, ssn_max_pollfd:0, 0(512)

19.4.0.0 in fact is the latest version.

In your command you should specify both - the recover and the receiving storage node separately.

Hello!

I don't understand, i checked license and have a surprese my licenses have a problems, not show license for the additional storage node. After usage a temporary license https://www.delltechnologies.com/en-us/collaterals/unauth/technical-guides-support-information/products/data-protection/docu91944.pdf and restarted all services for networker, gst the routines as normalized.

Very very curious, i go open a ticket with my partner for check the licenses because have a transition license for 9.3 to 19.3 have change format is a trick.

Thanks for all support, i return if have any update for this case on the topic!

Watch this jobs running and don't have "queuing" that is not running.

Hi , for this problem Marcos ,  Dell say :