stunner icon indicating copy to clipboard operation
stunner copied to clipboard
verified publisher icon l7mp

Erratic behaviour with SSL

Open moufmouf opened this issue 1 year ago • 3 comments

Description

Connection with turns seems to work randomly in TrickleICE.

I'm trying to setup Stunner as a replacement for my Coturn server. When trying to set up SSL, in Trickle ICE, I see the relay server appearing only some times (maybe one time for every 3 tries).

Here is the video of what I see:

https://github.com/user-attachments/assets/35df77fe-8262-4527-a502-655281d2817c

This happens only for TCP/SSL connections. If I try to connect via UDP, it works every time (so I know my credentials are OK)

Steps to Reproduce

I'm deploying on a OVH managed cluster. They are using Octavia load balancers.

Expected behavior: Relay server is reachable on every try.

Actual behavior: Relay server is reachable only sometimes

I'm not sure what to do from here? Any idea how I could troubleshoot this further?

BTW, thanks for this awesome project!

Versions

v0.21.0

Info

Gateway API status

Gateway settings 
apiVersion: v1
items:
- apiVersion: gateway.networking.k8s.io/v1
  kind: Gateway
  metadata:
    annotations:
      kubectl.kubernetes.io/last-applied-configuration: |
        {"apiVersion":"gateway.networking.k8s.io/v1","kind":"Gateway","metadata":{"annotations":{"stunner.l7mp.io/disable-session-affinity":"true","stunner.l7mp.io/enable-mixed-protocol-lb":"true"},"name":"udp-tcp-gateway","namespace":"stunner"},"spec":{"addresses":[{"type":"IPAddress","value":"xxx.xxx.xxx.xxx"}],"gatewayClassName":"stunner-gatewayclass","listeners":[{"name":"udp-listener","port":3478,"protocol":"TURN-UDP"},{"name":"tls-listener","port":443,"protocol":"TURN-TLS","tls":{"certificateRefs":[{"kind":"Secret","name":"stunner-gateway-cert","namespace":"stunner"}],"mode":"Terminate"}}]}}
      stunner.l7mp.io/disable-session-affinity: "true"
      stunner.l7mp.io/enable-mixed-protocol-lb: "true"
    creationTimestamp: "2024-06-07T15:17:36Z"
    generation: 4
    name: udp-tcp-gateway
    namespace: stunner
    resourceVersion: "19061562113"
    uid: d9ae46d3-2601-4592-9b96-08a92dcddfff
  spec:
    addresses:
    - type: IPAddress
      value: xxx.xxx.xxx.xxx
    gatewayClassName: stunner-gatewayclass
    listeners:
    - allowedRoutes:
        namespaces:
          from: Same
      name: udp-listener
      port: 3478
      protocol: TURN-UDP
    - allowedRoutes:
        namespaces:
          from: Same
      name: tls-listener
      port: 443
      protocol: TURN-TLS
      tls:
        certificateRefs:
        - group: ""
          kind: Secret
          name: stunner-gateway-cert
          namespace: stunner
        mode: Terminate
  status:
    addresses:
    - type: IPAddress
      value: xxx.xxx.xxx.xxx
    conditions:
    - lastTransitionTime: "2024-10-28T15:53:17Z"
      message: gateway accepted by controller stunner.l7mp.io/gateway-operator
      observedGeneration: 4
      reason: Accepted
      status: "True"
      type: Accepted
    - lastTransitionTime: "2024-10-30T11:08:00Z"
      message: dataplane configuration successfully rendered
      observedGeneration: 4
      reason: Programmed
      status: "True"
      type: Programmed
    listeners:
    - attachedRoutes: 1
      conditions:
      - lastTransitionTime: "2024-10-30T11:08:00Z"
        message: listener accepted
        observedGeneration: 4
        reason: Accepted
        status: "True"
        type: Accepted
      - lastTransitionTime: "2024-10-30T11:08:00Z"
        message: listener protocol-port available
        observedGeneration: 4
        reason: NoConflicts
        status: "False"
        type: Conflicted
      - lastTransitionTime: "2024-10-30T11:08:00Z"
        message: listener object references sucessfully resolved
        observedGeneration: 4
        reason: ResolvedRefs
        status: "True"
        type: ResolvedRefs
      name: udp-listener
      supportedKinds:
      - group: gateway.networking.k8s.io
        kind: UDPRoute
      - group: stunner.l7mp.io
        kind: UDPRoute
    - attachedRoutes: 1
      conditions:
      - lastTransitionTime: "2024-10-30T11:08:00Z"
        message: listener accepted
        observedGeneration: 4
        reason: Accepted
        status: "True"
        type: Accepted
      - lastTransitionTime: "2024-10-30T11:08:00Z"
        message: listener protocol-port available
        observedGeneration: 4
        reason: NoConflicts
        status: "False"
        type: Conflicted
      - lastTransitionTime: "2024-10-30T11:08:00Z"
        message: listener object references sucessfully resolved
        observedGeneration: 4
        reason: ResolvedRefs
        status: "True"
        type: ResolvedRefs
      name: tls-listener
      supportedKinds:
      - group: gateway.networking.k8s.io
        kind: UDPRoute
      - group: stunner.l7mp.io
        kind: UDPRoute
- apiVersion: stunner.l7mp.io/v1
  kind: GatewayConfig
  metadata:
    annotations:
      kubectl.kubernetes.io/last-applied-configuration: |
        {"apiVersion":"stunner.l7mp.io/v1","kind":"GatewayConfig","metadata":{"annotations":{},"name":"stunner-gatewayconfig","namespace":"stunner"},"spec":{"authType":"ephemeral","loadBalancerServiceAnnotations":{"loadbalancer.openstack.org/keep-floatingip":"true","loadbalancer.ovhcloud.com/class":"octavia","loadbalancer.ovhcloud.com/flavor":"small"},"realm":"stunner.l7mp.io","sharedSecret":"xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"}}
    creationTimestamp: "2024-06-07T15:17:36Z"
    generation: 3
    name: stunner-gatewayconfig
    namespace: stunner
    resourceVersion: "16277903378"
    uid: 49265083-a517-4134-9121-473440bfdfd6
  spec:
    authType: ephemeral
    dataplane: default
    loadBalancerServiceAnnotations:
      loadbalancer.openstack.org/keep-floatingip: "true"
      loadbalancer.ovhcloud.com/class: octavia
      loadbalancer.ovhcloud.com/flavor: small
    realm: stunner.l7mp.io
    sharedSecret: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
- apiVersion: gateway.networking.k8s.io/v1
  kind: GatewayClass
  metadata:
    annotations:
      kubectl.kubernetes.io/last-applied-configuration: |
        {"apiVersion":"gateway.networking.k8s.io/v1","kind":"GatewayClass","metadata":{"annotations":{},"name":"stunner-gatewayclass"},"spec":{"controllerName":"stunner.l7mp.io/gateway-operator","description":"STUNner is a WebRTC ingress gateway for Kubernetes","parametersRef":{"group":"stunner.l7mp.io","kind":"GatewayConfig","name":"stunner-gatewayconfig","namespace":"stunner"}}}
    creationTimestamp: "2024-06-07T15:17:36Z"
    generation: 1
    name: stunner-gatewayclass
    resourceVersion: "19027457773"
    uid: 2e0e26e2-60a3-4b7c-a80c-6fb0c3179be3
  spec:
    controllerName: stunner.l7mp.io/gateway-operator
    description: STUNner is a WebRTC ingress gateway for Kubernetes
    parametersRef:
      group: stunner.l7mp.io
      kind: GatewayConfig
      name: stunner-gatewayconfig
      namespace: stunner
  status:
    conditions:
    - lastTransitionTime: "2024-10-28T15:53:17Z"
      message: GatewayClass is now managed by controller "stunner.l7mp.io/gateway-operator"
      observedGeneration: 1
      reason: Accepted
      status: "True"
      type: Accepted
- apiVersion: stunner.l7mp.io/v1
  kind: UDPRoute
  metadata:
    annotations:
      kubectl.kubernetes.io/last-applied-configuration: |
        {"apiVersion":"stunner.l7mp.io/v1","kind":"UDPRoute","metadata":{"annotations":{},"name":"stunner-headless","namespace":"stunner"},"spec":{"parentRefs":[{"name":"udp-tcp-gateway"}],"rules":[{"backendRefs":[{"name":"udp-tcp-gateway","namespace":"stunner"}]}]}}
    creationTimestamp: "2024-06-07T15:17:36Z"
    generation: 1
    name: stunner-headless
    namespace: stunner
    resourceVersion: "19061562122"
    uid: e8cd3702-5ae4-4762-ab15-59f4a1e0102b
  spec:
    parentRefs:
    - group: gateway.networking.k8s.io
      kind: Gateway
      name: udp-tcp-gateway
    rules:
    - backendRefs:
      - group: ""
        kind: Service
        name: udp-tcp-gateway
        namespace: stunner
  status:
    parents:
    - conditions:
      - lastTransitionTime: "2024-10-30T11:08:00Z"
        message: parent accepts the route
        observedGeneration: 1
        reason: Accepted
        status: "True"
        type: Accepted
      - lastTransitionTime: "2024-10-30T11:08:00Z"
        message: all backend references successfully resolved
        observedGeneration: 1
        reason: ResolvedRefs
        status: "True"
        type: ResolvedRefs
      controllerName: stunner.l7mp.io/gateway-operator
      parentRef:
        group: gateway.networking.k8s.io
        kind: Gateway
        name: udp-tcp-gateway
kind: List
metadata:
  resourceVersion: ""

Operator logs

Operator logs 
2024-10-30T11:08:00.957638953Z	INFO	renderer	STUNner dataplane configuration ready	{"generation": 1571, "config": "{version=\"v1\",admin:{name=\"stunner/udp-tcp-gateway\",logLevel=\"all:INFO\",metrics=\"http://:8080/metrics\",health-check=\"http://:8086\"},ephemeral-auth:{realm=\"stunner.l7mp.io\",secret=\"<SECRET>\"},listeners=[\"stunner/udp-tcp-gateway/udp-listener\":{turn://0.0.0.0:3478,public=57.128.59.167:3478,cert/key=-/-,routes=[stunner/stunner-headless]},\"stunner/udp-tcp-gateway/tls-listener\":{turn://0.0.0.0:443,public=57.128.59.167:443,cert/key=<SECRET>/<SECRET>,routes=[stunner/stunner-headless]}],clusters=[\"stunner/stunner-headless\":{type=\"STATIC\",protocol=\"UDP\",endpoints=[10.2.2.94,10.3.241.92]}]}"}
2024-10-30T11:08:00.957819398Z	INFO	cds-server	Processing config update event	{"generation": 1571, "update": "update (gen: 1571, ack: true): upsert-queue: gway-cls: 1, gway: 1, route: 1, routeV1A2: 0, svc: 1, confmap: 0, dp: 1 / delete-queue: gway-cls: 0, gway: 0, route: 0, routeV1A2: 0, svc: 0, confmap: 0, dp: 0 / config-queue: 1"}
2024-10-30T11:08:00.957905339Z	INFO	updater	Processing update event	{"generation": 1571, "update": "update (gen: 1571, ack: true): upsert-queue: gway-cls: 1, gway: 1, route: 1, routeV1A2: 0, svc: 1, confmap: 0, dp: 1 / delete-queue: gway-cls: 0, gway: 0, route: 0, routeV1A2: 0, svc: 0, confmap: 0, dp: 0 / config-queue: 1"}
2024-10-30T11:08:38.651368127Z	INFO	node-controller	Reconciling	{"node": "/nodepool-1651987e-9645-4eea-96-node-7b238b"}
2024-10-30T11:08:38.651717768Z	INFO	node-controller	failed to find node with valid external address	{"reason": "End of node list reached after searching through 3 node(s)"}
2024-10-30T11:08:38.902681338Z	INFO	operator	Starting new reconcile generation	{"generation": 1571, "last-acked-generation": 1571}
2024-10-30T11:08:38.902774036Z	INFO	renderer	Rendering configuration	{"generation": 1572, "event": "render: generation: 1572"}
2024-10-30T11:08:38.902783846Z	INFO	renderer	Starting dataplane render	{"mode": "managed"}
2024-10-30T11:08:38.902816849Z	INFO	renderer	Rendering configuration	{"gateway-class": "/stunner-gatewayclass"}
2024-10-30T11:08:38.903388772Z	INFO	renderer	Creating public service for gateway	{"service": "stunner/udp-tcp-gateway", "gateway": "stunner/udp-tcp-gateway", "service": "{\"kind\":\"Service\",\"apiVersion\":\"v1\",\"metadata\":{\"name\":\"udp-tcp-gateway\",\"namespace\":\"stunner\",\"uid\":\"7461ee19-f16a-4367-aebf-c390654fe2dd\",\"resourceVersion\":\"19027534495\",\"creationTimestamp\":\"2024-10-28T15:53:17Z\",\"labels\":{\"stunner.l7mp.io/owned-by\":\"stunner\",\"stunner.l7mp.io/related-gateway-name\":\"udp-tcp-gateway\",\"stunner.l7mp.io/related-gateway-namespace\":\"stunner\"},\"annotations\":{\"loadbalancer.openstack.org/flavor-id\":\"2d4bc92c-38fc-4b50-9484-8351ab0c4e69\",\"loadbalancer.openstack.org/keep-floatingip\":\"true\",\"loadbalancer.openstack.org/load-balancer-address\":\"57.128.59.167\",\"loadbalancer.openstack.org/load-balancer-id\":\"a6e8985c-0441-4881-8848-0e3807955807\",\"loadbalancer.openstack.org/network-id\":\"974bf875-959f-4886-a329-56999a01c997\",\"loadbalancer.openstack.org/subnet-id\":\"01fac7e6-3f74-4bb3-8054-554dac0b85c6\",\"loadbalancer.ovhcloud.com/class\":\"octavia\",\"loadbalancer.ovhcloud.com/flavor\":\"small\",\"stunner.l7mp.io/disable-session-affinity\":\"true\",\"stunner.l7mp.io/enable-mixed-protocol-lb\":\"true\",\"stunner.l7mp.io/related-gateway-name\":\"stunner/udp-tcp-gateway\"},\"ownerReferences\":[{\"apiVersion\":\"gateway.networking.k8s.io/v1\",\"kind\":\"Gateway\",\"name\":\"udp-tcp-gateway\",\"uid\":\"d9ae46d3-2601-4592-9b96-08a92dcddfff\"}],\"finalizers\":[\"service.kubernetes.io/load-balancer-cleanup\"]},\"spec\":{\"ports\":[{\"name\":\"udp-listener\",\"protocol\":\"UDP\",\"port\":3478,\"targetPort\":0,\"nodePort\":31726},{\"name\":\"tls-listener\",\"protocol\":\"TCP\",\"port\":443,\"targetPort\":0,\"nodePort\":30423}],\"selector\":{\"app\":\"stunner\",\"stunner.l7mp.io/related-gateway-name\":\"udp-tcp-gateway\",\"stunner.l7mp.io/related-gateway-namespace\":\"stunner\"},\"clusterIP\":\"10.3.241.92\",\"clusterIPs\":[\"10.3.241.92\"],\"type\":\"LoadBalancer\",\"sessionAffinity\":\"None\",\"loadBalancerIP\":\"57.128.59.167\",\"ipFamilies\":[\"IPv4\"],\"ipFamilyPolicy\":\"SingleStack\",\"allocateLoadBalancerNodePorts\":true,\"internalTrafficPolicy\":\"Cluster\"},\"status\":{\"loadBalancer\":{\"ingress\":[{\"ip\":\"57.128.59.167\"}]}}}"}
2024-10-30T11:08:38.903582477Z	INFO	renderer	Update queue ready	{"queue": "update (gen: 1572, ack: false): upsert-queue: gway-cls: 0, gway: 1, route: 1, routeV1A2: 0, svc: 1, confmap: 0, dp: 0 / delete-queue: gway-cls: 0, gway: 0, route: 0, routeV1A2: 0, svc: 0, confmap: 0, dp: 0 / config-queue: 0"}
2024-10-30T11:08:38.904194172Z	INFO	renderer	STUNner dataplane Deployment ready	{"generation": 1572, "deployment": "{\"metadata\":{\"name\":\"udp-tcp-gateway\",\"namespace\":\"stunner\",\"creationTimestamp\":null,\"labels\":{\"stunner.l7mp.io/owned-by\":\"stunner\",\"stunner.l7mp.io/related-gateway-name\":\"udp-tcp-gateway\",\"stunner.l7mp.io/related-gateway-namespace\":\"stunner\"},\"annotations\":{\"stunner.l7mp.io/disable-session-affinity\":\"true\",\"stunner.l7mp.io/enable-mixed-protocol-lb\":\"true\",\"stunner.l7mp.io/related-gateway-name\":\"stunner/udp-tcp-gateway\"},\"ownerReferences\":[{\"apiVersion\":\"gateway.networking.k8s.io/v1\",\"kind\":\"Gateway\",\"name\":\"udp-tcp-gateway\",\"uid\":\"d9ae46d3-2601-4592-9b96-08a92dcddfff\"}]},\"spec\":{\"replicas\":1,\"selector\":{\"matchExpressions\":[{\"key\":\"app\",\"operator\":\"In\",\"values\":[\"stunner\"]},{\"key\":\"stunner.l7mp.io/related-gateway-name\",\"operator\":\"In\",\"values\":[\"udp-tcp-gateway\"]},{\"key\":\"stunner.l7mp.io/related-gateway-namespace\",\"operator\":\"In\",\"values\":[\"stunner\"]}]},\"template\":{\"metadata\":{\"creationTimestamp\":null,\"labels\":{\"app\":\"stunner\",\"stunner.l7mp.io/related-gateway-name\":\"udp-tcp-gateway\",\"stunner.l7mp.io/related-gateway-namespace\":\"stunner\"},\"annotations\":{\"stunner.l7mp.io/related-gateway-name\":\"stunner/udp-tcp-gateway\"}},\"spec\":{\"containers\":[{\"name\":\"stunner-daemon\",\"image\":\"docker.io/l7mp/stunnerd:0.21.0\",\"command\":[\"stunnerd\"],\"args\":[\"-w\",\"--udp-thread-num=16\"],\"ports\":[{\"name\":\"metrics-port\",\"containerPort\":8080,\"protocol\":\"TCP\"}],\"env\":[{\"name\":\"STUNNER_ADDR\",\"valueFrom\":{\"fieldRef\":{\"fieldPath\":\"status.podIP\"}}},{\"name\":\"STUNNER_NAME\",\"value\":\"udp-tcp-gateway\"},{\"name\":\"STUNNER_NAMESPACE\",\"value\":\"stunner\"},{\"name\":\"STUNNER_CONFIG_ORIGIN\",\"value\":\"http://10.2.2.91:13478\"}],\"resources\":{\"limits\":{\"cpu\":\"2\",\"memory\":\"512Mi\"},\"requests\":{\"cpu\":\"500m\",\"memory\":\"128Mi\"}},\"livenessProbe\":{\"httpGet\":{\"path\":\"/live\",\"port\":8086,\"scheme\":\"HTTP\"},\"timeoutSeconds\":1,\"periodSeconds\":15,\"successThreshold\":1,\"failureThreshold\":3},\"readinessProbe\":{\"httpGet\":{\"path\":\"/ready\",\"port\":8086,\"scheme\":\"HTTP\"},\"timeoutSeconds\":1,\"periodSeconds\":15,\"successThreshold\":1,\"failureThreshold\":3},\"imagePullPolicy\":\"Always\"}],\"terminationGracePeriodSeconds\":3600}},\"strategy\":{}},\"status\":{}}"}
2024-10-30T11:08:38.904282158Z	INFO	renderer	STUNner dataplane configuration ready	{"generation": 1572, "config": "{version=\"v1\",admin:{name=\"stunner/udp-tcp-gateway\",logLevel=\"all:INFO\",metrics=\"http://:8080/metrics\",health-check=\"http://:8086\"},ephemeral-auth:{realm=\"stunner.l7mp.io\",secret=\"<SECRET>\"},listeners=[\"stunner/udp-tcp-gateway/udp-listener\":{turn://0.0.0.0:3478,public=57.128.59.167:3478,cert/key=-/-,routes=[stunner/stunner-headless]},\"stunner/udp-tcp-gateway/tls-listener\":{turn://0.0.0.0:443,public=57.128.59.167:443,cert/key=<SECRET>/<SECRET>,routes=[stunner/stunner-headless]}],clusters=[\"stunner/stunner-headless\":{type=\"STATIC\",protocol=\"UDP\",endpoints=[10.2.2.94,10.3.241.92]}]}"}
2024-10-30T11:08:38.904463664Z	INFO	cds-server	Processing config update event	{"generation": 1572, "update": "update (gen: 1572, ack: true): upsert-queue: gway-cls: 1, gway: 1, route: 1, routeV1A2: 0, svc: 1, confmap: 0, dp: 1 / delete-queue: gway-cls: 0, gway: 0, route: 0, routeV1A2: 0, svc: 0, confmap: 0, dp: 0 / config-queue: 1"}
2024-10-30T11:08:38.904534254Z	INFO	updater	Processing update event	{"generation": 1572, "update": "update (gen: 1572, ack: true): upsert-queue: gway-cls: 1, gway: 1, route: 1, routeV1A2: 0, svc: 1, confmap: 0, dp: 1 / delete-queue: gway-cls: 0, gway: 0, route: 0, routeV1A2: 0, svc: 0, confmap: 0, dp: 0 / config-queue: 1"}
2024-10-30T11:09:56.395703031Z	INFO	node-controller	Reconciling	{"node": "/nodepool-1651987e-9645-4eea-96-node-761df2"}
2024-10-30T11:09:56.396116132Z	INFO	node-controller	failed to find node with valid external address	{"reason": "End of node list reached after searching through 3 node(s)"}
2024-10-30T11:09:56.646744957Z	INFO	operator	Starting new reconcile generation	{"generation": 1572, "last-acked-generation": 1572}
2024-10-30T11:09:56.646827235Z	INFO	renderer	Rendering configuration	{"generation": 1573, "event": "render: generation: 1573"}
2024-10-30T11:09:56.646836703Z	INFO	renderer	Starting dataplane render	{"mode": "managed"}
2024-10-30T11:09:56.646888657Z	INFO	renderer	Rendering configuration	{"gateway-class": "/stunner-gatewayclass"}
2024-10-30T11:09:56.64750017Z	INFO	renderer	Creating public service for gateway	{"service": "stunner/udp-tcp-gateway", "gateway": "stunner/udp-tcp-gateway", "service": "{\"kind\":\"Service\",\"apiVersion\":\"v1\",\"metadata\":{\"name\":\"udp-tcp-gateway\",\"namespace\":\"stunner\",\"uid\":\"7461ee19-f16a-4367-aebf-c390654fe2dd\",\"resourceVersion\":\"19027534495\",\"creationTimestamp\":\"2024-10-28T15:53:17Z\",\"labels\":{\"stunner.l7mp.io/owned-by\":\"stunner\",\"stunner.l7mp.io/related-gateway-name\":\"udp-tcp-gateway\",\"stunner.l7mp.io/related-gateway-namespace\":\"stunner\"},\"annotations\":{\"loadbalancer.openstack.org/flavor-id\":\"2d4bc92c-38fc-4b50-9484-8351ab0c4e69\",\"loadbalancer.openstack.org/keep-floatingip\":\"true\",\"loadbalancer.openstack.org/load-balancer-address\":\"57.128.59.167\",\"loadbalancer.openstack.org/load-balancer-id\":\"a6e8985c-0441-4881-8848-0e3807955807\",\"loadbalancer.openstack.org/network-id\":\"974bf875-959f-4886-a329-56999a01c997\",\"loadbalancer.openstack.org/subnet-id\":\"01fac7e6-3f74-4bb3-8054-554dac0b85c6\",\"loadbalancer.ovhcloud.com/class\":\"octavia\",\"loadbalancer.ovhcloud.com/flavor\":\"small\",\"stunner.l7mp.io/disable-session-affinity\":\"true\",\"stunner.l7mp.io/enable-mixed-protocol-lb\":\"true\",\"stunner.l7mp.io/related-gateway-name\":\"stunner/udp-tcp-gateway\"},\"ownerReferences\":[{\"apiVersion\":\"gateway.networking.k8s.io/v1\",\"kind\":\"Gateway\",\"name\":\"udp-tcp-gateway\",\"uid\":\"d9ae46d3-2601-4592-9b96-08a92dcddfff\"}],\"finalizers\":[\"service.kubernetes.io/load-balancer-cleanup\"]},\"spec\":{\"ports\":[{\"name\":\"udp-listener\",\"protocol\":\"UDP\",\"port\":3478,\"targetPort\":0,\"nodePort\":31726},{\"name\":\"tls-listener\",\"protocol\":\"TCP\",\"port\":443,\"targetPort\":0,\"nodePort\":30423}],\"selector\":{\"app\":\"stunner\",\"stunner.l7mp.io/related-gateway-name\":\"udp-tcp-gateway\",\"stunner.l7mp.io/related-gateway-namespace\":\"stunner\"},\"clusterIP\":\"10.3.241.92\",\"clusterIPs\":[\"10.3.241.92\"],\"type\":\"LoadBalancer\",\"sessionAffinity\":\"None\",\"loadBalancerIP\":\"57.128.59.167\",\"ipFamilies\":[\"IPv4\"],\"ipFamilyPolicy\":\"SingleStack\",\"allocateLoadBalancerNodePorts\":true,\"internalTrafficPolicy\":\"Cluster\"},\"status\":{\"loadBalancer\":{\"ingress\":[{\"ip\":\"57.128.59.167\"}]}}}"}
2024-10-30T11:09:56.647686854Z	INFO	renderer	Update queue ready	{"queue": "update (gen: 1573, ack: false): upsert-queue: gway-cls: 0, gway: 1, route: 1, routeV1A2: 0, svc: 1, confmap: 0, dp: 0 / delete-queue: gway-cls: 0, gway: 0, route: 0, routeV1A2: 0, svc: 0, confmap: 0, dp: 0 / config-queue: 0"}
2024-10-30T11:09:56.648276267Z	INFO	renderer	STUNner dataplane Deployment ready	{"generation": 1573, "deployment": "{\"metadata\":{\"name\":\"udp-tcp-gateway\",\"namespace\":\"stunner\",\"creationTimestamp\":null,\"labels\":{\"stunner.l7mp.io/owned-by\":\"stunner\",\"stunner.l7mp.io/related-gateway-name\":\"udp-tcp-gateway\",\"stunner.l7mp.io/related-gateway-namespace\":\"stunner\"},\"annotations\":{\"stunner.l7mp.io/disable-session-affinity\":\"true\",\"stunner.l7mp.io/enable-mixed-protocol-lb\":\"true\",\"stunner.l7mp.io/related-gateway-name\":\"stunner/udp-tcp-gateway\"},\"ownerReferences\":[{\"apiVersion\":\"gateway.networking.k8s.io/v1\",\"kind\":\"Gateway\",\"name\":\"udp-tcp-gateway\",\"uid\":\"d9ae46d3-2601-4592-9b96-08a92dcddfff\"}]},\"spec\":{\"replicas\":1,\"selector\":{\"matchExpressions\":[{\"key\":\"app\",\"operator\":\"In\",\"values\":[\"stunner\"]},{\"key\":\"stunner.l7mp.io/related-gateway-name\",\"operator\":\"In\",\"values\":[\"udp-tcp-gateway\"]},{\"key\":\"stunner.l7mp.io/related-gateway-namespace\",\"operator\":\"In\",\"values\":[\"stunner\"]}]},\"template\":{\"metadata\":{\"creationTimestamp\":null,\"labels\":{\"app\":\"stunner\",\"stunner.l7mp.io/related-gateway-name\":\"udp-tcp-gateway\",\"stunner.l7mp.io/related-gateway-namespace\":\"stunner\"},\"annotations\":{\"stunner.l7mp.io/related-gateway-name\":\"stunner/udp-tcp-gateway\"}},\"spec\":{\"containers\":[{\"name\":\"stunner-daemon\",\"image\":\"docker.io/l7mp/stunnerd:0.21.0\",\"command\":[\"stunnerd\"],\"args\":[\"-w\",\"--udp-thread-num=16\"],\"ports\":[{\"name\":\"metrics-port\",\"containerPort\":8080,\"protocol\":\"TCP\"}],\"env\":[{\"name\":\"STUNNER_ADDR\",\"valueFrom\":{\"fieldRef\":{\"fieldPath\":\"status.podIP\"}}},{\"name\":\"STUNNER_NAME\",\"value\":\"udp-tcp-gateway\"},{\"name\":\"STUNNER_NAMESPACE\",\"value\":\"stunner\"},{\"name\":\"STUNNER_CONFIG_ORIGIN\",\"value\":\"http://10.2.2.91:13478\"}],\"resources\":{\"limits\":{\"cpu\":\"2\",\"memory\":\"512Mi\"},\"requests\":{\"cpu\":\"500m\",\"memory\":\"128Mi\"}},\"livenessProbe\":{\"httpGet\":{\"path\":\"/live\",\"port\":8086,\"scheme\":\"HTTP\"},\"timeoutSeconds\":1,\"periodSeconds\":15,\"successThreshold\":1,\"failureThreshold\":3},\"readinessProbe\":{\"httpGet\":{\"path\":\"/ready\",\"port\":8086,\"scheme\":\"HTTP\"},\"timeoutSeconds\":1,\"periodSeconds\":15,\"successThreshold\":1,\"failureThreshold\":3},\"imagePullPolicy\":\"Always\"}],\"terminationGracePeriodSeconds\":3600}},\"strategy\":{}},\"status\":{}}"}
2024-10-30T11:09:56.648336451Z	INFO	renderer	STUNner dataplane configuration ready	{"generation": 1573, "config": "{version=\"v1\",admin:{name=\"stunner/udp-tcp-gateway\",logLevel=\"all:INFO\",metrics=\"http://:8080/metrics\",health-check=\"http://:8086\"},ephemeral-auth:{realm=\"stunner.l7mp.io\",secret=\"<SECRET>\"},listeners=[\"stunner/udp-tcp-gateway/udp-listener\":{turn://0.0.0.0:3478,public=57.128.59.167:3478,cert/key=-/-,routes=[stunner/stunner-headless]},\"stunner/udp-tcp-gateway/tls-listener\":{turn://0.0.0.0:443,public=57.128.59.167:443,cert/key=<SECRET>/<SECRET>,routes=[stunner/stunner-headless]}],clusters=[\"stunner/stunner-headless\":{type=\"STATIC\",protocol=\"UDP\",endpoints=[10.2.2.94,10.3.241.92]}]}"}
2024-10-30T11:09:56.648445933Z	INFO	cds-server	Processing config update event	{"generation": 1573, "update": "update (gen: 1573, ack: true): upsert-queue: gway-cls: 1, gway: 1, route: 1, routeV1A2: 0, svc: 1, confmap: 0, dp: 1 / delete-queue: gway-cls: 0, gway: 0, route: 0, routeV1A2: 0, svc: 0, confmap: 0, dp: 0 / config-queue: 1"}
2024-10-30T11:09:56.648571957Z	INFO	updater	Processing update event	{"generation": 1573, "update": "update (gen: 1573, ack: true): upsert-queue: gway-cls: 1, gway: 1, route: 1, routeV1A2: 0, svc: 1, confmap: 0, dp: 1 / delete-queue: gway-cls: 0, gway: 0, route: 0, routeV1A2: 0, svc: 0, confmap: 0, dp: 0 / config-queue: 1"}

Of interest: in the stunner logs, I regularly see messages like this one:

11:05:09.103349 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
11:05:10.232523 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header (suppressed 6 log events)
11:05:11.232391 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header (suppressed 6 log events)
11:05:13.104982 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header (suppressed 1 log events)
11:05:13.105003 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
11:05:14.105161 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header

moufmouf avatar Oct 30 '24 11:10 moufmouf

Hi @moufmouf !

Strange indeed. Thanks for the demo video and the detailed logs. We have seen similar issues with Octavia LB before: https://github.com/l7mp/stunner/issues/122

levaitamas avatar Oct 30 '24 14:10 levaitamas

TL;DR The problem is in pion/turn and we won't be able to address it in STUNner

Analysis.

The problem seems to come from pion/turn, the open-source TURN implementation that underlies STUNner. The issue itself is related to a fundamental impedance mismatch between TURN, which is message based, and TCP/TLS, which provides a bytestream abstraction. Mapping between the two can be done, but I think in this case this is somehow creating this problem. Plus TLS. Or the cloud provider. Or the load balancer. There are lots of moving parts here.

Anyway. The layer that is responsible for mapping the TLS/TCP bytestream to the message based semantics of TURN is called STUNConn. There are various heuristics implemented here that let the TURN server to consume the TCP/TLS bytestream per message: we read the stream into an internal buffer until we can form a full TURN message (this is known from the TURN or the ChannelData header message length field) and then return the message and truncate the internal buffer.

The error itself is triggered from the TURN server readloop, after trying to decode a TURN message using the encoder/decoder of pion/stun (TURN is a glorified version STUN that uses the same message header structure, hence the call into pion/stun). Now the first thing that the decoder does is that it checks whether it has enough bytes to decode the STUN/TURN header, which is supposed to be 20 bytes, and if not, we get the above error.

Now it seems to me that STUNConn somehow returns an incomplete TURN message that then triggers this error in the message decoder, but it is impossible to know at this point how and why this can happen. Can you post a full stunnerd log obtained at the all:TRACE loglevel? This could help us tracking this down to a specific point in the TURN state machine. Also, can you reproduce the problem with pion/turn example TLS/TCP server? I tried, but to no avail.

rg0now avatar Oct 30 '24 17:10 rg0now

Hey @rg0now ,

Thanks a lot for the detailed explanation.

While performing additional tests, I realized that I'm getting a very different behaviour if I'm doing the tests in Firefox or in Chrome. So I start to believe there are many issues mixed here.

First of all, the video of my initial bug report was done with Firefox. I can reproduce the same behaviour 100% of the time. But when I test in Chrome, everything is behaving correctly. I successfully get the relay server (see screenshot below)

image

I enabled the full stunnerd logs. Here is what I see.

First of all, I see the "not enough bytes to read header" message all the time (even when I'm doing no tests). So I'm starting to wonder if the message might not originate from some liveness probe or something like that. Here are some logs:

Logs 
08:17:25.213151 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.0.0:6548 on [::]:3478
08:17:25.213181 server.go:63: turn DEBUG: Handling TURN packet
08:17:25.213197 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:25.213949 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.1.0:20158 on [::]:3478
08:17:25.213988 server.go:63: turn DEBUG: Handling TURN packet
08:17:25.214026 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:28.046142 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.0.0:1831 on [::]:3478
08:17:28.046205 server.go:63: turn DEBUG: Handling TURN packet
08:17:28.046215 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.0.0:44502 on [::]:3478
08:17:28.046225 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:28.046231 server.go:63: turn DEBUG: Handling TURN packet
08:17:28.046142 server.go:38: turn DEBUG: Received 1 bytes of udp from 141.94.213.65:23465 on [::]:3478
08:17:28.046245 server.go:63: turn DEBUG: Handling TURN packet
08:17:28.046246 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:28.046253 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:28.046292 server.go:38: turn DEBUG: Received 1 bytes of udp from 141.94.213.65:16458 on [::]:3478
08:17:28.046312 server.go:63: turn DEBUG: Handling TURN packet
08:17:28.046324 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:28.047612 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.1.0:46029 on [::]:3478
08:17:28.047636 server.go:63: turn DEBUG: Handling TURN packet
08:17:28.047648 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:28.047712 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.1.0:42982 on [::]:3478
08:17:28.047722 server.go:63: turn DEBUG: Handling TURN packet
08:17:28.047731 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:29.046090 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.0.0:44502 on [::]:3478
08:17:29.046143 server.go:63: turn DEBUG: Handling TURN packet
08:17:29.046167 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:29.046768 server.go:38: turn DEBUG: Received 1 bytes of udp from 141.94.213.65:23465 on [::]:3478
08:17:29.046801 server.go:63: turn DEBUG: Handling TURN packet
08:17:29.046817 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:29.048748 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.1.0:46029 on [::]:3478
08:17:29.048786 server.go:63: turn DEBUG: Handling TURN packet
08:17:29.048888 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:29.214883 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.0.0:61969 on [::]:3478
08:17:29.214920 server.go:63: turn DEBUG: Handling TURN packet
08:17:29.214946 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:29.214966 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.0.0:57403 on [::]:3478
08:17:29.214971 server.go:63: turn DEBUG: Handling TURN packet
08:17:29.214977 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:29.216103 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.1.0:28350 on [::]:3478
08:17:29.216118 server.go:63: turn DEBUG: Handling TURN packet
08:17:29.216127 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:29.216142 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.1.0:51964 on [::]:3478
08:17:29.216147 server.go:63: turn DEBUG: Handling TURN packet
08:17:29.216153 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:29.216206 server.go:38: turn DEBUG: Received 1 bytes of udp from 141.94.213.65:7299 on [::]:3478
08:17:29.216215 server.go:63: turn DEBUG: Handling TURN packet
08:17:29.216221 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:29.216457 server.go:38: turn DEBUG: Received 1 bytes of udp from 141.94.213.65:7299 on [::]:3478
08:17:29.216464 server.go:63: turn DEBUG: Handling TURN packet
08:17:29.216470 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:30.215188 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.0.0:57403 on [::]:3478
08:17:30.215254 server.go:63: turn DEBUG: Handling TURN packet
08:17:30.215290 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:30.216399 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.1.0:28350 on [::]:3478
08:17:30.216428 server.go:63: turn DEBUG: Handling TURN packet
08:17:30.216443 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:30.216606 server.go:38: turn DEBUG: Received 1 bytes of udp from 141.94.213.65:7299 on [::]:3478
08:17:30.216628 server.go:63: turn DEBUG: Handling TURN packet
08:17:30.216641 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:33.046115 server.go:38: turn DEBUG: Received 1 bytes of udp from 141.94.213.65:4106 on [::]:3478
08:17:33.046158 server.go:63: turn DEBUG: Handling TURN packet
08:17:33.046181 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:33.046260 server.go:38: turn DEBUG: Received 1 bytes of udp from 141.94.213.65:34225 on [::]:3478
08:17:33.046270 server.go:63: turn DEBUG: Handling TURN packet
08:17:33.046282 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:33.048462 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.0.0:5292 on [::]:3478
08:17:33.048483 server.go:63: turn DEBUG: Handling TURN packet
08:17:33.048494 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:33.048525 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.0.0:20875 on [::]:3478
08:17:33.048566 server.go:63: turn DEBUG: Handling TURN packet
08:17:33.048583 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:33.049756 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.1.0:24769 on [::]:3478
08:17:33.049783 server.go:63: turn DEBUG: Handling TURN packet
08:17:33.049794 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:33.049792 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.1.0:27647 on [::]:3478
08:17:33.049812 server.go:63: turn DEBUG: Handling TURN packet
08:17:33.049855 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:34.046103 server.go:38: turn DEBUG: Received 1 bytes of udp from 141.94.213.65:34225 on [::]:3478
08:17:34.046147 server.go:63: turn DEBUG: Handling TURN packet
08:17:34.046165 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:34.048286 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.0.0:20875 on [::]:3478
08:17:34.048314 server.go:63: turn DEBUG: Handling TURN packet
08:17:34.048328 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:17:34.049884 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.1.0:27647 on [::]:3478
08:17:34.049905 server.go:63: turn DEBUG: Handling TURN packet
08:17:34.049913 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header

As you can see, it always receives just one byte. And this is me doing nothing (not trying to connect in any way).

When testing with Firefox, and when Firefox does not return a relay server, I see this in the logs:

Logs 
08:22:41.330040 server.go:38: turn DEBUG: Received 44 bytes of udp from 10.2.1.0:11188 on 10.2.2.94:443
08:22:41.330110 server.go:63: turn DEBUG: Handling TURN packet
08:22:41.330129 turn.go:21: turn DEBUG: Received AllocateRequest from 10.2.1.0:11188
08:22:41.331929 server.go:38: turn DEBUG: Received 44 bytes of udp from 10.2.1.0:14121 on 10.2.2.94:443
08:22:41.331968 server.go:63: turn DEBUG: Handling TURN packet
08:22:41.331984 turn.go:21: turn DEBUG: Received AllocateRequest from 10.2.1.0:14121
08:22:41.353577 server.go:38: turn DEBUG: Received 204 bytes of udp from 10.2.1.0:11188 on 10.2.2.94:443
08:22:41.353626 server.go:63: turn DEBUG: Handling TURN packet
08:22:41.353659 turn.go:21: turn DEBUG: Received AllocateRequest from 10.2.1.0:11188
08:22:41.353692 server.go:38: turn DEBUG: Received 204 bytes of udp from 10.2.1.0:14121 on 10.2.2.94:443
08:22:41.353717 server.go:63: turn DEBUG: Handling TURN packet
08:22:41.353742 turn.go:21: turn DEBUG: Received AllocateRequest from 10.2.1.0:14121
08:22:41.353753 handlers.go:38: stunner-auth INFO: ephemeral auth request: username="1730709263:testy-mc-testface" realm="stunner.l7mp.io" srcAddr=10.2.1.0:11188
08:22:41.353775 handlers.go:38: stunner-auth INFO: ephemeral auth request: username="1730709263:testy-mc-testface" realm="stunner.l7mp.io" srcAddr=10.2.1.0:14121
08:22:41.353803 handlers.go:53: stunner-auth INFO: ephemeral auth request: success
08:22:41.353803 handlers.go:53: stunner-auth INFO: ephemeral auth request: success
08:22:41.354002 allocation_manager.go:116: turn DEBUG: Listening on relay address: 10.2.2.94:56629
08:22:41.354113 allocation_manager.go:116: turn DEBUG: Listening on relay address: 10.2.2.94:51981
08:22:41.368301 server.go:211: turn DEBUG: Exit read loop on error: EOF
08:22:41.368341 server.go:211: turn DEBUG: Exit read loop on error: EOF

When testing with Firefox, and when Firefox does return a relay server, I see this in the logs:

Logs

image

08:24:24.225854 server.go:38: turn DEBUG: Received 44 bytes of udp from 10.2.1.0:50030 on 10.2.2.94:443
08:24:24.225921 server.go:63: turn DEBUG: Handling TURN packet
08:24:24.225939 turn.go:21: turn DEBUG: Received AllocateRequest from 10.2.1.0:50030
08:24:24.230523 server.go:38: turn DEBUG: Received 44 bytes of udp from 10.2.1.0:37877 on 10.2.2.94:443
08:24:24.230550 server.go:63: turn DEBUG: Handling TURN packet
08:24:24.230566 turn.go:21: turn DEBUG: Received AllocateRequest from 10.2.1.0:37877
08:24:24.236928 server.go:38: turn DEBUG: Received 204 bytes of udp from 10.2.1.0:50030 on 10.2.2.94:443
08:24:24.236980 server.go:63: turn DEBUG: Handling TURN packet
08:24:24.236997 turn.go:21: turn DEBUG: Received AllocateRequest from 10.2.1.0:50030
08:24:24.237031 handlers.go:38: stunner-auth INFO: ephemeral auth request: username="1730709263:testy-mc-testface" realm="stunner.l7mp.io" srcAddr=10.2.1.0:50030
08:24:24.237083 handlers.go:53: stunner-auth INFO: ephemeral auth request: success
08:24:24.237271 allocation_manager.go:116: turn DEBUG: Listening on relay address: 10.2.2.94:58629
08:24:24.242134 server.go:38: turn DEBUG: Received 204 bytes of udp from 10.2.1.0:37877 on 10.2.2.94:443
08:24:24.242173 server.go:63: turn DEBUG: Handling TURN packet
08:24:24.242193 turn.go:21: turn DEBUG: Received AllocateRequest from 10.2.1.0:37877
08:24:24.242225 handlers.go:38: stunner-auth INFO: ephemeral auth request: username="1730709263:testy-mc-testface" realm="stunner.l7mp.io" srcAddr=10.2.1.0:37877
08:24:24.242243 handlers.go:53: stunner-auth INFO: ephemeral auth request: success
08:24:24.242337 allocation_manager.go:116: turn DEBUG: Listening on relay address: 10.2.2.94:49300
08:24:24.260757 server.go:211: turn DEBUG: Exit read loop on error: EOF
08:24:24.261087 server.go:211: turn DEBUG: Exit read loop on error: EOF

Surprisingly, I don't see anything related to TCP in the logs.

When testing in Chrome, I see this in the logs:

Logs 
08:19:46.975761 server.go:38: turn DEBUG: Received 28 bytes of udp from 10.2.1.0:30581 on 10.2.2.94:443
08:19:46.975823 server.go:63: turn DEBUG: Handling TURN packet
08:19:46.975849 turn.go:21: turn DEBUG: Received AllocateRequest from 10.2.1.0:30581
08:19:46.976157 server.go:38: turn DEBUG: Received 28 bytes of udp from 10.2.1.0:33750 on 10.2.2.94:443
08:19:46.976201 server.go:63: turn DEBUG: Handling TURN packet
08:19:46.976217 turn.go:21: turn DEBUG: Received AllocateRequest from 10.2.1.0:33750
08:19:46.987184 server.go:38: turn DEBUG: Received 188 bytes of udp from 10.2.1.0:30581 on 10.2.2.94:443
08:19:46.987229 server.go:63: turn DEBUG: Handling TURN packet
08:19:46.987264 turn.go:21: turn DEBUG: Received AllocateRequest from 10.2.1.0:30581
08:19:46.987332 handlers.go:38: stunner-auth INFO: ephemeral auth request: username="1730709263:testy-mc-testface" realm="stunner.l7mp.io" srcAddr=10.2.1.0:30581
08:19:46.987396 handlers.go:53: stunner-auth INFO: ephemeral auth request: success
08:19:46.987628 allocation_manager.go:116: turn DEBUG: Listening on relay address: 10.2.2.94:53754
08:19:46.992618 server.go:38: turn DEBUG: Received 188 bytes of udp from 10.2.1.0:33750 on 10.2.2.94:443
08:19:46.992647 server.go:63: turn DEBUG: Handling TURN packet
08:19:46.992686 turn.go:21: turn DEBUG: Received AllocateRequest from 10.2.1.0:33750
08:19:46.992712 handlers.go:38: stunner-auth INFO: ephemeral auth request: username="1730709263:testy-mc-testface" realm="stunner.l7mp.io" srcAddr=10.2.1.0:33750
08:19:46.992731 handlers.go:53: stunner-auth INFO: ephemeral auth request: success
08:19:46.992884 allocation_manager.go:116: turn DEBUG: Listening on relay address: 10.2.2.94:38283
08:19:47.007979 server.go:38: turn DEBUG: Received 188 bytes of udp from 10.2.1.0:30581 on 10.2.2.94:443
08:19:47.008034 server.go:63: turn DEBUG: Handling TURN packet
08:19:47.008051 turn.go:186: turn DEBUG: Received RefreshRequest from 10.2.1.0:30581
08:19:47.008081 handlers.go:38: stunner-auth INFO: ephemeral auth request: username="1730709263:testy-mc-testface" realm="stunner.l7mp.io" srcAddr=10.2.1.0:30581
08:19:47.008116 handlers.go:53: stunner-auth INFO: ephemeral auth request: success
08:19:47.008379 server.go:211: turn DEBUG: Exit read loop on error: EOF
08:19:47.008573 server.go:38: turn DEBUG: Received 188 bytes of udp from 10.2.1.0:33750 on 10.2.2.94:443
08:19:47.008597 server.go:63: turn DEBUG: Handling TURN packet
08:19:47.008610 turn.go:186: turn DEBUG: Received RefreshRequest from 10.2.1.0:33750
08:19:47.008630 handlers.go:38: stunner-auth INFO: ephemeral auth request: username="1730709263:testy-mc-testface" realm="stunner.l7mp.io" srcAddr=10.2.1.0:33750
08:19:47.008640 handlers.go:53: stunner-auth INFO: ephemeral auth request: success
08:19:47.009435 server.go:211: turn DEBUG: Exit read loop on error: EOF
08:19:48.078466 server.go:38: turn DEBUG: Received 1 bytes of udp from 141.94.213.65:45408 on [::]:3478
08:19:48.078526 server.go:63: turn DEBUG: Handling TURN packet
08:19:48.078547 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:19:48.078477 server.go:38: turn DEBUG: Received 1 bytes of udp from 141.94.213.65:6834 on [::]:3478
08:19:48.078569 server.go:63: turn DEBUG: Handling TURN packet
08:19:48.078577 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:19:48.080184 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.1.0:29741 on [::]:3478
08:19:48.080228 server.go:63: turn DEBUG: Handling TURN packet
08:19:48.080245 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:19:48.080189 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.1.0:17409 on [::]:3478
08:19:48.080282 server.go:63: turn DEBUG: Handling TURN packet
08:19:48.080293 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header
08:19:48.080894 server.go:38: turn DEBUG: Received 1 bytes of udp from 10.2.0.0:30472 on [::]:3478
08:19:48.080919 server.go:63: turn DEBUG: Handling TURN packet
08:19:48.080933 server.go:229: turn ERROR: Failed to handle datagram: failed to create stun message from packet: unexpected EOF: not enough bytes to read header

moufmouf avatar Nov 04 '24 08:11 moufmouf

Closing this in preparation for the v1.1 release. Feel free to reopen if you have new input.

rg0now avatar May 06 '25 10:05 rg0now