Understanding the fabric link between two public edge routers

markamind · August 10, 2022, 7:02am

situation

I am working through the process of creating two public edge routers. I have worked through most of the issues, though I have one left that I want to confirm is an issue.

Once I start up the second edge router, I run the command

ziti fabric list links

Which shows both edge routers are working… one has a state of connected… the other has a state of Failed

When I re-run the command after 5 minutes… the failed edge router is dropped from the fabric links.

I thought to check if this is expected… which I assume it is. It highlights that I still have an issued with one of the edge routers that I am still working through… I think I need to re-enroll the remote edge router again after rebuilding the controller / edge router certificates.

markamind · August 10, 2022, 10:09am

@TheLumberjack … is there anything wrong with this that would cause an edge router dialer to result in a failed status?

I am still trying to work out what I am doing wrong.

TheLumberjack · August 10, 2022, 10:14am

You need to read the logs. On the router failing to establish the link, look at the log for errors. There will be a log message. Post it here.

Links are reported via the controller. When a link fails, it’ll only be reported at the controller for a short period. Inspect the controller logs for clues.

markamind · August 10, 2022, 10:21am

Does this make any sense?

 INFO fabric/controller/network.(*Network).handleLinkChanged: {linkId=[3M0Nz1RVehhtQdUtBDOIYy]} changed link
[  71.028]    INFO fabric/controller/handler_ctrl.(*faultHandler).handleFault [ch{H-X9R2EzNy}->u{classic}->i{45GX}]: {linkId=[3M0Nz1RVehhtQdUtBDOIYy]} link fault
[  71.028]    INFO fabric/controller/handler_ctrl.(*routerLinkHandler).HandleLinks [ch{H-X9R2EzNy}->u{classic}->i{45GX}]: {routerId=[H-X9R2EzNy] linkId=[1dXD4lqAuwW5oSKSJyG0I4] destRouterId=[lIlPn2E2W]} router reported link already known

markamind · August 10, 2022, 10:23am

This was from the edge router on the remote server… maybe I need to add the private IP address into the SAN… would this cause this type of error?

nc":"github.com/openziti/channel.(*classicListener).acceptConnection.func1","level":"error","msg":"error receiving hello from [tls:172.104.11.199:61000] (receive error (read tcp 10.0.0.157:8443-\u003e172.104.11.199:61000: i/o timeout))","time":"2022-08-10T20:22:06.900Z"}

TheLumberjack · August 10, 2022, 10:25am

Look at the router establishing the connection. Info messages are probably not useful yet. I’m specifically looking for and expecting warn or errors.

markamind · August 10, 2022, 10:32am

I noticed this in the audit logs… does this help?

I may still have a problem with my certificates

type=AVC msg=audit(1660126683.579:1427229): avc: denied { name_connect } for pid=1347879 comm="**ziti**-router" dest=10080 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:amanda_port_t:s0 tclass=tcp_socket permissive=1

TheLumberjack · August 10, 2022, 10:39am

I don’t know what the audit log is. It sounds to be like you have looked at the entire log, and do not see any errors.

On the router that won’t connect. I assume it is running as a service via systemd? Can you stop it, then run it interactively and show me the first 100 lines of output?

markamind · August 10, 2022, 10:50am

This time when I run the second edge router… the link failed when the second edge router attempts to dial the edge router on the server with the controller

Maybe I have something wrong in my thinking… as I am still learning how the fabric links work.

{"arch":"amd64","build-date":"2022-07-19T20:09:36Z","configFile":"/home/opc/.ziti/remote-router-n2/private-edge-router.yaml","file":"github.com/openziti/ziti/ziti-router/subcmd/run.go:74","func":"github.com/openziti/ziti/ziti-router/subcmd.run","go-version":"go1.18.4","level":"info","msg":"starting ziti-router","os":"linux","revision":"f4124e248129","routerId":"H-X9R2EzNy","time":"2022-08-10T20:47:21.149Z","version":"v0.26.3"}

{"file":"github.com/openziti/fabric@v0.19.28/router/forwarder/faulter.go:64","func":"github.com/openziti/fabric/router/forwarder.(*Faulter).run","level":"info","msg":"started","time":"2022-08-10T20:47:21.150Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/forwarder/scanner.go:59","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).run","level":"info","msg":"started","time":"2022-08-10T20:47:21.150Z"}

{"file":"github.com/openziti/edge@v0.22.36/router/internal/edgerouter/config.go:139","func":"github.com/openziti/edge/router/internal/edgerouter.(*Config).LoadConfigFromMap","level":"warning","msg":"Invalid heartbeat interval [0] (min: 60, max: 10), setting to default [60]","time":"2022-08-10T20:47:21.150Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/router.go:268","func":"github.com/openziti/fabric/router.(*Router).showOptions","level":"info","msg":"ctrl = {\"OutQueueSize\":4,\"MaxQueuedConnects\":1,\"MaxOutstandingConnects\":16,\"ConnectTimeout\":1000000000,\"DelayRxStart\":false,\"WriteTimeout\":0}","time":"2022-08-10T20:47:21.151Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/router.go:274","func":"github.com/openziti/fabric/router.(*Router).showOptions","level":"info","msg":"metrics = {\"ReportInterval\":60000000000,\"MessageQueueSize\":10}","time":"2022-08-10T20:47:21.151Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/router.go:473","func":"github.com/openziti/fabric/router.(*Router).initializeHealthChecks","level":"info","msg":"starting health check with ctrl ping initially after 15s, then every 30s, timing out after 15s","time":"2022-08-10T20:47:21.152Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/router.go:352","func":"github.com/openziti/fabric/router.(*Router).startXlinkDialers","level":"info","msg":"started Xlink dialer with binding [transport]","time":"2022-08-10T20:47:21.152Z"}

{"file":"github.com/openziti/fabric@v0.19.28/metrics/pool_metrics.go:50","func":"github.com/openziti/fabric/metrics.GoroutinesPoolMetricsConfigF.func1.1","idleTime":10000000000,"level":"info","maxQueueSize":1,"maxWorkers":16,"minWorkers":1,"msg":"starting goroutine pool","poolType":"pool.listener.link","time":"2022-08-10T20:47:21.152Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/router.go:369","func":"github.com/openziti/fabric/router.(*Router).startXlinkListeners","level":"info","msg":"started Xlink listener with binding [transport] advertising [tls:168.138.13.227:10080]","time":"2022-08-10T20:47:21.152Z"}

{"address":{},"file":"github.com/openziti/edge@v0.22.36/router/xgress_edge/listener.go:69","func":"github.com/openziti/edge/router/xgress_edge.(*listener).Listen","level":"info","msg":"starting channel listener","time":"2022-08-10T20:47:21.152Z"}

{"file":"github.com/openziti/fabric@v0.19.28/metrics/pool_metrics.go:50","func":"github.com/openziti/fabric/metrics.GoroutinesPoolMetricsConfigF.func1.1","idleTime":10000000000,"level":"info","maxQueueSize":1,"maxWorkers":16,"minWorkers":1,"msg":"starting goroutine pool","poolType":"pool.listener.xgress_edge","time":"2022-08-10T20:47:21.153Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/router.go:401","func":"github.com/openziti/fabric/router.(*Router).startXgressListeners","level":"info","msg":"created xgress listener [edge] at [tls:0.0.0.0:8443]","time":"2022-08-10T20:47:21.153Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/router.go:401","func":"github.com/openziti/fabric/router.(*Router).startXgressListeners","level":"info","msg":"created xgress listener [tunnel] at []","time":"2022-08-10T20:47:21.153Z"}

{"file":"github.com/openziti/edge@v0.22.36/router/xgress_edge/accept.go:108","func":"github.com/openziti/edge/router/xgress_edge.(*Acceptor).Run","level":"info","msg":"starting","time":"2022-08-10T20:47:21.153Z"}

{"file":"github.com/openziti/fabric@v0.19.28/metrics/pool_metrics.go:50","func":"github.com/openziti/fabric/metrics.GoroutinesPoolMetricsConfigF.func1.1","idleTime":30000000000,"level":"info","maxQueueSize":1000,"maxWorkers":32,"minWorkers":0,"msg":"starting goroutine pool","poolType":"pool.link.dialer","time":"2022-08-10T20:47:21.277Z"}

{"file":"github.com/openziti/fabric@v0.19.28/metrics/pool_metrics.go:50","func":"github.com/openziti/fabric/metrics.GoroutinesPoolMetricsConfigF.func1.1","idleTime":30000000000,"level":"info","maxQueueSize":1000,"maxWorkers":128,"minWorkers":0,"msg":"starting goroutine pool","poolType":"pool.route.handler","time":"2022-08-10T20:47:21.277Z"}

{"file":"github.com/openziti/edge@v0.22.36/router/fabric/manager.go:311","func":"github.com/openziti/edge/router/fabric.(*StateManagerImpl).StartHeartbeat","level":"info","msg":"heartbeat starting","time":"2022-08-10T20:47:21.277Z"}

{"file":"github.com/openziti/edge@v0.22.36/router/xgress_edge_tunnel/tunneler.go:65","func":"github.com/openziti/edge/router/xgress_edge_tunnel.(*tunneler).Start","level":"info","mode":"host","msg":"creating interceptor","time":"2022-08-10T20:47:21.277Z"}

{"file":"github.com/openziti/edge@v0.22.36/router/xgress_edge/certchecker.go:117","func":"github.com/openziti/edge/router/xgress_edge.(*CertExpirationChecker).Run","level":"info","msg":"waiting 8590h44m4.654405293s to renew certificates","time":"2022-08-10T20:47:21.345Z"}

{"file":"github.com/openziti/edge@v0.22.36/router/handler_edge_ctrl/hello.go:51","func":"github.com/openziti/edge/router/handler_edge_ctrl.(*helloHandler).HandleReceive.func1","level":"info","msg":"received server hello, replying","time":"2022-08-10T20:47:21.346Z"}

{"file":"github.com/openziti/edge@v0.22.36/router/handler_edge_ctrl/apiSessionAdded.go:200","func":"github.com/openziti/edge/router/handler_edge_ctrl.(*apiSessionAddedHandler).instantSync","level":"info","msg":"first api session syncId [cl6nhlzig01e2m18l3rluppiy], starting","strategy":"instant","time":"2022-08-10T20:47:21.362Z"}

{"file":"github.com/openziti/edge@v0.22.36/router/handler_edge_ctrl/apiSessionAdded.go:267","func":"github.com/openziti/edge/router/handler_edge_ctrl.(*apiSessionSyncTracker).Add","level":"info","msg":"received api session sync chunk 0, isLast=true","time":"2022-08-10T20:47:21.362Z"}

{"error":"exit status 1","file":"github.com/openziti/edge@v0.22.36/tunnel/dns/server.go:52","func":"github.com/openziti/edge/tunnel/dns.flushDnsCaches","level":"warning","msg":"unable to flush dns caches, consider adding a dns flush to your restart process","time":"2022-08-10T20:47:21.463Z"}

{"_channels":["link","linkDialer"],"address":"tls:140.238.207.245:10080","file":"github.com/openziti/fabric@v0.19.28/router/handler_ctrl/dial.go:95","func":"github.com/openziti/fabric/router/handler_ctrl.(*dialHandler).handle","level":"info","linkId":"3DyTFRH4jPiRtSJ826nr64","linkProtocol":"tls","msg":"dialing link","routerId":"lIlPn2E2W","routerVersion":"v0.26.3","time":"2022-08-10T20:47:21.548Z"}

{"_channels":["link","linkListener"],"file":"github.com/openziti/fabric@v0.19.28/router/xlink_transport/listener.go:108","func":"github.com/openziti/fabric/router/xlink_transport.(*listener).BindChannel","level":"info","linkId":"2BiGjfVthOkoFaC6B54z67","linkProtocol":"tls","msg":"accepting link","routerId":"lIlPn2E2W","time":"2022-08-10T20:47:21.854Z"}

{"_channels":["link","linkListener"],"channelType":1,"file":"github.com/openziti/fabric@v0.19.28/router/xlink_transport/listener.go:134","func":"github.com/openziti/fabric/router/xlink_transport.(*listener).bindSplitChannel","level":"info","linkId":"2BiGjfVthOkoFaC6B54z67","linkProtocol":"tls","msg":"accepted part of split conn","routerId":"lIlPn2E2W","routerVersion":"v0.26.3","time":"2022-08-10T20:47:21.854Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/handler_link/bind.go:157","func":"github.com/openziti/fabric/router/handler_link.(*bindHandler).verifyRouter","level":"info","linkId":"2BiGjfVthOkoFaC6B54z67","msg":"successfully verified router for link","routerId":"lIlPn2E2W","time":"2022-08-10T20:47:21.945Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/handler_link/bind.go:98","func":"github.com/openziti/fabric/router/handler_link.(*bindHandler).BindChannel","level":"info","linkId":"2BiGjfVthOkoFaC6B54z67","msg":"link destination support heartbeats","routerId":"lIlPn2E2W","routerVersion":"v0.26.3","time":"2022-08-10T20:47:21.946Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/handler_link/bind.go:98","func":"github.com/openziti/fabric/router/handler_link.(*bindHandler).BindChannel","level":"info","linkId":"3DyTFRH4jPiRtSJ826nr64","msg":"link destination support heartbeats","routerId":"lIlPn2E2W","routerVersion":"v0.26.3","time":"2022-08-10T20:47:21.961Z"}

{"_channels":["link","linkListener"],"file":"github.com/openziti/fabric@v0.19.28/router/xlink_transport/listener.go:108","func":"github.com/openziti/fabric/router/xlink_transport.(*listener).BindChannel","level":"info","linkId":"2BiGjfVthOkoFaC6B54z67","linkProtocol":"tls","msg":"accepting link","routerId":"lIlPn2E2W","time":"2022-08-10T20:47:22.363Z"}

{"_channels":["link","linkListener"],"channelType":2,"file":"github.com/openziti/fabric@v0.19.28/router/xlink_transport/listener.go:134","func":"github.com/openziti/fabric/router/xlink_transport.(*listener).bindSplitChannel","level":"info","linkId":"2BiGjfVthOkoFaC6B54z67","linkProtocol":"tls","msg":"accepted part of split conn","routerId":"lIlPn2E2W","routerVersion":"v0.26.3","time":"2022-08-10T20:47:22.364Z"}

{"file":"github.com/openziti/edge@v0.22.36/router/handler_edge_ctrl/apiSessionAdded.go:124","func":"github.com/openziti/edge/router/handler_edge_ctrl.(*apiSessionAddedHandler).applySync","level":"info","msg":"finished sychronizing api sessions [count: 11, syncId: cl6nhlzig01e2m18l3rluppiy, duration: 36.719µs]","time":"2022-08-10T20:47:22.455Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/handler_link/bind.go:157","func":"github.com/openziti/fabric/router/handler_link.(*bindHandler).verifyRouter","level":"info","linkId":"2BiGjfVthOkoFaC6B54z67","msg":"successfully verified router for link","routerId":"lIlPn2E2W","time":"2022-08-10T20:47:22.456Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/handler_link/bind.go:98","func":"github.com/openziti/fabric/router/handler_link.(*bindHandler).BindChannel","level":"info","linkId":"2BiGjfVthOkoFaC6B54z67","msg":"link destination support heartbeats","routerId":"lIlPn2E2W","routerVersion":"v0.26.3","time":"2022-08-10T20:47:22.456Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/accepter.go:19","func":"github.com/openziti/fabric/router.(*xlinkAccepter).Accept","level":"info","msg":"accepted new link [l/2BiGjfVthOkoFaC6B54z67]","time":"2022-08-10T20:47:22.456Z"}

{"_channels":["link","linkListener"],"channelType":2,"file":"github.com/openziti/fabric@v0.19.28/router/xlink_transport/listener.go:156","func":"github.com/openziti/fabric/router/xlink_transport.(*listener).bindSplitChannel","level":"info","linkId":"2BiGjfVthOkoFaC6B54z67","linkProtocol":"tls","msg":"accepted link","routerId":"lIlPn2E2W","routerVersion":"v0.26.3","time":"2022-08-10T20:47:22.456Z"}

{"_channels":["link","linkListener"],"channelType":2,"file":"github.com/openziti/fabric@v0.19.28/router/xlink_transport/listener.go:159","func":"github.com/openziti/fabric/router/xlink_transport.(*listener).bindSplitChannel","level":"info","linkId":"2BiGjfVthOkoFaC6B54z67","linkProtocol":"tls","msg":"link registered","routerId":"lIlPn2E2W","routerVersion":"v0.26.3","time":"2022-08-10T20:47:22.456Z"}

{"_context":"ch{l/3DyTFRH4jPiRtSJ826nr64}-\u003eu{classic}-\u003ei{ZNP0}","file":"github.com/openziti/fabric@v0.19.28/router/handler_link/close.go:62","func":"github.com/openziti/fabric/router/handler_link.(*closeHandler).HandleClose","level":"info","linkId":"3DyTFRH4jPiRtSJ826nr64","msg":"link closed","routerId":"lIlPn2E2W","time":"2022-08-10T20:47:22.552Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/handler_link/bind.go:98","func":"github.com/openziti/fabric/router/handler_link.(*bindHandler).BindChannel","level":"info","linkId":"3DyTFRH4jPiRtSJ826nr64","msg":"link destination support heartbeats","routerId":"lIlPn2E2W","routerVersion":"v0.26.3","time":"2022-08-10T20:47:22.555Z"}

{"file":"github.com/openziti/fabric@v0.19.28/router/accepter.go:19","func":"github.com/openziti/fabric/router.(*xlinkAccepter).Accept","level":"info","msg":"accepted new link [l/3DyTFRH4jPiRtSJ826nr64]","time":"2022-08-10T20:47:22.555Z"}

{"dest":"lIlPn2E2W","file":"github.com/openziti/fabric@v0.19.28/router/link_registry.go:154","func":"github.com/openziti/fabric/router.(*linkRegistryImpl).applyLink","level":"info","linkProtocol":"tls","msg":"link being registered, but is already closed, skipping registration","newLinkId":"3DyTFRH4jPiRtSJ826nr64","time":"2022-08-10T20:47:22.556Z"}

{"_context":"ch{l/3DyTFRH4jPiRtSJ826nr64}-\u003eu{classic}-\u003ei{ZAQZ}","file":"github.com/openziti/fabric@v0.19.28/router/handler_link/close.go:62","func":"github.com/openziti/fabric/router/handler_link.(*closeHandler).HandleClose","level":"info","linkId":"3DyTFRH4jPiRtSJ826nr64","msg":"link closed","routerId":"lIlPn2E2W","time":"2022-08-10T20:47:22.559Z"}

{"file":"github.com/openziti/edge@v0.22.36/tunnel/intercept/iputils.go:51","func":"github.com/openziti/edge/tunnel/intercept.SetDnsInterceptIpRange","level":"info","msg":"dns intercept IP range: 100.64.0.1 - 100.127.255.254","time":"2022-08-10T20:47:26.251Z"}

markamind · August 10, 2022, 10:52am

I just stopped it… and restarted it… now the opposite edge router dialer fails…

Here is a copy of the logs from the other edge router

0.623]    INFO ziti/ziti-router/subcmd.run: {arch=[amd64] revision=[f4124e248129] build-date=[2022-07-19T20:09:36Z] configFile=[/home/opc/.ziti/quickstart/instance-20220416-1712/instance-20220416-1712-edge-router.yaml] routerId=[lIlPn2E2W] version=[v0.26.3] go-version=[go1.18.4] os=[linux]} starting ziti-router
[   0.623] WARNING edge/router/internal/edgerouter.(*Config).LoadConfigFromMap: Invalid heartbeat interval [0] (min: 60, max: 10), setting to default [60]
[   0.623]    INFO fabric/router/forwarder.(*Faulter).run: started
[   0.623]    INFO fabric/router/forwarder.(*Scanner).run: started
[   0.627]    INFO fabric/router.(*Router).showOptions: ctrl = {"OutQueueSize":4,"MaxQueuedConnects":1,"MaxOutstandingConnects":16,"ConnectTimeout":1000000000,"DelayRxStart":false,"WriteTimeout":0}
[   0.627]    INFO fabric/router.(*Router).showOptions: metrics = {"ReportInterval":60000000000,"MessageQueueSize":10}
[   0.627]    INFO fabric/router.(*Router).initializeHealthChecks: starting health check with ctrl ping initially after 15s, then every 30s, timing out after 15s
[   0.627]    INFO fabric/router.(*Router).startXlinkDialers: started Xlink dialer with binding [transport]
[   0.628]    INFO fabric/metrics.GoroutinesPoolMetricsConfigF.func1.1: {maxQueueSize=[1] idleTime=[10s] poolType=[pool.listener.link] minWorkers=[1] maxWorkers=[16]} starting goroutine pool
[   0.628]    INFO fabric/router.(*Router).startXlinkListeners: started Xlink listener with binding [transport] advertising [tls:140.238.207.245:10080]
[   0.628]    INFO edge/router/xgress_edge.(*listener).Listen: {address=[tls:0.0.0.0:8442]} starting channel listener
[   0.628]    INFO fabric/metrics.GoroutinesPoolMetricsConfigF.func1.1: {minWorkers=[1] maxWorkers=[16] idleTime=[10s] maxQueueSize=[1] poolType=[pool.listener.xgress_edge]} starting goroutine pool
[   0.629]    INFO edge/router/xgress_edge.(*Acceptor).Run: starting
[   0.629]    INFO fabric/router.(*Router).startXgressListeners: created xgress listener [edge] at [tls:0.0.0.0:8442]
[   0.629]    INFO fabric/router.(*Router).startXgressListeners: created xgress listener [tunnel] at []
[   0.678]    INFO fabric/metrics.GoroutinesPoolMetricsConfigF.func1.1: {minWorkers=[0] maxQueueSize=[1000] maxWorkers=[32] idleTime=[30s] poolType=[pool.link.dialer]} starting goroutine pool
[   0.678]    INFO fabric/metrics.GoroutinesPoolMetricsConfigF.func1.1: {idleTime=[30s] maxQueueSize=[1000] poolType=[pool.route.handler] minWorkers=[0] maxWorkers=[128]} starting goroutine pool
[   0.679]    INFO edge/router/fabric.(*StateManagerImpl).StartHeartbeat: heartbeat starting
[   0.679]    INFO edge/router/xgress_edge_tunnel.(*tunneler).Start: {mode=[host]} creating interceptor
[   0.680]    INFO edge/router/xgress_edge.(*CertExpirationChecker).Run: waiting 8588h43m21.336473916s to renew certificates
[   0.741]    INFO edge/router/handler_edge_ctrl.(*helloHandler).HandleReceive.func1: received server hello, replying
[   0.762]    INFO edge/router/handler_edge_ctrl.(*apiSessionAddedHandler).instantSync: {strategy=[instant]} first api session syncId [cl6nhgcvd016km18lpy54007h], starting
[   0.763] WARNING edge/tunnel/dns.flushDnsCaches: {error=[exit status 1]} unable to flush dns caches, consider adding a dns flush to your restart process
[   0.763]    INFO edge/router/handler_edge_ctrl.(*apiSessionSyncTracker).Add: received api session sync chunk 0, isLast=true
[   2.036]    INFO edge/router/handler_edge_ctrl.(*apiSessionAddedHandler).applySync: finished sychronizing api sessions [count: 9, syncId: cl6nhgcvd016km18lpy54007h, duration: 463.526µs]
[   7.252]    INFO edge/tunnel/intercept.SetDnsInterceptIpRange: dns intercept IP range: 100.64.0.1 - 100.127.255.254
[  51.449]    INFO fabric/router/handler_ctrl.(*dialHandler).handle |link, linkDialer|: {routerId=[H-X9R2EzNy] address=[tls:168.138.13.227:10080] linkProtocol=[tls] routerVersion=[v0.26.3] linkId=[2GIw0KisD9EjKvl1oikxAE]} dialing link
[  51.680]    INFO fabric/router/xlink_transport.(*listener).BindChannel |link, linkListener|: {linkProtocol=[tls] linkId=[31DrKnEKTxsn6Xjtf7fcDE] routerId=[H-X9R2EzNy]} accepting link
[  51.681]    INFO fabric/router/xlink_transport.(*listener).bindSplitChannel |link, linkListener|: {linkProtocol=[tls] linkId=[31DrKnEKTxsn6Xjtf7fcDE] channelType=[payload] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3]} accepted part of split conn
[  51.684]    INFO fabric/router/handler_link.(*bindHandler).verifyRouter: {linkId=[31DrKnEKTxsn6Xjtf7fcDE] routerId=[H-X9R2EzNy]} successfully verified router for link
[  51.694]    INFO fabric/router/handler_link.(*bindHandler).BindChannel: {linkId=[31DrKnEKTxsn6Xjtf7fcDE] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3]} link destination support heartbeats
[  51.902]    INFO fabric/router/handler_link.(*bindHandler).BindChannel: {linkId=[2GIw0KisD9EjKvl1oikxAE] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3]} link destination support heartbeats
[  52.192]    INFO fabric/router/xlink_transport.(*listener).BindChannel |link, linkListener|: {linkId=[31DrKnEKTxsn6Xjtf7fcDE] linkProtocol=[tls] routerId=[H-X9R2EzNy]} accepting link
[  52.192]    INFO fabric/router/xlink_transport.(*listener).bindSplitChannel |link, linkListener|: {linkId=[31DrKnEKTxsn6Xjtf7fcDE] linkProtocol=[tls] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3] channelType=[ack]} accepted part of split conn
[  52.193]    INFO fabric/router/handler_link.(*bindHandler).verifyRouter: {linkId=[31DrKnEKTxsn6Xjtf7fcDE] routerId=[H-X9R2EzNy]} successfully verified router for link
[  52.193]    INFO fabric/router/handler_link.(*bindHandler).BindChannel: {linkId=[31DrKnEKTxsn6Xjtf7fcDE] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3]} link destination support heartbeats
[  52.196]    INFO fabric/router.(*xlinkAccepter).Accept: accepted new link [l/31DrKnEKTxsn6Xjtf7fcDE]
[  52.196]    INFO fabric/router/xlink_transport.(*listener).bindSplitChannel |link, linkListener|: {routerId=[H-X9R2EzNy] routerVersion=[v0.26.3] channelType=[ack] linkId=[31DrKnEKTxsn6Xjtf7fcDE] linkProtocol=[tls]} accepted link
[  52.196]    INFO fabric/router/xlink_transport.(*listener).bindSplitChannel |link, linkListener|: {linkId=[31DrKnEKTxsn6Xjtf7fcDE] linkProtocol=[tls] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3] channelType=[ack]} link registered
[  52.270]    INFO fabric/router/handler_link.(*bindHandler).BindChannel: {linkId=[2GIw0KisD9EjKvl1oikxAE] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3]} link destination support heartbeats
[  52.270]    INFO fabric/router.(*xlinkAccepter).Accept: accepted new link [l/2GIw0KisD9EjKvl1oikxAE]
[  52.270]    INFO fabric/router.(*linkRegistryImpl).applyLink: {linkProtocol=[tls] newLinkId=[2GIw0KisD9EjKvl1oikxAE] currentLinkId=[31DrKnEKTxsn6Xjtf7fcDE] dest=[H-X9R2EzNy]} duplicate link detected. closing current link (current link id is > than new link id)
[  52.270]    INFO fabric/router/handler_ctrl.(*dialHandler).handle |link, linkDialer|: {linkProtocol=[tls] routerVersion=[v0.26.3] linkId=[2GIw0KisD9EjKvl1oikxAE] routerId=[H-X9R2EzNy] address=[tls:168.138.13.227:10080]} link registered
[  52.285]    INFO fabric/router/handler_link.(*closeHandler).HandleClose [ch{l/31DrKnEKTxsn6Xjtf7fcDE}->u{classic}->i{0nN0}]: {linkId=[31DrKnEKTxsn6Xjtf7fcDE] routerId=[H-X9R2EzNy]} link closed
[  52.285]    INFO fabric/router/handler_link.(*closeHandler).HandleClose [ch{l/31DrKnEKTxsn6Xjtf7fcDE}->u{classic}->i{0mDe}]: {linkId=[31DrKnEKTxsn6Xjtf7fcDE] routerId=[H-X9R2EzNy]} link closed
[ 149.861]    INFO fabric/router/handler_link.(*closeHandler).HandleClose [ch{l/2GIw0KisD9EjKvl1oikxAE}->u{classic}->i{d58J}]: {linkId=[2GIw0KisD9EjKvl1oikxAE] routerId=[H-X9R2EzNy]} link closed
[ 149.861]    INFO fabric/router/handler_link.(*closeHandler).HandleClose [ch{l/2GIw0KisD9EjKvl1oikxAE}->u{classic}->i{78Zd}]: {routerId=[H-X9R2EzNy] linkId=[2GIw0KisD9EjKvl1oikxAE]} link closed
[ 149.861]   ERROR channel.(*channelImpl).rxer [ch{l/2GIw0KisD9EjKvl1oikxAE}->u{classic}->i{78Zd}]: rx error (read tcp 10.0.0.139:45112->168.138.13.227:10080: use of closed network connection)
[ 263.538]    INFO fabric/router/handler_ctrl.(*dialHandler).handle |link, linkDialer|: {linkId=[2BiGjfVthOkoFaC6B54z67] routerId=[H-X9R2EzNy] address=[tls:168.138.13.227:10080] linkProtocol=[tls] routerVersion=[v0.26.3]} dialing link
[ 263.877]    INFO fabric/router/handler_link.(*bindHandler).BindChannel: {routerId=[H-X9R2EzNy] routerVersion=[v0.26.3] linkId=[2BiGjfVthOkoFaC6B54z67]} link destination support heartbeats
[ 263.888]    INFO fabric/router/xlink_transport.(*listener).BindChannel |link, linkListener|: {linkProtocol=[tls] linkId=[3DyTFRH4jPiRtSJ826nr64] routerId=[H-X9R2EzNy]} accepting link
[ 263.888]    INFO fabric/router/xlink_transport.(*listener).bindSplitChannel |link, linkListener|: {routerVersion=[v0.26.3] linkProtocol=[tls] linkId=[3DyTFRH4jPiRtSJ826nr64] channelType=[payload] routerId=[H-X9R2EzNy]} accepted part of split conn
[ 263.889]    INFO fabric/router/handler_link.(*bindHandler).verifyRouter: {linkId=[3DyTFRH4jPiRtSJ826nr64] routerId=[H-X9R2EzNy]} successfully verified router for link
[ 263.889]    INFO fabric/router/handler_link.(*bindHandler).BindChannel: {routerId=[H-X9R2EzNy] routerVersion=[v0.26.3] linkId=[3DyTFRH4jPiRtSJ826nr64]} link destination support heartbeats
[ 264.386]    INFO fabric/router/handler_link.(*bindHandler).BindChannel: {routerVersion=[v0.26.3] linkId=[2BiGjfVthOkoFaC6B54z67] routerId=[H-X9R2EzNy]} link destination support heartbeats
[ 264.386]    INFO fabric/router.(*xlinkAccepter).Accept: accepted new link [l/2BiGjfVthOkoFaC6B54z67]
[ 264.386]    INFO fabric/router/handler_ctrl.(*dialHandler).handle |link, linkDialer|: {linkProtocol=[tls] routerVersion=[v0.26.3] linkId=[2BiGjfVthOkoFaC6B54z67] routerId=[H-X9R2EzNy] address=[tls:168.138.13.227:10080]} link registered
[ 264.490]    INFO fabric/router/xlink_transport.(*listener).BindChannel |link, linkListener|: {routerId=[H-X9R2EzNy] linkProtocol=[tls] linkId=[3DyTFRH4jPiRtSJ826nr64]} accepting link
[ 264.490]    INFO fabric/router/xlink_transport.(*listener).bindSplitChannel |link, linkListener|: {linkId=[3DyTFRH4jPiRtSJ826nr64] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3] channelType=[ack] linkProtocol=[tls]} accepted part of split conn
[ 264.491]    INFO fabric/router/handler_link.(*bindHandler).verifyRouter: {routerId=[H-X9R2EzNy] linkId=[3DyTFRH4jPiRtSJ826nr64]} successfully verified router for link
[ 264.491]    INFO fabric/router/handler_link.(*bindHandler).BindChannel: {routerVersion=[v0.26.3] linkId=[3DyTFRH4jPiRtSJ826nr64] routerId=[H-X9R2EzNy]} link destination support heartbeats
[ 264.491]    INFO fabric/router.(*xlinkAccepter).Accept: accepted new link [l/3DyTFRH4jPiRtSJ826nr64]
[ 264.491]    INFO fabric/router/xlink_transport.(*listener).bindSplitChannel |link, linkListener|: {channelType=[ack] linkProtocol=[tls] linkId=[3DyTFRH4jPiRtSJ826nr64] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3]} accepted link
[ 264.491]    INFO fabric/router.(*linkRegistryImpl).applyLink: {dest=[H-X9R2EzNy] newLinkId=[3DyTFRH4jPiRtSJ826nr64] currentLinkId=[2BiGjfVthOkoFaC6B54z67] linkProtocol=[tls]} duplicate link detected. closing new link (new link id is > than current link id)
[ 264.493]    INFO fabric/router/handler_link.(*closeHandler).HandleClose [ch{l/3DyTFRH4jPiRtSJ826nr64}->u{classic}->i{ZNP0}]: {linkId=[3DyTFRH4jPiRtSJ826nr64] routerId=[H-X9R2EzNy]} link closed
[ 264.493]    INFO fabric/router/handler_link.(*closeHandler).HandleClose [ch{l/3DyTFRH4jPiRtSJ826nr64}->u{classic}->i{ZAQZ}]: {linkId=[3DyTFRH4jPiRtSJ826nr64] routerId=[H-X9R2EzNy]} link closed
[ 264.493]   ERROR channel.(*channelImpl).rxer [ch{l/3DyTFRH4jPiRtSJ826nr64}->u{classic}->i{ZNP0}]: rx error (read tcp 10.0.0.139:10080->168.138.13.227:34670: use of closed network connection)
[ 264.494]    INFO fabric/router/xlink_transport.(*listener).bindSplitChannel |link, linkListener|: {channelType=[ack] linkProtocol=[tls] linkId=[3DyTFRH4jPiRtSJ826nr64] existingLinkId=[2BiGjfVthOkoFaC6B54z67] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3]} existing link found, new link closed
[ 264.494]   ERROR channel.(*channelImpl).rxer [ch{l/3DyTFRH4jPiRtSJ826nr64}->u{classic}->i{ZAQZ}]: rx error (underlay closed)
[ 440.872]    INFO fabric/router/handler_link.(*closeHandler).HandleClose [ch{l/2BiGjfVthOkoFaC6B54z67}->u{classic}->i{MXOr}]: {routerId=[H-X9R2EzNy] linkId=[2BiGjfVthOkoFaC6B54z67]} link closed
[ 440.872]    INFO fabric/router/handler_link.(*closeHandler).HandleClose [ch{l/2BiGjfVthOkoFaC6B54z67}->u{classic}->i{rpYM}]: {routerId=[H-X9R2EzNy] linkId=[2BiGjfVthOkoFaC6B54z67]} link closed
[ 440.872]   ERROR channel.(*channelImpl).rxer [ch{l/2BiGjfVthOkoFaC6B54z67}->u{classic}->i{rpYM}]: rx error (read tcp 10.0.0.139:45138->168.138.13.227:10080: use of closed network connection)
[ 443.585]    INFO fabric/router/handler_ctrl.(*dialHandler).handle |link, linkDialer|: {routerId=[H-X9R2EzNy] address=[tls:168.138.13.227:10080] linkProtocol=[tls] routerVersion=[v0.26.3] linkId=[DCw2pqwAr4WaJwBDPMDtc]} dialing link
[ 444.069]    INFO fabric/router/handler_link.(*bindHandler).BindChannel: {routerId=[H-X9R2EzNy] routerVersion=[v0.26.3] linkId=[DCw2pqwAr4WaJwBDPMDtc]} link destination support heartbeats
[ 444.093]    INFO fabric/router/xlink_transport.(*listener).BindChannel |link, linkListener|: {linkProtocol=[tls] linkId=[33T02OqcuPHHU04u3fuPWy] routerId=[H-X9R2EzNy]} accepting link
[ 444.093]    INFO fabric/router/xlink_transport.(*listener).bindSplitChannel |link, linkListener|: {linkId=[33T02OqcuPHHU04u3fuPWy] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3] channelType=[payload] linkProtocol=[tls]} accepted part of split conn
[ 444.093]    INFO fabric/router/handler_link.(*bindHandler).verifyRouter: {linkId=[33T02OqcuPHHU04u3fuPWy] routerId=[H-X9R2EzNy]} successfully verified router for link
[ 444.094]    INFO fabric/router/handler_link.(*bindHandler).BindChannel: {linkId=[33T02OqcuPHHU04u3fuPWy] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3]} link destination support heartbeats
[ 444.469]    INFO fabric/router/handler_link.(*bindHandler).BindChannel: {routerId=[H-X9R2EzNy] routerVersion=[v0.26.3] linkId=[DCw2pqwAr4WaJwBDPMDtc]} link destination support heartbeats
[ 444.469]    INFO fabric/router.(*xlinkAccepter).Accept: accepted new link [l/DCw2pqwAr4WaJwBDPMDtc]
[ 444.469]    INFO fabric/router/handler_ctrl.(*dialHandler).handle |link, linkDialer|: {routerVersion=[v0.26.3] linkId=[DCw2pqwAr4WaJwBDPMDtc] routerId=[H-X9R2EzNy] address=[tls:168.138.13.227:10080] linkProtocol=[tls]} link registered
[ 444.473]    INFO fabric/router/xlink_transport.(*listener).BindChannel |link, linkListener|: {routerId=[H-X9R2EzNy] linkProtocol=[tls] linkId=[33T02OqcuPHHU04u3fuPWy]} accepting link
[ 444.473]    INFO fabric/router/xlink_transport.(*listener).bindSplitChannel |link, linkListener|: {routerVersion=[v0.26.3] linkProtocol=[tls] channelType=[ack] linkId=[33T02OqcuPHHU04u3fuPWy] routerId=[H-X9R2EzNy]} accepted part of split conn
[ 444.474]    INFO fabric/router/handler_link.(*bindHandler).verifyRouter: {linkId=[33T02OqcuPHHU04u3fuPWy] routerId=[H-X9R2EzNy]} successfully verified router for link
[ 444.474]    INFO fabric/router/handler_link.(*bindHandler).BindChannel: {linkId=[33T02OqcuPHHU04u3fuPWy] routerId=[H-X9R2EzNy] routerVersion=[v0.26.3]} link destination support heartbeats
[ 444.474]    INFO fabric/router.(*xlinkAccepter).Accept: accepted new link [l/33T02OqcuPHHU04u3fuPWy]
[ 444.474]    INFO fabric/router/xlink_transport.(*listener).bindSplitChannel |link, linkListener|: {routerVersion=[v0.26.3] linkProtocol=[tls] channelType=[ack] linkId=[33T02OqcuPHHU04u3fuPWy] routerId=[H-X9R2EzNy]} accepted link
[ 444.474]    INFO fabric/router.(*linkRegistryImpl).applyLink: {linkProtocol=[tls] newLinkId=[33T02OqcuPHHU04u3fuPWy] currentLinkId=[DCw2pqwAr4WaJwBDPMDtc] dest=[H-X9R2EzNy]} duplicate link detected. closing current link (current link id is > than new link id)
[ 444.474]    INFO fabric/router/xlink_transport.(*listener).bindSplitChannel |link, linkListener|: {routerVersion=[v0.26.3] linkProtocol=[tls] channelType=[ack] linkId=[33T02OqcuPHHU04u3fuPWy] routerId=[H-X9R2EzNy]} link registered

markamind · August 10, 2022, 10:57am

I did notice something about a duplicate link… does this help explain what is happening?

“msg”:"duplicate link detected. closing current link (current link id is \u003e than new link id

markamind · August 10, 2022, 11:03am

I did not make the edge router a private router… does this make any difference?

link:
  dialers:
    - binding: transport
  listeners:
    - binding:          transport
      bind:             tls:0.0.0.0:10080
      advertise:        tls:168.138.13.227:10080
      options:
        outQueueSize:   4

markamind · August 10, 2022, 11:08am

This is what happens when I start and stop the remote edge router… the failed link alternates

markamind · August 10, 2022, 11:15am

To try an extra test… I commented out the link listeners in the remote edge router… this changed the fabric output… so that only one link is shown.

I am curious to know why this caused the behaviour… can only one link be established between two pubic edge routers?

link:
  dialers:
    - binding: transport
  #listeners:
  #  - binding:          transport
  #    bind:             tls:0.0.0.0:10080
  #    advertise:        tls:168.138.13.227:10080
  #    options:
  #      outQueueSize:   4

TheLumberjack · August 10, 2022, 11:24am

Oh geeeesh, I’m sorry. For some reason I thought you had three routers, one public and two private. Now I see you have two public routers, both with link listeners, that explains this behavior.

At this time, any two routers will only maintain a single link between them. So if there are two public edge routers with link listeners, they’ll both try link to each other. Then, one link will be chosen as the link to maintain and one link will be removed.

I was thrown off by the failed state. I’m pretty sure that’s been changed to say something like “duplicate” in recent versions of ziti, so it’s less confusing.

Anyway, the behavior you observed is expected, yes.

markamind · August 10, 2022, 11:31am

Awesome… thanks for your help with this. I can see how this makes sense… to avoid duplication.

I wanted to test the scenario out where both public edge routers were listening to see what happens… and make sure I was not making a mistake.

I have learnt so much with this example…

Topic		Replies	Views
Ziti fabric list links not showing other connections Ziti Overlay	9	28	October 3, 2024
Ziti Fabric Links Ziti Overlay	1	172	May 25, 2022
Inspecting the Fabric and Mesh Ziti Overlay	7	48	October 13, 2024
Problem when deploying Fabric Routers Ziti Overlay	15	327	July 6, 2022
Installing an edge router on a different compute Ziti Overlay	1	226	June 12, 2022

Understanding the fabric link between two public edge routers

situation

Related topics