fw fetchlogs (SIC failure from MDM log server retr...

David_Herselman · ‎2021-06-04

We appear to have some miss behaving R80.40 security gateways managed by MDM R81. Locally logged firewall logs are not transferred to the MDM log server as configured and executing a manual retrieval yields the error below.

Looks like a problem with SIC not being initialised properly when a MDM log server attempts to retrieve logs from a security gateway:

 SIC Error for fetch_logs: Client could not choose an authentication method for service fetch_logs

Could anyone suggest a work around or know how to fix this?

Management is Multi-Domain Management (primary with standby) and MDM log server running R81 with JHA take 23. Security Gateway is R80.40 with JHA take 67, will be installing JHA take 118 this coming weekend in the hope that something of this nature has already been fixed...

From MDM log server, we first switch to the appropriate domain and then attempt to retrieve the gateway's logs:

[Expert@fwcpl1:0]# mdsenv 222.222.222.222
[Expert@fwcpl1:0]# fw fetchlogs 111.111.111.111
Connection failed !!!
[Expert@fwcpl1:0]# fw -d fetchlogs 111.111.111.111
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_policy_create: version 5301.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_policy_add_name_to_group: finished successfully.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_policy_set_local_names: () names. finished successfully.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_policy_create: finished successfully.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_policy_read (/opt/CPmds-R81/customers/Redacted_Log/CPshrd-R81/conf/sic_policy.conf): finished successfully.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_set_external_host_groups: 49 names. finished successfully.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_policy_add_name_to_group: finished successfully.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_policy_set_local_names: (local_sic_name) names. finished successfully.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_policy_add_name_to_group: finished successfully.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_policy_set_local_names: (222.222.222.222) names. finished successfully.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_policy_add_name_to_group: finished successfully.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_policy_set_local_names: ("CN=Redacted_Log,O=Redacted_Server_1.redacted.com.tuissu") names. finished successfully.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_apply_default_dn: ca_dn = [O=Redacted_Server_1.redacted.com.tuissu].
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_apply_default_dn: calling PM_policy_DN_conversion ..
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_apply_default_dn: finished successfully.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] PM_apply_default_dn: [NOTE] for printing the policy set PM_POLICY_PRINT environment variable
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] fwPubKeyfromPKCS8: decoding RSA key
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 12
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] is_initialized: new process or forked
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] The PRNG was not initialized properly
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] hash_drbg_add_sample: Adding 55 bytes worth 27500 milibits. Total: 27500. Required: 256000
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] hash_drbg_add_sample: Adding 110 bytes worth 440000 milibits. Total: 467500. Required: 256000
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'CKPSSL_MIN_TLS_VERSION'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Get_TLS_Version_From_Registry: SOFTWARE\CheckPoint\FW1\CKPSSL_MIN_TLS_VERSION wasn't found in the registry
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'ENABLE_3DES'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] Error opening file /opt/CPmds-R81/customers/Redacted_Log/CPshrd-R81/database//authkeys.C:: No such file or directory
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 12
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 12
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 32
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 12
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 12
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 32
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 32
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 11
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 31
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 11
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 11
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 31
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSLctx_New: prefs = 31
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] ckpSSL_Set_TLS_Version: setting minimum TLS version: 0x301
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] cpcrypto_get_registry_value: could not query value of key 'Get_Disable_RC4'.
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] sic_sslca_Free: defs = 0x92c3b78, references = 0
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] fwobj_obj_initmode: mode=7
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] fwobj_obj_initmode: MGR RO NEW mode
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] fwobj_destroy_reference_hash: reference_resolving_hash_users<0
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] fetch_objects: Start
[20019 3977484288]@fwcpl1[4 Jun 13:15:25] fwobj_destroy_reference_hash: reference_resolving_hash_users<0
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fetch_objects: table log_actions was added to fw_confobj
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fetch_objects: table log_field_server_types was added to fw_confobj
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fetch_objects: table log_fields was added to fw_confobj
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] Did not load netobj for objsym
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwclient_do_connect_e: server 111.111.111.111 port 256 sicname N/A cmd 91
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwclient_do_connect_e: hostname 111.111.111.111 hostsicname N/A addr 6a48779a
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwclient_do_connect_e: addr 111.111.111.111
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwclient_do_connect_ei: sic name for server 938d2c0 is NULL.
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] peers addresses are
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] ::
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] peers addresses are
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] 222.222.222.222
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] sic_client_do_connect: no server sic name supplied, server sic name is unknown.
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] cpsicdemux_get_mode: the mode is 1
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] cpsicdemux_check_mode: server_mode=1 | requested_mode=1
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwasync_get_maxbuf: maxbuf=4194304
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwasync_conn_params: <647fca13,34890> -> <9a77486a,256>
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwasync_connbuf_realloc: reallocating 0 from 0 to 1028
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwasync_connbuf_realloc: reallocating 0 from 0 to 1028
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] sic_client_set_version: 16: protocol version is 59000000
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] cpsicdemux_check_mode: server_mode=1 | requested_mode=1
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] call_handlers_list: no conversion done, set CN=fwcp1,O=Redacted_Server_1.redacted.com.tuissu as sic name
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] PM_session_init: given session O(CN=Redacted_Log,O=Redacted_Server_1.redacted.com.tuissu;CN=fwcp1,O=Redacted_Server_1.redacted.com.tuissu;256;fetch_logs).
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] PM_policy_query: input session O(CN=Redacted_Log,O=Redacted_Server_1.redacted.com.tuissu;CN=fwcp1,O=Redacted_Server_1.redacted.com.tuissu;256;fetch_logs).
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwnetobj_getbysicname: table_chosen_get_with_param(eTABLE_NETWORK_OBJECTS, is_obj_SIC_name, CN=fwcp1,O=Redacted_Server_1.redacted.com.tuissu) returned NULL.
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwnetobj_getbysicname: table_chosen_get_with_param(eTABLE_NETWORK_OBJECTS, is_obj_SIC_name, CN=fwcp1,O=Redacted_Server_1.redacted.com.tuissu) returned NULL.
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwnetobj_getbysicname: table_chosen_get_with_param(eTABLE_NETWORK_OBJECTS, is_obj_SIC_name, CN=fwcp1,O=Redacted_Server_1.redacted.com.tuissu) returned NULL.
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwnetobj_getbysicname: table_chosen_get_with_param(eTABLE_NETWORK_OBJECTS, is_obj_SIC_name, CN=fwcp1,O=Redacted_Server_1.redacted.com.tuissu) returned NULL.
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] PM_policy_query: rule not found.
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] PM_policy_query: finished successfully. 1st method = deny
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] PM_policy_choose: finished successfully. choose: DENY.
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] policy_choose: choose failed.
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] sic_client_negotiate_auth_method: policy choose failed.
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwasync_do_mux_in: 16: handler returned with error
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] sic_client_end_handler: for conn id = 16
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwclient_connected: SIC Error for fetch_logs: Client could not choose an authentication method for service fetch_logs
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] fwclient_connected: connection failed
Connection failed !!!
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] T_event_mainloop_e: T_event_mainloop_iter returns 0
[20019 3977484288]@fwcpl1[4 Jun 13:15:26] destroy_rand_mutex: destroy

Regards

David Herselman

PhoneBoy · ‎2021-06-06

I believe the policy file in question is $CPDIR/conf/sic_policy.conf and probably needs adjusting.
This requires a cprestart on your log server after adjusting.
Also, this is just a guess, so it may not resolve the issue, in which case a TAC case is warranted.
Replace this line:

ANY ; Modules ; ANY ; adtlogswitch, logswitch, log_retrieve; sslca

With something like:

ANY ; Modules ; ANY ; adtlogswitch, logswitch, log_retrieve, fetch_logs; sslca

You may also want to see what the R80.40 version of this file says (it should exist on your gateways).

David_Herselman · ‎2021-06-07

Many thanks, my understanding of the following is that the defaults are right. I'll log the issue with TAC, many thanks for your assistance.

On the R81 JHA take 23 MDS log server, to which we want to pull logs from the gateway:

[Expert@fwcpl1:0]# mdsenv 100.127.202.19
[Expert@fwcpl1:0]# grep fetch_logs $CPDIR/conf/sic_policy.conf
ANY    ; Log_Server, Modules, Integrity_Server, IPS_sensor ; ANY ; fetch_logs, ls_logs ; sslca
ANY           ; Log_Server              ; ANY ; fetch_logs, ls_logs; sslca

On the R80.40 JHA take 118 gateway, has local firewall logs we wish to retrieve:

[Expert@fwcp1:0]# grep fetch_logs $CPDIR/conf/sic_policy.conf
ANY    ; Log_Server, Modules, Integrity_Server, IPS_sensor ; ANY ; fetch_logs, ls_logs ; sslca
ANY           ; Log_Server              ; ANY ; fetch_logs, ls_logs; sslca

Are you a member of CheckMates?

fw fetchlogs (SIC failure from MDM log server retrieving from gateway