Tunneler issue?

Hello Team,

I'm facing a strange issue and spent a lof of time finding the cause but I'm stuck now. Using a tunneler of server and client side, it works fine for multiple protocols but not at all for one and I don't know why.

My concerne is about the hfsql service on port 4900.

It always fails. Here is the capture on Ziti interface on client side:

When this traffic passes through underlay, it works fine:

Here are the tunneler settings on both sides:


I also tried without port forwarding with same result. The resource are available with the DNS brought by OpenZiti.

Any idea on the root cause? Am I doing something wrong?

Thank you for your help!

Hi Eric and welcome back. There's probably something helpful in the tunneler logs from the client or server side of the connection. Could you please send the tunneler logs from each side?

Thanks!

Hi Shawn,

Please find attached service and application logs for both server and client.

Thanks,

(Attachment Client_ZitiDesktopEdge.log is missing)

(Attachment Client_ziti-tunneler.log.202507250000.log is missing)

(Attachment Server_ziti-tunneler.log.202507250000.log is missing)

(Attachment Server_ZitiDesktopEdge.log is missing)

Hi Shawn,

Please find attached service and application logs for both server and client.

Thanks,

(attachments)

Archive.zip (13 KB)

Thanks for the DEBUG logs! In the client tunneler log I can see where the connection is being intercepted:

[2025-07-25T11:34:43.273Z]   DEBUG tunnel-sdk:tunnel_tcp.c:438 recv_tcp() intercepted address[tcp:100.64.0.3:4900] client[tcp:100.64.0.1:55509] service[hfsql]
[2025-07-25T11:34:43.273Z]   DEBUG tunnel-cbs:ziti_tunnel_cbs.c:354 ziti_sdk_c_dial() service[hfsql] app_data_json[173]='{"connType":null,"dst_protocol":"tcp","dst_hostname":"winpreprod.zpix","dst_ip":"100.64.0.3","dst_port":"4900","src_protocol":"tcp","src_ip":"100.64.0.1","src_port":"55509"}'
[2025-07-25T11:34:43.273Z]   DEBUG ziti-sdk:connect.c:431 connect_get_service_cb() conn[0.12/zkP4MH4_/Connecting](hfsql) got service[hfsql] id[6vud897IStOAIB6aa2t1rd]
[2025-07-25T11:34:43.273Z]   DEBUG ziti-sdk:posture.c:210 ziti_send_posture_data() ztx[0] posture checks must_send set to TRUE, new_session_id[FALSE], must_send_every_time[TRUE], new_controller_instance[FALSE]
[2025-07-25T11:34:43.273Z]   DEBUG ziti-sdk:connect.c:550 process_connect() conn[0.12/zkP4MH4_/Connecting](hfsql) starting Dial connection for service[hfsql] with session[cmdibw9novrdiqbdv4muj32h8]
[2025-07-25T11:34:43.273Z]   DEBUG ziti-sdk:connect.c:408 ziti_connect() conn[0.12/zkP4MH4_/Connecting](hfsql) selected ch[zpixr01@tls://zpixr01.vigitronic.eu:8442] for best latency(106 ms)
[2025-07-25T11:34:43.273Z]   DEBUG ziti-sdk:channel.c:238 ziti_channel_add_receiver() ch[0] added receiver[12]
[2025-07-25T11:34:43.295Z]   DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[tcp:100.64.0.1:55509] service[hfsql]

But in the server tunneler log I don't see any sign of the connection being received. I noticed that timestamps in the server tunneler log are a few minutes after the timestamp of the successful dial from the client log (the server log spans about 40 seconds from [2025-07-25T11:37:01.155Z] to [2025-07-25T11:37:40.795Z]).

Maybe the 11:34:00 - 11:35:00 timestamps are in one of the rolled logs on the server tunneler? If not could you please re-send client and server tunneler logs after attempting another connection of the hfsql service?

Thanks!

Hi Shown,

Sorry for the logs mismatch. Here are the logs for the same attempt.

Best regards,

(attachments)

Archive.zip (264 KB)

Hi. Are you sure that you're getting logs from the correct server tunneler? I see a connection to hfsql in the client log:

[2025-07-26T04:25:22.507Z]   DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[tcp:100.64.0.1:64385] service[hfsql]

The only incoming connections that show up in the server log are for the rdp service, and they are at different times than the client's hfsql connections:

[2025-07-26T04:19:03.162Z]    INFO tunnel-cbs:ziti_hosting.c:706 on_hosted_client_connect() hosted_service[rdp] client[Mac-EL] client_src_addr[tcp:100.64.0.1:65370] dst_addr[tcp:127.0.0.1:3389]: incoming connection
[2025-07-26T04:24:01.155Z]    INFO tunnel-cbs:ziti_hosting.c:706 on_hosted_client_connect() hosted_service[rdp] client[Mac-EL] client_src_addr[tcp:100.64.0.1:65407] dst_addr[tcp:127.0.0.1:3389]: incoming connection

Hi Shown,

The comprehensive story is there: actually, we have 2 servers that should be accessible on port 4900 for hfsql service. On both servers, I used the same bind config and on the client I used the dial config which was
mentioning both servers for traffic interception. Unfortunately, I got a strange behavior: it was working on one server alternatively. Impossible to open a session to one server and to the other. I have spent so much time to try make it work for both servers with no success that I decided to focus on one server only but it does not work neither.

When I look at the Wireshark traces on the client, it seems that even the TCP session is not correct. At the same time, on the server, I see no traffic at all in the tunnel. Could it be a DNS issue?

Best regards,

Eric LEJEUNE | |

| scareything OpenZiti Maintainer
July 26 |

  • | - |

Hi. Are you sure that you're getting logs from the correct server tunneler? I see a connection to hfsql in the client log:

[2025-07-26T04:25:22.507Z]   DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[tcp:100.64.0.1:64385] service[hfsql]

The only incoming connections that show up in the server log are for the rdp service, and they are at different times than the client's hfsql connections:

[2025-07-26T04:19:03.162Z]    INFO tunnel-cbs:ziti_hosting.c:706 on_hosted_client_connect() hosted_service[rdp] client[Mac-EL] client_src_addr[tcp:100.64.0.1:65370] dst_addr[tcp:127.0.0.1:3389]: incoming connection

[2025-07-26T04:24:01.155Z]    INFO tunnel-cbs:ziti_hosting.c:706 on_hosted_client_connect() hosted_service[rdp] client[Mac-EL] client_src_addr[tcp:100.64.0.1:65407] dst_addr[tcp:127.0.0.1:3389]: incoming connection

Hi Shawn,

Following my last message, do you have any idea of what’s wrong on my side?

Thanks.

Hi Eric. I’ve been away from my computer for a couple of days and I’ll be back tomorrow. My first thought is that you probably want to use addressable terminators if you intend to route connections to multiple endpoints. Does that make sense? If so have a search here in the forums and I’ll check in tomorrow.

Hi Shawn,

Thank you for your answer. Obviously, I’m completely lost because I face multiple issues when I try to achieve my organization target.

I think it should be easy to build this organization with OpenZiti as it’s not complex but I’m always stuck with the same issues.

My target is:

  1. Currently, we use SDK and tunnelers depending on the identities. At the end, all identities will use SDK.
  2. Two services: listening on TCP ports 2609 and 4900
  3. Groups contain dozens of identities
  4. In each group, every identity is simultaneoulsy a client and a server for all the members of the group, for both services noted above
  5. Groups can’t exchange data with other groups
  6. Exception to point 4: there is one administrative group that can access all identities from all groups for support purpose

I’m quite sure this can be done with OpenZiti but till now, despite reading a lot of topics and docs, I’m not able to make it work. Currently, I’m facing two issues:

  1. As you know, service on port 4900 does not work (using a tunneler)
  2. Apart the first two servers I created at the beginning, I can’t ping the identities. As far as I remember, the internal DNS added these servers automatically but for the new identities I created, fqdn is unknown.

I would be more than happy if you can enlighten me!

Shawn,

I did additional tests today: I have created rules dedicated to TCP 4900 service on one server and it works. So I think that my problem is linked to my attempts to have multiple clients to multiple servers for the same service.

I hope there is a solution to build something that meets my expectations. In the scenario I described, if I have to create rules for each server, knowing that each identity is a client and a server, it will be extremely difficult to manage.

As I believe my scenario is common, I’m quite optimistic that you can explain to me how to proceed. :slight_smile:

Thanks.

Hi Eric - this is the exact use case Addressable Terminators targets. You can find some good discussions and examples here on Discourse, e.g., How to bind each entry of host.v2 to an edge router? - #6 by TheLumberjack or Binding a service to multiple hosts - #3 by scareything

Hi Dave,

Thank you for the links, I’ll look at theses discussions ASAP. Will come back to share the result or ask questions. :slight_smile:

I’m back. After reading the discussions, I’ve been able to build something closer to my expectations with the BIND USING EDGE IDENTITY set to true and I was very happy! I also upgraded to 1.6.6 and it worked fine.

Unfortunately, I guess after rebooting the controller and the router, no traffic is passing on the overlay anymore.

In the tunneler log on the client, I see:

[2025-07-30T19:49:53.223Z] ERROR ziti-sdk:connect.c:1068 connect_reply_cb() conn0.562/jm457n0L/Connecting failed to connect, reason=no controller available, cannot create circuit
[2025-07-30T19:49:53.223Z] ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: connection is closed

I checked the controller and the router services, both are up and running. Is it due to the upgrade or the reboot? Any other reason?

Thanks.

Hi Eric,

Are you sure the controller restarted successfully? Could the controller be running on a host that has a dynamic IP address, and the address changed during the reboot?

Please send the complete log from the client, and verify that the controller address that the client is using (e.g. “https://ctrl.myziti.com:1280/”) is accessible from the host that the client is running on. You should be able to curl to it (perhaps with the -k option if you are using your own PKI).

Thanks!

Hi Shawn,

1. IP address is fixed

2. services status

eric@zpix:~$ systemctl status ziti-controller.service

ziti-controller.service - OpenZiti Controller

 Loaded: loaded (/lib/systemd/system/ziti-controller.service; **enabled**; preset: **enabled**)

Drop-In: /etc/systemd/system/ziti-controller.service.d

         └─override.conf

 Active: **active (running)** since Wed 2025-07-30 13:15:51 CEST; 16h ago

Process: 1730 ExecStartPre=/opt/openziti/etc/controller/entrypoint.bash check config.yml (code=exited, status=0/SUCCESS)

Main PID: 1750 (ziti)

  Tasks: 9 (limit: 2304)

 Memory: 104.2M

    CPU: 13min 1.672s

 CGroup: /system.slice/ziti-controller.service

         └─1750 /opt/openziti/bin/ziti controller run config.yml --

eric@zpix:~$

eric@ZPixR01:~$ systemctl status ziti-router.service

ziti-router.service - OpenZiti Router

 Loaded: loaded (/lib/systemd/system/ziti-router.service; **enabled**; preset: **enabled**)

Drop-In: /etc/systemd/system/ziti-router.service.d

         └─override.conf

 Active: **active (running)** since Wed 2025-07-30 11:43:44 CEST; 18h ago

Process: 635 ExecStartPre=/opt/openziti/etc/router/entrypoint.bash check config.yml (code=exited, status=0/SUCCESS)

Main PID: 645 (ziti)

  Tasks: 7 (limit: 2304)

 Memory: 102.4M

    CPU: 35.202s

 CGroup: /system.slice/ziti-router.service

         └─645 /opt/openziti/bin/ziti router run config.yml --extend

Warning: some journal files were not opened due to insufficient permissions.

eric@ZPixR01:~$

3. https://zpix.vigitronic.eu:8440

{
  "data": {
    "apiVersions": {
      "edge": {
        "v1": {
          "apiBaseUrls": [
            "https://zpix.vigitronic.eu:8440/edge/client/v1"
          ],
          "path": "/edge/client/v1"
        }
      },
      "edge-client": {
        "v1": {
          "apiBaseUrls": [
            "https://zpix.vigitronic.eu:8440/edge/client/v1"
          ],
          "path": "/edge/client/v1"
        }
      },
      "edge-management": {
        "v1": {
          "apiBaseUrls": [
            "https://zpix.vigitronic.eu:8440/edge/management/v1"
          ],
          "path": "/edge/management/v1"
        }
      },
      "edge-oidc": {
        "v1": {
          "apiBaseUrls": [
            "https://zpix.vigitronic.eu:8440"
          ],
          "path": "/oidc"
        }
      },
      "health-checks": {
        "v1": {
          "apiBaseUrls": [],
          "path": "/health-checks/v1"
        }
      }
    },
    "buildDate": "2025-07-25T17:21:06Z",
    "capabilities": [
      "OIDC_AUTH"
    ],
    "revision": "207d28c6bdee",
    "runtimeVersion": "go1.24.1",
    "version": "v1.6.6"
  },
  "meta": {

  }
}

4. tunnel logs

(3482)[2025-07-31T03:59:14.017Z] INFO ziti-sdk:utils.c:196 ziti_log_set_level() set log level: root=4/DEBUG

(3482)[2025-07-31T03:59:14.380Z] DEBUG ziti-sdk:bind.c:108 rebind_delay_cb() server[0.28](2609) staring re-bind

(3482)[2025-07-31T03:59:14.463Z] DEBUG ziti-sdk:ziti_ctrl.c:503 ctrl_body_cb() ctrl[https://zpix.vigitronic.eu:8440] completed GET[/services/AqErEuQI8ZfkKZzPTaVvt/edge-routers] in 0.082 s

(3482)[2025-07-31T03:59:14.463Z] DEBUG ziti-sdk:bind.c:273 list_routers_cb() server[0.28](2609) zpixr01/tls://zpixr01.vigitronic.eu:8442

(3482)[2025-07-31T03:59:14.463Z] DEBUG ziti-sdk:bind.c:136 process_bindings() server[0.28](2609) checking router[zpixr01]

(3482)[2025-07-31T03:59:14.463Z] DEBUG ziti-sdk:bind.c:537 start_binding() server[0.28](2609) requesting BIND on ch[zpixr01]

(3482)[2025-07-31T03:59:14.482Z] DEBUG ziti-sdk:bind.c:514 bind_reply_cb() server[0.28](2609) failed to bind on router[zpixr01]: OK

(3482)[2025-07-31T03:59:14.482Z] DEBUG ziti-sdk:bind.c:198 schedule_rebind() server[0.28](2609) scheduling re-bind(attempt=81) in 29.954s

(3482)[2025-07-31T03:59:14.560Z] DEBUG ziti-sdk:bind.c:108 rebind_delay_cb() server[0.79](4900) staring re-bind

(3482)[2025-07-31T03:59:14.565Z] DEBUG ziti-sdk:bind.c:108 rebind_delay_cb() server[0.159](rdp) staring re-bind

(3482)[2025-07-31T03:59:14.632Z] DEBUG ziti-sdk:posture.c:213 ziti_send_posture_data() ztx[0] posture checks must_send set to TRUE, new_session_id[FALSE], must_send_every_time[TRUE], new_controller_instance[FALSE]

(3482)[2025-07-31T03:59:14.643Z] DEBUG ziti-sdk:ziti_ctrl.c:503 ctrl_body_cb() ctrl[https://zpix.vigitronic.eu:8440] completed GET[/services/6vud897IStOAIB6aa2t1rd/edge-routers] in 0.082 s

(3482)[2025-07-31T03:59:14.643Z] DEBUG ziti-sdk:bind.c:273 list_routers_cb() server[0.79](4900) zpixr01/tls://zpixr01.vigitronic.eu:8442

(3482)[2025-07-31T03:59:14.643Z] DEBUG ziti-sdk:bind.c:136 process_bindings() server[0.79](4900) checking router[zpixr01]

(3482)[2025-07-31T03:59:14.643Z] DEBUG ziti-sdk:bind.c:537 start_binding() server[0.79](4900) requesting BIND on ch[zpixr01]

(3482)[2025-07-31T03:59:14.662Z] DEBUG ziti-sdk:bind.c:514 bind_reply_cb() server[0.79](4900) failed to bind on router[zpixr01]: OK

(3482)[2025-07-31T03:59:14.662Z] DEBUG ziti-sdk:bind.c:198 schedule_rebind() server[0.79](4900) scheduling re-bind(attempt=73) in 22.695s

(3482)[2025-07-31T03:59:14.665Z] DEBUG ziti-sdk:ziti_ctrl.c:503 ctrl_body_cb() ctrl[https://zpix.vigitronic.eu:8440] completed GET[/services/1cXQqC5s6i4VFzW67tKmvo/edge-routers] in 0.099 s

(3482)[2025-07-31T03:59:14.665Z] DEBUG ziti-sdk:bind.c:273 list_routers_cb() server[0.159](rdp) zpixr01/tls://zpixr01.vigitronic.eu:8442

(3482)[2025-07-31T03:59:14.665Z] DEBUG ziti-sdk:bind.c:136 process_bindings() server[0.159](rdp) checking router[zpixr01]

(3482)[2025-07-31T03:59:14.665Z] DEBUG ziti-sdk:bind.c:537 start_binding() server[0.159](rdp) requesting BIND on ch[zpixr01]

(3482)[2025-07-31T03:59:14.684Z] DEBUG ziti-sdk:bind.c:514 bind_reply_cb() server[0.159](rdp) failed to bind on router[zpixr01]: OK

(3482)[2025-07-31T03:59:14.684Z] DEBUG ziti-sdk:bind.c:198 schedule_rebind() server[0.159](rdp) scheduling re-bind(attempt=83) in 24.383s

(3482)[2025-07-31T03:59:15.307Z] DEBUG ziti-sdk:bind.c:108 rebind_delay_cb() server[0.64](2609) staring re-bind

(3482)[2025-07-31T03:59:15.396Z] DEBUG ziti-sdk:ziti_ctrl.c:503 ctrl_body_cb() ctrl[https://zpix.vigitronic.eu:8440] completed GET[/services/AqErEuQI8ZfkKZzPTaVvt/edge-routers] in 0.089 s

(3482)[2025-07-31T03:59:15.396Z] DEBUG ziti-sdk:bind.c:273 list_routers_cb() server[0.64](2609) zpixr01/tls://zpixr01.vigitronic.eu:8442

(3482)[2025-07-31T03:59:15.396Z] DEBUG ziti-sdk:bind.c:136 process_bindings() server[0.64](2609) checking router[zpixr01]

(3482)[2025-07-31T03:59:15.396Z] DEBUG ziti-sdk:bind.c:537 start_binding() server[0.64](2609) requesting BIND on ch[zpixr01]

(3482)[2025-07-31T03:59:15.416Z] DEBUG ziti-sdk:bind.c:514 bind_reply_cb() server[0.64](2609) failed to bind on router[zpixr01]: OK

(3482)[2025-07-31T03:59:15.416Z] DEBUG ziti-sdk:bind.c:198 schedule_rebind() server[0.64](2609) scheduling re-bind(attempt=77) in 25.350s

(3482)[2025-07-31T03:59:15.803Z] DEBUG ziti-sdk:bind.c:108 rebind_delay_cb() server[0.76](2609) staring re-bind

(3482)[2025-07-31T03:59:15.887Z] DEBUG ziti-sdk:ziti_ctrl.c:503 ctrl_body_cb() ctrl[https://zpix.vigitronic.eu:8440] completed GET[/services/AqErEuQI8ZfkKZzPTaVvt/edge-routers] in 0.083 s

...

Thanks,

Shawn,

As router was noticed in the fail message, I just rebooted it once again and now it works! I don’t understand, I’m 100% sure I already rebooted both controller and router after the upgrade.

When I need to do that, is there an order to follows or a certain amount of time to wait between the reboots?

Thanks,

The startup timing and order should not matter. Each component attempts to reconnect until it is successful (as you can see the tunneler was doing until you restarted the router).

With that said, I’m surprised a simple restart of your router got you going again. It would be interesting to see the complete tunneler and router logs spanning the time that the tunneler was unable to connect. You might have seen an issue there, but it would be hard to diagnose without seeing the logs.

Thanks.