private void ProcessInPacket(IncomingPacket incomingPacket) { Packet packet = incomingPacket.Packet; LLClientView client = incomingPacket.Client; if (client.IsActive) { m_currentIncomingClient = client; try { // Process this packet client.ProcessInPacket(packet); } catch (ThreadAbortException) { // If something is trying to abort the packet processing thread, take that as a hint that it's time to shut down m_log.Info("[LLUDPSERVER]: Caught a thread abort, shutting down the LLUDP server"); Stop(); } catch (Exception e) { // Don't let a failure in an individual client thread crash the whole sim. m_log.Error( string.Format( "[LLUDPSERVER]: Client packet handler for {0} for packet {1} threw ", client.Name, packet.Type), e); } finally { m_currentIncomingClient = null; } } else { m_log.DebugFormat( "[LLUDPSERVER]: Dropped incoming {0} for dead client {1} in {2}", packet.Type, client.Name, m_scene.RegionInfo.RegionName); } IncomingPacketsProcessed++; }
public override void PacketReceived(UDPPacketBuffer buffer) { // Debugging/Profiling //try { Thread.CurrentThread.Name = "PacketReceived (" + m_scene.RegionInfo.RegionName + ")"; } //catch (Exception) { } // m_log.DebugFormat( // "[LLUDPSERVER]: Packet received from {0} in {1}", buffer.RemoteEndPoint, m_scene.RegionInfo.RegionName); LLUDPClient udpClient = null; Packet packet = null; int packetEnd = buffer.DataLength - 1; IPEndPoint endPoint = (IPEndPoint)buffer.RemoteEndPoint; #region Decoding if (buffer.DataLength < 7) { // m_log.WarnFormat( // "[LLUDPSERVER]: Dropping undersized packet with {0} bytes received from {1} in {2}", // buffer.DataLength, buffer.RemoteEndPoint, m_scene.RegionInfo.RegionName); RecordMalformedInboundPacket(endPoint); return; // Drop undersized packet } int headerLen = 7; if (buffer.Data[6] == 0xFF) { if (buffer.Data[7] == 0xFF) headerLen = 10; else headerLen = 8; } if (buffer.DataLength < headerLen) { // m_log.WarnFormat( // "[LLUDPSERVER]: Dropping packet with malformed header received from {0} in {1}", // buffer.RemoteEndPoint, m_scene.RegionInfo.RegionName); RecordMalformedInboundPacket(endPoint); return; // Malformed header } try { // packet = Packet.BuildPacket(buffer.Data, ref packetEnd, // // Only allocate a buffer for zerodecoding if the packet is zerocoded // ((buffer.Data[0] & Helpers.MSG_ZEROCODED) != 0) ? new byte[4096] : null); // If OpenSimUDPBase.UsePool == true (which is currently separate from the PacketPool) then we // assume that packet construction does not retain a reference to byte[] buffer.Data (instead, all // bytes are copied out). packet = PacketPool.Instance.GetPacket(buffer.Data, ref packetEnd, // Only allocate a buffer for zerodecoding if the packet is zerocoded ((buffer.Data[0] & Helpers.MSG_ZEROCODED) != 0) ? new byte[4096] : null); } catch (Exception e) { if (IncomingMalformedPacketCount < 100) m_log.DebugFormat("[LLUDPSERVER]: Dropped malformed packet: " + e.ToString()); } // Fail-safe check if (packet == null) { if (IncomingMalformedPacketCount < 100) { m_log.WarnFormat("[LLUDPSERVER]: Malformed data, cannot parse {0} byte packet from {1}, data {2}:", buffer.DataLength, buffer.RemoteEndPoint, Utils.BytesToHexString(buffer.Data, buffer.DataLength, null)); } RecordMalformedInboundPacket(endPoint); return; } #endregion Decoding #region Packet to Client Mapping // UseCircuitCode handling if (packet.Type == PacketType.UseCircuitCode) { // We need to copy the endpoint so that it doesn't get changed when another thread reuses the // buffer. object[] array = new object[] { new IPEndPoint(endPoint.Address, endPoint.Port), packet }; Util.FireAndForget(HandleUseCircuitCode, array); return; } else if (packet.Type == PacketType.CompleteAgentMovement) { // Send ack straight away to let the viewer know that we got it. SendAckImmediate(endPoint, packet.Header.Sequence); // We need to copy the endpoint so that it doesn't get changed when another thread reuses the // buffer. object[] array = new object[] { new IPEndPoint(endPoint.Address, endPoint.Port), packet }; Util.FireAndForget(HandleCompleteMovementIntoRegion, array); return; } // Determine which agent this packet came from IClientAPI client; if (!m_scene.TryGetClient(endPoint, out client) || !(client is LLClientView)) { //m_log.Debug("[LLUDPSERVER]: Received a " + packet.Type + " packet from an unrecognized source: " + address + " in " + m_scene.RegionInfo.RegionName); IncomingOrphanedPacketCount++; if ((IncomingOrphanedPacketCount % 10000) == 0) m_log.WarnFormat( "[LLUDPSERVER]: Received {0} orphaned packets so far. Last was from {1}", IncomingOrphanedPacketCount, endPoint); return; } udpClient = ((LLClientView)client).UDPClient; if (!udpClient.IsConnected) return; #endregion Packet to Client Mapping // Stats tracking Interlocked.Increment(ref udpClient.PacketsReceived); int now = Environment.TickCount & Int32.MaxValue; udpClient.TickLastPacketReceived = now; #region ACK Receiving // Handle appended ACKs if (packet.Header.AppendedAcks && packet.Header.AckList != null) { // m_log.DebugFormat( // "[LLUDPSERVER]: Handling {0} appended acks from {1} in {2}", // packet.Header.AckList.Length, client.Name, m_scene.Name); for (int i = 0; i < packet.Header.AckList.Length; i++) udpClient.NeedAcks.Acknowledge(packet.Header.AckList[i], now, packet.Header.Resent); } // Handle PacketAck packets if (packet.Type == PacketType.PacketAck) { PacketAckPacket ackPacket = (PacketAckPacket)packet; // m_log.DebugFormat( // "[LLUDPSERVER]: Handling {0} packet acks for {1} in {2}", // ackPacket.Packets.Length, client.Name, m_scene.Name); for (int i = 0; i < ackPacket.Packets.Length; i++) udpClient.NeedAcks.Acknowledge(ackPacket.Packets[i].ID, now, packet.Header.Resent); // We don't need to do anything else with PacketAck packets return; } #endregion ACK Receiving #region ACK Sending if (packet.Header.Reliable) { // m_log.DebugFormat( // "[LLUDPSERVER]: Adding ack request for {0} {1} from {2} in {3}", // packet.Type, packet.Header.Sequence, client.Name, m_scene.Name); udpClient.PendingAcks.Enqueue(packet.Header.Sequence); // This is a somewhat odd sequence of steps to pull the client.BytesSinceLastACK value out, // add the current received bytes to it, test if 2*MTU bytes have been sent, if so remove // 2*MTU bytes from the value and send ACKs, and finally add the local value back to // client.BytesSinceLastACK. Lockless thread safety int bytesSinceLastACK = Interlocked.Exchange(ref udpClient.BytesSinceLastACK, 0); bytesSinceLastACK += buffer.DataLength; if (bytesSinceLastACK > LLUDPServer.MTU * 2) { bytesSinceLastACK -= LLUDPServer.MTU * 2; SendAcks(udpClient); } Interlocked.Add(ref udpClient.BytesSinceLastACK, bytesSinceLastACK); } #endregion ACK Sending #region Incoming Packet Accounting // Check the archive of received reliable packet IDs to see whether we already received this packet if (packet.Header.Reliable && !udpClient.PacketArchive.TryEnqueue(packet.Header.Sequence)) { if (packet.Header.Resent) m_log.DebugFormat( "[LLUDPSERVER]: Received a resend of already processed packet #{0}, type {1} from {2}", packet.Header.Sequence, packet.Type, client.Name); else m_log.WarnFormat( "[LLUDPSERVER]: Received a duplicate (not marked as resend) of packet #{0}, type {1} from {2}", packet.Header.Sequence, packet.Type, client.Name); // Avoid firing a callback twice for the same packet return; } #endregion Incoming Packet Accounting #region BinaryStats LogPacketHeader(true, udpClient.CircuitCode, 0, packet.Type, (ushort)packet.Length); #endregion BinaryStats if (packet.Type == PacketType.AgentUpdate) { if (m_discardAgentUpdates) return; ((LLClientView)client).TotalAgentUpdates++; AgentUpdatePacket agentUpdate = (AgentUpdatePacket)packet; LLClientView llClient = client as LLClientView; if (agentUpdate.AgentData.SessionID != client.SessionId || agentUpdate.AgentData.AgentID != client.AgentId || !(llClient == null || llClient.CheckAgentUpdateSignificance(agentUpdate.AgentData)) ) { PacketPool.Instance.ReturnPacket(packet); return; } } #region Ping Check Handling if (packet.Type == PacketType.StartPingCheck) { // m_log.DebugFormat("[LLUDPSERVER]: Handling ping from {0} in {1}", client.Name, m_scene.Name); // We don't need to do anything else with ping checks StartPingCheckPacket startPing = (StartPingCheckPacket)packet; CompletePing(udpClient, startPing.PingID.PingID); if ((Environment.TickCount - m_elapsedMSSinceLastStatReport) >= 3000) { udpClient.SendPacketStats(); m_elapsedMSSinceLastStatReport = Environment.TickCount; } return; } else if (packet.Type == PacketType.CompletePingCheck) { // We don't currently track client ping times return; } #endregion Ping Check Handling IncomingPacket incomingPacket; // Inbox insertion if (UsePools) { incomingPacket = m_incomingPacketPool.GetObject(); incomingPacket.Client = (LLClientView)client; incomingPacket.Packet = packet; } else { incomingPacket = new IncomingPacket((LLClientView)client, packet); } packetInbox.Enqueue(incomingPacket); }
private void HandleCompleteMovementIntoRegion(object o) { IPEndPoint endPoint = null; IClientAPI client = null; try { object[] array = (object[])o; endPoint = (IPEndPoint)array[0]; CompleteAgentMovementPacket packet = (CompleteAgentMovementPacket)array[1]; // Determine which agent this packet came from int count = 20; bool ready = false; while (!ready && count-- > 0) { if (m_scene.TryGetClient(endPoint, out client) && client.IsActive && client.SceneAgent != null) { LLClientView llClientView = (LLClientView)client; LLUDPClient udpClient = llClientView.UDPClient; if (udpClient != null && udpClient.IsConnected) ready = true; else { m_log.Debug("[LLUDPSERVER]: Received a CompleteMovementIntoRegion in " + m_scene.RegionInfo.RegionName + " (not ready yet)"); Thread.Sleep(200); } } else { m_log.Debug("[LLUDPSERVER]: Received a CompleteMovementIntoRegion in " + m_scene.RegionInfo.RegionName + " (not ready yet)"); Thread.Sleep(200); } } if (client == null) return; IncomingPacket incomingPacket1; // Inbox insertion if (UsePools) { incomingPacket1 = m_incomingPacketPool.GetObject(); incomingPacket1.Client = (LLClientView)client; incomingPacket1.Packet = packet; } else { incomingPacket1 = new IncomingPacket((LLClientView)client, packet); } packetInbox.Enqueue(incomingPacket1); } catch (Exception e) { m_log.ErrorFormat( "[LLUDPSERVER]: CompleteMovementIntoRegion handling from endpoint {0}, client {1} {2} failed. Exception {3}{4}", endPoint != null ? endPoint.ToString() : "n/a", client != null ? client.Name : "unknown", client != null ? client.AgentId.ToString() : "unknown", e.Message, e.StackTrace); } }
private void HandleCompleteMovementIntoRegion(object o) { IPEndPoint endPoint = null; IClientAPI client = null; try { object[] array = (object[])o; endPoint = (IPEndPoint)array[0]; CompleteAgentMovementPacket packet = (CompleteAgentMovementPacket)array[1]; m_log.DebugFormat( "[LLUDPSERVER]: Handling CompleteAgentMovement request from {0} in {1}", endPoint, Scene.Name); // Determine which agent this packet came from // We need to wait here because in when using the OpenSimulator V2 teleport protocol to travel to a destination // simulator with no existing child presence, the viewer (at least LL 3.3.4) will send UseCircuitCode // and then CompleteAgentMovement immediately without waiting for an ack. As we are now handling these // packets asynchronously, we need to account for this thread proceeding more quickly than the // UseCircuitCode thread. int count = 40; while (count-- > 0) { if (Scene.TryGetClient(endPoint, out client)) { if (!client.IsActive) { // This check exists to catch a condition where the client has been closed by another thread // but has not yet been removed from the client manager (and possibly a new connection has // not yet been established). m_log.DebugFormat( "[LLUDPSERVER]: Received a CompleteAgentMovement from {0} for {1} in {2} but client is not active yet. Waiting.", endPoint, client.Name, Scene.Name); } else if (client.SceneAgent == null) { // This check exists to catch a condition where the new client has been added to the client // manager but the SceneAgent has not yet been set in Scene.AddNewAgent(). If we are too // eager, then the new ScenePresence may not have registered a listener for this messsage // before we try to process it. // XXX: A better long term fix may be to add the SceneAgent before the client is added to // the client manager m_log.DebugFormat( "[LLUDPSERVER]: Received a CompleteAgentMovement from {0} for {1} in {2} but client SceneAgent not set yet. Waiting.", endPoint, client.Name, Scene.Name); } else { break; } } else { m_log.DebugFormat( "[LLUDPSERVER]: Received a CompleteAgentMovement from {0} in {1} but no client exists yet. Waiting.", endPoint, Scene.Name); } Thread.Sleep(200); } if (client == null) { m_log.DebugFormat( "[LLUDPSERVER]: No client found for CompleteAgentMovement from {0} in {1} after wait. Dropping.", endPoint, Scene.Name); return; } else if (!client.IsActive || client.SceneAgent == null) { // This check exists to catch a condition where the client has been closed by another thread // but has not yet been removed from the client manager. // The packet could be simply ignored but it is useful to know if this condition occurred for other debugging // purposes. m_log.DebugFormat( "[LLUDPSERVER]: Received a CompleteAgentMovement from {0} for {1} in {2} but client is not active after wait. Dropping.", endPoint, client.Name, Scene.Name); return; } IncomingPacket incomingPacket1; // Inbox insertion if (UsePools) { incomingPacket1 = m_incomingPacketPool.GetObject(); incomingPacket1.Client = (LLClientView)client; incomingPacket1.Packet = packet; } else { incomingPacket1 = new IncomingPacket((LLClientView)client, packet); } packetInbox.Enqueue(incomingPacket1); } catch (Exception e) { m_log.ErrorFormat( "[LLUDPSERVER]: CompleteAgentMovement handling from endpoint {0}, client {1} {2} failed. Exception {3}{4}", endPoint != null ? endPoint.ToString() : "n/a", client != null ? client.Name : "unknown", client != null ? client.AgentId.ToString() : "unknown", e.Message, e.StackTrace); } }