DNS issue with Tunnelers on Debian and Windows

1

I was trying to set up a demo using multiple VirtualBox VMs and my Windows Host system, but couldn’t get the overlay to work. On the Windows side, as it’s my corporate PC, I guess it could be an antivirus.
On all Linux and windows machines where the tunnelers are installed, the name webserver.ziti and datenbank.ziti can’t be resolved.
On the Debian machines it isn’t available in /etc/resolv.conf. Is there anything that needs to be done to allow the Tunneler to modify the resolv.conf file?
Thanks!

Windows:

> nslookup webserver.ziti 100.64.0.2
Server:  UnKnown
Address:  100.64.0.2

*** webserver.ziti wurde von UnKnown nicht gefunden: Non-existent domain.

> Get-DnsClientNrptRule


Name                             : {A925910B-9A0D-41A9-8D86-D5672548640D}
Version                          : 2
Namespace                        : {webserver.ziti}
IPsecCARestriction               :
DirectAccessDnsServers           :
DirectAccessEnabled              : False
DirectAccessProxyType            :
DirectAccessProxyName            :
DirectAccessQueryIPsecEncryption :
DirectAccessQueryIPsecRequired   :
NameServers                      : 100.64.0.2
DnsSecEnabled                    : False
DnsSecQueryIPsecEncryption       :
DnsSecQueryIPsecRequired         :
DnsSecValidationRequired         :
NameEncoding                     : Disable
DisplayName                      : ziti-edge-tunnel:webserver.ziti
Comment                          : Added by ziti-edge-tunnel

/etc/resolv.conf

# Generated by NetworkManager
search fritz.box
nameserver 172.31.134.110
nameserver 10.15.60.6
nameserver 192.168.178.1

Debian Logs:

Nov 25 10:16:58 webserver systemd[1]: Starting Ziti Edge Tunnel...
Nov 25 10:16:58 webserver ziti-edge-tunnel.sh[973]: NOTICE: no new JWT files in /opt/openziti/etc/identities/*.jwt
Nov 25 10:16:58 webserver systemd[1]: Started Ziti Edge Tunnel.
Nov 25 10:16:58 webserver ziti-edge-tunnel[976]: (976)[        0.000]    INFO ziti_log_set_level set log level: root=2
Nov 25 10:16:58 webserver ziti-edge-tunnel[976]: (976)[        0.090]    INFO ziti_log_set_level set log level: root=2

Windows Logs:

[2022-11-25T09:08:24.932Z]    INFO ziti-edge-tunnel:instance-config.c:86 load_tunnel_status_from_file() Loading config file from C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/config.json
[2022-11-25T09:08:24.933Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1879 run() ============================ service begins ================================
[2022-11-25T09:08:24.933Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1880 run() Logger initialization
[2022-11-25T09:08:24.933Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1881 run() 	- initialized at   : Fri Nov 25 2022, 10:08:24 AM (local time), 2022-11-25T09:08:24 (UTC)
[2022-11-25T09:08:24.933Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1882 run() 	- log file location: C:\Program Files (x86)\NetFoundry, Inc\Ziti Desktop Edge\/logs/service/ziti-tunneler.log.202211250000.log
[2022-11-25T09:08:24.933Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1883 run() ============================================================================
[2022-11-25T09:08:24.934Z]    INFO ziti_log_set_level set log level: root=4
[2022-11-25T09:08:24.936Z]    INFO ziti-edge-tunnel:tun.c:147 tun_open() Wintun v0.0 loaded
[2022-11-25T09:08:24.936Z]    INFO ziti-edge-tunnel:tun.c:496 cleanup_adapters() Cleaning up orphan wintun adapters
[2022-11-25T09:08:25.221Z]   DEBUG ziti-edge-tunnel:tun.c:375 if_change_cb() interface change: if_idx = 0, change = 3
[2022-11-25T09:08:25.221Z]    INFO ziti-edge-tunnel:tun.c:379 if_change_cb() default route is now via if_idx[10]
[2022-11-25T09:08:25.221Z]    INFO ziti-edge-tunnel:tun.c:385 if_change_cb() updating excluded routes
[2022-11-25T09:08:25.262Z]   DEBUG ziti-edge-tunnel:tun.c:351 tun_add_route() adding route: 100.64.0.0/10
[2022-11-25T09:08:25.262Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:444 is_nrpt_policies_effective() Executing add test nrpt rule. powershell -Command "Add-DnsClientNrptRule -Namespace '.ziti.test' -NameServers '100.64.0.2' -Comment 'Added by ziti-edge-tunnel' -DisplayName 'ziti-edge-tunnel:.ziti.test'"
[2022-11-25T09:08:25.264Z]   DEBUG ziti-edge-tunnel:tun.c:375 if_change_cb() interface change: if_idx = 15, change = 0
[2022-11-25T09:08:25.401Z]   DEBUG ziti-edge-tunnel:tun.c:375 if_change_cb() interface change: if_idx = 15, change = 0
[2022-11-25T09:08:25.404Z]   DEBUG ziti-edge-tunnel:tun.c:375 if_change_cb() interface change: if_idx = 15, change = 0
[2022-11-25T09:08:31.587Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:461 is_nrpt_policies_effective() test nrpt rule query returned 1 items
[2022-11-25T09:08:31.587Z]    INFO ziti-edge-tunnel:windows-scripts.c:469 is_nrpt_policies_effective() NRPT policies are effective in this system
[2022-11-25T09:08:31.587Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:430 remove_single_nrpt_rule() Executing Remove nrpt rule: powershell -Command "Get-DnsClientNrptRule | where Namespace -eq '.ziti.test' | Remove-DnsClientNrptRule -Force -ErrorAction SilentlyContinue"
[2022-11-25T09:08:34.760Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:435 remove_single_nrpt_rule() Removed nrpt rules
[2022-11-25T09:08:34.760Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1552 run_tunnel() Setting interface metric to 255
[2022-11-25T09:08:34.760Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:492 update_interface_metric() Executing Update Interface metric script :
[2022-11-25T09:08:34.760Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:493 update_interface_metric() powershell -Command "$i=Get-NetIPInterface | Where -FilterScript {$_.InterfaceAlias -Eq "ziti-tun0"}
Set-NetIPInterface -InterfaceIndex $i.ifIndex -InterfaceMetric 255"
[2022-11-25T09:08:34.763Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:499 update_interface_metric() Updated Interface metric
[2022-11-25T09:08:34.763Z]    INFO tunnel-sdk:ziti_tunnel.c:60 create_tunneler_ctx() Ziti Tunneler SDK (2.1.9)
[2022-11-25T09:08:34.769Z]   DEBUG ziti-edge-tunnel:tun.c:301 tun_setup_read() tun=0000025e71e68950, adapter=0000025e723e0860, session=0000025e723e0cc0
[2022-11-25T09:08:34.769Z]    INFO tunnel-cbs:ziti_dns.c:168 seed_dns() DNS configured with range 100.64.0.0 - 100.127.255.255 (4194302 ips)
[2022-11-25T09:08:34.770Z]   DEBUG tunnel-sdk:ziti_tunnel.c:320 ziti_tunneler_intercept() intercepting address[udp:100.64.0.2/32:53] service[ziti:dns-resolver]
[2022-11-25T09:08:34.770Z]   DEBUG ziti-edge-tunnel:tun.c:351 tun_add_route() adding route: 100.64.0.2/32
[2022-11-25T09:08:34.770Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1595 run_tunneler_loop() Loading identity files from C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry
[2022-11-25T09:08:34.770Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:1077 load_identities() skipping the configuration file: config.json
[2022-11-25T09:08:34.770Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:1080 load_identities() skipping the backup configuration file: config.json.backup
[2022-11-25T09:08:34.770Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1092 load_identities() loading identity file: dominik.json
[2022-11-25T09:08:34.770Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:1072 load_identities() skipping file in config dir as it's not the proper type. type: 2. file: ZitiUpdateService
[2022-11-25T09:08:34.772Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:515 update_symlink() Executing update symlink script :
[2022-11-25T09:08:34.772Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:516 update_symlink() powershell -Command "Get-Item -Path "C:\Program Files (x86)\NetFoundry, Inc\Ziti Desktop Edge\/logs/service/ziti-tunneler.log" | Remove-Item
New-Item -Itemtype SymbolicLink -Path "C:\Program Files (x86)\NetFoundry, Inc\Ziti Desktop Edge\/logs/service/ziti-tunneler.log" -Target "C:\Program Files (x86)\NetFoundry, Inc\Ziti Desktop Edge\/logs/service/ziti-tunneler.log.202211250000.log""
[2022-11-25T09:08:34.774Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:522 update_symlink() Updated symlink script
[2022-11-25T09:08:34.774Z]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:864 load_ziti_async() attempting to load ziti instance from file[C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/dominik.json]
[2022-11-25T09:08:34.774Z]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:871 load_ziti_async() loading ziti instance from C:\Windows\system32\config\systemprofile\AppData\Roaming\NetFoundry\dominik.json
[2022-11-25T09:08:34.775Z]    INFO ziti_log_set_level set log level: root=4
[2022-11-25T09:08:34.776Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1107 load_id_cb() identity[C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/dominik.json] loaded
[2022-11-25T09:08:34.777Z]   DEBUG ziti-edge-tunnel:instance-config.c:131 save_tunnel_status_to_file() Deleted backup config file C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/config.json.backup
[2022-11-25T09:08:34.777Z]   DEBUG ziti-edge-tunnel:instance-config.c:134 save_tunnel_status_to_file() Copied config file to backup config file C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/config.json.backup
[2022-11-25T09:08:34.778Z]   DEBUG ziti-edge-tunnel:instance-config.c:156 save_tunnel_status_to_file() Saved current tunnel status into Config file C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/config.json
[2022-11-25T09:08:34.778Z]    INFO ziti-sdk:ziti.c:426 ziti_init_async() ztx[0] Ziti C SDK version 0.30.8 @ecfee7b(HEAD) starting at (2022-11-25T09:08:34.778)
[2022-11-25T09:08:34.778Z]    INFO ziti-sdk:ziti.c:429 ziti_init_async() ztx[0] using uv_mbed[v0.14.11], tls[mbed TLS 3.2.1]
[2022-11-25T09:08:34.778Z]    INFO ziti-sdk:ziti.c:430 ziti_init_async() ztx[0] Loading from config[C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/dominik.json] controller[https://zt-controller:1280]
[2022-11-25T09:08:34.778Z]    INFO ziti-sdk:ziti_ctrl.c:407 ziti_ctrl_init() ctrl[zt-controller] ziti controller client initialized
[2022-11-25T09:08:34.778Z]   DEBUG ziti-sdk:ziti.c:452 ziti_init_async() ztx[0] using metrics interval: 0
[2022-11-25T09:08:34.778Z]   DEBUG ziti-sdk:ziti.c:259 ziti_set_unauthenticated() ztx[0] setting api_session_state[0] to 0
[2022-11-25T09:08:34.778Z]   DEBUG ziti-sdk:ziti_ctrl.c:244 ziti_ctrl_clear_api_session() ctrl[zt-controller] clearing api session token for ziti_controller
[2022-11-25T09:08:34.778Z]   DEBUG ziti-sdk:ziti.c:919 ziti_re_auth() ztx[0] re-auth executing, transitioning to unauthenticated
[2022-11-25T09:08:34.778Z]   DEBUG ziti-sdk:ziti.c:259 ziti_set_unauthenticated() ztx[0] setting api_session_state[0] to 0
[2022-11-25T09:08:34.778Z]   DEBUG ziti-sdk:ziti_ctrl.c:244 ziti_ctrl_clear_api_session() ctrl[zt-controller] clearing api session token for ziti_controller
[2022-11-25T09:08:34.778Z]   DEBUG ziti-sdk:ziti.c:290 is_api_session_expired() ztx[0] is_api_session_expired[TRUE] - api_session is null
[2022-11-25T09:08:34.778Z]    INFO ziti-sdk:ziti.c:866 ziti_re_auth_with_cb() ztx[0] starting to re-auth with ctlr[https://zt-controller:1280] api_session_status[0] api_session_expired[TRUE]
[2022-11-25T09:08:34.778Z]   DEBUG ziti-sdk:ziti.c:252 ziti_set_auth_started() ztx[0] setting api_session_state[0] to 1
[2022-11-25T09:08:34.778Z]   DEBUG ziti-sdk:ziti.c:324 ziti_stop_api_session_refresh() ztx[0] ziti_stop_api_session_refresh: stopping api session refresh
[2022-11-25T09:08:34.812Z]   DEBUG ziti-sdk:ziti_ctrl.c:324 ctrl_body_cb() ctrl[zt-controller] completed GET[/version] in 0.034 s
[2022-11-25T09:08:34.812Z]    INFO ziti-sdk:ziti.c:1532 version_cb() ztx[0] connected to controller https://zt-controller:1280 version v0.26.11(807dd591b1f5 2022-11-10T14:53:29Z)
[2022-11-25T09:08:34.813Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:708 on_events_client() Received events client connection request, count: 1
[2022-11-25T09:08:34.813Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:757 send_events_message() Events Message => {"Op":"status","Status":{"Active":true,"Duration":9881,"StartTime":"2022-11-25T09:08:24.932521Z","Identities":[{"Name":"dominik","Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/dominik.json","FingerPrint":"dominik","Active":true,"Loaded":true,"Config":{"ztAPI":"https://zt-controller:1280"},"ControllerVersion":"v0.26.11","IdFileStatus":true,"MfaEnabled":false,"MfaNeeded":false,"Metrics":{"Up":0,"Down":0},"MfaMinTimeout":0,"MfaMaxTimeout":0,"MfaMinTimeoutRem":0,"MfaMaxTimeoutRem":0,"MinTimeoutRemInSvcEvent":0,"MaxTimeoutRemInSvcEvent":0,"Deleted":false,"Notified":false}],"IpInfo":{"Ip":"100.64.0.1","Subnet":"255.192.0.0","MTU":65535,"DNS":"100.64.0.2"},"LogLevel":"debug","ServiceVersion":{"Version":"2.1.9","BuildDate":"Thu-11/10/2022-20:02:42-+00"},"TunIpv4":"100.64.0.1","TunIpv4Mask":10,"AddDns":false,"ApiPageSize":25}}
[2022-11-25T09:08:34.813Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:664 on_cmd_client() Received IPC client connection request, count: 1
[2022-11-25T09:08:34.838Z]   DEBUG ziti-sdk:ziti_ctrl.c:324 ctrl_body_cb() ctrl[zt-controller] completed POST[/authenticate?method=cert] in 0.059 s
[2022-11-25T09:08:34.838Z]   DEBUG ziti-sdk:ziti_ctrl.c:257 ctrl_login_cb() ctrl[zt-controller] authenticated successfully session[clawa73wu02r7cq3k8qu0ed5q]
[2022-11-25T09:08:34.838Z]   DEBUG ziti-sdk:ziti.c:1449 api_session_cb() ztx[0] logged in successfully => api_session[clawa73wu02r7cq3k8qu0ed5q]
[2022-11-25T09:08:34.838Z]   DEBUG ziti-sdk:ziti.c:1399 ziti_set_api_session() ztx[0] ziti api session expires in 1800 seconds
[2022-11-25T09:08:34.838Z]    INFO ziti-sdk:ziti.c:1423 ziti_set_api_session() ztx[0] api session set, setting api_session_timer to 1740s
[2022-11-25T09:08:34.838Z]   DEBUG ziti-sdk:ziti.c:329 ziti_schedule_api_session_refresh() ztx[0] ziti_schedule_api_session_refresh: scheduling api session refresh: 1740000ms
[2022-11-25T09:08:34.838Z]   DEBUG ziti-sdk:ziti.c:284 ziti_set_fully_authenticated() ztx[0] setting api_session_state[1] to 3
[2022-11-25T09:08:34.838Z]   DEBUG ziti-sdk:ziti.c:284 ziti_set_fully_authenticated() ztx[0] setting api_session_state[3] to 3
[2022-11-25T09:08:34.838Z]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:726 on_ziti_event() ziti_ctx[dominik] connected to controller
[2022-11-25T09:08:34.847Z]   DEBUG tunnel-sdk:ziti_tunnel.c:127 ziti_tunneler_exclude_route() excluding zt-controller from tunneler intercept
[2022-11-25T09:08:34.847Z]   DEBUG tunnel-sdk:ziti_tunnel.c:143 ziti_tunneler_exclude_route() 10.1.0.1 is a local address on VirtualBox Host-Only Network; not excluding route
[2022-11-25T09:08:34.847Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1137 on_event() ztx[C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/dominik.json] context event : status is OK
[2022-11-25T09:08:34.847Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:1189 on_event() ztx[C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/dominik.json] controller connected
[2022-11-25T09:08:34.847Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:757 send_events_message() Events Message => {"Op":"identity","Action":"added","Fingerprint":"dominik","Id":{"Name":"dominik","Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/dominik.json","FingerPrint":"dominik","Active":true,"Loaded":true,"Config":{"ztAPI":"https://zt-controller:1280"},"ControllerVersion":"v0.26.11","IdFileStatus":true,"MfaEnabled":false,"MfaNeeded":false,"Metrics":{"Up":0,"Down":0},"MfaMinTimeout":0,"MfaMaxTimeout":0,"MfaMinTimeoutRem":0,"MfaMaxTimeoutRem":0,"MinTimeoutRemInSvcEvent":0,"MaxTimeoutRemInSvcEvent":0,"Deleted":false,"Notified":false}}
[2022-11-25T09:08:34.847Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:757 send_events_message() Events Message => {"Op":"controller","Action":"connected","Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/dominik.json","Fingerprint":"dominik"}
[2022-11-25T09:08:34.847Z]   DEBUG ziti-sdk:ziti_ctrl.c:774 ctrl_paging_req() ctrl[zt-controller] starting paging request GET[/current-identity/edge-routers]
[2022-11-25T09:08:34.850Z]   DEBUG ziti-sdk:ziti_ctrl.c:324 ctrl_body_cb() ctrl[zt-controller] completed GET[/current-identity] in 0.012 s
[2022-11-25T09:08:34.852Z]   DEBUG ziti-sdk:ziti_ctrl.c:324 ctrl_body_cb() ctrl[zt-controller] completed GET[/current-identity] in 0.004 s
[2022-11-25T09:08:34.855Z]   DEBUG ziti-sdk:ziti_ctrl.c:324 ctrl_body_cb() ctrl[zt-controller] completed GET[/current-identity/edge-routers?limit=25&offset=0] in 0.007 s
[2022-11-25T09:08:34.855Z]   DEBUG ziti-sdk:ziti_ctrl.c:340 ctrl_body_cb() ctrl[zt-controller] received 1/1 for paging request GET[/current-identity/edge-routers]
[2022-11-25T09:08:34.855Z]   DEBUG ziti-sdk:ziti_ctrl.c:352 ctrl_body_cb() ctrl[zt-controller] completed paging request GET[/current-identity/edge-routers] in 0.007 s
[2022-11-25T09:08:34.859Z]    INFO ziti-sdk:channel.c:231 new_ziti_channel() ch[0] (zt-controller-edge-router@tls://zt-controller:8442) new channel for ztx[0] identity[dominik]
[2022-11-25T09:08:34.859Z]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:797 on_ziti_event() ztx[dominik] added edge router zt-controller-edge-router@tls://zt-controller:8442@zt-controller
[2022-11-25T09:08:34.867Z]   DEBUG tunnel-sdk:ziti_tunnel.c:127 ziti_tunneler_exclude_route() excluding zt-controller from tunneler intercept
[2022-11-25T09:08:34.867Z]   DEBUG tunnel-sdk:ziti_tunnel.c:143 ziti_tunneler_exclude_route() 10.1.0.1 is a local address on VirtualBox Host-Only Network; not excluding route
[2022-11-25T09:08:34.867Z]    INFO ziti-sdk:channel.c:742 reconnect_channel() ch[0] reconnecting NOW
[2022-11-25T09:08:34.867Z]   DEBUG ziti-sdk:channel.c:713 reconnect_cb() ch[0] connecting to zt-controller:8442
[2022-11-25T09:08:34.878Z]   DEBUG ziti-sdk:ziti_ctrl.c:324 ctrl_body_cb() ctrl[zt-controller] completed GET[/current-api-session/service-updates] in 0.029 s
[2022-11-25T09:08:34.878Z]   DEBUG ziti-sdk:ziti_ctrl.c:774 ctrl_paging_req() ctrl[zt-controller] starting paging request GET[/services]
[2022-11-25T09:08:34.881Z]   DEBUG ziti-sdk:ziti_ctrl.c:324 ctrl_body_cb() ctrl[zt-controller] completed GET[/services?limit=25&offset=0] in 0.002 s
[2022-11-25T09:08:34.881Z]   DEBUG ziti-sdk:ziti_ctrl.c:340 ctrl_body_cb() ctrl[zt-controller] received 1/1 for paging request GET[/services]
[2022-11-25T09:08:34.881Z]   DEBUG ziti-sdk:ziti_ctrl.c:352 ctrl_body_cb() ctrl[zt-controller] completed paging request GET[/services] in 0.002 s
[2022-11-25T09:08:34.881Z]   DEBUG ziti-sdk:ziti.c:1146 update_services() ztx[0] sending service event 1 added, 0 removed, 0 changed
[2022-11-25T09:08:34.881Z]   DEBUG tunnel-cbs:ziti_tunnel_ctrl.c:683 on_service() service[client_to_webserver]
[2022-11-25T09:08:34.881Z]    INFO tunnel-cbs:ziti_tunnel_cbs.c:403 new_ziti_intercept() creating intercept for service[client_to_webserver] with intercept.v1 = {"addresses":["webserver.ziti"],"dialOptions":{"connectTimeoutSeconds":5,"identity":""},"portRanges":[{"high":8080,"low":8080}],"protocols":["tcp"],"sourceIp":""}
[2022-11-25T09:08:34.881Z]    INFO tunnel-cbs:ziti_dns.c:296 new_ipv4_entry() registered DNS entry webserver.ziti -> 100.64.0.3
[2022-11-25T09:08:34.881Z]   DEBUG tunnel-sdk:ziti_tunnel.c:320 ziti_tunneler_intercept() intercepting address[tcp:100.64.0.3/32:8080] service[client_to_webserver]
[2022-11-25T09:08:34.881Z]   DEBUG ziti-edge-tunnel:tun.c:351 tun_add_route() adding route: 100.64.0.3/32
[2022-11-25T09:08:34.881Z]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:686 on_service() starting intercepting for service[client_to_webserver]
[2022-11-25T09:08:34.881Z]   DEBUG ziti-edge-tunnel:instance.c:258 setTunnelPostureDataTimeout() service[client_to_webserver] timeout=-1 timeoutRemaining=-1
[2022-11-25T09:08:34.881Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1262 on_event() =============== service event (added) - client_to_webserver:71lcuwaI1ukqLuUfCMcu03 ===============
[2022-11-25T09:08:34.881Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:171 chunked_add_nrpt_rules() Executing Add domains NRPT script :
[2022-11-25T09:08:34.881Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:172 chunked_add_nrpt_rules() powershell -Command "$Namespaces = @(
@{n='webserver.ziti';})

ForEach ($Namespace in $Namespaces) {
$ns=$Namespace['n']
$Rule = @{Namespace=${ns}; NameServers=@('100.64.0.2'); Comment='Added by ziti-edge-tunnel'; DisplayName='ziti-edge-tunnel:'+${ns}; }
Add-DnsClientNrptRule @Rule
}
"
[2022-11-25T09:08:34.884Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:178 chunked_add_nrpt_rules() Added domains using NRPT script
[2022-11-25T09:08:34.884Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:757 send_events_message() Events Message => {"Op":"bulkservice","Action":"updated","Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/dominik.json","Fingerprint":"dominik","AddedServices":[{"Id":"71lcuwaI1ukqLuUfCMcu03","Name":"client_to_webserver","Protocols":["tcp"],"Addresses":[{"IsHost":true,"HostName":"webserver.ziti","Prefix":0}],"Ports":[{"High":8080,"Low":8080}],"OwnsIntercept":true,"IsAccessible":true,"Timeout":-1,"TimeoutRemaining":-1}],"RemovedServices":[]}
[2022-11-25T09:08:34.884Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:757 send_events_message() Events Message => {"Op":"identity","Action":"updated","Fingerprint":"dominik","Id":{"Name":"dominik","Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/dominik.json","FingerPrint":"dominik","Active":true,"Loaded":true,"Config":{"ztAPI":"https://zt-controller:1280"},"ControllerVersion":"v0.26.11","IdFileStatus":true,"MfaEnabled":false,"MfaNeeded":false,"Services":[{"Id":"71lcuwaI1ukqLuUfCMcu03","Name":"client_to_webserver","Protocols":["tcp"],"Addresses":[{"IsHost":true,"HostName":"webserver.ziti","Prefix":0}],"Ports":[{"High":8080,"Low":8080}],"OwnsIntercept":true,"IsAccessible":true,"Timeout":-1,"TimeoutRemaining":-1}],"Metrics":{"Up":0,"Down":0},"MfaMinTimeout":-1,"MfaMaxTimeout":-1,"MfaMinTimeoutRem":-1,"MfaMaxTimeoutRem":-1,"MinTimeoutRemInSvcEvent":-1,"MaxTimeoutRemInSvcEvent":-1,"ServiceUpdatedTime":"2022-11-25T09:08:34.884913Z","Deleted":false,"Notified":false}}
[2022-11-25T09:08:34.903Z]   DEBUG ziti-sdk:channel.c:861 on_channel_connect_internal() ch[0] connected
[2022-11-25T09:08:34.904Z]    INFO ziti-sdk:channel.c:640 hello_reply_cb() ch[0] connected. EdgeRouter version: v0.26.11|807dd591b1f5|2022-11-10T14:53:29Z|linux|amd64
[2022-11-25T09:08:34.904Z]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:801 on_ziti_event() ztx[dominik] router zt-controller-edge-router@tls://zt-controller:8442 connected
[2022-11-25T09:08:34.922Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:708 on_events_client() Received events client connection request, count: 2
[2022-11-25T09:08:34.922Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:757 send_events_message() Events Message => {"Op":"status","Status":{"Active":true,"Duration":9990,"StartTime":"2022-11-25T09:08:24.932521Z","Identities":[{"Name":"dominik","Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/dominik.json","FingerPrint":"dominik","Active":true,"Loaded":true,"Config":{"ztAPI":"https://zt-controller:1280"},"ControllerVersion":"v0.26.11","IdFileStatus":true,"MfaEnabled":false,"MfaNeeded":false,"Services":[{"Id":"71lcuwaI1ukqLuUfCMcu03","Name":"client_to_webserver","Protocols":["tcp"],"Addresses":[{"IsHost":true,"HostName":"webserver.ziti","Prefix":0}],"Ports":[{"High":8080,"Low":8080}],"OwnsIntercept":true,"IsAccessible":true,"Timeout":-1,"TimeoutRemaining":-1}],"Metrics":{"Up":0,"Down":0},"MfaMinTimeout":-1,"MfaMaxTimeout":-1,"MfaMinTimeoutRem":-1,"MfaMaxTimeoutRem":-1,"MinTimeoutRemInSvcEvent":-1,"MaxTimeoutRemInSvcEvent":-1,"ServiceUpdatedTime":"2022-11-25T09:08:34.884913Z","Deleted":false,"Notified":false}],"IpInfo":{"Ip":"100.64.0.1","Subnet":"255.192.0.0","MTU":65535,"DNS":"100.64.0.2"},"LogLevel":"debug","ServiceVersion":{"Version":"2.1.9","BuildDate":"Thu-11/10/2022-20:02:42-+00"},"TunIpv4":"100.64.0.1","TunIpv4Mask":10,"AddDns":false,"ApiPageSize":25}}
[2022-11-25T09:08:34.922Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:664 on_cmd_client() Received IPC client connection request, count: 2
[2022-11-25T09:08:35.839Z]    INFO ziti-sdk:posture.c:204 ziti_send_posture_data() ztx[0] first run or potential controller restart detected
[2022-11-25T09:08:35.839Z]   DEBUG ziti-sdk:posture.c:208 ziti_send_posture_data() ztx[0] posture checks must_send set to TRUE, new_session_id[TRUE], must_send_every_time[TRUE], new_controller_instance[TRUE]
[2022-11-25T09:08:40.007Z]   DEBUG ziti-edge-tunnel:tun.c:375 if_change_cb() interface change: if_idx = 15, change = 0
[2022-11-25T09:08:44.885Z]   DEBUG ziti-sdk:ziti_ctrl.c:324 ctrl_body_cb() ctrl[zt-controller] completed GET[/current-api-session/service-updates] in 0.003 s
2

Hi @dmuensterer, it sounds to me like you’re saying dns intercepts are not working in either os? I’ve never seen that one yet.

Antivirus programs can cause problems. Particularly when they are terminating udp or tcp connections they think are questionable.

Neither of your logs have anything suspicious in them. The windows machine shows the proper entry in the nrpt. Do you have another VPN active? Dueling overlay technologies also can cause problems.

This is strange. It might be useful to get a feedback zip file from windows and the full set of logs from Linux at debug and mail them to support at OpenZiti.org

If you feel comfortable with advanced network debugging, you could try to watch the connections in Wireshark or tcpdump to see if they are behaving properly at layer 3. Does the nslookup make it to the interface etc… This one might be tricky

1 Like
3

Thanks! Let’s start with Linux because it’s a lot more transparent for me to debug.
I tried again on a fresh Debian 11 installation - the first start complains about missing resolve service:

Failed to flush caches: Unit dbus-org.freedesktop.resolve1.service not found.
(595770)[        0.184]   ERROR ziti-edge-tunnel:utils.c:31 run_command_va() cmd{/usr/bin/resolvectl flush-caches} failed: 256/11/Resource temporarily unavailable

Failed to set DNS configuration: Unit dbus-org.freedesktop.resolve1.service not found.
(595770)[       26.118]   ERROR ziti-edge-tunnel:utils.c:31 run_command_va() cmd{/usr/bin/resolvectl dns tun0 100.64.0.2} failed: 256/0/Success

Failed to get global data: Unit dbus-org.freedesktop.resolve1.service not found.
Call failed: Unit dbus-org.freedesktop.resolve1.service not found.
(595770)[       26.181]   ERROR ziti-edge-tunnel:utils.c:31 run_command_va() cmd{/usr/bin/busctl call org.freedesktop.resolve1 /org/freedesktop/resolve1 org.freedesktop.resolve1.Manager SetLinkDomains 'ia(sb)' 4 0} failed: 256/0/Success

After enabling and starting the service the errors are gone but there’s still no DNS entries in /etc/resolv.conf.
systemctl start systemd-resolved.service
Logs look like this:

pi@raspberrypi:/tmp $ sudo ziti-edge-tunnel run
(595933)[        0.000]    INFO tunnel-sdk:ziti_tunnel.c:60 create_tunneler_ctx() Ziti Tunneler SDK (v0.20.10)
(595933)[        0.000]    INFO tunnel-cbs:ziti_dns.c:171 seed_dns() DNS configured with range 100.64.0.0 - 100.127.255.255 (4194302 ips)
(595933)[        0.053]    INFO ziti-edge-tunnel:resolvers.c:67 init_libsystemd() Initializing libsystemd
(595933)[        0.053]   ERROR ziti-edge-tunnel:instance-config.c:136 save_tunnel_status_to_file() Could not copy config file [/var/lib/ziti/config.json] to backup config file, the config might not exists at the moment
(595933)[        0.053]   ERROR ziti-edge-tunnel:instance-config.c:142 save_tunnel_status_to_file() Could not open config file /var/lib/ziti/config.json to store the tunnel status data
(595933)[        0.054]    INFO ziti-edge-tunnel:resolvers.c:355 try_libsystemd_resolver() systemd-resolved selected as dns resolver manager

Any ideas?

4

An nslookup leaves me with
;; Got recursion not available from 100.64.0.2, trying next server

I’m unsure how I could proceed here. Looks like this is an internal ziti issue?

5

Those are all the logs?

You should be seeing messages like this - do you see them?

(189259)[        0.119]    INFO tunnel-cbs:ziti_dns.c:296 new_ipv4_entry() registered DNS entry http.ziti -> 100.64.0.3

Specifically this (replace http.ziti for your intercepted service config)

registered DNS entry http.ziti`

Once you see a message like that, nslookup should succeed.

If you're not seeing those - chances are your identity is not authorized for any dial services. Try running policy advisor:

ziti edge policy-advisor identities ${the_identity}

6

Thanks. Nope, I don’t see any DNS related messages.
When executing the policy advisor I get

OKAY : myidentity (1) -> myservice.svc (1) Common Routers: (1/1) Dial: Y Bind: N
7

That’s the complete output:

# systemctl status ziti-edge-tunnel.service 
● ziti-edge-tunnel.service - Ziti Edge Tunnel
   Loaded: loaded (/opt/openziti/share/ziti-edge-tunnel.service; enabled; vendor preset: enabled)
   Active: active (running) since Mon 2022-11-28 14:03:43 CET; 2s ago
  Process: 2817 ExecStartPre=/opt/openziti/bin/ziti-edge-tunnel.sh (code=exited, status=0/SUCCESS)
 Main PID: 2818 (ziti-edge-tunne)
    Tasks: 5 (limit: 4915)
   Memory: 33.3M
   CGroup: /system.slice/ziti-edge-tunnel.service
           └─2818 /opt/openziti/bin/ziti-edge-tunnel run --verbose=2 --dns-ip-range=100.64.0.1/10 --identity-dir=/opt/openziti/etc/identities

Nov 28 14:03:43 mss systemd[1]: Starting Ziti Edge Tunnel...
Nov 28 14:03:43 mss ziti-edge-tunnel.sh[2817]: NOTICE: no new JWT files in /opt/openziti/etc/identities/*.jwt
Nov 28 14:03:43 mss systemd[1]: Started Ziti Edge Tunnel.
Nov 28 14:03:43 mss ziti-edge-tunnel[2818]: (2818)[        0.000]    INFO ziti_log_set_level set log level: root=2
Nov 28 14:03:43 mss ziti-edge-tunnel[2818]: (2818)[        0.006]    INFO ziti_log_set_level set log level: root=2
8

Strange. And this is on any debian machine? Can you remind us again which version you're using? I don't think I saw it when looking back through this post? You're using the latest ziti-edge-tunnel I would assume as well? I think we'll have to try to replicate the behavior if we can here.

And this behavior is the same true for the Windows machine as well? On Windows you will need to specifically use the name server when using nslookup:

nslookup intercept.name 100.64.0.2

9

Jop, same behaviour on all Debian VMs - granted, they’re all the same.
Fresh Debian 11 install, newest ziti-edge-tunnel from the Ubuntu 20.04 repo.
Let me do some tests as well again, I’ll post the results here :slight_smile:

Thanks,
Dominik

10

Nope, can’t get it to work.
Is there a way I can find out in the client logs why there’s no DNS entry registration happening?

11

For the linux client, or windows? I'd start by running the tunneler at info (3, the default), debug (4), verbose (5) or trace (6) logging for more info. Debug is 'usually' enough info though.

If you grep through the logs for the service name, do you see anything at all? You should see stuff like:

#setup the service name for the grep i ran below:
service_name=http.svc

sudo ./ziti-edge-tunnel run -i ./http.client.json -v4 2>&1 | grep --color=auto "${service_name}"
(190052)[        0.126]   DEBUG tunnel-cbs:ziti_tunnel_ctrl.c:683 on_service() service[http.svc]
(190052)[        0.126]    INFO tunnel-cbs:ziti_tunnel_cbs.c:403 new_ziti_intercept() creating intercept for service[http.svc] with intercept.v1 = {"addresses":["http.ziti"],"portRanges":[{"high":80,"low":80}],"protocols":["tcp"]}
(190052)[        0.126]   DEBUG tunnel-sdk:ziti_tunnel.c:321 ziti_tunneler_intercept() intercepting address[tcp:100.64.0.3/32:80] service[http.svc]
(190052)[        0.126]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:686 on_service() starting intercepting for service[http.svc]
(190052)[        0.126]   DEBUG ziti-edge-tunnel:instance.c:258 setTunnelPostureDataTimeout() service[http.svc] timeout=-1 timeoutRemaining=-1
(190052)[        0.126]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1262 on_event() =============== service event (added) - http.svc:44GHTTayYXBMm8qqZNyzX4 ===============

You must see messages like the "on_service" shown:

on_service() service[http.svc]

If you're not seeing that service - are you sure this is the same/right identity? You definitely should see that. If you are seeing that, then after that I think we have to try to reproduce what you're seeing. I don't have the same problem so far which is disappointing, since it makes debugging harder for both of us!! :slight_smile:

12

Not sure what’s going on here! The identity is 100% the one that I am using but I don’t get it shown in the log.
That’s all I get without the grep:

/opt/openziti/bin/ziti-edge-tunnel run --verbose=6 --identity-dir=/opt/openziti/etc/identities
(3706)[        0.000]   TRACE ziti-edge-tunnel:instance-config.c:77 load_tunnel_status_from_file() config path exists at /var/lib/ziti
(3706)[        0.000]    INFO ziti-edge-tunnel:instance-config.c:86 load_tunnel_status_from_file() Loading config file from /var/lib/ziti/config.json
(3706)[        0.000]    INFO ziti_log_set_level set log level: root=2
(3706)[        0.005]    INFO ziti_log_set_level set log level: root=2

The tunneler works for binding but not for dialing… I’ve been using this exact host and tunneler successfully to accept connections from my Mac client.

13

Can you try with a specific identity and not the directory? instead of --identity-dir=/opt/openziti/etc/identities, use -i some.id.json…

maybe it’s a problem reading that folder/files in that folder

1 Like
14

Omg, yes I just had the same idea and tried that. That seems to work! At least I now get all the logs containing the services...
I don't understand how the tunneler could work in the past though for binding?

Permissions seem to be okay?

ls -la /opt/openziti/etc/identities/
total 20
drwxr-xr-x 2 root root 4096 Oct 18 22:50 .
drwxr-xr-x 3 root root 4096 Nov 4 16:38 ..
-rw-r--r-- 1 root root 10212 Oct 18 22:50 identity.json

1 Like
15

a.) yay!
b.) you “sure” it worked for bind? :slight_smile: I would be shocked since if it processed the identity file, i’d expect both bind/dial services to work. i can try to test that out EDIT: turns out it was indeed a problem. see Ken’s reply below
c.) my guess is that the directory processing is not working properly somehow.

the directory permissions definitely seem reasonable to me. It’ll probably be something silly like the lack of a trailing slash or some foolish bug on the way identity-dir processes the param. I’ll see if we can test it out

16

Huh, actually I think there was just something wrong with the logging.
I am certain that the binding worked and now that I restarted the service a couple times also only with the --identity setting, the logs are there. Awkward, I didn’t make any other changes.

The DNS issue still remains but the logs are there now but still no registered DNS:

(4170)[        0.000]    INFO ziti_log_set_level set log level: root=3
(4170)[        0.000]    INFO tunnel-sdk:ziti_tunnel.c:60 create_tunneler_ctx() Ziti Tunneler SDK (v0.20.7-local)
(4170)[        0.000]    INFO tunnel-cbs:ziti_dns.c:171 seed_dns() DNS configured with range 100.64.0.0 - 100.127.255.255 (4194302 ips)
(4170)[        0.000]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1595 run_tunneler_loop() Loading identity files from /opt/openziti/etc/identities
(4170)[        0.000]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1092 load_identities() loading identity file: gl01.json
(4170)[        0.005]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:864 load_ziti_async() attempting to load ziti instance from file[/opt/openziti/etc/identities/gl01.json]
(4170)[        0.005]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:871 load_ziti_async() loading ziti instance from /opt/openziti/etc/identities/gl01.json
(4170)[        0.005]    INFO ziti_log_set_level set log level: root=3
(4170)[        0.005]    INFO ziti-edge-tunnel:resolvers.c:66 init_libsystemd() Initializing libsystemd
(4170)[        0.005]    INFO ziti-edge-tunnel:resolvers.c:347 try_libsystemd_resolver() systemd-resolved selected as dns resolver manager
(4170)[        0.005]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1107 load_id_cb() identity[/opt/openziti/etc/identities/gl01.json] loaded
(4170)[        0.007]    INFO ziti-sdk:ziti.c:425 ziti_init_async() ztx[0] Ziti C SDK version 0.30.4 @64cb4f9(HEAD) starting at (2022-11-28T14:26:16.096)
(4170)[        0.007]    INFO ziti-sdk:ziti.c:426 ziti_init_async() ztx[0] using uv_mbed[v0.14.11], tls[OpenSSL 1.1.1n  15 Mar 2022]
(4170)[        0.007]    INFO ziti-sdk:ziti.c:427 ziti_init_async() ztx[0] Loading from config[/opt/openziti/etc/identities/gl01.json] controller[https://zt.mydomain.de:8441]
(4170)[        0.007]    INFO ziti-sdk:ziti_ctrl.c:401 ziti_ctrl_init() ctrl[zt.mydomain.de] ziti controller client initialized
(4170)[        0.007]    INFO ziti-sdk:ziti.c:860 ziti_re_auth_with_cb() ztx[0] starting to re-auth with ctlr[https://zt.mydomain.de:8441] api_session_status[0] api_session_expired[TRUE]
(4170)[        0.046]    INFO ziti-sdk:ziti.c:1525 version_cb() ztx[0] connected to controller https://zt.mydomain.de:8441 version v0.26.10(72978b5aa932 2022-10-13T15:31:04Z)
(4170)[        0.067]    INFO ziti-sdk:ziti.c:1415 ziti_set_api_session() ztx[0] api session set, setting api_session_timer to 1740s
(4170)[        0.067]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:726 on_ziti_event() ziti_ctx[gl01] connected to controller
(4170)[        0.067]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1137 on_event() ztx[/opt/openziti/etc/identities/gl01.json] context event : status is OK
(4170)[        5.104]    INFO ziti-sdk:posture.c:204 ziti_send_posture_data() ztx[0] first run or potential controller restart detected
(4170)[        5.157]    INFO ziti-sdk:channel.c:231 new_ziti_channel() ch[0] (zt-edge-router@tls://zt.mydomain.de:8442) new channel for ztx[0] identity[gl01]
(4170)[        5.157]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:797 on_ziti_event() ztx[gl01] added edge router zt-edge-router@tls://zt.mydomain.de:8442@zt.mydomain.de
(4170)[        5.157]    INFO ziti-sdk:channel.c:742 reconnect_channel() ch[0] reconnecting NOW
(4170)[       10.234]    INFO ziti-sdk:channel.c:640 hello_reply_cb() ch[0] connected. EdgeRouter version: v0.26.10|72978b5aa932|2022-10-13T15:31:04Z|linux|amd64
(4170)[       10.234]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:801 on_ziti_event() ztx[gl01] router zt-edge-router@tls://zt.mydomain.de:8442 connected
(4170)[       10.248]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:701 on_service() hosting server_address[tcp:127.0.0.1:9000] service[gl_client_access.svc]
(4170)[       10.248]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:701 on_service() hosting server_address[tcp:127.0.0.5:5000] service[gl_alert_to_soar.svc]
(4170)[       10.248]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:701 on_service() hosting server_address[tcp:127.0.0.1:6000] service[lc.svc]
(4170)[       10.248]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:701 on_service() hosting server_address[tcp:127.0.0.1:3000] service[mn01_client_access.svc]
(4170)[       10.248]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1262 on_event() =============== service event (added) - gl_client_access.svc:7moMQoJKRqz9o9COul31TN ===============
(4170)[       10.248]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1262 on_event() =============== service event (added) - gl_alert_to_soar.svc:5BZ5xOiq00QpTGgxYQ8el7 ===============
(4170)[       10.248]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1262 on_event() =============== service event (added) - lc.svc:4GREROoH2qkzmW3YzT13w1 ===============
(4170)[       10.248]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1262 on_event() =============== service event (added) - mn01_client_access.svc:49V3t6a8JfkZMH4TYB7raZ ===============
(4170)[       10.248]    INFO ziti-edge-tunnel:tun.c:174 tun_commit_routes() starting 1 route updates
(4170)[       10.254]    INFO ziti-edge-tunnel:tun.c:118 route_updates_done() route updates[1]: 0/OK
(4170)[       16.500]    INFO tunnel-cbs:ziti_hosting.c:611 on_hosted_client_connect() hosted_service[gl_client_access.svc], client[dm_mb] dst_addr[tcp:gl01.mydomain.de:80]: incoming connection
(4170)[       16.608]    INFO tunnel-cbs:ziti_hosting.c:611 on_hosted_client_connect() hosted_service[gl_client_access.svc], client[dm_mb] dst_addr[tcp:gl01.mydomain.de:80]: incoming connection
(4170)[       16.615]    INFO tunnel-cbs:ziti_hosting.c:611 on_hosted_client_connect() hosted_service[gl_client_access.svc], client[dm_mb] dst_addr[tcp:gl01.mydomain.de:80]: incoming connection
(4170)[       16.615]    INFO tunnel-cbs:ziti_hosting.c:611 on_hosted_client_connect() hosted_service[gl_client_access.svc], client[dm_mb] dst_addr[tcp:gl01.mydomain.de:80]: incoming connection
(4170)[      104.468]    INFO tunnel-cbs:ziti_hosting.c:611 on_hosted_client_connect() hosted_service[gl_client_access.svc], client[dm_mb] dst_addr[tcp:gl01.mydomain.de:80]: incoming connection
(4170)[      164.424]    INFO tunnel-cbs:ziti_hosting.c:611 on_hosted_client_connect() hosted_service[gl_client_access.svc], client[dm_mb] dst_addr[tcp:gl01.mydomain.de:80]: incoming connection
17

Hunh… That’s really quite strange. Maybe another tunneler was running at the same time? If you can reliably reproduce the problem, it’d be really useful to help us narrow down what might have been happening.

At this point, can you access those services? you can see in the logs this message too that lets you know it’s processing the identity files: “attempting to load ziti instance from file”

Can you add the -v4 flag and get DEBUG logs too? You can send logs to clint at openziti.org too if you prefer.

18

@dmuensterer I see the same thing with Debian 11 Bullseye. The cause is that ziti-edge-tunnel run depends on resolved (systemd-resolved) for DNS auto-configuration. In Bullseye, that systemd service is installed but not enabled. As soon as I enabled resolved and restart ziti-edge-tunnel.service that was installed by the DEB package then my Ziti service names start resolving normally.

Here are the steps to enable resolved. This assumes you want the Bullseye host to continue using the same automatically-configured recursive (fallback) nameservers from /etc/resolve.conf for non-Ziti domain names. This also assumes there is not another configuration-management system actively declaring the mode or contents of the /etc/resolv.conf file. You’re using VirtualBox, and it could potentially manage guest DNS.

# enable the pre-installed resolved service
vagrant@bullseye:~$ sudo systemctl enable --now systemd-resolved.service
Created symlink /etc/systemd/system/dbus-org.freedesktop.resolve1.service → /lib/systemd/system/systemd-resolved.service.
Created symlink /etc/systemd/system/multi-user.target.wants/systemd-resolved.service → /lib/systemd/system/systemd-resolved.service.

# configure resolved to manage /etc/resolv.conf
vagrant@bullseye:~$ sudo ln -sfvn /run/systemd/resolve/stub-resolv.conf /etc/resolv.conf
'/etc/resolv.conf' -> '/run/systemd/resolve/stub-resolv.conf'

# restart the tunneler so it can auto-configure DNS
vagrant@bullseye:~$ sudo systemctl restart ziti-edge-tunnel.service

# verify the tunneler has auto-configured a nameserver 
vagrant@bullseye:~$ resolvectl
Global
         Protocols: +LLMNR +mDNS -DNSOverTLS DNSSEC=no/unsupported
  resolv.conf mode: stub
Current DNS Server: 192.168.121.1
       DNS Servers: 192.168.121.1

Link 2 (eth0)
Current Scopes: LLMNR/IPv4 LLMNR/IPv6
     Protocols: -DefaultRoute +LLMNR -mDNS -DNSOverTLS DNSSEC=no/unsupported

Link 4 (tun0)
    Current Scopes: DNS
         Protocols: +DefaultRoute -LLMNR -mDNS -DNSOverTLS DNSSEC=no/unsupported
Current DNS Server: 100.64.0.2
       DNS Servers: 100.64.0.2

# assuming you have installed a Ziti identity that has service httpbin.ziti
vagrant@bullseye:~$ curl httpbin.ziti/ip
{ 
  "origin": "172.17.0.1"
}

So, what’s going on here with resolved? resolved provides a “stub resolver”, which is itself a nameserver that coalesces results from other nameservers. The default server listener for the stub resolver is 127.0.0.53. You can see it is running after enabling the systemd-resolved service.

vagrant@bullseye:~$ sudo ss -lnup|grep 127.*53
UNCONN 0      0      127.0.0.53%lo:53        0.0.0.0:*    users:(("systemd-resolve",pid=9945,fd=17))

The symlink you created to configure resolved in the preferred mode of operation causes all processes that rely on /etc/resolv.conf for nameservers to send their queries to the stub resolver.

resolved was auto-configured by ziti-edge-tunnel run to position the Ziti nameserver at a higher precedence than the fallback nameserver, and so it is checked for records before recursing to global DNS.

Ultimately, ziti-edge-tunnel run makes an effort to auto-configure the OS nameservers and will keep running if that is impossible. There are many variables with Linux DNS configuration, and there are some scenarios in which today’s ziti-edge-tunnel must be paired with post-install configuration to enable Ziti DNS. There may be a Bullseye+VirtualBox recipe we can document that makes this even easier. Please let me know if these manual Bullseye steps work for you too!

19

The issue that is impacting the default configuration on Bullseye was identified yesterday, and the fix has been submitted and merged. The next release will include the fix.

1 Like
20

I have the same issue on Debian 11 running as VM inside Qubes OS.

sudo ziti-edge-tunnel version
v0.22.7-local

sudo ziti-edge-tunnel run
(1076)[        0.000]    INFO ziti-sdk:utils.c:188 ziti_log_set_level() set log level: root=3/INFO
(1076)[        0.000]    INFO tunnel-sdk:ziti_tunnel.c:60 create_tunneler_ctx() Ziti Tunneler SDK (v0.22.7-local)
(1076)[        0.000]    INFO tunnel-cbs:ziti_dns.c:168 seed_dns() DNS configured with range 100.64.0.0 - 100.127.255.255 (4194302 ips)
(1076)[        0.000]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1621 make_socket_path() effective group set to 'ziti' (gid=996)
(1076)[        0.026]    INFO ziti-edge-tunnel:resolvers.c:68 init_libsystemd() Initializing libsystemd
(1076)[        0.028]    WARN ziti-edge-tunnel:resolvers.c:352 try_libsystemd_resolver() libsystemd resolver unsuccessful. Falling back to legacy resolvers
(1076)[        0.040]    WARN ziti-edge-tunnel:tun.c:277 find_dns_updater() Adding ziti resolver to /etc/resolv.conf. Ziti DNS functionality may be impaired
(1076)[        0.040]    INFO ziti-edge-tunnel:resolvers.c:425 make_copy() attempting copy of: /etc/resolv.conf
(1076)[        0.040]    INFO ziti-edge-tunnel:resolvers.c:439 make_copy() copy successful: /etc/resolv.conf.bkp

resolved service was not running ... so I started it:

sudo ln -sfvn /run/systemd/resolve/stub-resolv.conf /etc/resolv.conf
sudo systemctl start systemd-resolved.service

restart ziti tunnel

sudo ziti-edge-tunnel run
(1165)[        0.000]    INFO ziti-sdk:utils.c:188 ziti_log_set_level() set log level: root=3/INFO
(1165)[        0.000]    INFO tunnel-sdk:ziti_tunnel.c:60 create_tunneler_ctx() Ziti Tunneler SDK (v0.22.7-local)
(1165)[        0.000]    INFO tunnel-cbs:ziti_dns.c:168 seed_dns() DNS configured with range 100.64.0.0 - 100.127.255.255 (4194302 ips)
(1165)[        0.000]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1621 make_socket_path() effective group set to 'ziti' (gid=996)
(1165)[        0.028]    INFO ziti-edge-tunnel:resolvers.c:68 init_libsystemd() Initializing libsystemd
(1165)[        0.028]    INFO ziti-edge-tunnel:resolvers.c:356 try_libsystemd_resolver() systemd-resolved selected as DNS resolver manager
(1165)[      235.637]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:641 on_cmd() received cmd <{"Command":"Status"}

uname -a
Linux VM 6.1.42-1.qubes.fc32.x86_64 #1 SMP PREEMPT_DYNAMIC Mon Jul 31 02:24:56 CEST 2023 x86_64 GNU/Linux