Fortinet black logo

Administration Guide

ZTNA troubleshooting and debugging

ZTNA troubleshooting and debugging

Common troubleshooting issues

As FortiWeb ZTNA solution is integrated with FortiWeb, FortiClient and FortiClient EMS, issue troubleshooting sometimes needs checking on all these three components.

There are several ways or steps for ZTNA related issues troubleshooting:

  1. Check if FortiWeb is connected to EMS;
  2. Check if Tags and endpoint client information are synchronized to FortiWeb:
    • Compare information between FortiWeb and EMS
    • Check Event logs to see configuration or EMS data sync failures
    • Check diagnose log or fcnacd.log
  3. Check if the daemon fcnacd & fcsync are stable:
    • Check if pid changes
    • Check if there is any daemon coredump file under /var/log/gui_upload
  4. If browsers do not prompt selecting client certificate:
    • Check on FortiClient endpoint to see if certificate is signed successfully
    • Check client certificate verification configuration on FortiWeb
  5. If ZTNA rule/tag matching does not meet expectation:
    • If a visit is blocked, check Attack logs to see if any if it’s caused by ZTNA violation;
    • Check ZTNA or HTTP content-routing related diagnose logs to see processing details
  6. If the issue need further investigation, please collect below logs:
    • /var/log/debug/fcnacd.log and /var/log/debug/fcsync_log
    • Configuration file
    • Client information from “diagnose system endpoint-control clients”

ZTNA related diagnose logs:

# diagnose debug application ztna 7

# diagnose debug proxy svr-balance 7

# diagnose debug proxy thread-ztna-sync 7

# diagnose debug timestamp enable

# diagnose debug enable

Currently FortiWeb does not have very rich ZTNA logs. Here we list the related Event/Attack/Traffic logs as below:

  1. Event logs:
    • EMS/fctems configuration changes;
    • Tag sync > Add/delete tag configuration;
    • Sync data success/failure > caused by EMS connect/disconnect
  2. Attack logs:
    • HTTP Connection Failure logs when client certificate verification failed
    • Zero Trust Access logs when traffic matches ZTNA rule with Action Alert_Deny by ZTNA, or matches the default Action Alert_Deny of ZTNA profile;
    • No attack logs when ZTNA rule/profile is matched and the Action is Accept or Deny (No log)
    • No attack logs when ZTNA tags are matched or not matched in HTTP content-routing policy
  3. Traffic logs:

    When ZTNA profile/rule is matched and the Action is Accept, there will be a traffic log, but currently no ZTNA information within it.

FortiClient EMS connection issues

  • Check the network and FortiClient EMS port accessibility on FortiWeb:

    • Ping the IP address or the Domain Name of the FortiClient EMS;

      Note: only IPv4 & Domain Name are supported; IPv6 is not supported by FortiClient EMS

    • Use execute telnettest command to check if EMS service is reachable:

      FWB # execute telnettest 10.65.1.98:443

      Connected

  • Use execute & diagnose commands to check FortiClient EMS status on FortiWeb:

    • Run execute fctems is-verified <EMS>

      FWB-91 # execute fctems is-verified EMS95

      Configured FortiClient EMS has not been verified.

      This message means that the FortiClient EMS certificate has not been verified by FortiWeb yet. You need to verify it via execute fctems verify <EMS> or click Authorize on GUI.

      FWB # execute fctems is-verified EMS95

      Configured FortiClient EMS has been verified.

      This status means that the FortiClient EMS certificate has been verified by FortiWeb, while FortiWeb is not necessarily authorized by EMS.

      Once the FortiClient EMS has been verified, the system will add configuration of fingerprint and EMS_SN as below:

      config system endpoint-control fctems

      edit "EMS95"

      set server 10.0.10.95

      set capabilities fabric-auth silent-approval websocket websocket-malware push-ca-certs

      set fingerprint B7:0B:6E:A4:7A:8F:7F:2F:E1:4A:18:F4:0E:34:65:C8:F0:A6:A7:F7:C7:D2:60:43:A5:49:A0:F6:35:EA:A1:C3:85:87:E1:15:95:B3:12:42:D3:80:96:50:10:EA:1C:2C:49:85:DC:F1:B5:EB:10:24:5A:61:A7:37:E8:64:31:CF

      set EMS_SN FCTEMS8822003349

      next

      end

    • Run diagnose system endpoint-control test <EMS>

      FWB # diagnose system endpoint-control test EMS95

      Connection test had an error -3: EMS server connection failed. Authentication denied

      #This message indicates FortiWeb has not been authorized, or denied by FortiClient EMS, or the EMS certificate has not been verified by FortiWeb. When adding a new FortiClient EMS connector, FortiWeb and FortiClient EMS need to verify/authorize each other.

  • Check the FortiClient EMS status and failure reasons on FortiWeb or FortiClient EMS GUI:

    • The EMS status will be shown with a question mark if FortiClient EMS fabric connection has not been established:

    • Check the FortiClient EMS status with failure reasons in the Edit page.

      auth_pending: It means FortiWeb has not been authorized by FortiClient EMS, or the FortiClient EMS certificate has not been verified by FortiWeb.

      auth_deny: It means FortiWeb authorization has been denied by FortiClient EMS.

      cert_unauthorzied: It means FortiClient EMS certificate has not been verified by FortiWeb, but FortiWeb has been authorized by EMS.

      cert_unknown: It means FortiClient EMS certificate cannot be retrieved, which is usually caused by the EMS IP/Domain or Port is not reachable.

ZTNA Tags sync issues

Normally, ZTNA tags created on FortiClient EMS will be synchronized in a few seconds after FortiClient EMS connection is established. If new tags or tag changes (e.g. delete) are not updated correctly to FortiWeb, please follow these steps to troubleshoot:

  1. Use the methods in section “Check FortiClient EMS connection issues” to confirm if FortiClient EMS is connected successfully and stably.
  2. Add a new Zero Trust Tagging rule on FortiClient EMS, check if the new tag can be synchronized to FortiWeb or not.
  3. Check if the daemon fcnacd is stable:
    • Execute “fn pidof fcnacd” several times to check if the pid changes

    • Check /var/log/gui_upload to see if there is any fcnacd or fcsync coredump files

  4. Enable diagnose log on FortiWeb to check the sync details.

    # diagnose debug application fcnacd 7 #communication logs between FortiWeb & EMS

    # diagnose debug enable

    E.g. check the output of api/v1/report/fct/host_tags for a successful tag sync process:

    : [2022-08-09-23:34:10] [ec_ems_context_submit_work:431] Call submitted successfully.

    obj-id: 10, desc: REST API to get updates about host tags., entry: api/v1/report/fct/host_tags.

    : [2022-08-09-23:34:10] [ec_ez_worker_process:273] Processing call for obj-id: 10, entry: "api/v1/report/fct/host_tags"

    : [2022-08-09-23:34:10] [ec_ez_worker_process:348] Call completed successfully.

    obj-id: 10, desc: "REST API to get updates about host tags.", entry: "api/v1/report/fct/host_tags".

    For more detailed fcnacd logs, please download /var/log/debug/fcnacd.log.

    Login to the backend shell, check the output in /var/log/debug/fcnacd.log or copy it to /var/log/gui_upload and download it via GUI for further checking.

    Check the output of api/v1/report/fct/host_tags to see if tags are included in the json content:

    E.g. check the output of api/v1/report/fct/host_tags for a successful tag sync process:

    : [2022-08-10-00:38:37] [ec_ez_worker_prep_data_url:177] Full URL: HTTPs://10.65.1.99/api/v1/report/fct/host_tags?&updated_after=2022-06-29%2006%3A47%3A03%2E5700870&send_mac=true

    : [2022-08-10-00:38:37] [ec_ems_context_submit_work:431] Call submitted successfully.

    obj-id: 10, desc: REST API to get updates about host tags., entry: api/v1/report/fct/host_tags.

    : [2022-08-10-00:38:37] [ec_ez_worker_process:273] Processing call for obj-id: 10, entry: "api/v1/report/fct/host_tags"

    : [2022-08-10-00:38:37] [ec_ez_worker_process:293] reply:

    """

    {"result": {"retval": 1, "message": null}, "data": {"is_final": true, "updated_after": "2022-06-29 06:47:03.5700870", "is_zipped": true, "unzipped_size": 474, "data": "eJxlkM1ugzAQhF8l8jmpHMpP4JYYUCs1itT21IvlwJKsajCyTdoo4t0LMhVVetrZb6z1zt4IGm4a0ZqzsiSphDSwJFacODaVIsmNCCm5hhMaCxpKXkiExprB6ZfkRX05sYcSu9rpJzydnWIaLRZCuu4DtFqV4rpIwUJhUTXTlOcDW7x1psUCVTex1+yCkg/O9Le+8k+43nuFtvcIvsGhrSs7V96HRHHMqTe1YCwfGV3Pfi6OGgt+aP6jqppZCpe52Qs5r927y9VQH0FPQTos+QjlEOIP+r1uEIUs2O5YmLHMj9guztZplucbj1E/8NNwfHNWw7LjjK4thQVusR4yEo963oqGKy9e0DDxo4Q+PgQRpZuIkr7vfwAn/pyS"}}

    """

    : [2022-08-10-00:38:37] [fcems_json_unzip:267] unzipped:

    """

    {"is_snapshot":false,"tag_info":{"all_registered_clients":{},"Low":{},"Medium":{},"High":{},"Critical":{},"Zero-day Detections":{},"IOC Suspicious":{},"REvil_IOC_registry_key":{},"REvil_IOC_crt":{},"REvil_IOC_exe":{},"A":{},"B":{},"Tag_99_02":{},"Test_Tag_01":{},"Tag_Fabric_On":{},"Tag_Fabric_Off":{},"Tag_Dev":{},"Tag_Malicious":{}},"tag_members":{},"uid_tag_lists":{},"uid_info":{"576C5ABC6ECE47CB9E1DEFF82C0454D6":{"host_tag_update_time":"2022-06-29 06:47:03.5700870"}}}

    """

    : [2022-08-10-00:38:37] [ec_ez_worker_process:348] Call completed successfully.

    obj-id: 10, desc: "REST API to get updates about host tags.", entry: "api/v1/report/fct/host_tags".

    All EMS tags are synchronized and contained in the above unzipped json content. You can check if the newly-added tag is included or the removed tag is NOT included. If the new tag is NOT included, you may check if it is an EMS problem rather than a FortiWeb issue.

    To improve the readability, the above json content is transferred with a json formatter and simplified:

    {

    "tag_info":{

    "Test_Tag_01":{

    },

    "Tag_Fabric_On":{

    },

    "Tag_Fabric_Off":{

    },

    "Tag_Dev":{

    },

    "Tag_Malicious":{

    }

    },

    "uid_info":{

    "576C5ABC6ECE47CB9E1DEFF82C0454D6":{

    "host_tag_update_time":"2022-06-29 06:47:03.5700870"

    }

    }

    }

  5. Particularly, if you are deleting a tag, please double confirm not only the tagging rule is deleted, but also the tag is deleted in “Manage Tags” in FortiClient EMS.
  6. A tag referenced in a ZTNA rule or HTTP Content-routing policy will NOT be removed from FortiWeb immediately after the tag is removed from FortiClient EMS.

    Only if the tag is removed from ZTNA rule or HTTP Content-routing policy, it will be removed by FortiWeb automatically;

    FortiWeb will check if a current tag saved in configuration is used or not in each tag sync cycle. When the system boots up, if it has been removed from FortiClient EMS and not used in any ZTNA rule or HTTP Content-routing policy any more, the tag will be deleted.

Endpoint client information sync issues

Information of all endpoint clients registered to the FortiClient EMS will be synchronized to FortiWeb. If you find that an endpoint is not synchronized or information changes are not updated to FortiWeb, please follow the below steps for troubleshooting:

  1. Check diagnose system endpoint client on FortiWeb to see if the client information is up-to-date:

    You can add filters to search a specific endpoint client:

    FortiWeb # diagnose system endpoint-control clients <IP> <MAC> <FCT_SN>

    Each filter option can be set as “any” for all.

  2. Compare client info on FortiWeb with the endpoint info shown in FortiClient EMS Endpoints > All Endpoints, and that displayed in FortiClient.
  3. Pay attention to the circled info: EMS SN, FortiClient ID / UID, IP and Tags.

    If Show Zero Trust Tag on FortiClient GUI is enabled in FortiClient EMS Endpoint > Profiles > System Settings, you can also see the ZTNA tags on the FortiClient.

  4. If there is no Endpoint information or some information is not up-to-date on FortiWeb, check if FortiClient EMS is connected successfully and stably first, with the methods mentioned in section "Check FortiClient EMS connection issues".
  5. Check if the daemon fcnacd is stable:
    1. Execute fn pidof fcnacd several times to check if the pid changes.
    2. Check /var/log/gui_upload to see if there is any fcnacd or fcsync coredump files.
  6. If FortiClient EMS is connected while client information is not updated, enable diagnose log on FortiWeb to check if there is any sync failure.
  7. # diagnose debug application fcnacd 7 #communication logs between FortiWeb & EMS

    # diagnose debug enable

    E.g. check the output of api/v1/report/fct/uid_tags to see if the tag changes is reflected in logs:

    : [2022-08-09-23:34:10] [ec_ems_context_submit_work:431] Call submitted successfully.

    obj-id: 12, desc: REST API to get updates of tags associated with FCT UID., entry: api/v1/report/fct/uid_tags.

    : [2022-08-09-23:34:10] [ec_ez_worker_process:273] Processing call for obj-id: 12, entry: "api/v1/report/fct/uid_tags"

    : [2022-08-09-23:34:10] [ec_ez_worker_process:348] Call completed successfully.

    obj-id: 12, desc: "REST API to get updates of tags associated with FCT UID.", entry: "api/v1/report/fct/uid_tags".

    For more detailed fcnacd logs, please download /var/log/debug/fcnacd.log.

  8. Log in to the backend shell, check output in /var/log/debug/fcnacd.log or copy it to /var/log/gui_upload and download it via GUI for further checking.

    Particularly when you find tags are not updated to a specific client, check the output of api/v1/report/fct/uid_tags to see if tags are included in the json content:

    E.g. the output of api/v1/report/fct/uid_tags below is when a new tag “” is applied to the client, UID CA0EF982B9604702862F95798F73C060::

    : [2022-08-10-14:08:47] [ec_ez_worker_prep_data_url:177] Full URL: HTTPs://10.65.1.99/api/v1/report/fct/uid_tags?&updated_after=2022-08-10%2020%3A28%3A25%2E7803527&uid_offset=CA0EF982B9604702862F95798F73C060&send_mac=true

    : [2022-08-10-14:08:47] [ec_ems_context_submit_work:431] Call submitted successfully.

    obj-id: 12, desc: REST API to get updates of tags associated with FCT UID., entry: api/v1/report/fct/uid_tags.

    : [2022-08-10-14:08:47] [ec_ez_worker_process:273] Processing call for obj-id: 12, entry: "api/v1/report/fct/uid_tags"

    : [2022-08-10-14:08:47] [ec_ez_worker_process:293] reply:

    """

    {"result": {"retval": 1, "message": null}, "data": {"uid_offset": "CA0EF982B9604702862F95798F73C060", "updated_after": "2022-08-10 21:08:41.8294435", "is_zipped": true, "is_final": true, "unzipped_size": 558, "data": "eJxl0T1vGzEMBuC/Umg2C4oi9eFNH6epQJduRXG4xEJygO0E9iUdjPvvVbyduwkQ30cieVMf82FcppfxOF+Xq9rfVI441OApBYvskLylGsQFX53JaPGr5tROT+3Sy3/f1Fe4I2qvtFDWlCMUwxY4uwihFgOOxIoZKDJntbsHztOp9URU624jJGtqQgG07LsQLUSLESRSEpsDc7VbIT0I/YvinTBELgm4aAMxmQBWUuCQK2nSW2E6HsdLe+ntt0s7jM/HuZ37JLasd/1tHgwEtNJZNpCSGDAua4em2OTqlv3Vj3V6uszP48/zg1aISAg1RJP7oFxA8MFoGJJLLHEIgfz/WmmfD84gyJkoQfbEwFQqpOgQUCSWkEqWULbOj7e/av2zU69v1+W+9o/3w7S0cZnv14REgB40fiO9R79n/d1Tb92IWtf1H0gJmbU="}}

    """

    : [2022-08-10-14:08:47] [fcems_json_unzip:267] unzipped:

    """

    {"uid_tag_lists":{"CA0EF982B9604702862F95798F73C060":{"members":[{"tag_uid":"152C12CA-D346-4C7A-9FD3-725653E2A44C","tag_name":"A"},{"tag_uid":"1B63FB05-0648-4CA6-A60A-5A2B56C944F6","tag_name":"B"},{"tag_uid":"3C058754-A4DB-4D13-AB39-65B949CF2121","tag_name":"all_registered_clients"},{"tag_uid":"879444E3-9065-4D43-BB53-37C1703D6B7F","tag_name":"Tag_Fabric_On"},{"tag_uid":"D2225201-A3C6-4790-8931-EB7B45AE9928","tag_name":"Tag_Dev"},{"tag_uid":"E504C22B-C824-42DF-BA70-055AD9BDC59D","tag_name":"Low"}],"host_tag_update_time":"2022-08-10 21:08:41.8294435"}}}

    """

    : [2022-08-10-14:08:47] [__handle_json_tag_list:93] Add 1 member tags for FCTEMS8822003003

    : [2022-08-10-14:08:47] [ec_ez_worker_process:348] Call completed successfully.

    obj-id: 12, desc: "REST API to get updates of tags associated with FCT UID.", entry: "api/v1/report/fct/uid_tags".

    All EMS tags applied to a specific client will be contained in the unzipped json content. One can check if the newly-added tag is included or the removed tag is NOT included. If the new tag is NOT included, one may check if it is an EMS problem rather than a FortiWeb issue.

    To improve the readability, the above json content is transferred with a json formatter and simplified:

    {

    "uid_tag_lists":{

    "CA0EF982B9604702862F95798F73C060":{

    "members":[

    {

    "tag_uid":"152C12CA-D346-4C7A-9FD3-725653E2A44C",

    "tag_name":"A"

    },

    {

    "tag_uid":"1B63FB05-0648-4CA6-A60A-5A2B56C944F6",

    "tag_name":"B"

    },

    {

    "tag_uid":"3C058754-A4DB-4D13-AB39-65B949CF2121",

    "tag_name":"all_registered_clients"

    },

    {

    "tag_uid":"879444E3-9065-4D43-BB53-37C1703D6B7F",

    "tag_name":"Tag_Fabric_On"

    },

    {

    "tag_uid":"D2225201-A3C6-4790-8931-EB7B45AE9928",

    "tag_name":"Tag_Dev"

    },

    {

    "tag_uid":"E504C22B-C824-42DF-BA70-055AD9BDC59D",

    "tag_name":"Low"

    }

    ],

    "host_tag_update_time":"2022-08-10 21:08:41.8294435"

    }

    }

    }

    You can only see the content of uid_tag_lists when tags applied to a client are changed, either added or removed. Without tag changes, the content of the uid_tag_lists will be empty:

    : [2022-08-10-14:08:53] [fcems_json_unzip:267] unzipped:

    """

    {"uid_tag_lists":{}}

    """

ZTNA Access Control issues 1 - browsers do not prompt certificate selecting

HTTPS with client certificate verification is a must when a ZTNA profile is applied to a server policy. So to use ZTNA, you need to create a certificate verification rule and select it in Advanced SSL settings > Certificate Verification for HTTPS, or enable SNI and select one in a SNI policy.

If the browser does not pop up the FortiClient certificate when you visiting a server policy, please follow these steps for troubleshooting:

  1. Check if the FortiWeb and server policy is reachable;
    • Disable ZTNA profile first and guarantee the server policy works without ZTNA;
    • Refer to "Diagnose server-policy connectivity issues" above for more troubleshooting methods
  2. Check if the client certificate is signed and stored on the FortiClient PC:
    • Confirm the FortiClient is connected to the correct FortiClient EMS;
  3. Check if the client certificate is available on the client PC;

    Use either of the below two ways to check:

    • Check if the client certificate is available in the browser storage:

    • Search & open “Manage user certificates” on the Client PC; the FortiClient certificate signed by FortiClient EMS should be seen in Personal certificate directory as below:

    Please note if the certificate is not available, it might be a FortiClient or FortiClient EMS issue. You can try to disconnect and reconnect the FortiClient EMS to see if a new certificate can be fetched. This process may take a few seconds or more than one minute.

  4. Check the SSL configuration on FortiWeb.

    If client certificate verification is not configured properly, the browser will not prompt certificate selecting.

    Pay attention to these configuration:

    • Confirm that the CA Group in Certificate Verify rule includes the correct CA certificate.

      This CA certificate is the FortiClient EMS CA certificate (ZTNA) that can be found in FortiClient EMS in System Settings > EMS Settings;

      This CA certificate is synchronized from FortiClient EMS and can be found on in FortiWeb Server Objects > Certificates > CA; the name is the EMS SN.

    • Similarly, if you configure a SNI policy instead of directly selecting a client certificate verify rule, please make sure the correct certificate verify rule is configured for the SNI policy.

ZTNA Access Control issues 2 - ZTNA tags are not matched as expected in ZTNA rules or HTTP Content-routing policy

When the client certificate is selected but ZTNA actions are not taken as expected, please troubleshoot from these aspects:

  1. Confirm the client certificate is correct:
    • When multiple certificates are prompted by the browser, confirm the correct certificate is selected.

      Only when the UID (FortiClient ID) and the FortiClient EMS SN match, tag searching may continue.

    • Do not click Cancel selecting the certificate on browser, otherwise SSL handshake will fail (when Strictly Require Client Certificate is enabled in the Client Certificate Verify rule), then tag matching cannot be processed.

  2. Confirm the Tags of the client match those configured in ZTNA rules:
    • Compare client information displayed in diagnose system endpoint client with that shown on FortiClient EMS or FortiClient; make sure that the key fields such as FortiClient ID/UID, EMS SN, IP, FCT_SN, and Tags are the same.

    • Check the tag name carefully. Tags displayed in diagnose system endpoint client should be the same with that configured in ZTNA rule and originally created on EMS

      • Tags shown on FortiWeb CLI has a prefix as the EMS_SN, but the prefix is not included in the diagnose output and FortiWeb GUI

      • Although FortiClient EMS and FortiWeb support almost all special characters as the tag name, we recommend using alphabet and numbers. Please examine and compare the tags carefully when you encounter tag matching failures.

  3. Enable diagnose debug logs to check the detailed ZTNA processing:

    # diagnose debug application ztna 7 #ZTNA rule matching logs

    # diagnose debug proxy svr-balance 7 #ZTNA server load balance logs

    # diagnose debug proxy thread-ztna-sync 7 #ZTNA endpoint sync logs

    # diagnose debug timestamp enable

    # diagnose debug enable

    Example 1: Server-policy + Certificate Verification + ZTNA Profile/Rule

    <11: 8: 2>[SLB][DEBUG][line:0514]

    <11: 8: 2>[SLB][DEBUG][line:0515] Prepare to run slb in pool

    <11: 8: 2>[SLB][DEBUG][line:0058] ----------------Assign server ---------------

    <11: 8: 2>[SLB][DEBUG][line:0061] Assign server IP: 2001:1234::a41:142

    <11: 8: 2>[SLB][DEBUG][line:0068] Assign server port 443

    <11: 8: 2>[SLB][DEBUG][line:0070] Connection Number 1

    <11: 8: 2>[SLB][DEBUG][line:0072] ----------------Assign server finished---------------

    <11: 8: 2>[ZTNA_RULE][INFO] Enter ZTNA rule match

    <11: 8: 2>[ZTNA_RULE][INFO] Client cert issuer common name: FCTEMS8822003003

    <11: 8: 2>[ZTNA_RULE][INFO] Client cert subject common name: CA0EF982B9604702862F95798F73C060

    ==> Certificate verification passed; start checking tags via UID fetched from certificate

    <11: 8: 2>[ZTNA_RULE][INFO] ZTNA rule ztna_rule_01 match begin

    <11: 8: 2>[ZTNA_RULE][INFO] ===Check GEO===: Unknown Country/Region

    <11: 8: 2>[ZTNA_RULE][INFO] Matched ztna geo condition 1

    <11: 8: 2>[ZTNA_RULE][INFO] ===Check EMS Tags===: client ems tags: 4, ems tag rule: 1

    <11: 8: 2>[ZTNA_RULE][INFO] Check ZTNA ems tag condition 1

    <11: 8: 2>[ZTNA_RULE][INFO] Check Client EMS tag: all_registered_clients

    <11: 8: 2>[ZTNA_RULE][INFO] Check Client EMS tag: Tag_Sales

    <11: 8: 2>[ZTNA_RULE][INFO] Check Client EMS tag: Tag_Fabric_On

    <11: 8: 2>[ZTNA_RULE][INFO] Check Client EMS tag: High

    <11: 8: 2>[ZTNA_RULE][INFO] Not matched any ztna ems tags condition

    <11: 8: 2>[ZTNA_RULE][INFO] ZTNA rule ztna_rule_01 match finish, not matched

    <11: 8: 2>[ZTNA_RULE][INFO] ZTNA rule ztna_rule_02 match begin

    <11: 8: 2>[ZTNA_RULE][INFO] ===Check source address===: 10.65.1.63

    <11: 8: 2>[ZTNA_RULE][INFO] Matched ztna source addr condition 1

    <11: 8: 2>[ZTNA_RULE][INFO] ===Check EMS Tags===: client ems tags: 4, ems tag rule: 1

    <11: 8: 2>[ZTNA_RULE][INFO] Check ZTNA ems tag condition 1

    <11: 8: 2>[ZTNA_RULE][INFO] Check ZTNA rule EMS tag: FCTEMS8822003003_Tag_Fabric_On

    <11: 8: 2>[ZTNA_RULE][INFO] Check ZTNA rule EMS tag: FCTEMS8822003003_Tag_Sales

    <11: 8: 2>[ZTNA_RULE][INFO] Matched ztna ems tags condition 1

    <11: 8: 2>[ZTNA_RULE][INFO] ZTNA rule ztna_rule_02 match finish, matched

    <11: 8: 2>[ZTNA_RULE][INFO] Matched ztna-profile ztna_profile_01, ztna-rule ztna_rule_02, action 1

    ==> Action Code: 1: Accept; 4: Deny (no log); 6: Alert & Deny

    Example 2: HTTP Content-routing policy + Certificate Verification + ZTNA Profile/Rule

    <11:36:55>[SLB][DEBUG][line:0825] HTTP Request URL : /sales/index.html

    <11:36:55>[ZTNA_RULE][INFO] Client cert issuer common name: FCTEMS8822003003

    <11:36:55>[ZTNA_RULE][INFO] Client cert subject common name: CA0EF982B9604702862F95798F73C060

    ==> Certificate verification passed; start checking tags via UID fetched from certificate

    <11:36:55>[ZTNA_RULE][INFO] Check ZTNA rule EMS tag: FCTEMS8822002977_all_registered_clients #The ZTNA Tag configured in the policy

    <11:36:55>[SLB][DEBUG][line:0878] not matched ztna ems tag

    <11:36:55>[SLB][DEBUG][line:1146] Match item id(2) match_object(13) ret = -1.

    ==> The 1st HTTP content-routing policy not matched due to tags are not matched

    <11:36:55>[SLB][DEBUG][line:0933] match request: /sales/index.html <-> /sales/.

    <11:36:55>[SLB][DEBUG][line:1146] Match item id(1) match_object(2) ret = 0.

    ==> The 1st match object (URL) in the 2nd HTTP content-routing policy matched

    <11:36:55>[ZTNA_RULE][INFO] Client cert issuer common name: FCTEMS8822003003

    <11:36:55>[ZTNA_RULE][INFO] Client cert subject common name: CA0EF982B9604702862F95798F73C060

    <11:36:55>[ZTNA_RULE][INFO] Check ZTNA rule EMS tag: FCTEMS8822003003_Tag_Sales

    <11:36:55>[ZTNA_RULE][INFO] Check ZTNA rule EMS tag: FCTEMS8822003003_all_registered_clients

    <11:36:55>[SLB][DEBUG][line:0875] matched ztna ems tag

    <11:36:55>[SLB][DEBUG][line:1146] Match item id(2) match_object(13) ret = 0.

    ==> The 2st match object (ZTNA Tags) in the 2nd HTTP content-routing policy matched

    <11:36:55>[SLB][DEBUG][line:1375] Hit content routing (CR_Policy_Sales).

    ==> The 2nd HTTP content-routing policy matched

    <11:36:55>[SLB][DEBUG][line:0514]

    <11:36:55>[SLB][DEBUG][line:0515] Prepare to run slb in pool

    <11:36:55>[SLB][DEBUG][line:0126] scheduler_rr: server_count=1, backup =0

    <11:36:55>[SLB][DEBUG][line:0058] ----------------Assign server ---------------

    <11:36:55>[SLB][DEBUG][line:0061] Assign server IP: 10.65.1.66

    <11:36:55>[SLB][DEBUG][line:0068] Assign server port 80

    <11:36:55>[SLB][DEBUG][line:0070] Connection Number 1

    <11:36:55>[SLB][DEBUG][line:0072] ----------------Assign server finished---------------

    <11:36:55>[ZTNA_RULE][INFO] Enter ZTNA rule match

    <11:36:55>[ZTNA_RULE][INFO] Client cert issuer common name: FCTEMS8822003003

    <11:36:55>[ZTNA_RULE][INFO] Client cert subject common name: CA0EF982B9604702862F95798F73C060

    <11:36:55>[ZTNA_RULE][INFO] ZTNA rule ztna_rule_03 match begin

    <11:36:55>[ZTNA_RULE][INFO] ===Check source address===: 10.65.1.63

    <11:36:55>[ZTNA_RULE][INFO] Matched ztna source addr condition 1

    <11:36:55>[ZTNA_RULE][INFO] ===Check GEO===: Unknown Country/Region

    <11:36:55>[ZTNA_RULE][INFO] Matched ztna geo condition 1

    <11:36:55>[ZTNA_RULE][INFO] ===Check EMS Tags===: client ems tags: 4, ems tag rule: 1

    <11:36:55>[ZTNA_RULE][INFO] Check ZTNA ems tag condition 1

    <11:36:55>[ZTNA_RULE][INFO] Check ZTNA rule EMS tag: FCTEMS8822003003_High

    <11:36:55>[ZTNA_RULE][INFO] Matched ztna ems tags condition 1

    <11:36:55>[ZTNA_RULE][INFO] ZTNA rule ztna_rule_03 match finish, matched

    <11:36:55>[ZTNA_RULE][INFO] Matched ztna-profile ztna_profile_02, ztna-rule ztna_rule_03, action 1

    ==> After HTTP content-routing policy matched, ZTNA profile/rule also matched

    Example 3: When an incorrect client certificate is selected

    <12:53: 6>[ZTNA_RULE][INFO] Client cert issuer common name: FCTEMS8822002977

    <12:53: 6>[ZTNA_RULE][INFO] Client cert subject common name: CA0EF982B9604702862F95798F73C060

    <12:53: 6>[ZTNA_THREAD][ERR] ztna get client tags from db failed, uid: CA0EF982B9604702862F95798F73C060, sn: FCTEMS8822002977

    <12:53: 6>[ZTNA_RULE][DEBUG] Cannot get client ems tags or no ems tags

    ==> ZTNA fails to get the client tags from database due to failing to fetch the corresponding UID from the client certificate.

  4. Sometimes you may find even if a tag is removed on FortiClient EMS, and the tag has been removed from the client displayed in diagnose system endpoint clients, it will still be matched in ZTNA rule.

    You may wait for one more minute and check the result again. In current implementation, there is a time gap between tags synchronized from FortiClient EMS to FortiWeb redis db and tags synchronized from redis db to proxyd cache. Proxyd sync interval is 60 seconds. It means that even if you see the tag is removed in diagnose system endpoint clients, this change will take more time to update to Proxyd.

ZTNA Access Control issues 3 - Source IP or GEO IP are not matched in ZTNA rules

Source IP and GEO IP can be configured as conditions in a ZTNA rule. This improves the flexibility of ZTNA rules.

There are several tips when using Source IP or GEO IP rather than ZTNA Tags as a condition:

  • The source IP to be matched is the source IP in the IP header of the request packet sent to FortiWeb, not the IP field in the endpoint information

  • IP addresses in X-Forward-For headers will not be matched

You can enable diagnose debug logs to check process details.

ZTNA issues in HA environment

In HA deployment, only the primary FortiWeb connects to FortiClient EMS and keeps pulling ZTNA tags and clients information from it, and then synchronizes these information to the secondary nodes.

In Active-Passive mode, only the primary FortiWeb processes ZTNA traffic, so if there is any issue, you just needs to troubleshoot on the primary node according to above methods.

In Active-Active standard and Active-Active high volume HA modes, the situation is a little different - both the primary and secondary nodes may process ZTNA traffic. So when issues occur, you also need to consider troubleshooting on secondary nodes.

  1. Make sure that HA status is stable and configuration are synchronized among all HA nodes;
  2. In Active-Active standard and Active-Active high volume HA modes, makes that server policy works well without ZTNA profile;
  3. Check fcnacd diagnose logs to guarantee only the primary node communicates with FortiClient EMS;
  4. Check if all endpoint clients information are synchronized among all HA nodes;
  5. If the clients information are not synchronized among all HA nodes, or new client information cannot be synchronized from FortiClient EMS after HA failover, check with below points:
    • Check if redis processes are working properly:

      On the primary node, redis-server is working on 169.254.0.1:6389

      # ps | grep redis-server | grep 6389

      29158 root 55448 S /bin/redis-server 169.254.0.1:6389

      On secondary nodes, redis-server is working on 169.254.0.2, 169.254.0.3 or other IP:

      # ps | grep redis-server | grep 6389

      22682 root 128m S /bin/redis-server 169.254.0.2:6389

    • Check fcsync logs to see if there is any sync issues among HA nodes:

      # diagnose debug application fcsync 7

      # diagnose debug enable

      For more details, log in to the backend shell, check the output in /var/log/debug/fcsync_log or copy it to /var/log/gui_upload and download it via GUI for further checking.

      E.g. when secondary HA node switches to be the primary role, fcsync will monitor this event and re-initiate redis service and db sync process

      /# tail -f /var/log/debug/fcsync_log

      * Thu Aug 11 17:44:00 2022 : dbsync_msg_act.c[ 26]: <--- fcsync ---> recv msg from confd_ha, ha mode change, old role:2 new member id is:1

      * Thu Aug 11 17:44:00 2022 : main.c [ 283]: running mode changed, old mode:2

      * Thu Aug 11 17:44:00 2022 : main.c [ 182]: release cmdb poll:7 for fcsync

      * Thu Aug 11 17:44:00 2022 : main.c [ 189]: release sync msg poll:9 for fcsync

      * Thu Aug 11 17:44:02 2022 : main.c [ 368]: <--- fcsync 0 ---> start pid:25360

      * Thu Aug 11 17:44:02 2022 : main.c [ 143]: init cmdb poll:7 for fcsync

      * Thu Aug 11 17:44:02 2022 : main.c [ 155]: init trans poll for fcsync

      * Thu Aug 11 17:44:02 2022 : main.c [ 170]: init config for fcsync

      * Thu Aug 11 17:44:02 2022 : main.c [ 230]: <--- fcsync 1 ---> ha_mode:1 pid:25360

      * Thu Aug 11 17:44:02 2022 : main.c [ 257]: <--- fcsync 2 ---> ha role:1

      * Thu Aug 11 17:44:02 2022 : main.c [ 258]: AP mode, role is 1, unknown:0 master:1, slave:2

      * Thu Aug 11 17:44:02 2022 : dbsync_redis.c [ 377]: <--- fcsync ---> dbsync_change_to_master:377 change to master

      * Thu Aug 11 17:44:02 2022 : dbsync_redis.c [ 147]: old config:<bind 169.254.0.2 127.0.0.1

      > new config:<bind 169.254.0.1 127.0.0.1

      * Thu Aug 11 17:44:02 2022 : dbsync_redis.c [ 385]: dbsync_change_to_master:385 restart_daemon change[3]

      * Thu Aug 11 17:44:04 2022 : dbsync_redis.c [ 352]: s_pid:29158 root 52888 S /bin/redis-server 169.254.0.1:6389

      Notes: Collect /var/log/debug/fcsync_log and /etc/redis/redis_6389.conf on both primary node and secondary nodes for support team analysis.

ZTNA troubleshooting and debugging

Common troubleshooting issues

As FortiWeb ZTNA solution is integrated with FortiWeb, FortiClient and FortiClient EMS, issue troubleshooting sometimes needs checking on all these three components.

There are several ways or steps for ZTNA related issues troubleshooting:

  1. Check if FortiWeb is connected to EMS;
  2. Check if Tags and endpoint client information are synchronized to FortiWeb:
    • Compare information between FortiWeb and EMS
    • Check Event logs to see configuration or EMS data sync failures
    • Check diagnose log or fcnacd.log
  3. Check if the daemon fcnacd & fcsync are stable:
    • Check if pid changes
    • Check if there is any daemon coredump file under /var/log/gui_upload
  4. If browsers do not prompt selecting client certificate:
    • Check on FortiClient endpoint to see if certificate is signed successfully
    • Check client certificate verification configuration on FortiWeb
  5. If ZTNA rule/tag matching does not meet expectation:
    • If a visit is blocked, check Attack logs to see if any if it’s caused by ZTNA violation;
    • Check ZTNA or HTTP content-routing related diagnose logs to see processing details
  6. If the issue need further investigation, please collect below logs:
    • /var/log/debug/fcnacd.log and /var/log/debug/fcsync_log
    • Configuration file
    • Client information from “diagnose system endpoint-control clients”

ZTNA related diagnose logs:

# diagnose debug application ztna 7

# diagnose debug proxy svr-balance 7

# diagnose debug proxy thread-ztna-sync 7

# diagnose debug timestamp enable

# diagnose debug enable

Currently FortiWeb does not have very rich ZTNA logs. Here we list the related Event/Attack/Traffic logs as below:

  1. Event logs:
    • EMS/fctems configuration changes;
    • Tag sync > Add/delete tag configuration;
    • Sync data success/failure > caused by EMS connect/disconnect
  2. Attack logs:
    • HTTP Connection Failure logs when client certificate verification failed
    • Zero Trust Access logs when traffic matches ZTNA rule with Action Alert_Deny by ZTNA, or matches the default Action Alert_Deny of ZTNA profile;
    • No attack logs when ZTNA rule/profile is matched and the Action is Accept or Deny (No log)
    • No attack logs when ZTNA tags are matched or not matched in HTTP content-routing policy
  3. Traffic logs:

    When ZTNA profile/rule is matched and the Action is Accept, there will be a traffic log, but currently no ZTNA information within it.

FortiClient EMS connection issues

  • Check the network and FortiClient EMS port accessibility on FortiWeb:

    • Ping the IP address or the Domain Name of the FortiClient EMS;

      Note: only IPv4 & Domain Name are supported; IPv6 is not supported by FortiClient EMS

    • Use execute telnettest command to check if EMS service is reachable:

      FWB # execute telnettest 10.65.1.98:443

      Connected

  • Use execute & diagnose commands to check FortiClient EMS status on FortiWeb:

    • Run execute fctems is-verified <EMS>

      FWB-91 # execute fctems is-verified EMS95

      Configured FortiClient EMS has not been verified.

      This message means that the FortiClient EMS certificate has not been verified by FortiWeb yet. You need to verify it via execute fctems verify <EMS> or click Authorize on GUI.

      FWB # execute fctems is-verified EMS95

      Configured FortiClient EMS has been verified.

      This status means that the FortiClient EMS certificate has been verified by FortiWeb, while FortiWeb is not necessarily authorized by EMS.

      Once the FortiClient EMS has been verified, the system will add configuration of fingerprint and EMS_SN as below:

      config system endpoint-control fctems

      edit "EMS95"

      set server 10.0.10.95

      set capabilities fabric-auth silent-approval websocket websocket-malware push-ca-certs

      set fingerprint B7:0B:6E:A4:7A:8F:7F:2F:E1:4A:18:F4:0E:34:65:C8:F0:A6:A7:F7:C7:D2:60:43:A5:49:A0:F6:35:EA:A1:C3:85:87:E1:15:95:B3:12:42:D3:80:96:50:10:EA:1C:2C:49:85:DC:F1:B5:EB:10:24:5A:61:A7:37:E8:64:31:CF

      set EMS_SN FCTEMS8822003349

      next

      end

    • Run diagnose system endpoint-control test <EMS>

      FWB # diagnose system endpoint-control test EMS95

      Connection test had an error -3: EMS server connection failed. Authentication denied

      #This message indicates FortiWeb has not been authorized, or denied by FortiClient EMS, or the EMS certificate has not been verified by FortiWeb. When adding a new FortiClient EMS connector, FortiWeb and FortiClient EMS need to verify/authorize each other.

  • Check the FortiClient EMS status and failure reasons on FortiWeb or FortiClient EMS GUI:

    • The EMS status will be shown with a question mark if FortiClient EMS fabric connection has not been established:

    • Check the FortiClient EMS status with failure reasons in the Edit page.

      auth_pending: It means FortiWeb has not been authorized by FortiClient EMS, or the FortiClient EMS certificate has not been verified by FortiWeb.

      auth_deny: It means FortiWeb authorization has been denied by FortiClient EMS.

      cert_unauthorzied: It means FortiClient EMS certificate has not been verified by FortiWeb, but FortiWeb has been authorized by EMS.

      cert_unknown: It means FortiClient EMS certificate cannot be retrieved, which is usually caused by the EMS IP/Domain or Port is not reachable.

ZTNA Tags sync issues

Normally, ZTNA tags created on FortiClient EMS will be synchronized in a few seconds after FortiClient EMS connection is established. If new tags or tag changes (e.g. delete) are not updated correctly to FortiWeb, please follow these steps to troubleshoot:

  1. Use the methods in section “Check FortiClient EMS connection issues” to confirm if FortiClient EMS is connected successfully and stably.
  2. Add a new Zero Trust Tagging rule on FortiClient EMS, check if the new tag can be synchronized to FortiWeb or not.
  3. Check if the daemon fcnacd is stable:
    • Execute “fn pidof fcnacd” several times to check if the pid changes

    • Check /var/log/gui_upload to see if there is any fcnacd or fcsync coredump files

  4. Enable diagnose log on FortiWeb to check the sync details.

    # diagnose debug application fcnacd 7 #communication logs between FortiWeb & EMS

    # diagnose debug enable

    E.g. check the output of api/v1/report/fct/host_tags for a successful tag sync process:

    : [2022-08-09-23:34:10] [ec_ems_context_submit_work:431] Call submitted successfully.

    obj-id: 10, desc: REST API to get updates about host tags., entry: api/v1/report/fct/host_tags.

    : [2022-08-09-23:34:10] [ec_ez_worker_process:273] Processing call for obj-id: 10, entry: "api/v1/report/fct/host_tags"

    : [2022-08-09-23:34:10] [ec_ez_worker_process:348] Call completed successfully.

    obj-id: 10, desc: "REST API to get updates about host tags.", entry: "api/v1/report/fct/host_tags".

    For more detailed fcnacd logs, please download /var/log/debug/fcnacd.log.

    Login to the backend shell, check the output in /var/log/debug/fcnacd.log or copy it to /var/log/gui_upload and download it via GUI for further checking.

    Check the output of api/v1/report/fct/host_tags to see if tags are included in the json content:

    E.g. check the output of api/v1/report/fct/host_tags for a successful tag sync process:

    : [2022-08-10-00:38:37] [ec_ez_worker_prep_data_url:177] Full URL: HTTPs://10.65.1.99/api/v1/report/fct/host_tags?&updated_after=2022-06-29%2006%3A47%3A03%2E5700870&send_mac=true

    : [2022-08-10-00:38:37] [ec_ems_context_submit_work:431] Call submitted successfully.

    obj-id: 10, desc: REST API to get updates about host tags., entry: api/v1/report/fct/host_tags.

    : [2022-08-10-00:38:37] [ec_ez_worker_process:273] Processing call for obj-id: 10, entry: "api/v1/report/fct/host_tags"

    : [2022-08-10-00:38:37] [ec_ez_worker_process:293] reply:

    """

    {"result": {"retval": 1, "message": null}, "data": {"is_final": true, "updated_after": "2022-06-29 06:47:03.5700870", "is_zipped": true, "unzipped_size": 474, "data": "eJxlkM1ugzAQhF8l8jmpHMpP4JYYUCs1itT21IvlwJKsajCyTdoo4t0LMhVVetrZb6z1zt4IGm4a0ZqzsiSphDSwJFacODaVIsmNCCm5hhMaCxpKXkiExprB6ZfkRX05sYcSu9rpJzydnWIaLRZCuu4DtFqV4rpIwUJhUTXTlOcDW7x1psUCVTex1+yCkg/O9Le+8k+43nuFtvcIvsGhrSs7V96HRHHMqTe1YCwfGV3Pfi6OGgt+aP6jqppZCpe52Qs5r927y9VQH0FPQTos+QjlEOIP+r1uEIUs2O5YmLHMj9guztZplucbj1E/8NNwfHNWw7LjjK4thQVusR4yEo963oqGKy9e0DDxo4Q+PgQRpZuIkr7vfwAn/pyS"}}

    """

    : [2022-08-10-00:38:37] [fcems_json_unzip:267] unzipped:

    """

    {"is_snapshot":false,"tag_info":{"all_registered_clients":{},"Low":{},"Medium":{},"High":{},"Critical":{},"Zero-day Detections":{},"IOC Suspicious":{},"REvil_IOC_registry_key":{},"REvil_IOC_crt":{},"REvil_IOC_exe":{},"A":{},"B":{},"Tag_99_02":{},"Test_Tag_01":{},"Tag_Fabric_On":{},"Tag_Fabric_Off":{},"Tag_Dev":{},"Tag_Malicious":{}},"tag_members":{},"uid_tag_lists":{},"uid_info":{"576C5ABC6ECE47CB9E1DEFF82C0454D6":{"host_tag_update_time":"2022-06-29 06:47:03.5700870"}}}

    """

    : [2022-08-10-00:38:37] [ec_ez_worker_process:348] Call completed successfully.

    obj-id: 10, desc: "REST API to get updates about host tags.", entry: "api/v1/report/fct/host_tags".

    All EMS tags are synchronized and contained in the above unzipped json content. You can check if the newly-added tag is included or the removed tag is NOT included. If the new tag is NOT included, you may check if it is an EMS problem rather than a FortiWeb issue.

    To improve the readability, the above json content is transferred with a json formatter and simplified:

    {

    "tag_info":{

    "Test_Tag_01":{

    },

    "Tag_Fabric_On":{

    },

    "Tag_Fabric_Off":{

    },

    "Tag_Dev":{

    },

    "Tag_Malicious":{

    }

    },

    "uid_info":{

    "576C5ABC6ECE47CB9E1DEFF82C0454D6":{

    "host_tag_update_time":"2022-06-29 06:47:03.5700870"

    }

    }

    }

  5. Particularly, if you are deleting a tag, please double confirm not only the tagging rule is deleted, but also the tag is deleted in “Manage Tags” in FortiClient EMS.
  6. A tag referenced in a ZTNA rule or HTTP Content-routing policy will NOT be removed from FortiWeb immediately after the tag is removed from FortiClient EMS.

    Only if the tag is removed from ZTNA rule or HTTP Content-routing policy, it will be removed by FortiWeb automatically;

    FortiWeb will check if a current tag saved in configuration is used or not in each tag sync cycle. When the system boots up, if it has been removed from FortiClient EMS and not used in any ZTNA rule or HTTP Content-routing policy any more, the tag will be deleted.

Endpoint client information sync issues

Information of all endpoint clients registered to the FortiClient EMS will be synchronized to FortiWeb. If you find that an endpoint is not synchronized or information changes are not updated to FortiWeb, please follow the below steps for troubleshooting:

  1. Check diagnose system endpoint client on FortiWeb to see if the client information is up-to-date:

    You can add filters to search a specific endpoint client:

    FortiWeb # diagnose system endpoint-control clients <IP> <MAC> <FCT_SN>

    Each filter option can be set as “any” for all.

  2. Compare client info on FortiWeb with the endpoint info shown in FortiClient EMS Endpoints > All Endpoints, and that displayed in FortiClient.
  3. Pay attention to the circled info: EMS SN, FortiClient ID / UID, IP and Tags.

    If Show Zero Trust Tag on FortiClient GUI is enabled in FortiClient EMS Endpoint > Profiles > System Settings, you can also see the ZTNA tags on the FortiClient.

  4. If there is no Endpoint information or some information is not up-to-date on FortiWeb, check if FortiClient EMS is connected successfully and stably first, with the methods mentioned in section "Check FortiClient EMS connection issues".
  5. Check if the daemon fcnacd is stable:
    1. Execute fn pidof fcnacd several times to check if the pid changes.
    2. Check /var/log/gui_upload to see if there is any fcnacd or fcsync coredump files.
  6. If FortiClient EMS is connected while client information is not updated, enable diagnose log on FortiWeb to check if there is any sync failure.
  7. # diagnose debug application fcnacd 7 #communication logs between FortiWeb & EMS

    # diagnose debug enable

    E.g. check the output of api/v1/report/fct/uid_tags to see if the tag changes is reflected in logs:

    : [2022-08-09-23:34:10] [ec_ems_context_submit_work:431] Call submitted successfully.

    obj-id: 12, desc: REST API to get updates of tags associated with FCT UID., entry: api/v1/report/fct/uid_tags.

    : [2022-08-09-23:34:10] [ec_ez_worker_process:273] Processing call for obj-id: 12, entry: "api/v1/report/fct/uid_tags"

    : [2022-08-09-23:34:10] [ec_ez_worker_process:348] Call completed successfully.

    obj-id: 12, desc: "REST API to get updates of tags associated with FCT UID.", entry: "api/v1/report/fct/uid_tags".

    For more detailed fcnacd logs, please download /var/log/debug/fcnacd.log.

  8. Log in to the backend shell, check output in /var/log/debug/fcnacd.log or copy it to /var/log/gui_upload and download it via GUI for further checking.

    Particularly when you find tags are not updated to a specific client, check the output of api/v1/report/fct/uid_tags to see if tags are included in the json content:

    E.g. the output of api/v1/report/fct/uid_tags below is when a new tag “” is applied to the client, UID CA0EF982B9604702862F95798F73C060::

    : [2022-08-10-14:08:47] [ec_ez_worker_prep_data_url:177] Full URL: HTTPs://10.65.1.99/api/v1/report/fct/uid_tags?&updated_after=2022-08-10%2020%3A28%3A25%2E7803527&uid_offset=CA0EF982B9604702862F95798F73C060&send_mac=true

    : [2022-08-10-14:08:47] [ec_ems_context_submit_work:431] Call submitted successfully.

    obj-id: 12, desc: REST API to get updates of tags associated with FCT UID., entry: api/v1/report/fct/uid_tags.

    : [2022-08-10-14:08:47] [ec_ez_worker_process:273] Processing call for obj-id: 12, entry: "api/v1/report/fct/uid_tags"

    : [2022-08-10-14:08:47] [ec_ez_worker_process:293] reply:

    """

    {"result": {"retval": 1, "message": null}, "data": {"uid_offset": "CA0EF982B9604702862F95798F73C060", "updated_after": "2022-08-10 21:08:41.8294435", "is_zipped": true, "is_final": true, "unzipped_size": 558, "data": "eJxl0T1vGzEMBuC/Umg2C4oi9eFNH6epQJduRXG4xEJygO0E9iUdjPvvVbyduwkQ30cieVMf82FcppfxOF+Xq9rfVI441OApBYvskLylGsQFX53JaPGr5tROT+3Sy3/f1Fe4I2qvtFDWlCMUwxY4uwihFgOOxIoZKDJntbsHztOp9URU624jJGtqQgG07LsQLUSLESRSEpsDc7VbIT0I/YvinTBELgm4aAMxmQBWUuCQK2nSW2E6HsdLe+ntt0s7jM/HuZ37JLasd/1tHgwEtNJZNpCSGDAua4em2OTqlv3Vj3V6uszP48/zg1aISAg1RJP7oFxA8MFoGJJLLHEIgfz/WmmfD84gyJkoQfbEwFQqpOgQUCSWkEqWULbOj7e/av2zU69v1+W+9o/3w7S0cZnv14REgB40fiO9R79n/d1Tb92IWtf1H0gJmbU="}}

    """

    : [2022-08-10-14:08:47] [fcems_json_unzip:267] unzipped:

    """

    {"uid_tag_lists":{"CA0EF982B9604702862F95798F73C060":{"members":[{"tag_uid":"152C12CA-D346-4C7A-9FD3-725653E2A44C","tag_name":"A"},{"tag_uid":"1B63FB05-0648-4CA6-A60A-5A2B56C944F6","tag_name":"B"},{"tag_uid":"3C058754-A4DB-4D13-AB39-65B949CF2121","tag_name":"all_registered_clients"},{"tag_uid":"879444E3-9065-4D43-BB53-37C1703D6B7F","tag_name":"Tag_Fabric_On"},{"tag_uid":"D2225201-A3C6-4790-8931-EB7B45AE9928","tag_name":"Tag_Dev"},{"tag_uid":"E504C22B-C824-42DF-BA70-055AD9BDC59D","tag_name":"Low"}],"host_tag_update_time":"2022-08-10 21:08:41.8294435"}}}

    """

    : [2022-08-10-14:08:47] [__handle_json_tag_list:93] Add 1 member tags for FCTEMS8822003003

    : [2022-08-10-14:08:47] [ec_ez_worker_process:348] Call completed successfully.

    obj-id: 12, desc: "REST API to get updates of tags associated with FCT UID.", entry: "api/v1/report/fct/uid_tags".

    All EMS tags applied to a specific client will be contained in the unzipped json content. One can check if the newly-added tag is included or the removed tag is NOT included. If the new tag is NOT included, one may check if it is an EMS problem rather than a FortiWeb issue.

    To improve the readability, the above json content is transferred with a json formatter and simplified:

    {

    "uid_tag_lists":{

    "CA0EF982B9604702862F95798F73C060":{

    "members":[

    {

    "tag_uid":"152C12CA-D346-4C7A-9FD3-725653E2A44C",

    "tag_name":"A"

    },

    {

    "tag_uid":"1B63FB05-0648-4CA6-A60A-5A2B56C944F6",

    "tag_name":"B"

    },

    {

    "tag_uid":"3C058754-A4DB-4D13-AB39-65B949CF2121",

    "tag_name":"all_registered_clients"

    },

    {

    "tag_uid":"879444E3-9065-4D43-BB53-37C1703D6B7F",

    "tag_name":"Tag_Fabric_On"

    },

    {

    "tag_uid":"D2225201-A3C6-4790-8931-EB7B45AE9928",

    "tag_name":"Tag_Dev"

    },

    {

    "tag_uid":"E504C22B-C824-42DF-BA70-055AD9BDC59D",

    "tag_name":"Low"

    }

    ],

    "host_tag_update_time":"2022-08-10 21:08:41.8294435"

    }

    }

    }

    You can only see the content of uid_tag_lists when tags applied to a client are changed, either added or removed. Without tag changes, the content of the uid_tag_lists will be empty:

    : [2022-08-10-14:08:53] [fcems_json_unzip:267] unzipped:

    """

    {"uid_tag_lists":{}}

    """

ZTNA Access Control issues 1 - browsers do not prompt certificate selecting

HTTPS with client certificate verification is a must when a ZTNA profile is applied to a server policy. So to use ZTNA, you need to create a certificate verification rule and select it in Advanced SSL settings > Certificate Verification for HTTPS, or enable SNI and select one in a SNI policy.

If the browser does not pop up the FortiClient certificate when you visiting a server policy, please follow these steps for troubleshooting:

  1. Check if the FortiWeb and server policy is reachable;
    • Disable ZTNA profile first and guarantee the server policy works without ZTNA;
    • Refer to "Diagnose server-policy connectivity issues" above for more troubleshooting methods
  2. Check if the client certificate is signed and stored on the FortiClient PC:
    • Confirm the FortiClient is connected to the correct FortiClient EMS;
  3. Check if the client certificate is available on the client PC;

    Use either of the below two ways to check:

    • Check if the client certificate is available in the browser storage:

    • Search & open “Manage user certificates” on the Client PC; the FortiClient certificate signed by FortiClient EMS should be seen in Personal certificate directory as below:

    Please note if the certificate is not available, it might be a FortiClient or FortiClient EMS issue. You can try to disconnect and reconnect the FortiClient EMS to see if a new certificate can be fetched. This process may take a few seconds or more than one minute.

  4. Check the SSL configuration on FortiWeb.

    If client certificate verification is not configured properly, the browser will not prompt certificate selecting.

    Pay attention to these configuration:

    • Confirm that the CA Group in Certificate Verify rule includes the correct CA certificate.

      This CA certificate is the FortiClient EMS CA certificate (ZTNA) that can be found in FortiClient EMS in System Settings > EMS Settings;

      This CA certificate is synchronized from FortiClient EMS and can be found on in FortiWeb Server Objects > Certificates > CA; the name is the EMS SN.

    • Similarly, if you configure a SNI policy instead of directly selecting a client certificate verify rule, please make sure the correct certificate verify rule is configured for the SNI policy.

ZTNA Access Control issues 2 - ZTNA tags are not matched as expected in ZTNA rules or HTTP Content-routing policy

When the client certificate is selected but ZTNA actions are not taken as expected, please troubleshoot from these aspects:

  1. Confirm the client certificate is correct:
    • When multiple certificates are prompted by the browser, confirm the correct certificate is selected.

      Only when the UID (FortiClient ID) and the FortiClient EMS SN match, tag searching may continue.

    • Do not click Cancel selecting the certificate on browser, otherwise SSL handshake will fail (when Strictly Require Client Certificate is enabled in the Client Certificate Verify rule), then tag matching cannot be processed.

  2. Confirm the Tags of the client match those configured in ZTNA rules:
    • Compare client information displayed in diagnose system endpoint client with that shown on FortiClient EMS or FortiClient; make sure that the key fields such as FortiClient ID/UID, EMS SN, IP, FCT_SN, and Tags are the same.

    • Check the tag name carefully. Tags displayed in diagnose system endpoint client should be the same with that configured in ZTNA rule and originally created on EMS

      • Tags shown on FortiWeb CLI has a prefix as the EMS_SN, but the prefix is not included in the diagnose output and FortiWeb GUI

      • Although FortiClient EMS and FortiWeb support almost all special characters as the tag name, we recommend using alphabet and numbers. Please examine and compare the tags carefully when you encounter tag matching failures.

  3. Enable diagnose debug logs to check the detailed ZTNA processing:

    # diagnose debug application ztna 7 #ZTNA rule matching logs

    # diagnose debug proxy svr-balance 7 #ZTNA server load balance logs

    # diagnose debug proxy thread-ztna-sync 7 #ZTNA endpoint sync logs

    # diagnose debug timestamp enable

    # diagnose debug enable

    Example 1: Server-policy + Certificate Verification + ZTNA Profile/Rule

    <11: 8: 2>[SLB][DEBUG][line:0514]

    <11: 8: 2>[SLB][DEBUG][line:0515] Prepare to run slb in pool

    <11: 8: 2>[SLB][DEBUG][line:0058] ----------------Assign server ---------------

    <11: 8: 2>[SLB][DEBUG][line:0061] Assign server IP: 2001:1234::a41:142

    <11: 8: 2>[SLB][DEBUG][line:0068] Assign server port 443

    <11: 8: 2>[SLB][DEBUG][line:0070] Connection Number 1

    <11: 8: 2>[SLB][DEBUG][line:0072] ----------------Assign server finished---------------

    <11: 8: 2>[ZTNA_RULE][INFO] Enter ZTNA rule match

    <11: 8: 2>[ZTNA_RULE][INFO] Client cert issuer common name: FCTEMS8822003003

    <11: 8: 2>[ZTNA_RULE][INFO] Client cert subject common name: CA0EF982B9604702862F95798F73C060

    ==> Certificate verification passed; start checking tags via UID fetched from certificate

    <11: 8: 2>[ZTNA_RULE][INFO] ZTNA rule ztna_rule_01 match begin

    <11: 8: 2>[ZTNA_RULE][INFO] ===Check GEO===: Unknown Country/Region

    <11: 8: 2>[ZTNA_RULE][INFO] Matched ztna geo condition 1

    <11: 8: 2>[ZTNA_RULE][INFO] ===Check EMS Tags===: client ems tags: 4, ems tag rule: 1

    <11: 8: 2>[ZTNA_RULE][INFO] Check ZTNA ems tag condition 1

    <11: 8: 2>[ZTNA_RULE][INFO] Check Client EMS tag: all_registered_clients

    <11: 8: 2>[ZTNA_RULE][INFO] Check Client EMS tag: Tag_Sales

    <11: 8: 2>[ZTNA_RULE][INFO] Check Client EMS tag: Tag_Fabric_On

    <11: 8: 2>[ZTNA_RULE][INFO] Check Client EMS tag: High

    <11: 8: 2>[ZTNA_RULE][INFO] Not matched any ztna ems tags condition

    <11: 8: 2>[ZTNA_RULE][INFO] ZTNA rule ztna_rule_01 match finish, not matched

    <11: 8: 2>[ZTNA_RULE][INFO] ZTNA rule ztna_rule_02 match begin

    <11: 8: 2>[ZTNA_RULE][INFO] ===Check source address===: 10.65.1.63

    <11: 8: 2>[ZTNA_RULE][INFO] Matched ztna source addr condition 1

    <11: 8: 2>[ZTNA_RULE][INFO] ===Check EMS Tags===: client ems tags: 4, ems tag rule: 1

    <11: 8: 2>[ZTNA_RULE][INFO] Check ZTNA ems tag condition 1

    <11: 8: 2>[ZTNA_RULE][INFO] Check ZTNA rule EMS tag: FCTEMS8822003003_Tag_Fabric_On

    <11: 8: 2>[ZTNA_RULE][INFO] Check ZTNA rule EMS tag: FCTEMS8822003003_Tag_Sales

    <11: 8: 2>[ZTNA_RULE][INFO] Matched ztna ems tags condition 1

    <11: 8: 2>[ZTNA_RULE][INFO] ZTNA rule ztna_rule_02 match finish, matched

    <11: 8: 2>[ZTNA_RULE][INFO] Matched ztna-profile ztna_profile_01, ztna-rule ztna_rule_02, action 1

    ==> Action Code: 1: Accept; 4: Deny (no log); 6: Alert & Deny

    Example 2: HTTP Content-routing policy + Certificate Verification + ZTNA Profile/Rule

    <11:36:55>[SLB][DEBUG][line:0825] HTTP Request URL : /sales/index.html

    <11:36:55>[ZTNA_RULE][INFO] Client cert issuer common name: FCTEMS8822003003

    <11:36:55>[ZTNA_RULE][INFO] Client cert subject common name: CA0EF982B9604702862F95798F73C060

    ==> Certificate verification passed; start checking tags via UID fetched from certificate

    <11:36:55>[ZTNA_RULE][INFO] Check ZTNA rule EMS tag: FCTEMS8822002977_all_registered_clients #The ZTNA Tag configured in the policy

    <11:36:55>[SLB][DEBUG][line:0878] not matched ztna ems tag

    <11:36:55>[SLB][DEBUG][line:1146] Match item id(2) match_object(13) ret = -1.

    ==> The 1st HTTP content-routing policy not matched due to tags are not matched

    <11:36:55>[SLB][DEBUG][line:0933] match request: /sales/index.html <-> /sales/.

    <11:36:55>[SLB][DEBUG][line:1146] Match item id(1) match_object(2) ret = 0.

    ==> The 1st match object (URL) in the 2nd HTTP content-routing policy matched

    <11:36:55>[ZTNA_RULE][INFO] Client cert issuer common name: FCTEMS8822003003

    <11:36:55>[ZTNA_RULE][INFO] Client cert subject common name: CA0EF982B9604702862F95798F73C060

    <11:36:55>[ZTNA_RULE][INFO] Check ZTNA rule EMS tag: FCTEMS8822003003_Tag_Sales

    <11:36:55>[ZTNA_RULE][INFO] Check ZTNA rule EMS tag: FCTEMS8822003003_all_registered_clients

    <11:36:55>[SLB][DEBUG][line:0875] matched ztna ems tag

    <11:36:55>[SLB][DEBUG][line:1146] Match item id(2) match_object(13) ret = 0.

    ==> The 2st match object (ZTNA Tags) in the 2nd HTTP content-routing policy matched

    <11:36:55>[SLB][DEBUG][line:1375] Hit content routing (CR_Policy_Sales).

    ==> The 2nd HTTP content-routing policy matched

    <11:36:55>[SLB][DEBUG][line:0514]

    <11:36:55>[SLB][DEBUG][line:0515] Prepare to run slb in pool

    <11:36:55>[SLB][DEBUG][line:0126] scheduler_rr: server_count=1, backup =0

    <11:36:55>[SLB][DEBUG][line:0058] ----------------Assign server ---------------

    <11:36:55>[SLB][DEBUG][line:0061] Assign server IP: 10.65.1.66

    <11:36:55>[SLB][DEBUG][line:0068] Assign server port 80

    <11:36:55>[SLB][DEBUG][line:0070] Connection Number 1

    <11:36:55>[SLB][DEBUG][line:0072] ----------------Assign server finished---------------

    <11:36:55>[ZTNA_RULE][INFO] Enter ZTNA rule match

    <11:36:55>[ZTNA_RULE][INFO] Client cert issuer common name: FCTEMS8822003003

    <11:36:55>[ZTNA_RULE][INFO] Client cert subject common name: CA0EF982B9604702862F95798F73C060

    <11:36:55>[ZTNA_RULE][INFO] ZTNA rule ztna_rule_03 match begin

    <11:36:55>[ZTNA_RULE][INFO] ===Check source address===: 10.65.1.63

    <11:36:55>[ZTNA_RULE][INFO] Matched ztna source addr condition 1

    <11:36:55>[ZTNA_RULE][INFO] ===Check GEO===: Unknown Country/Region

    <11:36:55>[ZTNA_RULE][INFO] Matched ztna geo condition 1

    <11:36:55>[ZTNA_RULE][INFO] ===Check EMS Tags===: client ems tags: 4, ems tag rule: 1

    <11:36:55>[ZTNA_RULE][INFO] Check ZTNA ems tag condition 1

    <11:36:55>[ZTNA_RULE][INFO] Check ZTNA rule EMS tag: FCTEMS8822003003_High

    <11:36:55>[ZTNA_RULE][INFO] Matched ztna ems tags condition 1

    <11:36:55>[ZTNA_RULE][INFO] ZTNA rule ztna_rule_03 match finish, matched

    <11:36:55>[ZTNA_RULE][INFO] Matched ztna-profile ztna_profile_02, ztna-rule ztna_rule_03, action 1

    ==> After HTTP content-routing policy matched, ZTNA profile/rule also matched

    Example 3: When an incorrect client certificate is selected

    <12:53: 6>[ZTNA_RULE][INFO] Client cert issuer common name: FCTEMS8822002977

    <12:53: 6>[ZTNA_RULE][INFO] Client cert subject common name: CA0EF982B9604702862F95798F73C060

    <12:53: 6>[ZTNA_THREAD][ERR] ztna get client tags from db failed, uid: CA0EF982B9604702862F95798F73C060, sn: FCTEMS8822002977

    <12:53: 6>[ZTNA_RULE][DEBUG] Cannot get client ems tags or no ems tags

    ==> ZTNA fails to get the client tags from database due to failing to fetch the corresponding UID from the client certificate.

  4. Sometimes you may find even if a tag is removed on FortiClient EMS, and the tag has been removed from the client displayed in diagnose system endpoint clients, it will still be matched in ZTNA rule.

    You may wait for one more minute and check the result again. In current implementation, there is a time gap between tags synchronized from FortiClient EMS to FortiWeb redis db and tags synchronized from redis db to proxyd cache. Proxyd sync interval is 60 seconds. It means that even if you see the tag is removed in diagnose system endpoint clients, this change will take more time to update to Proxyd.

ZTNA Access Control issues 3 - Source IP or GEO IP are not matched in ZTNA rules

Source IP and GEO IP can be configured as conditions in a ZTNA rule. This improves the flexibility of ZTNA rules.

There are several tips when using Source IP or GEO IP rather than ZTNA Tags as a condition:

  • The source IP to be matched is the source IP in the IP header of the request packet sent to FortiWeb, not the IP field in the endpoint information

  • IP addresses in X-Forward-For headers will not be matched

You can enable diagnose debug logs to check process details.

ZTNA issues in HA environment

In HA deployment, only the primary FortiWeb connects to FortiClient EMS and keeps pulling ZTNA tags and clients information from it, and then synchronizes these information to the secondary nodes.

In Active-Passive mode, only the primary FortiWeb processes ZTNA traffic, so if there is any issue, you just needs to troubleshoot on the primary node according to above methods.

In Active-Active standard and Active-Active high volume HA modes, the situation is a little different - both the primary and secondary nodes may process ZTNA traffic. So when issues occur, you also need to consider troubleshooting on secondary nodes.

  1. Make sure that HA status is stable and configuration are synchronized among all HA nodes;
  2. In Active-Active standard and Active-Active high volume HA modes, makes that server policy works well without ZTNA profile;
  3. Check fcnacd diagnose logs to guarantee only the primary node communicates with FortiClient EMS;
  4. Check if all endpoint clients information are synchronized among all HA nodes;
  5. If the clients information are not synchronized among all HA nodes, or new client information cannot be synchronized from FortiClient EMS after HA failover, check with below points:
    • Check if redis processes are working properly:

      On the primary node, redis-server is working on 169.254.0.1:6389

      # ps | grep redis-server | grep 6389

      29158 root 55448 S /bin/redis-server 169.254.0.1:6389

      On secondary nodes, redis-server is working on 169.254.0.2, 169.254.0.3 or other IP:

      # ps | grep redis-server | grep 6389

      22682 root 128m S /bin/redis-server 169.254.0.2:6389

    • Check fcsync logs to see if there is any sync issues among HA nodes:

      # diagnose debug application fcsync 7

      # diagnose debug enable

      For more details, log in to the backend shell, check the output in /var/log/debug/fcsync_log or copy it to /var/log/gui_upload and download it via GUI for further checking.

      E.g. when secondary HA node switches to be the primary role, fcsync will monitor this event and re-initiate redis service and db sync process

      /# tail -f /var/log/debug/fcsync_log

      * Thu Aug 11 17:44:00 2022 : dbsync_msg_act.c[ 26]: <--- fcsync ---> recv msg from confd_ha, ha mode change, old role:2 new member id is:1

      * Thu Aug 11 17:44:00 2022 : main.c [ 283]: running mode changed, old mode:2

      * Thu Aug 11 17:44:00 2022 : main.c [ 182]: release cmdb poll:7 for fcsync

      * Thu Aug 11 17:44:00 2022 : main.c [ 189]: release sync msg poll:9 for fcsync

      * Thu Aug 11 17:44:02 2022 : main.c [ 368]: <--- fcsync 0 ---> start pid:25360

      * Thu Aug 11 17:44:02 2022 : main.c [ 143]: init cmdb poll:7 for fcsync

      * Thu Aug 11 17:44:02 2022 : main.c [ 155]: init trans poll for fcsync

      * Thu Aug 11 17:44:02 2022 : main.c [ 170]: init config for fcsync

      * Thu Aug 11 17:44:02 2022 : main.c [ 230]: <--- fcsync 1 ---> ha_mode:1 pid:25360

      * Thu Aug 11 17:44:02 2022 : main.c [ 257]: <--- fcsync 2 ---> ha role:1

      * Thu Aug 11 17:44:02 2022 : main.c [ 258]: AP mode, role is 1, unknown:0 master:1, slave:2

      * Thu Aug 11 17:44:02 2022 : dbsync_redis.c [ 377]: <--- fcsync ---> dbsync_change_to_master:377 change to master

      * Thu Aug 11 17:44:02 2022 : dbsync_redis.c [ 147]: old config:<bind 169.254.0.2 127.0.0.1

      > new config:<bind 169.254.0.1 127.0.0.1

      * Thu Aug 11 17:44:02 2022 : dbsync_redis.c [ 385]: dbsync_change_to_master:385 restart_daemon change[3]

      * Thu Aug 11 17:44:04 2022 : dbsync_redis.c [ 352]: s_pid:29158 root 52888 S /bin/redis-server 169.254.0.1:6389

      Notes: Collect /var/log/debug/fcsync_log and /etc/redis/redis_6389.conf on both primary node and secondary nodes for support team analysis.