Connectivity problems, timeout. ICE log included
-
Problem connecting to games. It gets stuck on the "Setting up automatch" and crashes, with "You caused a problem" and the ensuing timeout.
Any ideas?
See file for full log advanced-ice-adapter.log
First and last part of advanced-ice-adapter.log:
18:42:37.187 [main] INFO c.f.i.d.TelemetryDebugger - Open the telemetry ui via https://ice-telemetry.faforever.com/app.html?gameId=21064496&playerId=487490
Eki 26, 2023 6:42:37 �S com.sun.javafx.application.PlatformImpl startup
WARNING: Unsupported JavaFX configuration: classes were loaded from 'unnamed module @548a102f'
18:42:38.100 [main] INFO c.f.i.u.TrayIcon - Created tray icon
18:42:38.101 [main] INFO c.f.i.IceAdapter - Version: SNAPSHOT
18:42:38.102 [main] INFO c.f.i.g.GPGNetServer - Using GPGNET_PORT: 51544
18:42:38.108 [main] INFO c.f.i.g.GPGNetServer - Generated LOBBY_PORT: 48442
18:42:38.109 [main] INFO c.f.i.g.GPGNetServer - GPGNetServer started
18:42:38.110 [main] INFO c.f.i.r.RPCService - Creating RPC server on port 51543
18:42:38.112 [main] INFO c.n.j.TcpServer - TCP Server started.
18:42:38.113 [main] INFO c.f.i.d.TelemetryDebugger - RPC started
18:42:38.335 [Thread-5] INFO c.n.j.SocketListener - New client connected on port 51556
18:42:38.337 [Thread-5] INFO c.f.i.d.TelemetryDebugger - RPC connected
18:42:38.338 [JJsonPeer] INFO c.n.j.JJsonPeer - JJSON Peer listening
18:42:38.341 [JavaFX Application Thread] INFO c.f.i.d.DebugWindow - Created debug window.
18:42:38.353 [JJsonPeer] DEBUG c.f.i.r.RPCHandler - LobbyInitMode set to auto
18:42:38.354 [JJsonPeer] INFO c.n.j.JJsonPeer - Sending Response:{"result":null,"id":0,"jsonrpc":"2.0"}
18:42:38.427 [WebSocketConnectReadThread-35] INFO c.f.i.d.TelemetryDebugger - Telemetry websocket opened
18:42:38.689 [JJsonPeer] INFO c.f.i.i.GameSession - Ice Servers set, total addresses: 3
18:42:38.690 [JJsonPeer] INFO c.n.j.JJsonPeer - Sending Response:{"result":null,"id":1,"jsonrpc":"2.0"}
18:42:39.385 [JavaFX Application Thread] INFO c.f.i.d.InfoWindow - Created info window.
18:42:41.689 [Thread-4] INFO c.n.j.JJsonPeer - Sending Notification:{"method":"onConnectionStateChanged","params":["Connected"],"jsonrpc":"2.0"}
18:42:41.689 [Thread-4] INFO c.f.i.g.GPGNetServer - GPGNetClient has connected
18:42:41.713 [Thread-11] DEBUG c.f.i.g.GPGNetServer - Listening for GPG messages
18:42:41.729 [Thread-11] DEBUG c.f.i.g.GPGNetServer - New GameState: Idle
18:42:41.730 [Thread-11] INFO c.f.i.g.GPGNetServer - Sent GPGNet message: CreateLobby 1 48442 commanderbambi 487490 1
18:42:41.734 [Thread-11] INFO c.f.i.g.GPGNetServer - Received GPGNet message: GameState Idle
18:42:41.735 [Thread-11] INFO c.n.j.JJsonPeer - Sending Notification:{"method":"onGpgNetMessageReceived","params":["GameState",["Idle"]],"jsonrpc":"2.0"}
18:42:41.952 [Thread-11] DEBUG c.f.i.g.GPGNetServer - New GameState: Lobby
18:42:41.953 [Thread-11] INFO c.f.i.g.GPGNetServer - Received GPGNet message: GameState Lobby
18:42:41.953 [Thread-11] INFO c.n.j.JJsonPeer - Sending Notification:{"method":"onGpgNetMessageReceived","params":["GameState",["Lobby"]],"jsonrpc":"2.0"}
18:42:42.034 [JJsonPeer] INFO c.f.i.IceAdapter - onHostGame
18:42:42.035 [JJsonPeer] INFO c.f.i.g.GPGNetServer - Sent GPGNet message: HostGame neroxis_map_generator_1.9.0_vte3ulqcewrvm_bafa
18:42:42.036 [JJsonPeer] INFO c.n.j.JJsonPeer - Sending Response:{"result":null,"id":2,"jsonrpc":"2.0"}
18:42:42.831 [ForkJoinPool.commonPool-worker-1] WARN c.f.i.u.PingWrapper - Failed to ping coturn1.faforever.com
18:42:48.548 [JJsonPeer] INFO c.f.i.IceAdapter - onConnectToPeer 28275 Guy, offer: true
18:42:48.552 [JJsonPeer] DEBUG c.f.i.i.Peer - Peer created: 28275, Guy, localOffer: true
18:42:48.554 [JJsonPeer] DEBUG c.f.i.i.Peer - Now forwarding data to peer Guy(28275)
18:42:48.556 [Thread-13] INFO c.n.j.JJsonPeer - Sending Notification:{"method":"onIceConnectionStateChanged","params":[487490,28275,"gathering"],"jsonrpc":"2.0"}
18:42:48.564 [JJsonPeer] INFO c.f.i.g.GPGNetServer - Sent GPGNet message: ConnectToPeer 127.0.0.1:49478 Guy 28275
18:42:48.565 [JJsonPeer] INFO c.n.j.JJsonPeer - Sending Response:{"result":null,"id":3,"jsonrpc":"2.0"}
18:42:48.574 [Thread-13] INFO c.f.i.i.PeerIceModule - ICE Guy(28275): Initiating ICE for peer
18:42:48.575 [Thread-11] INFO c.f.i.g.GPGNetServer - Received GPGNet message: Disconnected 28275
18:42:48.575 [Thread-11] INFO c.n.j.JJsonPeer - Sending Notification:{"method":"onGpgNetMessageReceived","params":["Disconnected",["28275"]],"jsonrpc":"2.0"}
Eki 26, 2023 6:42:49 �S org.ice4j.ice.harvest.MappingCandidateHarvesters initialize
INFO: Initialized mapping harvesters (delay=504ms). stunDiscoveryFailed=false
18:42:49.108 [Thread-13] INFO c.f.i.i.PeerIceModule - ICE Guy(28275): Gathering ice candidates
18:42:49.111 [Thread-13] INFO c.f.i.i.PeerIceModule - Using official ice servers: [94.130.225.99:3478/tcp, 94.130.225.99:3478/udp, 94.130.225.99:3478/udp]
Eki 26, 2023 6:42:49 �S org.ice4j.util.Logger log
INFO: Gathering candidates for component faData.RTP. Local ufrag 13dsr1hdmae2ok
18:42:49.435 [JJsonPeer] INFO c.f.i.IceAdapter - onConnectToPeer 413575 Alcaloz, offer: true
18:42:49.435 [JJsonPeer] DEBUG c.f.i.i.Peer - Peer created: 413575, Alcaloz, localOffer: true
18:42:49.435 [JJsonPeer] DEBUG c.f.i.i.Peer - Now forwarding data to peer Alcaloz(413575)
18:42:49.437 [JJsonPeer] INFO c.f.i.g.GPGNetServer - Sent GPGNet message: ConnectToPeer 127.0.0.1:49480 Alcaloz 413575
18:42:49.438 [Thread-19] INFO c.n.j.JJsonPeer - Sending Notification:{"method":"onIceConnectionStateChanged","params":[487490,413575,"gathering"],"jsonrpc":"2.0"}
18:42:49.438 [JJsonPeer] INFO c.n.j.JJsonPeer - Sending Response:{"result":null,"id":4,"jsonrpc":"2.0"}
18:42:49.440 [Thread-19] INFO c.f.i.i.PeerIceModule - ICE Alcaloz(413575): Initiating ICE for peer
18:42:49.441 [Thread-19] INFO c.f.i.i.PeerIceModule - ICE Alcaloz(413575): Gathering ice candidates
18:42:49.442 [Thread-19] INFO c.f.i.i.PeerIceModule - Using official ice servers: [94.130.225.99:3478/tcp, 94.130.225.99:3478/udp, 94.130.225.99:3478/udp]
Eki 26, 2023 6:42:49 �S org.ice4j.util.Logger log
INFO: Gathering candidates for component faData.RTP. Local ufrag btnle1hdmae3j1
18:42:49.501 [Thread-11] INFO c.f.i.g.GPGNetServer - Received GPGNet message: Disconnected 413575
18:42:49.501 [Thread-11] INFO c.n.j.JJsonPeer - Sending Notification:{"method":"onGpgNetMessageReceived","params":["Disconnected",["413575"]],"jsonrpc":"2.0"}
18:42:51.455 [Thread-13] DEBUG c.f.i.i.PeerIceModule - ICE Guy(28275): Sending own candidates to 28275, offered candidates: host(udp)
18:42:51.455 [Thread-13] INFO c.n.j.JJsonPeer - Sending Notification:{"method":"onIceConnectionStateChanged","params":[487490,28275,"awaitingCandidates"],"jsonrpc":"2.0"}***A LOT CUT OUT, TOO LONG OTHERWISE. SEE ATTACHED FILE FOR COMPLETE LOG ***
INFO: Closing.
at java.base/java.net.DatagramSocket.receive(DatagramSocket.java:700)
at com.faforever.iceadapter.ice.Peer.faListener(Peer.java:81)
at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.nio.channels.AsynchronousCloseException: null
at java.base/sun.nio.ch.DatagramChannelImpl.endRead(DatagramChannelImpl.java:523)
at java.base/sun.nio.ch.DatagramChannelImpl.trustedBlockingReceive(DatagramChannelImpl.java:677)
at java.base/sun.nio.ch.DatagramChannelImpl.blockingReceive(DatagramChannelImpl.java:635)
at java.base/sun.nio.ch.DatagramSocketAdaptor.receive(DatagramSocketAdaptor.java:240)
... 3 common frames omitted
19:24:45.512 [Thread-74] DEBUG c.f.i.i.Peer - Error while reading from local FA as peer (probably disconnecting from peer) dipollwody(348482)
java.net.SocketException: Socket closed
at java.base/sun.nio.ch.DatagramSocketAdaptor.receive(DatagramSocketAdaptor.java:252)
at java.base/java.net.DatagramSocket.receive(DatagramSocket.java:700)
at com.faforever.iceadapter.ice.Peer.faListener(Peer.java:81)
at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.nio.channels.AsynchronousCloseException: null
at java.base/sun.nio.ch.DatagramChannelImpl.endRead(DatagramChannelImpl.java:523)
at java.base/sun.nio.ch.DatagramChannelImpl.trustedBlockingReceive(DatagramChannelImpl.java:677)
at java.base/sun.nio.ch.DatagramChannelImpl.blockingReceive(DatagramChannelImpl.java:635)
at java.base/sun.nio.ch.DatagramSocketAdaptor.receive(DatagramSocketAdaptor.java:240)
... 3 common frames omitted
19:24:45.513 [Thread-12] DEBUG c.f.i.i.Peer - Error while reading from local FA as peer (probably disconnecting from peer) omega22(403305)
java.net.SocketException: Socket closed
at java.base/sun.nio.ch.DatagramSocketAdaptor.receive(DatagramSocketAdaptor.java:252)
at java.base/java.net.DatagramSocket.receive(DatagramSocket.java:700)
at com.faforever.iceadapter.ice.Peer.faListener(Peer.java:81)
at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.nio.channels.AsynchronousCloseException: null
at java.base/sun.nio.ch.DatagramChannelImpl.endRead(DatagramChannelImpl.java:523)
at java.base/sun.nio.ch.DatagramChannelImpl.trustedBlockingReceive(DatagramChannelImpl.java:677)
at java.base/sun.nio.ch.DatagramChannelImpl.blockingReceive(DatagramChannelImpl.java:635)
at java.base/sun.nio.ch.DatagramSocketAdaptor.receive(DatagramSocketAdaptor.java:240)
... 3 common frames omitted
19:24:45.514 [JJsonPeer] WARN c.f.i.r.RPCHandler - Close requested, stopping...
19:24:45.514 [JJsonPeer] INFO c.f.i.IceAdapter - close() - stopping the adapter
19:24:45.515 [JJsonPeer] INFO c.f.i.g.GPGNetServer - GPGNetServer stopped
19:24:45.515 [Thread-11] DEBUG c.f.i.g.GPGNetServer - No longer listening for GPGPNET from FA
java.net.SocketException: Socket closed
at java.base/sun.nio.ch.NioSocketImpl.endAccept(NioSocketImpl.java:689)
at java.base/sun.nio.ch.NioSocketImpl.accept(NioSocketImpl.java:762)
at java.base/java.net.ServerSocket.implAccept(ServerSocket.java:675)
at java.base/java.net.ServerSocket.platformImplAccept(ServerSocket.java:641)
at java.base/java.net.ServerSocket.implAccept(ServerSocket.java:617)
at java.base/java.net.ServerSocket.implAccept(ServerSocket.java:574)
at java.base/java.net.ServerSocket.accept(ServerSocket.java:532)
at com.nbarraille.jjsonrpc.SocketListener.run(SocketListener.java:36)
Eki 26, 2023 7:24:45 �S org.ice4j.util.Logger log
INFO: Failed to receive: java.net.SocketException: Socket closed
Eki 26, 2023 7:24:45 �S org.ice4j.util.Logger log
INFO: Failed to receive: java.net.SocketException: Socket closed
Hello! It looks like you're interested in this conversation, but you don't have an account yet.
Getting fed up of having to scroll through the same posts each visit? When you register for an account, you'll always come back to exactly where you were before, and choose to be notified of new replies (either via email, or push notification). You'll also be able to save bookmarks and upvote posts to show your appreciation to other community members.
With your input, this post could be even better 💗
Register Login