Symptom

Conditions

>FMC has multiple interfaces configured with different subnets >FTD is running on 6.4.0 and FMC on 6.4.0.10 >FQDN of the FMC is used while attempting registration.

Workaround

1.Use FMC IP to register the FTD 2.Use NATid to register the FTD (FMC FQDN can be used in this case)

Further Problem Description

RPC request fails while trying to register the FTD using FMC FQDN. ===== FTD LOGS WITH FAILED RPC REQUESTS GETTING DROPPED === Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [13874] sfmgr:sfmanager [INFO] SFMGR: UNIX socket '/ngfw/var/sf/peers/firepower-xyz.com/mgr.sox': 9 is listening... Mar 16 08:26:30 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [13920] sfmgr:sfmanager [INFO] (1)Interrupted processing request. Mar 16 08:26:55 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [13874] sfmgr:sfmanager [WARN] Remote task (fd=197, uuid=314cdbdc-b267-11ea-aa26-4f7554d12e22,task_id_remote=193877 : task_id_local=193471) (sp=0x7f52080011c0)exited and the peer send another one!! Mar 16 08:26:55 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [15149] sfmgr:sfmanager [INFO] (1)Interrupted processing request. Mar 16 08:27:20 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [13874] sfmgr:sfmanager [WARN] Remote task (fd=197, uuid=314cdbdc-b267-11ea-aa26-4f7554d12e22,task_id_remote=193889 : task_id_local=193877) (sp=0x7f520c000e10)exited and the peer send another one!! Mar 16 08:27:20 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [16356] sfmgr:sfmanager [INFO] (1)Interrupted processing request. ====== From the above logs it is observed that the tasks are compared against the wrong local task ID. For example ?193877 != 193471? but later same 193877 is available in the subsequent request processing by ProcessRequestFromPeer. So what could lead into out of order processing requests at the FTD end is not clear. === request handling - ProcessRequestFromPeer === 340 if( sp->task->task_id != 0 && 341 sp->task->task_id != task->task_id) 342 { 343 struct peer_service_entry *sp_new = NULL; 344 //this is the case when we need to try to kill the job and use a mutex 345 SFWARN(MODULE, "Remote task (fd=%d, uuid=%s,task_id_remote=%u : task_id_local=%u) (sp=%p)" 346 "exited and the peer send another one!!", 347 task->fd_service_src,task->uuid,task->task_id,sp->task->task_id,sp); 348 //put it on retired list - should be only one? 349 350 sp->task->fd_service_src = EXPIRED_MESSSAGE_ID; 351 sp->task->task_id = 0; ===== === exec_remote_command code === if(SF_SIG_TERM || 3814 !p || 3815 p != info->peer || 3816 p->is_configured==PEER_REMOVED || //parent thread is notified to exit 3817 p->is_configured==PEER_REMOVED_NOTIFY || //parent thread is set to exit 3818 !p->handled_by_spawn_child || //parent thread is gone 3819 !check_peer_msg(p,info->sp,p->msgs_from_requests) || //request is purged 3820 !info->sp || 3821 !info->sp->task) 3822 { 3823 3824 while(i>0) 3825 { 3826 i--; 3827 FREEREF(&(info->argv[i])); 3828 } 3829 SFINFO(MODULE, "(1)Interrupted processing request."); 3830 FREEREF(&(info)); 3831 //interrupted request ==== === logs with FMC FQDN == Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [26466] sfmgr:sfmanager [INFO] Established connection to sftunnel for peer firepower-xyz.com(fd 8) Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [13875] sfmgr:sfmanager [INFO] Writing out service number - SFMGR for peer firepower-xyz.com Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26431]: [13719] sftunneld:sf_heartbeat [INFO] RPC Service is published for peer firepower-xyz.com Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26431]: [13719] sftunneld:sf_peers [INFO] Using a 20 entry queue for firepower-xyz.com - 6666 Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26431]: [13719] sftunneld:sf_connections [INFO] Need to send SW version and Published Services to firepower-xyz.com Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26431]: [13719] sftunneld:sf_peers [INFO] Confirm RPC service in CONTROL channel Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [13874] sfmgr:sfmanager [INFO] SFMGR is published on peer firepower-xyz.com Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [13874] sfmgr:sfmanager [INFO] Save a message for/from firepower-xyz.com Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [13874] sfmgr:sfmanager [INFO] Save a message for/from firepower-xyz.com Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [13874] sfmgr:sfmanager [INFO] Save a message for/from firepower-xyz.com Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26431]: [13719] sftunneld:sf_channel [INFO] >> ChannelState do_dataio_for_heartbeat peer firepower-xyz.com / channelA / CONTROL [ msgSock & ssl_context ] << Mar 16 08:26:29 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [13874] sfmgr:sfmanager [INFO] SFMGR: UNIX socket '/ngfw/var/sf/peers/firepower-xyz.com/mgr.sox': 9 is listening... Mar 16 08:26:30 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [13920] sfmgr:sfmanager [INFO] (1)Interrupted processing request. Mar 16 08:26:55 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [13874] sfmgr:sfmanager [WARN] Remote task (fd=197, uuid=314cdbdc-b267-11ea-aa26-4f7554d12e22,task_id_remote=193877 : task_id_local=193471) (sp=0x7f52080011c0)exited and the peer send another one!! Mar 16 08:26:55 IDFFI-11010-OF01SVR-FP01 SF-IMS[26432]: [15149] sfmgr:sfmanager [INFO] (1)Interrupted processing request. ===== ===== logs with FMC IP === Mar 16 08:51:44 IDFFI-11010-OF01SVR-FP01 SF-IMS[16815]: [16851] sfmgr:sfmanager [INFO] Established connection to sftunnel for peer 10.189.8.18 (fd 8) Mar 16 08:51:44 IDFFI-11010-OF01SVR-FP01 SF-IMS[16815]: [23392] sfmgr:sfmanager [INFO] Writing out service number - SFMGR for peer 10.189.8.18 Mar 16 08:51:44 IDFFI-11010-OF01SVR-FP01 SF-IMS[16814]: [23216] sftunneld:sf_heartbeat [INFO] RPC Service is published for peer 10.189.8.18. Mar 16 08:51:44 IDFFI-11010-OF01SVR-FP01 SF-IMS[16814]: [23216] sftunneld:sf_peers [INFO] Using a 20 entry queue for 10.189.8.18 - 6666 Mar 16 08:51:44 IDFFI-11010-OF01SVR-FP01 SF-IMS[16814]: [23216] sftunneld:sf_connections [INFO] Need to send SW version and Published Services to 10.189.8.18 Mar 16 08:51:44 IDFFI-11010-OF01SVR-FP01 SF-IMS[16814]: [23216] sftunneld:sf_peers [INFO] Confirm RPC service in CONTROL channel Mar 16 08:51:44 IDFFI-11010-OF01SVR-FP01 SF-IMS[16814]: [23216] sftunneld:sf_channel [INFO] >> ChannelState do_dataio_for_heartbeat peer 10.189.8.18 / channelA / CONTROL [ msgSock & ssl_context ] << Mar 16 08:51:44 IDFFI-11010-OF01SVR-FP01 SF-IMS[16815]: [23391] sfmgr:sfmanager [INFO] Waiting for RPC service to be published on peer 10.189.8.18 Mar 16 08:51:47 IDFFI-11010-OF01SVR-FP01 SF-IMS[16814]: [23216] sftunneld:sf_heartbeat [INFO] Saved SW VERSION from peer 10.189.8.18 (6.7.0.2) Mar 16 08:51:47 IDFFI-11010-OF01SVR-FP01 SF-IMS[16814]: [23216] sftunneld:sf_heartbeat [INFO] (2)FORWARDED Product Info received from peer 10.189.8.18 to SFMGR Mar 16 08:51:47 IDFFI-11010-OF01SVR-FP01 SF-IMS[16815]: [23391] sfmgr:sfmanager [INFO] SFMGR is published on peer 10.189.8.18 Mar 16 08:51:47 IDFFI-11010-OF01SVR-FP01 SF-IMS[16815]: [23391] sfmgr:sfmanager [INFO] SFMGR: UNIX socket '/ngfw/var/sf/peers/10.189.8.18/mgr.sox': 9 is listening... Mar 16 08:52:07 IDFFI-11010-OF01SVR-FP01 SF-IMS[16815]: [24459] sfmgr:file_validator [INFO] File [/etc/sf/model.conf] for [1] role validated as SUCCESS =====