telepresence icon indicating copy to clipboard operation
telepresence copied to clipboard

Published 20 hours ago • verified publisher icon telepresenceio

Cannot access services with telepresence version above 2.4.10

Open alexis-wefight opened this issue 2 years ago • 18 comments

Describe the bug I'm not able to access services in a connected cluster with telepresence using version above 2.4.10 without login to ambassador cloud.

In Traffic manager logs there is: Issuing a systema request without ApiKey or InstallID may result in an error

In connector.logs, there is unable to get APIKey: GetAPIKey: not logged in

Everything worked will using telepresence 2.4.10. Did something change about the licence and the requirement to be logged to Ambassador Cloud?

  • Traffic manager logs:
2022-06-28 08:19:12.4948 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:13.0008 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:13.4945 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:13.9841 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:14.5153 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:15.0062 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:15.5261 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:16.0425 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:16.5910 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:17.0790 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:17.6022 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:18.0936 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:18.5735 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:19.0781 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:19.5853 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:20.0704 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:20.5701 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:21.0560 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:21.5376 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:22.0504 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:22.5420 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:19:23.0946 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:25:22.8165 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:25:23.3625 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:25:23.8947 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:25:23.8947 warning agent-injector : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:25:24.1657 info    agent-injector : using agent image docker.io/datawire/ambassador-telepresence-agent:1.12.8
2022-06-28 08:25:24.1713 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:25:24.2732 info    agent-injector : Injecting traffic-agent into pod myvik-back-67766bfb48-.fabvik
2022-06-28 08:25:24.2733 info    agent-injector : Injecting 5 patches into pod myvik-back-67766bfb48-.fabvik
2022-06-28 08:25:24.3160 info    agent-configs : Successfully rolled out myvik-back.fabvik
2022-06-28 08:25:24.6052 info    agent-injector : Injecting traffic-agent into pod myvik-back-57cb7db46b-.fabvik
2022-06-28 08:25:24.6056 info    agent-injector : Injecting 5 patches into pod myvik-back-57cb7db46b-.fabvik
2022-06-28 08:25:25.3259 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:25:25.9409 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:25:26.5806 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:25:27.1992 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:25:27.7501 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:25:29.2913 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-06-28 08:25:30.4872 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
  • connector.log:
2022-06-28 10:13:31.5799 info    Logging at this level "info"
2022-06-28 10:13:31.5811 info    ---
2022-06-28 10:13:31.5811 info    Telepresence Connector v2.4.10 (api v3) starting...
2022-06-28 10:13:31.5811 info    PID is 644
2022-06-28 10:13:31.5811 info    
2022-06-28 10:13:31.5813 info    connector/server-grpc : gRPC server started
2022-06-28 10:13:31.7918 info    connector/background-init : Connecting to daemon...
2022-06-28 10:13:31.7923 info    connector/background-init : Connecting to k8s cluster...
2022-06-28 10:13:32.1528 info    connector/background-init : Server version v1.23.5
2022-06-28 10:13:32.1528 info    connector/background-init : Context: aks-francecentral-vik-dev
2022-06-28 10:13:32.1528 info    connector/background-init : Server: https://wefight-francecentral-vik-dev.privatelink.francecentral.azmk8s.io:443
2022-06-28 10:13:32.1528 info    connector/background-init : Connected to context aks-francecentral-vik-dev (https://wefight-francecentral-vik-dev.privatelink.francecentral.azmk8s.io:443)
2022-06-28 10:13:32.3878 info    connector/background-init : Connecting to traffic manager...
2022-06-28 10:13:32.3879 info    connector/background-init : Waiting for TrafficManager to connect
2022/06/28 10:13:32 Patching synced Namespace 4ea06f45-72a4-487b-a5b3-b91fb8294f1e
2022-06-28 10:13:32.4829 info    connector/background-manager : Existing Traffic Manager 2.4.10 not owned by cli or does not need upgrade, will not modify
2022-06-28 10:13:33.2917 info    connector/server-grpc/conn=1/Uninstall-3 : Uninstalling Traffic Manager in namespace ambassador
2022-06-28 10:13:34.9032 info    connector/server-grpc/conn=2:shutdown_logger : shutting down (gracefully)...
2022-06-28 10:13:35.1176 info    connector/background-manager:shutdown_logger : shutting down (gracefully)...
2022-06-28 10:13:35.1177 info    connector/background-k8swatch:shutdown_logger : shutting down (gracefully)...
2022-06-28 10:13:35.1177 info    connector:shutdown_logger : shutting down (gracefully)...
2022-06-28 10:13:35.1178 info    connector/background-systema:shutdown_logger : shutting down (gracefully)...
2022-06-28 10:18:35.6096 info    ---
2022-06-28 10:18:35.6097 info    Telepresence Connector v2.6.8 (api v3) starting...
2022-06-28 10:18:35.6097 info    PID is 1339
2022-06-28 10:18:35.6097 info    
2022-06-28 10:18:35.6111 info    connector/server-grpc : gRPC server started
2022-06-28 10:18:35.8844 info    connector/session : -- Starting new session
2022-06-28 10:18:35.8848 info    connector/session : Connecting to root daemon...
2022-06-28 10:18:35.8867 info    connector/session : Connecting to k8s cluster...
W0628 10:18:35.907486    1339 azure.go:92] WARNING: the azure auth plugin is deprecated in v1.22+, unavailable in v1.25+; use https://github.com/Azure/kubelogin instead.
To learn more, consult https://kubernetes.io/docs/reference/access-authn-authz/authentication/#client-go-credential-plugins
2022-06-28 10:18:36.1419 info    connector/session : Server version v1.23.5
2022-06-28 10:18:36.1420 info    connector/session : Context: aks-francecentral-vik-dev
2022-06-28 10:18:36.1420 info    connector/session : Server: https://wefight-francecentral-vik-dev.privatelink.francecentral.azmk8s.io:443
2022-06-28 10:18:36.1455 info    connector/session : Connected to context aks-francecentral-vik-dev (https://wefight-francecentral-vik-dev.privatelink.francecentral.azmk8s.io:443)
2022-06-28 10:18:36.1960 info    connector/session : Connecting to traffic manager...
2022-06-28 10:18:36.1961 error   connector/session : unable to get APIKey: GetAPIKey: not logged in
2022-06-28 10:18:36.3192 info    connector/session : No existing Traffic Manager found in namespace ambassador, installing v2.6.8...
2022-06-28 10:20:19.8299 debug   Logging at this level "debug"
2022-06-28 10:20:19.8299 info    connector/config-reload : Configuration reloaded
2022-06-28 10:27:19.3740 debug   connector/server-grpc/conn=3/ListCommands-3 : called
2022-06-28 10:27:19.3741 debug   connector/server-grpc/conn=3/ListCommands-3 : returned
2022-06-28 10:27:19.3785 debug   connector/server-grpc/conn=4/Status-4 : called
2022-06-28 10:27:19.3785 debug   connector/server-grpc/conn=4/UserNotifications-5 : called
2022-06-28 10:27:19.4169 debug   connector/server-grpc/conn=4/Status-4 : returned
2022-06-28 10:27:19.4202 debug   connector/server-grpc/conn=4/GatherLogs-6 : called
2022-06-28 10:27:19.7935 debug   connector/session/GatherLogs-0 : gathering logs for myvik-back-57cb7db46b-cnm9t.fabvik, yaml = false
2022-06-28 10:27:23.2165 debug   connector/session/GatherLogs-0 : gathering logs for traffic-manager-5d6bcf4df7-4p6gc.ambassador, yaml = false
2022-06-28 10:27:23.4345 debug   connector/server-grpc/conn=4/GatherLogs-6 : returned
2022-06-28 10:27:23.4360 debug   connector/server-grpc/conn=4/UserNotifications-5 : returned
  • daemon.log:
2022-06-28 10:45:05.0277 debug   daemon/server-grpc/conn=2 : Received gRPC Connect
2022-06-28 10:45:05.0278 info    daemon/session : -- Starting new session
2022-06-28 10:45:05.0582 info    daemon/session : Connected to Manager 2.6.8
2022-06-28 10:45:05.1150 info    daemon/session : Adding never-proxy subnet 10.11.2.101/32
2022-06-28 10:45:05.2235 info    daemon/session/watch-cluster-info : Already connected to cluster, will not map cluster subnets
2022-06-28 10:45:05.2236 info    daemon/session/watch-cluster-info : Setting cluster DNS to 10.0.0.10
2022-06-28 10:45:05.2236 info    daemon/session/watch-cluster-info : Setting cluster domain to "cluster.local."
2022-06-28 10:45:05.2236 debug   daemon/session/watch-cluster-info : WatchClusterInfo update
2022-06-28 10:45:05.2237 error   daemon/session/dns/resolved : failed to connect to system bus: dial unix /var/run/dbus/system_bus_socket: connect: no such file or directory
2022-06-28 10:45:05.2238 error   daemon/session/dns/resolved : systemd-resolved is not running
2022-06-28 10:45:05.2238 debug   daemon/session/router : TUN read loop starting
2022-06-28 10:45:05.2238 info    daemon/session/dns : Unable to use systemd-resolved, falling back to local server
2022-06-28 10:45:05.2239 info    daemon/session/dns/legacy : Automatically set -dns=172.23.96.1
2022-06-28 10:45:05.2243 info    daemon/session/dns/legacy : started command ["docker" "inspect" "bridge" "-f" "{{(index .IPAM.Config 0).Gateway}}"] : dexec.pid="4555"
2022-06-28 10:45:05.2244 info    daemon/session/dns/legacy :  : dexec.pid="4555" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.3769 info    daemon/session/dns/legacy :  : dexec.pid="4555" dexec.stream="stdout" dexec.data="172.17.0.1\n"
2022-06-28 10:45:05.4299 info    daemon/session/dns/legacy : finished successfully: exit status 0 : dexec.pid="4555"
2022-06-28 10:45:05.4302 info    daemon/session/dns/legacy : docker gateway 172.17.0.1 is not visible as a network interface
2022-06-28 10:45:05.4302 debug   daemon/session/dns/legacy : Bootstrapping local DNS server on port 59699
2022-06-28 10:45:05.4324 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-D" "OUTPUT" "-j" "TELEPRESENCE_DNS"] : dexec.pid="4600"
2022-06-28 10:45:05.4326 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4600" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4329 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4600" dexec.stream="stdout+stderr" dexec.data="iptables v1.8.4 (legacy): Couldn't load target `TELEPRESENCE_DNS':No such file or directory\n"
2022-06-28 10:45:05.4329 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4600" dexec.stream="stdout+stderr" dexec.data="\n"
2022-06-28 10:45:05.4329 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4600" dexec.stream="stdout+stderr" dexec.data="Try `iptables -h' or 'iptables --help' for more information.\n"
2022-06-28 10:45:05.4330 info    daemon/session/dns/legacy/NAT-redirect : finished with error: exit status 2 : dexec.pid="4600"
2022-06-28 10:45:05.4333 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-F" "TELEPRESENCE_DNS"] : dexec.pid="4601"
2022-06-28 10:45:05.4334 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4601" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4338 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4601" dexec.stream="stdout+stderr" dexec.data="iptables: No chain/target/match by that name.\n"
2022-06-28 10:45:05.4339 info    daemon/session/dns/legacy/NAT-redirect : finished with error: exit status 1 : dexec.pid="4601"
2022-06-28 10:45:05.4341 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-X" "TELEPRESENCE_DNS"] : dexec.pid="4602"
2022-06-28 10:45:05.4343 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4602" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4346 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4602" dexec.stream="stdout+stderr" dexec.data="iptables: No chain/target/match by that name.\n"
2022-06-28 10:45:05.4347 info    daemon/session/dns/legacy/NAT-redirect : finished with error: exit status 1 : dexec.pid="4602"
2022-06-28 10:45:05.4353 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-N" "TELEPRESENCE_DNS"] : dexec.pid="4603"
2022-06-28 10:45:05.4353 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4603" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4359 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4603"
2022-06-28 10:45:05.4363 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "55601" "-j" "RETURN"] : dexec.pid="4604"
2022-06-28 10:45:05.4364 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4604" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4375 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4604"
2022-06-28 10:45:05.4378 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "34757" "-j" "RETURN"] : dexec.pid="4605"
2022-06-28 10:45:05.4379 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4605" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4388 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4605"
2022-06-28 10:45:05.4391 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "44631" "-j" "RETURN"] : dexec.pid="4606"
2022-06-28 10:45:05.4392 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4606" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4400 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4606"
2022-06-28 10:45:05.4403 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "40748" "-j" "RETURN"] : dexec.pid="4607"
2022-06-28 10:45:05.4404 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4607" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4411 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4607"
2022-06-28 10:45:05.4414 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "44575" "-j" "RETURN"] : dexec.pid="4608"
2022-06-28 10:45:05.4415 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4608" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4423 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4608"
2022-06-28 10:45:05.4426 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "38382" "-j" "RETURN"] : dexec.pid="4609"
2022-06-28 10:45:05.4427 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4609" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4435 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4609"
2022-06-28 10:45:05.4438 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "45222" "-j" "RETURN"] : dexec.pid="4610"
2022-06-28 10:45:05.4440 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4610" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4450 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4610"
2022-06-28 10:45:05.4453 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "57924" "-j" "RETURN"] : dexec.pid="4611"
2022-06-28 10:45:05.4454 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4611" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4462 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4611"
2022-06-28 10:45:05.4464 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "47509" "-j" "RETURN"] : dexec.pid="4612"
2022-06-28 10:45:05.4465 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4612" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4474 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4612"
2022-06-28 10:45:05.4477 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "39938" "-j" "RETURN"] : dexec.pid="4613"
2022-06-28 10:45:05.4479 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4613" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4488 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4613"
2022-06-28 10:45:05.4491 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--dest" "172.23.96.1/32" "--dport" "53" "-j" "DNAT" "--to-destination" "127.0.0.1:59699"] : dexec.pid="4614"
2022-06-28 10:45:05.4492 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4614" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4504 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4614"
2022-06-28 10:45:05.4507 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-I" "OUTPUT" "1" "-j" "TELEPRESENCE_DNS"] : dexec.pid="4615"
2022-06-28 10:45:05.4508 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4615" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:05.4515 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4615"
2022-06-28 10:45:07.6765 debug   daemon/session/dns/legacy/SearchPaths : [] -> [ambassador calico-system cert-manager data datavik default elastic-system fabvik internal-api kube-node-lease kube-public kube-system kubecost medvik mongodb monitoring nginx nginx-internal observability rbac redis redis-authentication-api tigera-operator vela-system viking webvik]
2022-06-28 10:45:07.6766 debug   daemon/session/dns/legacy/SearchPaths : Performing initial recursion check with tel2-recursion-check.kube-system
2022-06-28 10:45:07.6771 debug   daemon/session/dns/legacy/Server : LookupHost "tel2-recursion-check.kube-system"
2022-06-28 10:45:07.7554 debug   daemon/session/dns/legacy/Server : DNS resolver is not recursive
2022-06-28 10:45:07.7555 debug   daemon/session/dns/legacy/Server : A      tel2-recursion-check.kube-system. -> NXDOMAIN 
2022-06-28 10:45:07.7556 debug   daemon/session/dns/legacy/SearchPaths : Recursion check finished
2022-06-28 10:45:14.2400 debug   daemon/server-grpc/conn=8 : Received gRPC Disconnect
2022-06-28 10:45:14.2403 debug   daemon/session/watch-cluster-info : goroutine "/daemon/session/watch-cluster-info" exited without error
2022-06-28 10:45:14.2403 info    daemon/session/dns/legacy:shutdown_logger : shutting down (gracefully)...
2022-06-28 10:45:14.2403 info    daemon/session:shutdown_logger : shutting down (gracefully)...
2022-06-28 10:45:14.2403 info    daemon/session/dns/legacy/Server:shutdown_logger : shutting down (gracefully)...
2022-06-28 10:45:14.2403 debug   daemon/session/dns/legacy/Server/127.0.0.1:59699 : Shutting down DNS server
2022-06-28 10:45:14.2403 debug   daemon/session/dns/legacy/SearchPaths : goroutine "/daemon/session/dns/legacy/SearchPaths" exited without error
2022-06-28 10:45:14.2404 debug   daemon/session/dns/legacy/Server/127.0.0.1:59699 : goroutine "/daemon/session/dns/legacy/Server/127.0.0.1:59699" exited without error
2022-06-28 10:45:14.2404 debug   daemon/session/dns/legacy/Server : goroutine "/daemon/session/dns/legacy/Server" exited without error
time="2022-06-28T10:45:14+02:00" level=info dexec.pid=4690 msg="started command [\"iptables\" \"-t\" \"nat\" \"-D\" \"OUTPUT\" \"-j\" \"TELEPRESENCE_DNS\"]"
time="2022-06-28T10:45:14+02:00" level=info dexec.pid=4690 dexec.stream=stdin dexec.err=EOF
time="2022-06-28T10:45:14+02:00" level=info dexec.pid=4690 msg="finished successfully: exit status 0"
time="2022-06-28T10:45:14+02:00" level=info dexec.pid=4691 msg="started command [\"iptables\" \"-t\" \"nat\" \"-F\" \"TELEPRESENCE_DNS\"]"
time="2022-06-28T10:45:14+02:00" level=info dexec.pid=4691 dexec.stream=stdin dexec.err=EOF
time="2022-06-28T10:45:14+02:00" level=info dexec.pid=4691 msg="finished successfully: exit status 0"
time="2022-06-28T10:45:14+02:00" level=info dexec.pid=4692 msg="started command [\"iptables\" \"-t\" \"nat\" \"-X\" \"TELEPRESENCE_DNS\"]"
time="2022-06-28T10:45:14+02:00" level=info dexec.pid=4692 dexec.stream=stdin dexec.err=EOF
time="2022-06-28T10:45:14+02:00" level=info dexec.pid=4692 msg="finished successfully: exit status 0"
2022-06-28 10:45:14.2443 debug   daemon/session/dns/legacy/NAT-redirect : goroutine "/daemon/session/dns/legacy/NAT-redirect" exited without error
2022-06-28 10:45:14.2444 debug   daemon/session : Brining down TUN-device
2022-06-28 10:45:14.3718 debug   daemon/session : Sending disconnect message to connector
2022-06-28 10:45:14.3721 debug   daemon/session : Connector disconnect complete
2022-06-28 10:45:14.3722 debug   daemon/session/dns : goroutine "/daemon/session/dns" exited without error
2022-06-28 10:45:14.3718 debug   daemon/session/router : goroutine "/daemon/session/router" exited without error
2022-06-28 10:45:14.3723 info    daemon/session : -- Session ended
2022-06-28 10:45:19.9009 debug   daemon/server-grpc/conn=2 : Received gRPC Connect
2022-06-28 10:45:19.9010 info    daemon/session : -- Starting new session
2022-06-28 10:45:19.9463 info    daemon/session : Connected to Manager 2.6.8
2022-06-28 10:45:19.9832 info    daemon/session : Adding never-proxy subnet 10.11.2.101/32
2022-06-28 10:45:20.0765 info    daemon/session/watch-cluster-info : Already connected to cluster, will not map cluster subnets
2022-06-28 10:45:20.0766 info    daemon/session/watch-cluster-info : Setting cluster DNS to 10.0.0.10
2022-06-28 10:45:20.0766 info    daemon/session/watch-cluster-info : Setting cluster domain to "cluster.local."
2022-06-28 10:45:20.0766 debug   daemon/session/watch-cluster-info : WatchClusterInfo update
2022-06-28 10:45:20.0767 debug   daemon/session/router : TUN read loop starting
2022-06-28 10:45:20.0768 error   daemon/session/dns/resolved : failed to connect to system bus: dial unix /var/run/dbus/system_bus_socket: connect: no such file or directory
2022-06-28 10:45:20.0769 error   daemon/session/dns/resolved : systemd-resolved is not running
2022-06-28 10:45:20.0769 info    daemon/session/dns : Unable to use systemd-resolved, falling back to local server
2022-06-28 10:45:20.0770 info    daemon/session/dns/legacy : Automatically set -dns=172.23.96.1
2022-06-28 10:45:20.0775 info    daemon/session/dns/legacy : started command ["docker" "inspect" "bridge" "-f" "{{(index .IPAM.Config 0).Gateway}}"] : dexec.pid="4747"
2022-06-28 10:45:20.0776 info    daemon/session/dns/legacy :  : dexec.pid="4747" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2182 info    daemon/session/dns/legacy :  : dexec.pid="4747" dexec.stream="stdout" dexec.data="172.17.0.1\n"
2022-06-28 10:45:20.2495 info    daemon/session/dns/legacy : finished successfully: exit status 0 : dexec.pid="4747"
2022-06-28 10:45:20.2498 info    daemon/session/dns/legacy : docker gateway 172.17.0.1 is not visible as a network interface
2022-06-28 10:45:20.2499 debug   daemon/session/dns/legacy : Bootstrapping local DNS server on port 53591
2022-06-28 10:45:20.2518 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-D" "OUTPUT" "-j" "TELEPRESENCE_DNS"] : dexec.pid="4791"
2022-06-28 10:45:20.2519 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4791" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2523 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4791" dexec.stream="stdout+stderr" dexec.data="iptables v1.8.4 (legacy): Couldn't load target `TELEPRESENCE_DNS':No such file or directory\n"
2022-06-28 10:45:20.2524 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4791" dexec.stream="stdout+stderr" dexec.data="\n"
2022-06-28 10:45:20.2524 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4791" dexec.stream="stdout+stderr" dexec.data="Try `iptables -h' or 'iptables --help' for more information.\n"
2022-06-28 10:45:20.2524 info    daemon/session/dns/legacy/NAT-redirect : finished with error: exit status 2 : dexec.pid="4791"
2022-06-28 10:45:20.2527 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-F" "TELEPRESENCE_DNS"] : dexec.pid="4792"
2022-06-28 10:45:20.2528 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4792" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2532 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4792" dexec.stream="stdout+stderr" dexec.data="iptables: No chain/target/match by that name.\n"
2022-06-28 10:45:20.2532 info    daemon/session/dns/legacy/NAT-redirect : finished with error: exit status 1 : dexec.pid="4792"
2022-06-28 10:45:20.2535 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-X" "TELEPRESENCE_DNS"] : dexec.pid="4793"
2022-06-28 10:45:20.2536 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4793" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2540 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4793" dexec.stream="stdout+stderr" dexec.data="iptables: No chain/target/match by that name.\n"
2022-06-28 10:45:20.2540 info    daemon/session/dns/legacy/NAT-redirect : finished with error: exit status 1 : dexec.pid="4793"
2022-06-28 10:45:20.2543 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-N" "TELEPRESENCE_DNS"] : dexec.pid="4794"
2022-06-28 10:45:20.2544 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4794" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2555 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4794"
2022-06-28 10:45:20.2558 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "38433" "-j" "RETURN"] : dexec.pid="4795"
2022-06-28 10:45:20.2559 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4795" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2567 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4795"
2022-06-28 10:45:20.2571 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "54275" "-j" "RETURN"] : dexec.pid="4796"
2022-06-28 10:45:20.2571 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4796" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2578 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4796"
2022-06-28 10:45:20.2581 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "48140" "-j" "RETURN"] : dexec.pid="4797"
2022-06-28 10:45:20.2582 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4797" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2589 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4797"
2022-06-28 10:45:20.2591 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "40682" "-j" "RETURN"] : dexec.pid="4798"
2022-06-28 10:45:20.2591 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4798" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2598 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4798"
2022-06-28 10:45:20.2600 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "45948" "-j" "RETURN"] : dexec.pid="4799"
2022-06-28 10:45:20.2601 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4799" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2609 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4799"
2022-06-28 10:45:20.2611 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "44144" "-j" "RETURN"] : dexec.pid="4800"
2022-06-28 10:45:20.2612 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4800" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2619 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4800"
2022-06-28 10:45:20.2622 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "43590" "-j" "RETURN"] : dexec.pid="4801"
2022-06-28 10:45:20.2623 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4801" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2631 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4801"
2022-06-28 10:45:20.2634 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "48280" "-j" "RETURN"] : dexec.pid="4802"
2022-06-28 10:45:20.2634 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4802" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2642 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4802"
2022-06-28 10:45:20.2644 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "51165" "-j" "RETURN"] : dexec.pid="4803"
2022-06-28 10:45:20.2645 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4803" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2652 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4803"
2022-06-28 10:45:20.2654 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--source" "172.23.105.19" "--sport" "51654" "-j" "RETURN"] : dexec.pid="4804"
2022-06-28 10:45:20.2654 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4804" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2665 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4804"
2022-06-28 10:45:20.2667 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-A" "TELEPRESENCE_DNS" "-p" "udp" "--dest" "172.23.96.1/32" "--dport" "53" "-j" "DNAT" "--to-destination" "127.0.0.1:53591"] : dexec.pid="4805"
2022-06-28 10:45:20.2668 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4805" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2676 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4805"
2022-06-28 10:45:20.2678 info    daemon/session/dns/legacy/NAT-redirect : started command ["iptables" "-t" "nat" "-I" "OUTPUT" "1" "-j" "TELEPRESENCE_DNS"] : dexec.pid="4806"
2022-06-28 10:45:20.2679 info    daemon/session/dns/legacy/NAT-redirect :  : dexec.pid="4806" dexec.stream="stdin" dexec.err="EOF"
2022-06-28 10:45:20.2683 info    daemon/session/dns/legacy/NAT-redirect : finished successfully: exit status 0 : dexec.pid="4806"
2022-06-28 10:45:22.4939 debug   daemon/session/dns/legacy/SearchPaths : [] -> [ambassador calico-system cert-manager data datavik default elastic-system fabvik internal-api kube-node-lease kube-public kube-system kubecost medvik mongodb monitoring nginx nginx-internal observability rbac redis redis-authentication-api tigera-operator vela-system viking webvik]
2022-06-28 10:45:22.4940 debug   daemon/session/dns/legacy/SearchPaths : Performing initial recursion check with tel2-recursion-check.kube-system
2022-06-28 10:45:22.4945 debug   daemon/session/dns/legacy/Server : LookupHost "tel2-recursion-check.kube-system"
2022-06-28 10:45:22.5659 debug   daemon/session/dns/legacy/Server : DNS resolver is not recursive
2022-06-28 10:45:22.5883 debug   daemon/session/dns/legacy/Server : A      tel2-recursion-check.kube-system. -> NXDOMAIN 
2022-06-28 10:45:22.5885 debug   daemon/session/dns/legacy/SearchPaths : Recursion check finished
2022-06-28 10:46:16.7823 debug   daemon/session/dns/legacy/Server : (172.23.96.1) AAAA   default.exp-tas.com. -> NOERROR [default.exp-tas.com.	0	IN	CNAME	deault-exp-tas-com.e-0014.e-msedge.net. deault-exp-tas-com.e-0014.e-msedge.net.	0	IN	CNAME	e-0014.e-msedge.net.]
2022-06-28 10:46:16.8266 debug   daemon/session/dns/legacy/Server : (172.23.96.1) A      default.exp-tas.com. -> NOERROR [default.exp-tas.com.	0	IN	CNAME	deault-exp-tas-com.e-0014.e-msedge.net. deault-exp-tas-com.e-0014.e-msedge.net.	0	IN	CNAME	e-0014.e-msedge.net. e-0014.e-msedge.net.	0	IN	A	13.107.5.93]
2022-06-28 10:46:28.9971 debug   daemon/session/dns/legacy/Server : LookupHost "kubernetes.default"
2022-06-28 10:46:29.0333 debug   daemon/session/dns/legacy/Server : AAAA   kubernetes.default. -> NOERROR EMPTY
2022-06-28 10:46:29.0333 debug   daemon/session/dns/legacy/Server : A      kubernetes.default. -> NOERROR kubernetes.default.	4	IN	A	10.0.0.1

To Reproduce

  • Install telepresence 2.6.8
  • Create config.yaml 
cloud:
  skipLogin: true
logLevels:
  userDaemon: debug
  rootDaemon: debug
  • telepresence connect
  • curl -ik https://kubernetes.default --> timeout (but able to resolve DNS)

Expected behavior It should be able to access https://kubernetes.default

Versions (please complete the following information):

  • Output of telepresence version:
Client: v2.6.8 (api v3)
Root Daemon: v2.6.8 (api v3)
User Daemon: v2.6.8 (api v3)
  • Operating system of workstation running telepresence commands --> WSL (same behavior on MacOS)
  • Kubernetes environment and Version [e.g. Minikube, bare metal, Google Kubernetes Engine] : Azure Kubernetes Service

VPN-related bugs: If you're reporting an issue around telepresence connectivity when using a VPN, and are running Telepresence 2.4.8 or above, please also attach the output of telepresence test-vpn, and the following information: ---------- Test Results: ✅ pod subnet 10.11.0.0/22 is clear of VPN ✅ svc subnet 10.0.0.0/24 is clear of VPN

  • Which VPN client are you using: OpenVPN
  • Which VPN server are you using: OpenVPN
  • How is your VPN pushing DNS configuration? It does not push any DNS configuration.

Additional context Add any other context about the problem here.

alexis-wefight avatar Jun 28 '22 08:06 alexis-wefight

facing the same issue

maxyurk avatar Jul 10 '22 10:07 maxyurk

I have the same issue

gunsluo avatar Jul 13 '22 03:07 gunsluo

same issue here, with the same version as above

aldycool avatar Jul 27 '22 01:07 aldycool

I have the same issue

jiangxiaoqiang avatar Aug 05 '22 07:08 jiangxiaoqiang

The message 2022-06-28 08:19:12.4948 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error is not an error, and it is not what's causing the timeout. The expected behavior when doing curl -ik https://kubernetes.default while telepresence is connected, is a response similar to:

HTTP/2 401 
audit-id: aab1a9b7-9cdb-4687-bda8-949d3b6670ef
cache-control: no-cache, private
content-type: application/json
content-length: 157
date: Sat, 06 Aug 2022 06:54:30 GMT

{
  "kind": "Status",
  "apiVersion": "v1",
  "metadata": {},
  "status": "Failure",
  "message": "Unauthorized",
  "reason": "Unauthorized",
  "code": 401
}

If you instead get a timeout, please try:

telepresence loglevel debug

then look at the logs of the traffic manager when the curl call is made. There should be some additional info if you get a timeout.

thallgren avatar Aug 06 '22 06:08 thallgren

when I using this command curl -ik https://kubernetes.default in macOS Monterey 12 5 terminal after run connect, just shows error:

➜  cruise-web git:(main) ✗ curl -ik https://kubernetes.default
curl: (97) Could not resolve host: kubernetes.default

this is the full log:

➜  cruise-web git:(main) ✗ telepresence connect
telepresence: error: connector.Connect: Cluster configuration changed, please quit telepresence and reconnect

See logs for details (1 error found): "/Users/xiaoqiangjiang/Library/Logs/telepresence/daemon.log"

See logs for details (2 errors found): "/Users/xiaoqiangjiang/Library/Logs/telepresence/connector.log"
If you think you have encountered a bug, please run `telepresence gather-logs` and attach the telepresence_logs.zip to your github issue or create a new one: https://github.com/telepresenceio/telepresence/issues/new?template=Bug_report.md .
➜  cruise-web git:(main) ✗ telepresence quit
Telepresence Network disconnecting...done
Telepresence Traffic Manager disconnecting...done
➜  cruise-web git:(main) ✗ telepresence connect
Connected to context context-reddwarf (https://106.141.13.121:6443)
➜  cruise-web git:(main) ✗ curl -ik https://kubernetes.default
curl: (97) Could not resolve host: kubernetes.default
➜  cruise-web git:(main) ✗ telepresence loglevel debug

➜  cruise-web git:(main) ✗ curl -ik https://kubernetes.default
curl: (97) Could not resolve host: kubernetes.default
➜  cruise-web git:(main) ✗ telepresence quit
Telepresence Network disconnecting...done
Telepresence Traffic Manager disconnecting...done
➜  cruise-web git:(main) ✗ telepresence loglevel debug

Connected to context context-reddwarf (https://106.14.183.131:6443)

and this is the version info:

➜  cruise-web git:(main) ✗ telepresence version
Client: v2.6.8 (api v3)
Root Daemon: v2.6.8 (api v3)
User Daemon: v2.6.8 (api v3)

jiangxiaoqiang avatar Aug 06 '22 17:08 jiangxiaoqiang

Then that's a different problem than the one originally reported. Here DNS is not working. Would you care to share the logs?

thallgren avatar Aug 07 '22 18:08 thallgren

this is the detail log:

➜  cruise-open git:(main) tail -f /Users/xiaoqiangjiang/Library/Logs/telepresence/daemon.log
2022-08-07 01:29:06.5043 debug   daemon/server-grpc/conn=8 : Received gRPC Disconnect
2022-08-07 01:29:06.5044 info    daemon/session : -- Session ended
2022-08-07 01:29:06.5044 info    daemon/session:shutdown_logger : shutting down (gracefully)...
2022-08-07 01:29:06.5044 debug   daemon/session/watch-cluster-info : goroutine "/daemon/session/watch-cluster-info" exited without error
2022-08-07 01:29:10.8791 debug   daemon/server-grpc/conn=2 : Received gRPC Connect
2022-08-07 01:29:10.8792 info    daemon/session : -- Starting new session
2022-08-07 01:29:10.9337 info    daemon/session : Connected to Manager 2.6.8
2022-08-07 01:29:10.9428 info    daemon/session : Adding never-proxy subnet 106.14.183.131/32
2022-08-07 01:59:11.3369 info    Logging at this level "info"
2022-08-07 22:45:36.5198 error   daemon/session/watch-cluster-info : WatchClusterInfo recv: Unavailable: error reading from server: EOF

jiangxiaoqiang avatar Aug 13 '22 12:08 jiangxiaoqiang

same here, it used to be working and today it stopped to work suddenly.

❯ curl -ik https://kubernetes.default
curl: (6) Could not resolve host: kubernetes.default

The daemon log at debug level, seems to be exactly the same as Jiangxiaoqiang's.

2022-08-24 01:15:25.9511 debug   Logging at this level "debug"
2022-08-24 01:15:37.8592 debug   daemon/server-grpc/conn=14 : Received gRPC Disconnect
2022-08-24 01:15:37.8593 debug   daemon/session/watch-cluster-info : goroutine "/daemon/session/watch-cluster-info" exited without error
2022-08-24 01:15:37.8593 info    daemon/session : -- Session ended
2022-08-24 01:15:37.8593 info    daemon/session:shutdown_logger : shutting down (gracefully)...
2022-08-24 01:15:40.8106 debug   daemon/server-grpc/conn=2 : Received gRPC Connect
2022-08-24 01:15:40.8106 info    daemon/session : -- Starting new session
2022-08-24 01:15:40.8140 info    daemon/session : Connected to Manager 2.7.1
2022-08-24 01:15:40.8186 info    daemon/session : Adding never-proxy subnet 127.0.0.1/32

DanielYWoo avatar Aug 23 '22 17:08 DanielYWoo

Our solution was to re-install telepresence:

telepresence helm uninstall
telepresence helm install

iosifnicolae2 avatar Sep 02 '22 13:09 iosifnicolae2

Our solution was to re-install telepresence:

telepresence helm uninstall
telepresence helm install

It does not help here. The problem is, it sometimes works, sometimes not, it's really difficult to find the failure patterns. From the doc

macOS resolver This resolver hooks into the macOS DNS system by creating files under /etc/resolver. Those files correspond to some domain and contain the port number of the Telepresence resolver. Telepresence creates one such file for each of the currently mapped namespaces and include-suffixes option. The file telepresence.local contains a search path that is configured based on current intercepts so that single label names can be resolved correctly.

But I do have a lot of files under /etc/resolver, but it just does not work. e.g., I have a file like this:

port 51681
domain test
nameserver 127.0.0.1

But I don't have anything with this command

 lsof -i:51681

The port forward does not exist.

DanielYWoo avatar Sep 03 '22 15:09 DanielYWoo

@DanielYWoo telepresence will only put files under /etc/resolver when it is connected. When you disconnect (using telepresence quit), the DNS is restored to what it was before telepresence connect and the files are removed. Perhaps you have files lingering there even though telepresence is disconnected? If so, then removing them might help.

thallgren avatar Sep 04 '22 02:09 thallgren

@thallgren Sorry, I did not make it clear. I checked the /etc/resovler and lsof when telepresence tells me it's connected. Today I manually deleted everything in /etc/resolver and restart telepresence daemon, run telepresence connect again, then nothing is created in /etc/resolver and port-forward is not created too. My understanding is that, with telepresence connect, the DNS and port-forward is triggered on the fly, and the files under /etc/resolver are triggered on the fly, when I access something in the cluster, right?

DanielYWoo avatar Sep 05 '22 01:09 DanielYWoo

@DanielYWoo , if you do telepresence connect on a macOS and no files show up under /etc/resolver, that means that the telepresence DNS doesn't start at all. The probable cause for that is that it doesn't get the information it requests from the traffic-manager. Logs of interest to track down what's going on are the connector.log and the log from the traffic-manager pod.

thallgren avatar Sep 05 '22 06:09 thallgren

I set the log level to debug and this is what I got.

telepresence loglevel debug

telepresence status
W0905 16:40:34.648537   72573 native_arm64.go:52] Could not read /proc/cpuinfo: open /proc/cpuinfo: no such file or directory
W0905 16:40:34.648565   72573 native_arm64.go:177] Could not read /proc/self/auxv: open /proc/self/auxv: no such file or directory
Root Daemon: Running
  Version   : v2.7.2 (api 3)
  DNS       :
    Remote IP       : <nil>
    Exclude suffixes: [.arpa .com .io .net .org .ru]
    Include suffixes: []
    Timeout         : 8s
  Also Proxy : (0 subnets)
  Never Proxy: (1 subnets)
    - 127.0.0.1/32
User Daemon: Running
  Version         : v2.7.2 (api 3)
  Executable      : /Users/I532165/Library/Application Support/telepresence/telepresence-pro
  Install ID      : 65e27462-740c-4796-945e-1e81bafbe98d
  Ambassador Cloud: ...
  Status            : Connected
  Kubernetes server : https://kubernetes.docker.internal:6443
  Kubernetes context: docker-desktop
  Intercepts        : 0 total

The connector.log shows

2022-09-05 16:40:29.3529 info    connector/session : -- Starting new session
2022-09-05 16:40:29.3539 info    connector/session : Connecting to k8s cluster...
2022-09-05 16:40:29.3934 info    connector/session : Server version v1.24.2
2022-09-05 16:40:29.3934 info    connector/session : Context: docker-desktop
2022-09-05 16:40:29.3934 info    connector/session : Server: https://kubernetes.docker.internal:6443
2022-09-05 16:40:29.3946 info    connector/session : Connected to context docker-desktop (https://kubernetes.docker.internal:6443)
2022-09-05 16:40:29.3983 info    connector/session : Connecting to traffic manager...
2022-09-05 16:40:29.4109 info    connector/session : IsTrafficManager(namespace="ambassador"): current install: version="2.7.1", owner="unknown", state.status="deployed", state.desc="Install complete"
2022-09-05 16:40:30.4647 info    connector/session : Starting additional session service reverse-conn
2022-09-05 16:40:30.4650 info    connector/session : Starting additional session service namespace-watcher
2022-09-05 16:40:30.4650 info    connector/session : Starting additional session service ingress-info-connection
2022-09-05 16:40:30.4656 debug   Logging at this level "debug"
2022-09-05 16:40:30.4661 debug   connector/server-grpc/conn=20/SetLogLevel-34 : returned
2022-09-05 16:40:30.4730 debug   connector/session/intercept-port-forward : posting search paths [ambassador dapr-poc dapr-poc-elk dapr-poc-facility dapr-poc-foundation dapr-poc-grafana dapr-poc-prometheus dapr-poc-recruiting dapr-poc-zipkin dapr-system default kube-node-lease kube-public kube-system test-cpu-quota] and namespaces []
2022-09-05 16:40:30.4735 debug   connector/session/intercept-port-forward : search paths posted successfully
2022-09-05 16:40:30.4917 debug   connector/server-grpc/conn=20/UserNotifications-33 : returned
2022-09-05 16:40:31.6676 debug   connector/server-grpc/conn=23/UserNotifications-35 : called
2022-09-05 16:40:31.6677 debug   connector/server-grpc/conn=22/UserNotifications-36 : called
2022-09-05 16:40:31.6681 debug   connector/server-grpc/conn=23/GetCloudAPIKey-37 : called
2022-09-05 16:40:31.6683 debug   connector/server-grpc/conn=23/GetCloudAPIKey-37 : returned
2022-09-05 16:40:31.6681 debug   connector/server-grpc/conn=22/GetCloudAPIKey-38 : called
2022-09-05 16:40:31.6684 debug   connector/server-grpc/conn=22/GetCloudAPIKey-38 : returned
2022-09-05 16:40:31.6693 info    connector/session/reverse-conn/client : Established a reverse connection to Ambassador Cloud
2022-09-05 16:40:31.6695 debug   connector/server-grpc/conn=22/UserNotifications-36 : returned
2022-09-05 16:40:31.6696 debug   connector/server-grpc/conn=23/UserNotifications-35 : returned
2022-09-05 16:40:32.2174 debug   connector/session/reverse-conn/server/conn=localrole=client,localhostname=manager/GetConnectorInfo-39 : called
2022-09-05 16:40:32.2210 debug   connector/session/reverse-conn/server/conn=localrole=client,localhostname=manager/GetConnectorInfo-39 : returned
2022-09-05 16:40:34.6498 debug   connector/server-grpc/conn=24/ListCommands-40 : called
2022-09-05 16:40:34.6505 debug   connector/server-grpc/conn=24/ListCommands-40 : returned
2022-09-05 16:40:34.6662 debug   connector/server-grpc/conn=25/GetCloudUserInfo-41 : called
2022-09-05 16:40:34.8777 debug   connector/server-grpc/conn=25/GetCloudUserInfo-41 : returned
2022-09-05 16:40:34.8787 debug   connector/server-grpc/conn=25/Status-42 : called
2022-09-05 16:40:34.8815 debug   connector/server-grpc/conn=25/Status-42 : returned

The traffic-manager log is dull

2022-09-05 07:47:39.4830 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 07:47:39.7868 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:40:30.4874 debug   Logging at this level "debug"
2022-09-05 08:42:37.7107 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:37.9473 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:38.1776 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:38.4151 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:38.6556 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:38.8907 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:39.1269 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:39.3885 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:39.6326 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:39.8748 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:40.1419 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:40.3795 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:40.6642 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:40.9310 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:41.1586 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:41.3856 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:41.6191 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:41.8467 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:42.0823 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:42.3219 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:42.5582 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error
2022-09-05 08:42:42.8021 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error

So I restarted the traffic manager, it printed below

❯ 
2022-09-05 08:47:44.1527 info    Traffic Manager v2.7.1 [pid:1]
2022-09-05 08:47:44.1840 info    unable to load license: error reading license: open /home/telepresence/license: no such file or directory
2022-09-05 08:47:44.2680 info    Using DNS IP from kube-dns.kube-system
2022-09-05 08:47:44.2712 info    Using cluster domain "cluster.local."
2022-09-05 08:47:44.2835 info    Extracting service subnet 10.96.0.0/12 from create service error message
2022-09-05 08:47:44.2837 info    Using podCIDRStrategy: auto
2022-09-05 08:47:44.3100 info    prometheus : Prometheus metrics server not started
2022-09-05 08:47:44.3150 info    agent-injector : Loading ConfigMaps from []
2022-09-05 08:47:44.3228 info    agent-injector : Mutating webhook service is listening on :8443
2022-09-05 08:47:44.3957 info    Scanning 1 nodes
2022-09-05 08:47:44.3962 info    No subnets found
2022-09-05 08:47:44.3963 error   Unable to derive subnets from nodes
2022-09-05 08:47:44.6034 info    Deriving subnets from IPs of pods
2022-09-05 08:47:45.3182 info    agent-configs : Started watcher for Services cluster wide
2022-09-05 08:47:45.3192 info    agent-configs : Started watcher for ConfigMap telepresence-agents cluster wide
2022-09-05 08:47:46.1312 warning agent-configs : Issuing a systema request without ApiKey or InstallID may result in an error

Seems not very intersting.

DanielYWoo avatar Sep 05 '22 08:09 DanielYWoo

Can you please provide the daemon.log too? This output in the connector.log seems to suggest that the DNS indeed is running, but for some reason it seems to get stuck.

2022-09-05 16:40:30.4730 debug   connector/session/intercept-port-forward : posting search paths [ambassador dapr-poc dapr-poc-elk dapr-poc-facility dapr-poc-foundation dapr-poc-grafana dapr-poc-prometheus dapr-poc-recruiting dapr-poc-zipkin dapr-system default kube-node-lease kube-public kube-system test-cpu-quota] and namespaces []
2022-09-05 16:40:30.4735 debug   connector/session/intercept-port-forward : search paths posted successfully

thallgren avatar Sep 06 '22 06:09 thallgren

Ha, it frustrats me because it works today. I will try to catch it when it does not work.

DanielYWoo avatar Sep 06 '22 17:09 DanielYWoo

I have the same issue

gunsluo avatar Sep 13 '22 09:09 gunsluo

Closing this as it's not clear what the issue is. Some fixed it, others have the same issue. If a problem still persist with a more recent version of Telepresence, then please open a new issue.

thallgren avatar Feb 21 '23 20:02 thallgren