search

Glimesh / broadcast-box

A broadcast, in a box.
MIT License
688 stars 57 forks source link

mux: ending readLoop packetio.Buffer error the agent is closed #113

Closed rosch100 closed 3 months ago

rosch100 commented 4 months ago

I set up broadcast-box on a public server in a docker container using the provided docker-compose.yaml. Ports 80 and 443 are exposed so that the web server obtains a certificate. It works as expected and the web site shows the broadcast box banner.

However, publishing a stream to the broadcast box from OBS fails.

The log of the broadcast-box docker container reads:

2024/04/20 20:48:32 Loading `.env.production`
NETWORK_TEST_ON_START is enabled. If the test fails Broadcast Box will exit.
See the README for how to debug or disable NETWORK_TEST_ON_START
2024/04/20 20:48:32 Running HTTP Server at `:8080`
Network Test passed.
Have fun using Broadcast Box.
mux ERROR: 2024/04/20 20:48:37 mux: ending readLoop packetio.Buffer error the agent is closed
Sean-Der commented 4 months ago

Hey @rosch100

Also if you get a chance we have a discord and happy to help on that also!

Sean-Der commented 3 months ago

Hi @rosch100

Thanks for filing this. If this is still an issue I am here to help

rosch100 commented 1 month ago

Sorry for the delay. Here is the requested info:

It works, when broadcasting directly on the web.

The server runs on docker in MS Azure on a Ubuntu 24 server. I also tried using another provider (Ionos in Germany) with the same problem. broadcast-box runs behind a nginx reverse proxy for HTTP traffic (jwilder/docker-gen, jrcs/letsencrypt-nginx-proxy-companion) and has UPD 8080 exposed. The nginx proxy also takes care of HTTPS encryption.

docker-compose.yaml:

services:
  broadcast-box:
    image: seaduboi/broadcast-box:latest
    container_name: broadcast-box
    hostname: broadcast-box
    environment:
      - INCLUDE_PUBLIC_IP_IN_NAT_1_TO_1_IP=yes
      - UDP_MUX_PORT=8080
      - PION_LOG_TRACE=all
      - VIRTUAL_HOST=myhost
      - VIRTUAL_PORT=8080
      - LETSENCRYPT_HOST=myhost
      - LETSENCRYPT_EMAIL=myemail
      - SSL_POLICY=Mozilla-Modern
    privileged: true
    expose:
      - "8080"
    ports:
      - "8080:8080/udp"
networks:
  default:
    name: nginx-proxy
    external: true

log output:

2024/07/08 14:18:34 Loading `.env.production`
2024/07/08 14:18:34 Running HTTP Server at `:8080`
NETWORK_TEST_ON_START is enabled. If the test fails Broadcast Box will exit.
See the README for how to debug or disable NETWORK_TEST_ON_START
ice TRACE: 14:18:39.981988 agent.go:443: Unset selected candidate pair
pc INFO: 2024/07/08 14:18:39 signaling state changed to have-local-offer
pc INFO: 2024/07/08 14:18:39 signaling state changed to have-remote-offer
ice TRACE: 14:18:39.986374 agent.go:443: Unset selected candidate pair
pc INFO: 2024/07/08 14:18:39 signaling state changed to stable
ice DEBUG: 14:18:39.986597 agent.go:320: Started agent: isControlling? false, remoteUfrag: "kexFMlwenwlWqOXm", remotePwd: "jJDVFPIPMsBjPgovBPMiccbmYYZTLnFW"
ice INFO: 2024/07/08 14:18:39 Setting new connection state: Checking
pc INFO: 2024/07/08 14:18:39 ICE connection state changed: checking
pc INFO: 2024/07/08 14:18:39 peer connection state changed: connecting
ice TRACE: 14:18:39.986649 agent.go:461: Pinging all candidates
ice WARNING: 2024/07/08 14:18:39 Failed to ping without candidate pairs. Connection is not possible yet.
ice TRACE: 14:18:39.986709 agent.go:461: Pinging all candidates
ice WARNING: 2024/07/08 14:18:39 Failed to ping without candidate pairs. Connection is not possible yet.
pc INFO: 2024/07/08 14:18:39 signaling state changed to stable
ice DEBUG: 14:18:39.988963 agent.go:320: Started agent: isControlling? true, remoteUfrag: "QetKVJmSeVsfGfrA", remotePwd: "SHuKrdpILYUJRVqUTCDLUZFzhloyChlS"
ice INFO: 2024/07/08 14:18:39 Setting new connection state: Checking
pc INFO: 2024/07/08 14:18:39 ICE connection state changed: checking
pc INFO: 2024/07/08 14:18:39 peer connection state changed: connecting
ice TRACE: 14:18:39.989324 agent.go:461: Pinging all candidates
ice TRACE: 14:18:39.989845 agent.go:895: Ping STUN from udp4 host 172.18.0.13:47052 (resolved: 172.18.0.13:47052) to udp4 host my.public.ip:8080 (resolved: my.public.ip:8080)
ice TRACE: 14:18:39.990710 agent.go:1010: Inbound STUN (Request) from my.public.ip:47052 to udp4 host my.public.ip:8080 (resolved: my.public.ip:8080), useCandidate: false
ice DEBUG: 14:18:39.990897 agent.go:1043: Adding a new peer-reflexive candidate: my.public.ip:47052
ice DEBUG: 14:18:39.990975 udp_mux.go:268: Registered ::ffff:my.public.ip for QetKVJmSeVsfGfrA
ice TRACE: 14:18:39.991098 agent.go:895: Ping STUN from udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) to udp4 prflx my.public.ip:47052 related :0 (resolved: my.public.ip:47052)
ice TRACE: 14:18:39.991259 agent.go:461: Pinging all candidates
ice TRACE: 14:18:39.991531 agent.go:895: Ping STUN from udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) to udp4 prflx my.public.ip:47052 related :0 (resolved: my.public.ip:47052)
ice TRACE: 14:18:39.991492 selection.go:138: Inbound STUN (SuccessResponse) from udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) to udp4 host 172.18.0.13:47052 (resolved: 172.18.0.13:47052)
ice TRACE: 14:18:39.991874 selection.go:148: Found valid candidate pair: prio 9151314440652587007 (local, prio 2130706431) udp4 host 172.18.0.13:47052 (resolved: 172.18.0.13:47052) <-> udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) (remote, prio 2130706431), state: succeeded, nominated: false, nominateOnBindingSuccess: false
ice TRACE: 14:18:39.991986 agent.go:1010: Inbound STUN (Request) from my.public.ip:8080 to udp4 host 172.18.0.13:47052 (resolved: 172.18.0.13:47052), useCandidate: false
ice TRACE: 14:18:39.992162 selection.go:109: The candidate (udp4 host 172.18.0.13:47052 (resolved: 172.18.0.13:47052), udp4 host my.public.ip:8080 (resolved: my.public.ip:8080)) is the best candidate available, marking it as nominated
ice TRACE: 14:18:39.992407 selection.go:90: Ping STUN (nominate candidate pair) from udp4 host 172.18.0.13:47052 (resolved: 172.18.0.13:47052) to udp4 host my.public.ip:8080 (resolved: my.public.ip:8080)
ice TRACE: 14:18:39.992346 selection.go:229: Inbound STUN (SuccessResponse) from udp4 prflx my.public.ip:47052 related :0 (resolved: my.public.ip:47052) to udp4 host my.public.ip:8080 (resolved: my.public.ip:8080)
ice TRACE: 14:18:39.992525 selection.go:239: Found valid candidate pair: prio 7998392936314175487 (local, prio 2130706431) udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) <-> udp4 prflx my.public.ip:47052 related :0 (resolved: my.public.ip:47052) (remote, prio 1862270975), state: succeeded, nominated: false, nominateOnBindingSuccess: false
ice TRACE: 14:18:39.992649 agent.go:895: Ping STUN from udp4 host 172.18.0.13:47052 (resolved: 172.18.0.13:47052) to udp4 host my.public.ip:8080 (resolved: my.public.ip:8080)
ice TRACE: 14:18:39.992878 agent.go:1010: Inbound STUN (Request) from my.public.ip:8080 to udp4 host 172.18.0.13:47052 (resolved: 172.18.0.13:47052), useCandidate: false
ice TRACE: 14:18:39.993381 agent.go:1010: Inbound STUN (Request) from my.public.ip:47052 to udp4 host my.public.ip:8080 (resolved: my.public.ip:8080), useCandidate: true
ice TRACE: 14:18:39.993402 agent.go:449: Set selected candidate pair: prio 7998392936314175487 (local, prio 2130706431) udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) <-> udp4 prflx my.public.ip:47052 related :0 (resolved: my.public.ip:47052) (remote, prio 1862270975), state: succeeded, nominated: true, nominateOnBindingSuccess: false
ice INFO: 2024/07/08 14:18:39 Setting new connection state: Connected
ice TRACE: 14:18:39.993484 agent.go:895: Ping STUN from udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) to udp4 prflx my.public.ip:47052 related :0 (resolved: my.public.ip:47052)
pc INFO: 2024/07/08 14:18:39 ICE connection state changed: connected
dtls TRACE: 14:18:39.993595 handshaker.go:176: [handshake:client] Flight 1: Preparing
dtls TRACE: 14:18:39.993615 handshaker.go:176: [handshake:client] Flight 1: Sending
dtls TRACE: 14:18:39.993626 conn.go:416: [handshake:client] -> ClientHello (epoch: 0, seq: 0)
dtls TRACE: 14:18:39.993672 handshaker.go:176: [handshake:client] Flight 1: Waiting
ice TRACE: 14:18:39.993797 selection.go:138: Inbound STUN (SuccessResponse) from udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) to udp4 host 172.18.0.13:47052 (resolved: 172.18.0.13:47052)
ice TRACE: 14:18:39.993964 selection.go:148: Found valid candidate pair: prio 9151314440652587007 (local, prio 2130706431) udp4 host 172.18.0.13:47052 (resolved: 172.18.0.13:47052) <-> udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) (remote, prio 2130706431), state: succeeded, nominated: false, nominateOnBindingSuccess: false
ice TRACE: 14:18:39.994014 agent.go:449: Set selected candidate pair: prio 9151314440652587007 (local, prio 2130706431) udp4 host 172.18.0.13:47052 (resolved: 172.18.0.13:47052) <-> udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) (remote, prio 2130706431), state: succeeded, nominated: true, nominateOnBindingSuccess: false
ice INFO: 2024/07/08 14:18:39 Setting new connection state: Connected
ice TRACE: 14:18:39.994138 agent.go:1010: Inbound STUN (Request) from my.public.ip:8080 to udp4 host 172.18.0.13:47052 (resolved: 172.18.0.13:47052), useCandidate: false
ice TRACE: 14:18:39.993936 selection.go:229: Inbound STUN (SuccessResponse) from udp4 prflx my.public.ip:47052 related :0 (resolved: my.public.ip:47052) to udp4 host my.public.ip:8080 (resolved: my.public.ip:8080)
ice TRACE: 14:18:39.994306 selection.go:239: Found valid candidate pair: prio 7998392936314175487 (local, prio 2130706431) udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) <-> udp4 prflx my.public.ip:47052 related :0 (resolved: my.public.ip:47052) (remote, prio 1862270975), state: succeeded, nominated: true, nominateOnBindingSuccess: false
pc INFO: 2024/07/08 14:18:39 ICE connection state changed: connected
ice INFO: 2024/07/08 14:18:39 Setting new connection state: Closed
pc INFO: 2024/07/08 14:18:39 peer connection state changed: closed
Network Test passed.
Have fun using Broadcast Box.
pc WARNING: 2024/07/08 14:18:39 Failed to start manager: InvalidStateError: attempted to start DTLSTransport that is not in new state: closed
pc WARNING: 2024/07/08 14:18:39 undeclaredMediaProcessor failed to open SrtcpSession: the DTLS transport has not started yet
pc INFO: 2024/07/08 14:18:39 ICE connection state changed: closed
mux ERROR: 2024/07/08 14:18:39 mux: ending readLoop packetio.Buffer error the agent is closed
pc WARNING: 2024/07/08 14:18:39 undeclaredMediaProcessor failed to open SrtpSession: the DTLS transport has not started yet
ice TRACE: 14:18:39.996221 selection.go:229: Inbound STUN (SuccessResponse) from udp4 prflx my.public.ip:47052 related :0 (resolved: my.public.ip:47052) to udp4 host my.public.ip:8080 (resolved: my.public.ip:8080)
ice TRACE: 14:18:39.996240 selection.go:239: Found valid candidate pair: prio 7998392936314175487 (local, prio 2130706431) udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) <-> udp4 prflx my.public.ip:47052 related :0 (resolved: my.public.ip:47052) (remote, prio 1862270975), state: succeeded, nominated: true, nominateOnBindingSuccess: false
ice TRACE: 14:18:40.193189 selection.go:181: Checking keepalive
sender_interceptor WARNING: 2024/07/08 14:18:40 failed sending: the DTLS transport has not started yet
sender_interceptor WARNING: 2024/07/08 14:18:40 failed sending: the DTLS transport has not started yet
dtls TRACE: 14:18:40.993938 handshaker.go:176: [handshake:client] Flight 1: Sending
dtls TRACE: 14:18:40.994094 conn.go:416: [handshake:client] -> ClientHello (epoch: 0, seq: 0)
dtls TRACE: 14:18:40.994433 handshaker.go:176: [handshake:client] Flight 1: Waiting
sender_interceptor WARNING: 2024/07/08 14:18:41 failed sending: the DTLS transport has not started yet
sender_interceptor WARNING: 2024/07/08 14:18:41 failed sending: the DTLS transport has not started yet
dtls TRACE: 14:18:41.995099 handshaker.go:176: [handshake:client] Flight 1: Sending
dtls TRACE: 14:18:41.995130 conn.go:416: [handshake:client] -> ClientHello (epoch: 0, seq: 0)
dtls TRACE: 14:18:41.995311 handshaker.go:176: [handshake:client] Flight 1: Waiting
ice TRACE: 14:18:42.193968 selection.go:181: Checking keepalive
ice TRACE: 14:18:42.194022 agent.go:895: Ping STUN from udp4 host my.public.ip:8080 (resolved: my.public.ip:8080) to udp4 prflx my.public.ip:47052 related :0 (resolved: my.public.ip:47052)
sender_interceptor WARNING: 2024/07/08 14:18:42 failed sending: the DTLS transport has not started yet
sender_interceptor WARNING: 2024/07/08 14:18:42 failed sending: the DTLS transport has not started yet
dtls TRACE: 14:18:42.995618 handshaker.go:176: [handshake:client] Flight 1: Sending
dtls TRACE: 14:18:42.995651 conn.go:416: [handshake:client] -> ClientHello (epoch: 0, seq: 0)
dtls TRACE: 14:18:42.995763 handshaker.go:176: [handshake:client] Flight 1: Waiting
sender_interceptor WARNING: 2024/07/08 14:18:43 failed sending: the DTLS transport has not started yet
sender_interceptor WARNING: 2024/07/08 14:18:43 failed sending: the DTLS transport has not started yet
:
:
ice TRACE: 14:19:10.205047 agent.go:443: Unset selected candidate pair
ice INFO: 2024/07/08 14:19:10 Setting new connection state: Failed
ice TRACE: 14:19:10.205087 selection.go:181: Checking keepalive
pc INFO: 2024/07/08 14:19:10 ICE connection state changed: failed
dtls TRACE: 14:19:10.205175 conn.go:936: handshake timeouts - closing underline connection
pc INFO: 2024/07/08 14:19:10 Closing PeerConnection from DTLS CloseNotify
pc INFO: 2024/07/08 14:19:10 peer connection state changed: closed
pc WARNING: 2024/07/08 14:19:10 Failed to start manager: handshake error: context deadline exceeded
pc WARNING: 2024/07/08 14:19:10 undeclaredMediaProcessor failed to open SrtcpSession: the DTLS transport has not started yet
pc WARNING: 2024/07/08 14:19:10 undeclaredMediaProcessor failed to open SrtpSession: the DTLS transport has not started yet
ice INFO: 2024/07/08 14:19:10 Setting new connection state: Closed
pc INFO: 2024/07/08 14:19:10 ICE connection state changed: closed