opensim-development – Blame information for rev 1
?pathlinks?
Rev | Author | Line No. | Line |
---|---|---|---|
1 | eva | 1 | /* |
2 | * Copyright (c) Contributors, http://opensimulator.org/ |
||
3 | * See CONTRIBUTORS.TXT for a full list of copyright holders. |
||
4 | * |
||
5 | * Redistribution and use in source and binary forms, with or without |
||
6 | * modification, are permitted provided that the following conditions are met: |
||
7 | * * Redistributions of source code must retain the above copyright |
||
8 | * notice, this list of conditions and the following disclaimer. |
||
9 | * * Redistributions in binary form must reproduce the above copyright |
||
10 | * notice, this list of conditions and the following disclaimer in the |
||
11 | * documentation and/or other materials provided with the distribution. |
||
12 | * * Neither the name of the OpenSimulator Project nor the |
||
13 | * names of its contributors may be used to endorse or promote products |
||
14 | * derived from this software without specific prior written permission. |
||
15 | * |
||
16 | * THIS SOFTWARE IS PROVIDED BY THE DEVELOPERS ``AS IS'' AND ANY |
||
17 | * EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED |
||
18 | * WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE |
||
19 | * DISCLAIMED. IN NO EVENT SHALL THE CONTRIBUTORS BE LIABLE FOR ANY |
||
20 | * DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES |
||
21 | * (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; |
||
22 | * LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND |
||
23 | * ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT |
||
24 | * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS |
||
25 | * SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. |
||
26 | */ |
||
27 | |||
28 | using System; |
||
29 | using System.Collections.Generic; |
||
30 | using System.Diagnostics; |
||
31 | using System.IO; |
||
32 | using System.Net; |
||
33 | using System.Net.Sockets; |
||
34 | using System.Reflection; |
||
35 | using System.Threading; |
||
36 | using log4net; |
||
37 | using NDesk.Options; |
||
38 | using Nini.Config; |
||
39 | using OpenMetaverse.Packets; |
||
40 | using OpenSim.Framework; |
||
41 | using OpenSim.Framework.Console; |
||
42 | using OpenSim.Framework.Monitoring; |
||
43 | using OpenSim.Region.Framework.Scenes; |
||
44 | using OpenMetaverse; |
||
45 | |||
46 | using TokenBucket = OpenSim.Region.ClientStack.LindenUDP.TokenBucket; |
||
47 | |||
48 | namespace OpenSim.Region.ClientStack.LindenUDP |
||
49 | { |
||
50 | /// <summary> |
||
51 | /// A shim around LLUDPServer that implements the IClientNetworkServer interface |
||
52 | /// </summary> |
||
53 | public sealed class LLUDPServerShim : IClientNetworkServer |
||
54 | { |
||
55 | LLUDPServer m_udpServer; |
||
56 | |||
57 | public LLUDPServerShim() |
||
58 | { |
||
59 | } |
||
60 | |||
61 | public void Initialise(IPAddress listenIP, ref uint port, int proxyPortOffsetParm, bool allow_alternate_port, IConfigSource configSource, AgentCircuitManager circuitManager) |
||
62 | { |
||
63 | m_udpServer = new LLUDPServer(listenIP, ref port, proxyPortOffsetParm, allow_alternate_port, configSource, circuitManager); |
||
64 | } |
||
65 | |||
66 | public void AddScene(IScene scene) |
||
67 | { |
||
68 | m_udpServer.AddScene(scene); |
||
69 | |||
70 | StatsManager.RegisterStat( |
||
71 | new Stat( |
||
72 | "ClientLogoutsDueToNoReceives", |
||
73 | "Number of times a client has been logged out because no packets were received before the timeout.", |
||
74 | "", |
||
75 | "", |
||
76 | "clientstack", |
||
77 | scene.Name, |
||
78 | StatType.Pull, |
||
79 | MeasuresOfInterest.None, |
||
80 | stat => stat.Value = m_udpServer.ClientLogoutsDueToNoReceives, |
||
81 | StatVerbosity.Debug)); |
||
82 | |||
83 | StatsManager.RegisterStat( |
||
84 | new Stat( |
||
85 | "IncomingUDPReceivesCount", |
||
86 | "Number of UDP receives performed", |
||
87 | "", |
||
88 | "", |
||
89 | "clientstack", |
||
90 | scene.Name, |
||
91 | StatType.Pull, |
||
92 | MeasuresOfInterest.AverageChangeOverTime, |
||
93 | stat => stat.Value = m_udpServer.UdpReceives, |
||
94 | StatVerbosity.Debug)); |
||
95 | |||
96 | StatsManager.RegisterStat( |
||
97 | new Stat( |
||
98 | "IncomingPacketsProcessedCount", |
||
99 | "Number of inbound LL protocol packets processed", |
||
100 | "", |
||
101 | "", |
||
102 | "clientstack", |
||
103 | scene.Name, |
||
104 | StatType.Pull, |
||
105 | MeasuresOfInterest.AverageChangeOverTime, |
||
106 | stat => stat.Value = m_udpServer.IncomingPacketsProcessed, |
||
107 | StatVerbosity.Debug)); |
||
108 | |||
109 | StatsManager.RegisterStat( |
||
110 | new Stat( |
||
111 | "IncomingPacketsMalformedCount", |
||
112 | "Number of inbound UDP packets that could not be recognized as LL protocol packets.", |
||
113 | "", |
||
114 | "", |
||
115 | "clientstack", |
||
116 | scene.Name, |
||
117 | StatType.Pull, |
||
118 | MeasuresOfInterest.AverageChangeOverTime, |
||
119 | stat => stat.Value = m_udpServer.IncomingMalformedPacketCount, |
||
120 | StatVerbosity.Info)); |
||
121 | |||
122 | StatsManager.RegisterStat( |
||
123 | new Stat( |
||
124 | "IncomingPacketsOrphanedCount", |
||
125 | "Number of inbound packets that were not initial connections packets and could not be associated with a viewer.", |
||
126 | "", |
||
127 | "", |
||
128 | "clientstack", |
||
129 | scene.Name, |
||
130 | StatType.Pull, |
||
131 | MeasuresOfInterest.AverageChangeOverTime, |
||
132 | stat => stat.Value = m_udpServer.IncomingOrphanedPacketCount, |
||
133 | StatVerbosity.Info)); |
||
134 | |||
135 | StatsManager.RegisterStat( |
||
136 | new Stat( |
||
137 | "IncomingPacketsResentCount", |
||
138 | "Number of inbound packets that clients indicate are resends.", |
||
139 | "", |
||
140 | "", |
||
141 | "clientstack", |
||
142 | scene.Name, |
||
143 | StatType.Pull, |
||
144 | MeasuresOfInterest.AverageChangeOverTime, |
||
145 | stat => stat.Value = m_udpServer.IncomingPacketsResentCount, |
||
146 | StatVerbosity.Debug)); |
||
147 | |||
148 | StatsManager.RegisterStat( |
||
149 | new Stat( |
||
150 | "OutgoingUDPSendsCount", |
||
151 | "Number of UDP sends performed", |
||
152 | "", |
||
153 | "", |
||
154 | "clientstack", |
||
155 | scene.Name, |
||
156 | StatType.Pull, |
||
157 | MeasuresOfInterest.AverageChangeOverTime, |
||
158 | stat => stat.Value = m_udpServer.UdpSends, |
||
159 | StatVerbosity.Debug)); |
||
160 | |||
161 | StatsManager.RegisterStat( |
||
162 | new Stat( |
||
163 | "OutgoingPacketsResentCount", |
||
164 | "Number of packets resent because a client did not acknowledge receipt", |
||
165 | "", |
||
166 | "", |
||
167 | "clientstack", |
||
168 | scene.Name, |
||
169 | StatType.Pull, |
||
170 | MeasuresOfInterest.AverageChangeOverTime, |
||
171 | stat => stat.Value = m_udpServer.PacketsResentCount, |
||
172 | StatVerbosity.Debug)); |
||
173 | |||
174 | StatsManager.RegisterStat( |
||
175 | new Stat( |
||
176 | "AverageUDPProcessTime", |
||
177 | "Average number of milliseconds taken to process each incoming UDP packet in a sample.", |
||
178 | "This is for initial receive processing which is separate from the later client LL packet processing stage.", |
||
179 | "ms", |
||
180 | "clientstack", |
||
181 | scene.Name, |
||
182 | StatType.Pull, |
||
183 | MeasuresOfInterest.None, |
||
184 | stat => stat.Value = m_udpServer.AverageReceiveTicksForLastSamplePeriod / TimeSpan.TicksPerMillisecond, |
||
185 | // stat => |
||
186 | // stat.Value = Math.Round(m_udpServer.AverageReceiveTicksForLastSamplePeriod / TimeSpan.TicksPerMillisecond, 7), |
||
187 | StatVerbosity.Debug)); |
||
188 | } |
||
189 | |||
190 | public bool HandlesRegion(Location x) |
||
191 | { |
||
192 | return m_udpServer.HandlesRegion(x); |
||
193 | } |
||
194 | |||
195 | public void Start() |
||
196 | { |
||
197 | m_udpServer.Start(); |
||
198 | } |
||
199 | |||
200 | public void Stop() |
||
201 | { |
||
202 | m_udpServer.Stop(); |
||
203 | } |
||
204 | } |
||
205 | |||
206 | /// <summary> |
||
207 | /// The LLUDP server for a region. This handles incoming and outgoing |
||
208 | /// packets for all UDP connections to the region |
||
209 | /// </summary> |
||
210 | public class LLUDPServer : OpenSimUDPBase |
||
211 | { |
||
212 | private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType); |
||
213 | |||
214 | /// <summary>Maximum transmission unit, or UDP packet size, for the LLUDP protocol</summary> |
||
215 | public const int MTU = 1400; |
||
216 | |||
217 | /// <summary>Number of forced client logouts due to no receipt of packets before timeout.</summary> |
||
218 | public int ClientLogoutsDueToNoReceives { get; private set; } |
||
219 | |||
220 | /// <summary> |
||
221 | /// Default packet debug level given to new clients |
||
222 | /// </summary> |
||
223 | public int DefaultClientPacketDebugLevel { get; set; } |
||
224 | |||
225 | /// <summary>The measured resolution of Environment.TickCount</summary> |
||
226 | public readonly float TickCountResolution; |
||
227 | |||
228 | /// <summary>Number of prim updates to put on the queue each time the |
||
229 | /// OnQueueEmpty event is triggered for updates</summary> |
||
230 | public readonly int PrimUpdatesPerCallback; |
||
231 | |||
232 | /// <summary>Number of texture packets to put on the queue each time the |
||
233 | /// OnQueueEmpty event is triggered for textures</summary> |
||
234 | public readonly int TextureSendLimit; |
||
235 | |||
236 | /// <summary>Handlers for incoming packets</summary> |
||
237 | //PacketEventDictionary packetEvents = new PacketEventDictionary(); |
||
238 | /// <summary>Incoming packets that are awaiting handling</summary> |
||
239 | private OpenMetaverse.BlockingQueue<IncomingPacket> packetInbox = new OpenMetaverse.BlockingQueue<IncomingPacket>(); |
||
240 | |||
241 | /// <summary></summary> |
||
242 | //private UDPClientCollection m_clients = new UDPClientCollection(); |
||
243 | /// <summary>Bandwidth throttle for this UDP server</summary> |
||
244 | protected TokenBucket m_throttle; |
||
245 | |||
246 | /// <summary>Bandwidth throttle rates for this UDP server</summary> |
||
247 | public ThrottleRates ThrottleRates { get; private set; } |
||
248 | |||
249 | /// <summary>Manages authentication for agent circuits</summary> |
||
250 | private AgentCircuitManager m_circuitManager; |
||
251 | |||
252 | /// <summary>Reference to the scene this UDP server is attached to</summary> |
||
253 | protected Scene m_scene; |
||
254 | |||
255 | /// <summary>The X/Y coordinates of the scene this UDP server is attached to</summary> |
||
256 | private Location m_location; |
||
257 | |||
258 | /// <summary>The size of the receive buffer for the UDP socket. This value |
||
259 | /// is passed up to the operating system and used in the system networking |
||
260 | /// stack. Use zero to leave this value as the default</summary> |
||
261 | private int m_recvBufferSize; |
||
262 | |||
263 | /// <summary>Flag to process packets asynchronously or synchronously</summary> |
||
264 | private bool m_asyncPacketHandling; |
||
265 | |||
266 | /// <summary>Tracks whether or not a packet was sent each round so we know |
||
267 | /// whether or not to sleep</summary> |
||
268 | private bool m_packetSent; |
||
269 | |||
270 | /// <summary>Environment.TickCount of the last time that packet stats were reported to the scene</summary> |
||
271 | private int m_elapsedMSSinceLastStatReport = 0; |
||
272 | |||
273 | /// <summary>Environment.TickCount of the last time the outgoing packet handler executed</summary> |
||
274 | private int m_tickLastOutgoingPacketHandler; |
||
275 | |||
276 | /// <summary>Keeps track of the number of elapsed milliseconds since the last time the outgoing packet handler looped</summary> |
||
277 | private int m_elapsedMSOutgoingPacketHandler; |
||
278 | |||
279 | /// <summary>Keeps track of the number of 100 millisecond periods elapsed in the outgoing packet handler executed</summary> |
||
280 | private int m_elapsed100MSOutgoingPacketHandler; |
||
281 | |||
282 | /// <summary>Keeps track of the number of 500 millisecond periods elapsed in the outgoing packet handler executed</summary> |
||
283 | private int m_elapsed500MSOutgoingPacketHandler; |
||
284 | |||
285 | /// <summary>Flag to signal when clients should check for resends</summary> |
||
286 | protected bool m_resendUnacked; |
||
287 | |||
288 | /// <summary>Flag to signal when clients should send ACKs</summary> |
||
289 | protected bool m_sendAcks; |
||
290 | |||
291 | /// <summary>Flag to signal when clients should send pings</summary> |
||
292 | protected bool m_sendPing; |
||
293 | |||
294 | /// <summary> |
||
295 | /// Event used to signal when queued packets are available for sending. |
||
296 | /// </summary> |
||
297 | /// <remarks> |
||
298 | /// This allows the outbound loop to only operate when there is data to send rather than continuously polling. |
||
299 | /// Some data is sent immediately and not queued. That data would not trigger this event. |
||
300 | /// </remarks> |
||
301 | private AutoResetEvent m_dataPresentEvent = new AutoResetEvent(false); |
||
302 | |||
303 | private Pool<IncomingPacket> m_incomingPacketPool; |
||
304 | |||
305 | /// <summary> |
||
306 | /// Stat for number of packets in the main pool awaiting use. |
||
307 | /// </summary> |
||
308 | private Stat m_poolCountStat; |
||
309 | |||
310 | /// <summary> |
||
311 | /// Stat for number of packets in the inbound packet pool awaiting use. |
||
312 | /// </summary> |
||
313 | private Stat m_incomingPacketPoolStat; |
||
314 | |||
315 | private int m_defaultRTO = 0; |
||
316 | private int m_maxRTO = 0; |
||
317 | private int m_ackTimeout = 0; |
||
318 | private int m_pausedAckTimeout = 0; |
||
319 | private bool m_disableFacelights = false; |
||
320 | |||
321 | public Socket Server { get { return null; } } |
||
322 | |||
323 | /// <summary> |
||
324 | /// Record how many packets have been resent |
||
325 | /// </summary> |
||
326 | internal int PacketsResentCount { get; set; } |
||
327 | |||
328 | /// <summary> |
||
329 | /// Record how many packets have been sent |
||
330 | /// </summary> |
||
331 | internal int PacketsSentCount { get; set; } |
||
332 | |||
333 | /// <summary> |
||
334 | /// Record how many incoming packets are indicated as resends by clients. |
||
335 | /// </summary> |
||
336 | internal int IncomingPacketsResentCount { get; set; } |
||
337 | |||
338 | /// <summary> |
||
339 | /// Record how many inbound packets could not be recognized as LLUDP packets. |
||
340 | /// </summary> |
||
341 | public int IncomingMalformedPacketCount { get; private set; } |
||
342 | |||
343 | /// <summary> |
||
344 | /// Record how many inbound packets could not be associated with a simulator circuit. |
||
345 | /// </summary> |
||
346 | public int IncomingOrphanedPacketCount { get; private set; } |
||
347 | |||
348 | /// <summary> |
||
349 | /// Record current outgoing client for monitoring purposes. |
||
350 | /// </summary> |
||
351 | private IClientAPI m_currentOutgoingClient; |
||
352 | |||
353 | /// <summary> |
||
354 | /// Recording current incoming client for monitoring purposes. |
||
355 | /// </summary> |
||
356 | private IClientAPI m_currentIncomingClient; |
||
357 | |||
358 | public LLUDPServer( |
||
359 | IPAddress listenIP, ref uint port, int proxyPortOffsetParm, bool allow_alternate_port, |
||
360 | IConfigSource configSource, AgentCircuitManager circuitManager) |
||
361 | : base(listenIP, (int)port) |
||
362 | { |
||
363 | #region Environment.TickCount Measurement |
||
364 | |||
365 | // Measure the resolution of Environment.TickCount |
||
366 | TickCountResolution = 0f; |
||
367 | for (int i = 0; i < 5; i++) |
||
368 | { |
||
369 | int start = Environment.TickCount; |
||
370 | int now = start; |
||
371 | while (now == start) |
||
372 | now = Environment.TickCount; |
||
373 | TickCountResolution += (float)(now - start) * 0.2f; |
||
374 | } |
||
375 | m_log.Info("[LLUDPSERVER]: Average Environment.TickCount resolution: " + TickCountResolution + "ms"); |
||
376 | TickCountResolution = (float)Math.Ceiling(TickCountResolution); |
||
377 | |||
378 | #endregion Environment.TickCount Measurement |
||
379 | |||
380 | m_circuitManager = circuitManager; |
||
381 | int sceneThrottleBps = 0; |
||
382 | bool usePools = false; |
||
383 | |||
384 | IConfig config = configSource.Configs["ClientStack.LindenUDP"]; |
||
385 | if (config != null) |
||
386 | { |
||
387 | m_asyncPacketHandling = config.GetBoolean("async_packet_handling", true); |
||
388 | m_recvBufferSize = config.GetInt("client_socket_rcvbuf_size", 0); |
||
389 | sceneThrottleBps = config.GetInt("scene_throttle_max_bps", 0); |
||
390 | |||
391 | PrimUpdatesPerCallback = config.GetInt("PrimUpdatesPerCallback", 100); |
||
392 | TextureSendLimit = config.GetInt("TextureSendLimit", 20); |
||
393 | |||
394 | m_defaultRTO = config.GetInt("DefaultRTO", 0); |
||
395 | m_maxRTO = config.GetInt("MaxRTO", 0); |
||
396 | m_disableFacelights = config.GetBoolean("DisableFacelights", false); |
||
397 | m_ackTimeout = 1000 * config.GetInt("AckTimeout", 60); |
||
398 | m_pausedAckTimeout = 1000 * config.GetInt("PausedAckTimeout", 300); |
||
399 | } |
||
400 | else |
||
401 | { |
||
402 | PrimUpdatesPerCallback = 100; |
||
403 | TextureSendLimit = 20; |
||
404 | m_ackTimeout = 1000 * 60; // 1 minute |
||
405 | m_pausedAckTimeout = 1000 * 300; // 5 minutes |
||
406 | } |
||
407 | |||
408 | // FIXME: This actually only needs to be done once since the PacketPool is shared across all servers. |
||
409 | // However, there is no harm in temporarily doing it multiple times. |
||
410 | IConfig packetConfig = configSource.Configs["PacketPool"]; |
||
411 | if (packetConfig != null) |
||
412 | { |
||
413 | PacketPool.Instance.RecyclePackets = packetConfig.GetBoolean("RecyclePackets", true); |
||
414 | PacketPool.Instance.RecycleDataBlocks = packetConfig.GetBoolean("RecycleDataBlocks", true); |
||
415 | usePools = packetConfig.GetBoolean("RecycleBaseUDPPackets", usePools); |
||
416 | } |
||
417 | |||
418 | #region BinaryStats |
||
419 | config = configSource.Configs["Statistics.Binary"]; |
||
420 | m_shouldCollectStats = false; |
||
421 | if (config != null) |
||
422 | { |
||
423 | m_shouldCollectStats = config.GetBoolean("Enabled", false); |
||
424 | binStatsMaxFilesize = TimeSpan.FromSeconds(config.GetInt("packet_headers_period_seconds", 300)); |
||
425 | binStatsDir = config.GetString("stats_dir", "."); |
||
426 | m_aggregatedBWStats = config.GetBoolean("aggregatedBWStats", false); |
||
427 | } |
||
428 | #endregion BinaryStats |
||
429 | |||
430 | m_throttle = new TokenBucket(null, sceneThrottleBps); |
||
431 | ThrottleRates = new ThrottleRates(configSource); |
||
432 | |||
433 | if (usePools) |
||
434 | EnablePools(); |
||
435 | } |
||
436 | |||
437 | public void Start() |
||
438 | { |
||
439 | StartInbound(); |
||
440 | StartOutbound(); |
||
441 | |||
442 | m_elapsedMSSinceLastStatReport = Environment.TickCount; |
||
443 | } |
||
444 | |||
445 | private void StartInbound() |
||
446 | { |
||
447 | m_log.InfoFormat( |
||
448 | "[LLUDPSERVER]: Starting inbound packet processing for the LLUDP server in {0} mode with UsePools = {1}", |
||
449 | m_asyncPacketHandling ? "asynchronous" : "synchronous", UsePools); |
||
450 | |||
451 | base.StartInbound(m_recvBufferSize, m_asyncPacketHandling); |
||
452 | |||
453 | // This thread will process the packets received that are placed on the packetInbox |
||
454 | Watchdog.StartThread( |
||
455 | IncomingPacketHandler, |
||
456 | string.Format("Incoming Packets ({0})", m_scene.RegionInfo.RegionName), |
||
457 | ThreadPriority.Normal, |
||
458 | false, |
||
459 | true, |
||
460 | GetWatchdogIncomingAlarmData, |
||
461 | Watchdog.DEFAULT_WATCHDOG_TIMEOUT_MS); |
||
462 | } |
||
463 | |||
464 | private new void StartOutbound() |
||
465 | { |
||
466 | m_log.Info("[LLUDPSERVER]: Starting outbound packet processing for the LLUDP server"); |
||
467 | |||
468 | base.StartOutbound(); |
||
469 | |||
470 | Watchdog.StartThread( |
||
471 | OutgoingPacketHandler, |
||
472 | string.Format("Outgoing Packets ({0})", m_scene.RegionInfo.RegionName), |
||
473 | ThreadPriority.Normal, |
||
474 | false, |
||
475 | true, |
||
476 | GetWatchdogOutgoingAlarmData, |
||
477 | Watchdog.DEFAULT_WATCHDOG_TIMEOUT_MS); |
||
478 | } |
||
479 | |||
480 | public void Stop() |
||
481 | { |
||
482 | m_log.Info("[LLUDPSERVER]: Shutting down the LLUDP server for " + m_scene.RegionInfo.RegionName); |
||
483 | base.StopOutbound(); |
||
484 | base.StopInbound(); |
||
485 | } |
||
486 | |||
487 | protected override bool EnablePools() |
||
488 | { |
||
489 | if (!UsePools) |
||
490 | { |
||
491 | base.EnablePools(); |
||
492 | |||
493 | m_incomingPacketPool = new Pool<IncomingPacket>(() => new IncomingPacket(), 500); |
||
494 | |||
495 | return true; |
||
496 | } |
||
497 | |||
498 | return false; |
||
499 | } |
||
500 | |||
501 | protected override bool DisablePools() |
||
502 | { |
||
503 | if (UsePools) |
||
504 | { |
||
505 | base.DisablePools(); |
||
506 | |||
507 | StatsManager.DeregisterStat(m_incomingPacketPoolStat); |
||
508 | |||
509 | // We won't null out the pool to avoid a race condition with code that may be in the middle of using it. |
||
510 | |||
511 | return true; |
||
512 | } |
||
513 | |||
514 | return false; |
||
515 | } |
||
516 | |||
517 | /// <summary> |
||
518 | /// This is a seperate method so that it can be called once we have an m_scene to distinguish different scene |
||
519 | /// stats. |
||
520 | /// </summary> |
||
521 | private void EnablePoolStats() |
||
522 | { |
||
523 | m_poolCountStat |
||
524 | = new Stat( |
||
525 | "UDPPacketBufferPoolCount", |
||
526 | "Objects within the UDPPacketBuffer pool", |
||
527 | "The number of objects currently stored within the UDPPacketBuffer pool", |
||
528 | "", |
||
529 | "clientstack", |
||
530 | m_scene.Name, |
||
531 | StatType.Pull, |
||
532 | stat => stat.Value = Pool.Count, |
||
533 | StatVerbosity.Debug); |
||
534 | |||
535 | StatsManager.RegisterStat(m_poolCountStat); |
||
536 | |||
537 | m_incomingPacketPoolStat |
||
538 | = new Stat( |
||
539 | "IncomingPacketPoolCount", |
||
540 | "Objects within incoming packet pool", |
||
541 | "The number of objects currently stored within the incoming packet pool", |
||
542 | "", |
||
543 | "clientstack", |
||
544 | m_scene.Name, |
||
545 | StatType.Pull, |
||
546 | stat => stat.Value = m_incomingPacketPool.Count, |
||
547 | StatVerbosity.Debug); |
||
548 | |||
549 | StatsManager.RegisterStat(m_incomingPacketPoolStat); |
||
550 | } |
||
551 | |||
552 | /// <summary> |
||
553 | /// Disables pool stats. |
||
554 | /// </summary> |
||
555 | private void DisablePoolStats() |
||
556 | { |
||
557 | StatsManager.DeregisterStat(m_poolCountStat); |
||
558 | m_poolCountStat = null; |
||
559 | |||
560 | StatsManager.DeregisterStat(m_incomingPacketPoolStat); |
||
561 | m_incomingPacketPoolStat = null; |
||
562 | } |
||
563 | |||
564 | /// <summary> |
||
565 | /// If the outgoing UDP thread times out, then return client that was being processed to help with debugging. |
||
566 | /// </summary> |
||
567 | /// <returns></returns> |
||
568 | private string GetWatchdogIncomingAlarmData() |
||
569 | { |
||
570 | return string.Format( |
||
571 | "Client is {0}", |
||
572 | m_currentIncomingClient != null ? m_currentIncomingClient.Name : "none"); |
||
573 | } |
||
574 | |||
575 | /// <summary> |
||
576 | /// If the outgoing UDP thread times out, then return client that was being processed to help with debugging. |
||
577 | /// </summary> |
||
578 | /// <returns></returns> |
||
579 | private string GetWatchdogOutgoingAlarmData() |
||
580 | { |
||
581 | return string.Format( |
||
582 | "Client is {0}", |
||
583 | m_currentOutgoingClient != null ? m_currentOutgoingClient.Name : "none"); |
||
584 | } |
||
585 | |||
586 | public void AddScene(IScene scene) |
||
587 | { |
||
588 | if (m_scene != null) |
||
589 | { |
||
590 | m_log.Error("[LLUDPSERVER]: AddScene() called on an LLUDPServer that already has a scene"); |
||
591 | return; |
||
592 | } |
||
593 | |||
594 | if (!(scene is Scene)) |
||
595 | { |
||
596 | m_log.Error("[LLUDPSERVER]: AddScene() called with an unrecognized scene type " + scene.GetType()); |
||
597 | return; |
||
598 | } |
||
599 | |||
600 | m_scene = (Scene)scene; |
||
601 | m_location = new Location(m_scene.RegionInfo.RegionHandle); |
||
602 | |||
603 | StatsManager.RegisterStat( |
||
604 | new Stat( |
||
605 | "InboxPacketsCount", |
||
606 | "Number of LL protocol packets waiting for the second stage of processing after initial receive.", |
||
607 | "Number of LL protocol packets waiting for the second stage of processing after initial receive.", |
||
608 | "", |
||
609 | "clientstack", |
||
610 | scene.Name, |
||
611 | StatType.Pull, |
||
612 | MeasuresOfInterest.AverageChangeOverTime, |
||
613 | stat => stat.Value = packetInbox.Count, |
||
614 | StatVerbosity.Debug)); |
||
615 | |||
616 | // XXX: These stats are also pool stats but we register them separately since they are currently not |
||
617 | // turned on and off by EnablePools()/DisablePools() |
||
618 | StatsManager.RegisterStat( |
||
619 | new PercentageStat( |
||
620 | "PacketsReused", |
||
621 | "Packets reused", |
||
622 | "Number of packets reused out of all requests to the packet pool", |
||
623 | "clientstack", |
||
624 | m_scene.Name, |
||
625 | StatType.Pull, |
||
626 | stat => |
||
627 | { PercentageStat pstat = (PercentageStat)stat; |
||
628 | pstat.Consequent = PacketPool.Instance.PacketsRequested; |
||
629 | pstat.Antecedent = PacketPool.Instance.PacketsReused; }, |
||
630 | StatVerbosity.Debug)); |
||
631 | |||
632 | StatsManager.RegisterStat( |
||
633 | new PercentageStat( |
||
634 | "PacketDataBlocksReused", |
||
635 | "Packet data blocks reused", |
||
636 | "Number of data blocks reused out of all requests to the packet pool", |
||
637 | "clientstack", |
||
638 | m_scene.Name, |
||
639 | StatType.Pull, |
||
640 | stat => |
||
641 | { PercentageStat pstat = (PercentageStat)stat; |
||
642 | pstat.Consequent = PacketPool.Instance.BlocksRequested; |
||
643 | pstat.Antecedent = PacketPool.Instance.BlocksReused; }, |
||
644 | StatVerbosity.Debug)); |
||
645 | |||
646 | StatsManager.RegisterStat( |
||
647 | new Stat( |
||
648 | "PacketsPoolCount", |
||
649 | "Objects within the packet pool", |
||
650 | "The number of objects currently stored within the packet pool", |
||
651 | "", |
||
652 | "clientstack", |
||
653 | m_scene.Name, |
||
654 | StatType.Pull, |
||
655 | stat => stat.Value = PacketPool.Instance.PacketsPooled, |
||
656 | StatVerbosity.Debug)); |
||
657 | |||
658 | StatsManager.RegisterStat( |
||
659 | new Stat( |
||
660 | "PacketDataBlocksPoolCount", |
||
661 | "Objects within the packet data block pool", |
||
662 | "The number of objects currently stored within the packet data block pool", |
||
663 | "", |
||
664 | "clientstack", |
||
665 | m_scene.Name, |
||
666 | StatType.Pull, |
||
667 | stat => stat.Value = PacketPool.Instance.BlocksPooled, |
||
668 | StatVerbosity.Debug)); |
||
669 | |||
670 | // We delay enabling pool stats to AddScene() instead of Initialize() so that we can distinguish pool stats by |
||
671 | // scene name |
||
672 | if (UsePools) |
||
673 | EnablePoolStats(); |
||
674 | |||
675 | MainConsole.Instance.Commands.AddCommand( |
||
676 | "Debug", false, "debug lludp packet", |
||
677 | "debug lludp packet [--default] <level> [<avatar-first-name> <avatar-last-name>]", |
||
678 | "Turn on packet debugging", |
||
679 | "If level > 255 then all incoming and outgoing packets are logged.\n" |
||
680 | + "If level <= 255 then incoming AgentUpdate and outgoing SimStats and SimulatorViewerTimeMessage packets are not logged.\n" |
||
681 | + "If level <= 200 then incoming RequestImage and outgoing ImagePacket, ImageData, LayerData and CoarseLocationUpdate packets are not logged.\n" |
||
682 | + "If level <= 100 then incoming ViewerEffect and AgentAnimation and outgoing ViewerEffect and AvatarAnimation packets are not logged.\n" |
||
683 | + "If level <= 50 then outgoing ImprovedTerseObjectUpdate packets are not logged.\n" |
||
684 | + "If level <= 0 then no packets are logged.\n" |
||
685 | + "If --default is specified then the level becomes the default logging level for all subsequent agents.\n" |
||
686 | + "In this case, you cannot also specify an avatar name.\n" |
||
687 | + "If an avatar name is given then only packets from that avatar are logged.", |
||
688 | HandlePacketCommand); |
||
689 | |||
690 | MainConsole.Instance.Commands.AddCommand( |
||
691 | "Debug", |
||
692 | false, |
||
693 | "debug lludp start", |
||
694 | "debug lludp start <in|out|all>", |
||
695 | "Control LLUDP packet processing.", |
||
696 | "No effect if packet processing has already started.\n" |
||
697 | + "in - start inbound processing.\n" |
||
698 | + "out - start outbound processing.\n" |
||
699 | + "all - start in and outbound processing.\n", |
||
700 | HandleStartCommand); |
||
701 | |||
702 | MainConsole.Instance.Commands.AddCommand( |
||
703 | "Debug", |
||
704 | false, |
||
705 | "debug lludp stop", |
||
706 | "debug lludp stop <in|out|all>", |
||
707 | "Stop LLUDP packet processing.", |
||
708 | "No effect if packet processing has already stopped.\n" |
||
709 | + "in - stop inbound processing.\n" |
||
710 | + "out - stop outbound processing.\n" |
||
711 | + "all - stop in and outbound processing.\n", |
||
712 | HandleStopCommand); |
||
713 | |||
714 | MainConsole.Instance.Commands.AddCommand( |
||
715 | "Debug", |
||
716 | false, |
||
717 | "debug lludp pool", |
||
718 | "debug lludp pool <on|off>", |
||
719 | "Turn object pooling within the lludp component on or off.", |
||
720 | HandlePoolCommand); |
||
721 | |||
722 | MainConsole.Instance.Commands.AddCommand( |
||
723 | "Debug", |
||
724 | false, |
||
725 | "debug lludp status", |
||
726 | "debug lludp status", |
||
727 | "Return status of LLUDP packet processing.", |
||
728 | HandleStatusCommand); |
||
729 | |||
730 | MainConsole.Instance.Commands.AddCommand( |
||
731 | "Debug", |
||
732 | false, |
||
733 | "debug lludp toggle agentupdate", |
||
734 | "debug lludp toggle agentupdate", |
||
735 | "Toggle whether agentupdate packets are processed or simply discarded.", |
||
736 | HandleAgentUpdateCommand); |
||
737 | } |
||
738 | |||
739 | private void HandlePacketCommand(string module, string[] args) |
||
740 | { |
||
741 | if (SceneManager.Instance.CurrentScene != null && SceneManager.Instance.CurrentScene != m_scene) |
||
742 | return; |
||
743 | |||
744 | bool setAsDefaultLevel = false; |
||
745 | OptionSet optionSet = new OptionSet().Add("default", o => setAsDefaultLevel = o != null); |
||
746 | List<string> filteredArgs = optionSet.Parse(args); |
||
747 | |||
748 | string name = null; |
||
749 | |||
750 | if (filteredArgs.Count == 6) |
||
751 | { |
||
752 | if (!setAsDefaultLevel) |
||
753 | { |
||
754 | name = string.Format("{0} {1}", filteredArgs[4], filteredArgs[5]); |
||
755 | } |
||
756 | else |
||
757 | { |
||
758 | MainConsole.Instance.OutputFormat("ERROR: Cannot specify a user name when setting default logging level"); |
||
759 | return; |
||
760 | } |
||
761 | } |
||
762 | |||
763 | if (filteredArgs.Count > 3) |
||
764 | { |
||
765 | int newDebug; |
||
766 | if (int.TryParse(filteredArgs[3], out newDebug)) |
||
767 | { |
||
768 | if (setAsDefaultLevel) |
||
769 | { |
||
770 | DefaultClientPacketDebugLevel = newDebug; |
||
771 | MainConsole.Instance.OutputFormat( |
||
772 | "Debug packet debug for new clients set to {0} in {1}", DefaultClientPacketDebugLevel, m_scene.Name); |
||
773 | } |
||
774 | else |
||
775 | { |
||
776 | m_scene.ForEachScenePresence(sp => |
||
777 | { |
||
778 | if (name == null || sp.Name == name) |
||
779 | { |
||
780 | MainConsole.Instance.OutputFormat( |
||
781 | "Packet debug for {0} ({1}) set to {2} in {3}", |
||
782 | sp.Name, sp.IsChildAgent ? "child" : "root", newDebug, m_scene.Name); |
||
783 | |||
784 | sp.ControllingClient.DebugPacketLevel = newDebug; |
||
785 | } |
||
786 | }); |
||
787 | } |
||
788 | } |
||
789 | else |
||
790 | { |
||
791 | MainConsole.Instance.Output("Usage: debug lludp packet [--default] 0..255 [<first-name> <last-name>]"); |
||
792 | } |
||
793 | } |
||
794 | } |
||
795 | |||
796 | private void HandleStartCommand(string module, string[] args) |
||
797 | { |
||
798 | if (SceneManager.Instance.CurrentScene != null && SceneManager.Instance.CurrentScene != m_scene) |
||
799 | return; |
||
800 | |||
801 | if (args.Length != 4) |
||
802 | { |
||
803 | MainConsole.Instance.Output("Usage: debug lludp start <in|out|all>"); |
||
804 | return; |
||
805 | } |
||
806 | |||
807 | string subCommand = args[3]; |
||
808 | |||
809 | if (subCommand == "in" || subCommand == "all") |
||
810 | StartInbound(); |
||
811 | |||
812 | if (subCommand == "out" || subCommand == "all") |
||
813 | StartOutbound(); |
||
814 | } |
||
815 | |||
816 | private void HandleStopCommand(string module, string[] args) |
||
817 | { |
||
818 | if (SceneManager.Instance.CurrentScene != null && SceneManager.Instance.CurrentScene != m_scene) |
||
819 | return; |
||
820 | |||
821 | if (args.Length != 4) |
||
822 | { |
||
823 | MainConsole.Instance.Output("Usage: debug lludp stop <in|out|all>"); |
||
824 | return; |
||
825 | } |
||
826 | |||
827 | string subCommand = args[3]; |
||
828 | |||
829 | if (subCommand == "in" || subCommand == "all") |
||
830 | StopInbound(); |
||
831 | |||
832 | if (subCommand == "out" || subCommand == "all") |
||
833 | StopOutbound(); |
||
834 | } |
||
835 | |||
836 | private void HandlePoolCommand(string module, string[] args) |
||
837 | { |
||
838 | if (SceneManager.Instance.CurrentScene != null && SceneManager.Instance.CurrentScene != m_scene) |
||
839 | return; |
||
840 | |||
841 | if (args.Length != 4) |
||
842 | { |
||
843 | MainConsole.Instance.Output("Usage: debug lludp pool <on|off>"); |
||
844 | return; |
||
845 | } |
||
846 | |||
847 | string enabled = args[3]; |
||
848 | |||
849 | if (enabled == "on") |
||
850 | { |
||
851 | if (EnablePools()) |
||
852 | { |
||
853 | EnablePoolStats(); |
||
854 | MainConsole.Instance.OutputFormat("Packet pools enabled on {0}", m_scene.Name); |
||
855 | } |
||
856 | } |
||
857 | else if (enabled == "off") |
||
858 | { |
||
859 | if (DisablePools()) |
||
860 | { |
||
861 | DisablePoolStats(); |
||
862 | MainConsole.Instance.OutputFormat("Packet pools disabled on {0}", m_scene.Name); |
||
863 | } |
||
864 | } |
||
865 | else |
||
866 | { |
||
867 | MainConsole.Instance.Output("Usage: debug lludp pool <on|off>"); |
||
868 | } |
||
869 | } |
||
870 | |||
871 | bool m_discardAgentUpdates; |
||
872 | |||
873 | private void HandleAgentUpdateCommand(string module, string[] args) |
||
874 | { |
||
875 | if (SceneManager.Instance.CurrentScene != null && SceneManager.Instance.CurrentScene != m_scene) |
||
876 | return; |
||
877 | |||
878 | m_discardAgentUpdates = !m_discardAgentUpdates; |
||
879 | |||
880 | MainConsole.Instance.OutputFormat( |
||
881 | "Discard AgentUpdates now {0} for {1}", m_discardAgentUpdates, m_scene.Name); |
||
882 | } |
||
883 | |||
884 | private void HandleStatusCommand(string module, string[] args) |
||
885 | { |
||
886 | if (SceneManager.Instance.CurrentScene != null && SceneManager.Instance.CurrentScene != m_scene) |
||
887 | return; |
||
888 | |||
889 | MainConsole.Instance.OutputFormat( |
||
890 | "IN LLUDP packet processing for {0} is {1}", m_scene.Name, IsRunningInbound ? "enabled" : "disabled"); |
||
891 | |||
892 | MainConsole.Instance.OutputFormat( |
||
893 | "OUT LLUDP packet processing for {0} is {1}", m_scene.Name, IsRunningOutbound ? "enabled" : "disabled"); |
||
894 | |||
895 | MainConsole.Instance.OutputFormat("LLUDP pools in {0} are {1}", m_scene.Name, UsePools ? "on" : "off"); |
||
896 | |||
897 | MainConsole.Instance.OutputFormat( |
||
898 | "Packet debug level for new clients is {0}", DefaultClientPacketDebugLevel); |
||
899 | } |
||
900 | |||
901 | public bool HandlesRegion(Location x) |
||
902 | { |
||
903 | return x == m_location; |
||
904 | } |
||
905 | |||
906 | // public void BroadcastPacket(Packet packet, ThrottleOutPacketType category, bool sendToPausedAgents, bool allowSplitting) |
||
907 | // { |
||
908 | // // CoarseLocationUpdate and AvatarGroupsReply packets cannot be split in an automated way |
||
909 | // if ((packet.Type == PacketType.CoarseLocationUpdate || packet.Type == PacketType.AvatarGroupsReply) && allowSplitting) |
||
910 | // allowSplitting = false; |
||
911 | // |
||
912 | // if (allowSplitting && packet.HasVariableBlocks) |
||
913 | // { |
||
914 | // byte[][] datas = packet.ToBytesMultiple(); |
||
915 | // int packetCount = datas.Length; |
||
916 | // |
||
917 | // if (packetCount < 1) |
||
918 | // m_log.Error("[LLUDPSERVER]: Failed to split " + packet.Type + " with estimated length " + packet.Length); |
||
919 | // |
||
920 | // for (int i = 0; i < packetCount; i++) |
||
921 | // { |
||
922 | // byte[] data = datas[i]; |
||
923 | // m_scene.ForEachClient( |
||
924 | // delegate(IClientAPI client) |
||
925 | // { |
||
926 | // if (client is LLClientView) |
||
927 | // SendPacketData(((LLClientView)client).UDPClient, data, packet.Type, category, null); |
||
928 | // } |
||
929 | // ); |
||
930 | // } |
||
931 | // } |
||
932 | // else |
||
933 | // { |
||
934 | // byte[] data = packet.ToBytes(); |
||
935 | // m_scene.ForEachClient( |
||
936 | // delegate(IClientAPI client) |
||
937 | // { |
||
938 | // if (client is LLClientView) |
||
939 | // SendPacketData(((LLClientView)client).UDPClient, data, packet.Type, category, null); |
||
940 | // } |
||
941 | // ); |
||
942 | // } |
||
943 | // } |
||
944 | |||
945 | /// <summary> |
||
946 | /// Start the process of sending a packet to the client. |
||
947 | /// </summary> |
||
948 | /// <param name="udpClient"></param> |
||
949 | /// <param name="packet"></param> |
||
950 | /// <param name="category"></param> |
||
951 | /// <param name="allowSplitting"></param> |
||
952 | /// <param name="method"> |
||
953 | /// The method to call if the packet is not acked by the client. If null, then a standard |
||
954 | /// resend of the packet is done. |
||
955 | /// </param> |
||
956 | public virtual void SendPacket( |
||
957 | LLUDPClient udpClient, Packet packet, ThrottleOutPacketType category, bool allowSplitting, UnackedPacketMethod method) |
||
958 | { |
||
959 | // CoarseLocationUpdate packets cannot be split in an automated way |
||
960 | if (packet.Type == PacketType.CoarseLocationUpdate && allowSplitting) |
||
961 | allowSplitting = false; |
||
962 | |||
963 | bool packetQueued = false; |
||
964 | |||
965 | if (allowSplitting && packet.HasVariableBlocks) |
||
966 | { |
||
967 | byte[][] datas = packet.ToBytesMultiple(); |
||
968 | int packetCount = datas.Length; |
||
969 | |||
970 | if (packetCount < 1) |
||
971 | m_log.Error("[LLUDPSERVER]: Failed to split " + packet.Type + " with estimated length " + packet.Length); |
||
972 | |||
973 | for (int i = 0; i < packetCount; i++) |
||
974 | { |
||
975 | byte[] data = datas[i]; |
||
976 | |||
977 | if (!SendPacketData(udpClient, data, packet.Type, category, method)) |
||
978 | packetQueued = true; |
||
979 | } |
||
980 | } |
||
981 | else |
||
982 | { |
||
983 | byte[] data = packet.ToBytes(); |
||
984 | packetQueued = SendPacketData(udpClient, data, packet.Type, category, method); |
||
985 | } |
||
986 | |||
987 | PacketPool.Instance.ReturnPacket(packet); |
||
988 | |||
989 | if (packetQueued) |
||
990 | m_dataPresentEvent.Set(); |
||
991 | } |
||
992 | |||
993 | /// <summary> |
||
994 | /// Start the process of sending a packet to the client. |
||
995 | /// </summary> |
||
996 | /// <param name="udpClient"></param> |
||
997 | /// <param name="data"></param> |
||
998 | /// <param name="type"></param> |
||
999 | /// <param name="category"></param> |
||
1000 | /// <param name="method"> |
||
1001 | /// The method to call if the packet is not acked by the client. If null, then a standard |
||
1002 | /// resend of the packet is done. |
||
1003 | /// </param> |
||
1004 | /// <returns>true if the data was sent immediately, false if it was queued for sending</returns> |
||
1005 | public bool SendPacketData( |
||
1006 | LLUDPClient udpClient, byte[] data, PacketType type, ThrottleOutPacketType category, UnackedPacketMethod method) |
||
1007 | { |
||
1008 | int dataLength = data.Length; |
||
1009 | bool doZerocode = (data[0] & Helpers.MSG_ZEROCODED) != 0; |
||
1010 | bool doCopy = true; |
||
1011 | |||
1012 | // Frequency analysis of outgoing packet sizes shows a large clump of packets at each end of the spectrum. |
||
1013 | // The vast majority of packets are less than 200 bytes, although due to asset transfers and packet splitting |
||
1014 | // there are a decent number of packets in the 1000-1140 byte range. We allocate one of two sizes of data here |
||
1015 | // to accomodate for both common scenarios and provide ample room for ACK appending in both |
||
1016 | int bufferSize = (dataLength > 180) ? LLUDPServer.MTU : 200; |
||
1017 | |||
1018 | UDPPacketBuffer buffer = new UDPPacketBuffer(udpClient.RemoteEndPoint, bufferSize); |
||
1019 | |||
1020 | // Zerocode if needed |
||
1021 | if (doZerocode) |
||
1022 | { |
||
1023 | try |
||
1024 | { |
||
1025 | dataLength = Helpers.ZeroEncode(data, dataLength, buffer.Data); |
||
1026 | doCopy = false; |
||
1027 | } |
||
1028 | catch (IndexOutOfRangeException) |
||
1029 | { |
||
1030 | // The packet grew larger than the bufferSize while zerocoding. |
||
1031 | // Remove the MSG_ZEROCODED flag and send the unencoded data |
||
1032 | // instead |
||
1033 | m_log.Debug("[LLUDPSERVER]: Packet exceeded buffer size during zerocoding for " + type + ". DataLength=" + dataLength + |
||
1034 | " and BufferLength=" + buffer.Data.Length + ". Removing MSG_ZEROCODED flag"); |
||
1035 | data[0] = (byte)(data[0] & ~Helpers.MSG_ZEROCODED); |
||
1036 | } |
||
1037 | } |
||
1038 | |||
1039 | // If the packet data wasn't already copied during zerocoding, copy it now |
||
1040 | if (doCopy) |
||
1041 | { |
||
1042 | if (dataLength <= buffer.Data.Length) |
||
1043 | { |
||
1044 | Buffer.BlockCopy(data, 0, buffer.Data, 0, dataLength); |
||
1045 | } |
||
1046 | else |
||
1047 | { |
||
1048 | bufferSize = dataLength; |
||
1049 | buffer = new UDPPacketBuffer(udpClient.RemoteEndPoint, bufferSize); |
||
1050 | |||
1051 | // m_log.Error("[LLUDPSERVER]: Packet exceeded buffer size! This could be an indication of packet assembly not obeying the MTU. Type=" + |
||
1052 | // type + ", DataLength=" + dataLength + ", BufferLength=" + buffer.Data.Length + ". Dropping packet"); |
||
1053 | Buffer.BlockCopy(data, 0, buffer.Data, 0, dataLength); |
||
1054 | } |
||
1055 | } |
||
1056 | |||
1057 | buffer.DataLength = dataLength; |
||
1058 | |||
1059 | #region Queue or Send |
||
1060 | |||
1061 | OutgoingPacket outgoingPacket = new OutgoingPacket(udpClient, buffer, category, null); |
||
1062 | // If we were not provided a method for handling unacked, use the UDPServer default method |
||
1063 | outgoingPacket.UnackedMethod = ((method == null) ? delegate(OutgoingPacket oPacket) { ResendUnacked(oPacket); } : method); |
||
1064 | |||
1065 | // If a Linden Lab 1.23.5 client receives an update packet after a kill packet for an object, it will |
||
1066 | // continue to display the deleted object until relog. Therefore, we need to always queue a kill object |
||
1067 | // packet so that it isn't sent before a queued update packet. |
||
1068 | bool requestQueue = type == PacketType.KillObject; |
||
1069 | if (!outgoingPacket.Client.EnqueueOutgoing(outgoingPacket, requestQueue)) |
||
1070 | { |
||
1071 | SendPacketFinal(outgoingPacket); |
||
1072 | return true; |
||
1073 | } |
||
1074 | else |
||
1075 | { |
||
1076 | return false; |
||
1077 | } |
||
1078 | |||
1079 | #endregion Queue or Send |
||
1080 | } |
||
1081 | |||
1082 | public void SendAcks(LLUDPClient udpClient) |
||
1083 | { |
||
1084 | uint ack; |
||
1085 | |||
1086 | if (udpClient.PendingAcks.Dequeue(out ack)) |
||
1087 | { |
||
1088 | List<PacketAckPacket.PacketsBlock> blocks = new List<PacketAckPacket.PacketsBlock>(); |
||
1089 | PacketAckPacket.PacketsBlock block = new PacketAckPacket.PacketsBlock(); |
||
1090 | block.ID = ack; |
||
1091 | blocks.Add(block); |
||
1092 | |||
1093 | while (udpClient.PendingAcks.Dequeue(out ack)) |
||
1094 | { |
||
1095 | block = new PacketAckPacket.PacketsBlock(); |
||
1096 | block.ID = ack; |
||
1097 | blocks.Add(block); |
||
1098 | } |
||
1099 | |||
1100 | PacketAckPacket packet = new PacketAckPacket(); |
||
1101 | packet.Header.Reliable = false; |
||
1102 | packet.Packets = blocks.ToArray(); |
||
1103 | |||
1104 | SendPacket(udpClient, packet, ThrottleOutPacketType.Unknown, true, null); |
||
1105 | } |
||
1106 | } |
||
1107 | |||
1108 | public void SendPing(LLUDPClient udpClient) |
||
1109 | { |
||
1110 | StartPingCheckPacket pc = (StartPingCheckPacket)PacketPool.Instance.GetPacket(PacketType.StartPingCheck); |
||
1111 | pc.Header.Reliable = false; |
||
1112 | |||
1113 | pc.PingID.PingID = (byte)udpClient.CurrentPingSequence++; |
||
1114 | // We *could* get OldestUnacked, but it would hurt performance and not provide any benefit |
||
1115 | pc.PingID.OldestUnacked = 0; |
||
1116 | |||
1117 | SendPacket(udpClient, pc, ThrottleOutPacketType.Unknown, false, null); |
||
1118 | } |
||
1119 | |||
1120 | public void CompletePing(LLUDPClient udpClient, byte pingID) |
||
1121 | { |
||
1122 | CompletePingCheckPacket completePing = new CompletePingCheckPacket(); |
||
1123 | completePing.PingID.PingID = pingID; |
||
1124 | SendPacket(udpClient, completePing, ThrottleOutPacketType.Unknown, false, null); |
||
1125 | } |
||
1126 | |||
1127 | public void HandleUnacked(LLClientView client) |
||
1128 | { |
||
1129 | LLUDPClient udpClient = client.UDPClient; |
||
1130 | |||
1131 | if (!udpClient.IsConnected) |
||
1132 | return; |
||
1133 | |||
1134 | // Disconnect an agent if no packets are received for some time |
||
1135 | int timeoutTicks = m_ackTimeout; |
||
1136 | |||
1137 | // Allow more slack if the client is "paused" eg file upload dialogue is open |
||
1138 | // Some sort of limit is needed in case the client crashes, loses its network connection |
||
1139 | // or some other disaster prevents it from sendung the AgentResume |
||
1140 | if (udpClient.IsPaused) |
||
1141 | timeoutTicks = m_pausedAckTimeout; |
||
1142 | |||
1143 | if (client.IsActive && |
||
1144 | (Environment.TickCount & Int32.MaxValue) - udpClient.TickLastPacketReceived > timeoutTicks) |
||
1145 | { |
||
1146 | // We must set IsActive synchronously so that we can stop the packet loop reinvoking this method, even |
||
1147 | // though it's set later on by LLClientView.Close() |
||
1148 | client.IsActive = false; |
||
1149 | |||
1150 | // Fire this out on a different thread so that we don't hold up outgoing packet processing for |
||
1151 | // everybody else if this is being called due to an ack timeout. |
||
1152 | // This is the same as processing as the async process of a logout request. |
||
1153 | Util.FireAndForget(o => DeactivateClientDueToTimeout(client, timeoutTicks)); |
||
1154 | |||
1155 | return; |
||
1156 | } |
||
1157 | |||
1158 | // Get a list of all of the packets that have been sitting unacked longer than udpClient.RTO |
||
1159 | List<OutgoingPacket> expiredPackets = udpClient.NeedAcks.GetExpiredPackets(udpClient.RTO); |
||
1160 | |||
1161 | if (expiredPackets != null) |
||
1162 | { |
||
1163 | //m_log.Debug("[LLUDPSERVER]: Handling " + expiredPackets.Count + " packets to " + udpClient.AgentID + ", RTO=" + udpClient.RTO); |
||
1164 | // Exponential backoff of the retransmission timeout |
||
1165 | udpClient.BackoffRTO(); |
||
1166 | for (int i = 0; i < expiredPackets.Count; ++i) |
||
1167 | expiredPackets[i].UnackedMethod(expiredPackets[i]); |
||
1168 | } |
||
1169 | } |
||
1170 | |||
1171 | public void ResendUnacked(OutgoingPacket outgoingPacket) |
||
1172 | { |
||
1173 | //m_log.DebugFormat("[LLUDPSERVER]: Resending packet #{0} (attempt {1}), {2}ms have passed", |
||
1174 | // outgoingPacket.SequenceNumber, outgoingPacket.ResendCount, Environment.TickCount - outgoingPacket.TickCount); |
||
1175 | |||
1176 | // Set the resent flag |
||
1177 | outgoingPacket.Buffer.Data[0] = (byte)(outgoingPacket.Buffer.Data[0] | Helpers.MSG_RESENT); |
||
1178 | outgoingPacket.Category = ThrottleOutPacketType.Resend; |
||
1179 | |||
1180 | // Bump up the resend count on this packet |
||
1181 | Interlocked.Increment(ref outgoingPacket.ResendCount); |
||
1182 | |||
1183 | // Requeue or resend the packet |
||
1184 | if (!outgoingPacket.Client.EnqueueOutgoing(outgoingPacket, false)) |
||
1185 | SendPacketFinal(outgoingPacket); |
||
1186 | } |
||
1187 | |||
1188 | public void Flush(LLUDPClient udpClient) |
||
1189 | { |
||
1190 | // FIXME: Implement? |
||
1191 | } |
||
1192 | |||
1193 | /// <summary> |
||
1194 | /// Actually send a packet to a client. |
||
1195 | /// </summary> |
||
1196 | /// <param name="outgoingPacket"></param> |
||
1197 | internal void SendPacketFinal(OutgoingPacket outgoingPacket) |
||
1198 | { |
||
1199 | UDPPacketBuffer buffer = outgoingPacket.Buffer; |
||
1200 | byte flags = buffer.Data[0]; |
||
1201 | bool isResend = (flags & Helpers.MSG_RESENT) != 0; |
||
1202 | bool isReliable = (flags & Helpers.MSG_RELIABLE) != 0; |
||
1203 | bool isZerocoded = (flags & Helpers.MSG_ZEROCODED) != 0; |
||
1204 | LLUDPClient udpClient = outgoingPacket.Client; |
||
1205 | |||
1206 | if (!udpClient.IsConnected) |
||
1207 | return; |
||
1208 | |||
1209 | #region ACK Appending |
||
1210 | |||
1211 | int dataLength = buffer.DataLength; |
||
1212 | |||
1213 | // NOTE: I'm seeing problems with some viewers when ACKs are appended to zerocoded packets so I've disabled that here |
||
1214 | if (!isZerocoded) |
||
1215 | { |
||
1216 | // Keep appending ACKs until there is no room left in the buffer or there are |
||
1217 | // no more ACKs to append |
||
1218 | uint ackCount = 0; |
||
1219 | uint ack; |
||
1220 | while (dataLength + 5 < buffer.Data.Length && udpClient.PendingAcks.Dequeue(out ack)) |
||
1221 | { |
||
1222 | Utils.UIntToBytesBig(ack, buffer.Data, dataLength); |
||
1223 | dataLength += 4; |
||
1224 | ++ackCount; |
||
1225 | } |
||
1226 | |||
1227 | if (ackCount > 0) |
||
1228 | { |
||
1229 | // Set the last byte of the packet equal to the number of appended ACKs |
||
1230 | buffer.Data[dataLength++] = (byte)ackCount; |
||
1231 | // Set the appended ACKs flag on this packet |
||
1232 | buffer.Data[0] = (byte)(buffer.Data[0] | Helpers.MSG_APPENDED_ACKS); |
||
1233 | } |
||
1234 | } |
||
1235 | |||
1236 | buffer.DataLength = dataLength; |
||
1237 | |||
1238 | #endregion ACK Appending |
||
1239 | |||
1240 | #region Sequence Number Assignment |
||
1241 | |||
1242 | if (!isResend) |
||
1243 | { |
||
1244 | // Not a resend, assign a new sequence number |
||
1245 | uint sequenceNumber = (uint)Interlocked.Increment(ref udpClient.CurrentSequence); |
||
1246 | Utils.UIntToBytesBig(sequenceNumber, buffer.Data, 1); |
||
1247 | outgoingPacket.SequenceNumber = sequenceNumber; |
||
1248 | |||
1249 | if (isReliable) |
||
1250 | { |
||
1251 | // Add this packet to the list of ACK responses we are waiting on from the server |
||
1252 | udpClient.NeedAcks.Add(outgoingPacket); |
||
1253 | } |
||
1254 | } |
||
1255 | else |
||
1256 | { |
||
1257 | Interlocked.Increment(ref udpClient.PacketsResent); |
||
1258 | |||
1259 | // We're not going to worry about interlock yet since its not currently critical that this total count |
||
1260 | // is 100% correct |
||
1261 | PacketsResentCount++; |
||
1262 | } |
||
1263 | |||
1264 | #endregion Sequence Number Assignment |
||
1265 | |||
1266 | // Stats tracking |
||
1267 | Interlocked.Increment(ref udpClient.PacketsSent); |
||
1268 | |||
1269 | // We're not going to worry about interlock yet since its not currently critical that this total count |
||
1270 | // is 100% correct |
||
1271 | PacketsSentCount++; |
||
1272 | |||
1273 | // Put the UDP payload on the wire |
||
1274 | AsyncBeginSend(buffer); |
||
1275 | |||
1276 | // Keep track of when this packet was sent out (right now) |
||
1277 | outgoingPacket.TickCount = Environment.TickCount & Int32.MaxValue; |
||
1278 | } |
||
1279 | |||
1280 | private void RecordMalformedInboundPacket(IPEndPoint endPoint) |
||
1281 | { |
||
1282 | // if (m_malformedCount < 100) |
||
1283 | // m_log.DebugFormat("[LLUDPSERVER]: Dropped malformed packet: " + e.ToString()); |
||
1284 | |||
1285 | IncomingMalformedPacketCount++; |
||
1286 | |||
1287 | if ((IncomingMalformedPacketCount % 10000) == 0) |
||
1288 | m_log.WarnFormat( |
||
1289 | "[LLUDPSERVER]: Received {0} malformed packets so far, probable network attack. Last was from {1}", |
||
1290 | IncomingMalformedPacketCount, endPoint); |
||
1291 | } |
||
1292 | |||
1293 | public override void PacketReceived(UDPPacketBuffer buffer) |
||
1294 | { |
||
1295 | // Debugging/Profiling |
||
1296 | //try { Thread.CurrentThread.Name = "PacketReceived (" + m_scene.RegionInfo.RegionName + ")"; } |
||
1297 | //catch (Exception) { } |
||
1298 | // m_log.DebugFormat( |
||
1299 | // "[LLUDPSERVER]: Packet received from {0} in {1}", buffer.RemoteEndPoint, m_scene.RegionInfo.RegionName); |
||
1300 | |||
1301 | LLUDPClient udpClient = null; |
||
1302 | Packet packet = null; |
||
1303 | int packetEnd = buffer.DataLength - 1; |
||
1304 | IPEndPoint endPoint = (IPEndPoint)buffer.RemoteEndPoint; |
||
1305 | |||
1306 | #region Decoding |
||
1307 | |||
1308 | if (buffer.DataLength < 7) |
||
1309 | { |
||
1310 | // m_log.WarnFormat( |
||
1311 | // "[LLUDPSERVER]: Dropping undersized packet with {0} bytes received from {1} in {2}", |
||
1312 | // buffer.DataLength, buffer.RemoteEndPoint, m_scene.RegionInfo.RegionName); |
||
1313 | |||
1314 | RecordMalformedInboundPacket(endPoint); |
||
1315 | |||
1316 | return; // Drop undersized packet |
||
1317 | } |
||
1318 | |||
1319 | int headerLen = 7; |
||
1320 | if (buffer.Data[6] == 0xFF) |
||
1321 | { |
||
1322 | if (buffer.Data[7] == 0xFF) |
||
1323 | headerLen = 10; |
||
1324 | else |
||
1325 | headerLen = 8; |
||
1326 | } |
||
1327 | |||
1328 | if (buffer.DataLength < headerLen) |
||
1329 | { |
||
1330 | // m_log.WarnFormat( |
||
1331 | // "[LLUDPSERVER]: Dropping packet with malformed header received from {0} in {1}", |
||
1332 | // buffer.RemoteEndPoint, m_scene.RegionInfo.RegionName); |
||
1333 | |||
1334 | RecordMalformedInboundPacket(endPoint); |
||
1335 | |||
1336 | return; // Malformed header |
||
1337 | } |
||
1338 | |||
1339 | try |
||
1340 | { |
||
1341 | // packet = Packet.BuildPacket(buffer.Data, ref packetEnd, |
||
1342 | // // Only allocate a buffer for zerodecoding if the packet is zerocoded |
||
1343 | // ((buffer.Data[0] & Helpers.MSG_ZEROCODED) != 0) ? new byte[4096] : null); |
||
1344 | // If OpenSimUDPBase.UsePool == true (which is currently separate from the PacketPool) then we |
||
1345 | // assume that packet construction does not retain a reference to byte[] buffer.Data (instead, all |
||
1346 | // bytes are copied out). |
||
1347 | packet = PacketPool.Instance.GetPacket(buffer.Data, ref packetEnd, |
||
1348 | // Only allocate a buffer for zerodecoding if the packet is zerocoded |
||
1349 | ((buffer.Data[0] & Helpers.MSG_ZEROCODED) != 0) ? new byte[4096] : null); |
||
1350 | } |
||
1351 | catch (Exception e) |
||
1352 | { |
||
1353 | if (IncomingMalformedPacketCount < 100) |
||
1354 | m_log.DebugFormat("[LLUDPSERVER]: Dropped malformed packet: " + e.ToString()); |
||
1355 | } |
||
1356 | |||
1357 | // Fail-safe check |
||
1358 | if (packet == null) |
||
1359 | { |
||
1360 | if (IncomingMalformedPacketCount < 100) |
||
1361 | { |
||
1362 | m_log.WarnFormat("[LLUDPSERVER]: Malformed data, cannot parse {0} byte packet from {1}, data {2}:", |
||
1363 | buffer.DataLength, buffer.RemoteEndPoint, Utils.BytesToHexString(buffer.Data, buffer.DataLength, null)); |
||
1364 | } |
||
1365 | |||
1366 | RecordMalformedInboundPacket(endPoint); |
||
1367 | |||
1368 | return; |
||
1369 | } |
||
1370 | |||
1371 | #endregion Decoding |
||
1372 | |||
1373 | #region Packet to Client Mapping |
||
1374 | |||
1375 | // UseCircuitCode handling |
||
1376 | if (packet.Type == PacketType.UseCircuitCode) |
||
1377 | { |
||
1378 | // We need to copy the endpoint so that it doesn't get changed when another thread reuses the |
||
1379 | // buffer. |
||
1380 | object[] array = new object[] { new IPEndPoint(endPoint.Address, endPoint.Port), packet }; |
||
1381 | |||
1382 | Util.FireAndForget(HandleUseCircuitCode, array); |
||
1383 | |||
1384 | return; |
||
1385 | } |
||
1386 | else if (packet.Type == PacketType.CompleteAgentMovement) |
||
1387 | { |
||
1388 | // Send ack straight away to let the viewer know that we got it. |
||
1389 | SendAckImmediate(endPoint, packet.Header.Sequence); |
||
1390 | |||
1391 | // We need to copy the endpoint so that it doesn't get changed when another thread reuses the |
||
1392 | // buffer. |
||
1393 | object[] array = new object[] { new IPEndPoint(endPoint.Address, endPoint.Port), packet }; |
||
1394 | |||
1395 | Util.FireAndForget(HandleCompleteMovementIntoRegion, array); |
||
1396 | |||
1397 | return; |
||
1398 | } |
||
1399 | |||
1400 | // Determine which agent this packet came from |
||
1401 | IClientAPI client; |
||
1402 | if (!m_scene.TryGetClient(endPoint, out client) || !(client is LLClientView)) |
||
1403 | { |
||
1404 | //m_log.Debug("[LLUDPSERVER]: Received a " + packet.Type + " packet from an unrecognized source: " + address + " in " + m_scene.RegionInfo.RegionName); |
||
1405 | |||
1406 | IncomingOrphanedPacketCount++; |
||
1407 | |||
1408 | if ((IncomingOrphanedPacketCount % 10000) == 0) |
||
1409 | m_log.WarnFormat( |
||
1410 | "[LLUDPSERVER]: Received {0} orphaned packets so far. Last was from {1}", |
||
1411 | IncomingOrphanedPacketCount, endPoint); |
||
1412 | |||
1413 | return; |
||
1414 | } |
||
1415 | |||
1416 | udpClient = ((LLClientView)client).UDPClient; |
||
1417 | |||
1418 | if (!udpClient.IsConnected) |
||
1419 | return; |
||
1420 | |||
1421 | #endregion Packet to Client Mapping |
||
1422 | |||
1423 | // Stats tracking |
||
1424 | Interlocked.Increment(ref udpClient.PacketsReceived); |
||
1425 | |||
1426 | int now = Environment.TickCount & Int32.MaxValue; |
||
1427 | udpClient.TickLastPacketReceived = now; |
||
1428 | |||
1429 | #region ACK Receiving |
||
1430 | |||
1431 | // Handle appended ACKs |
||
1432 | if (packet.Header.AppendedAcks && packet.Header.AckList != null) |
||
1433 | { |
||
1434 | // m_log.DebugFormat( |
||
1435 | // "[LLUDPSERVER]: Handling {0} appended acks from {1} in {2}", |
||
1436 | // packet.Header.AckList.Length, client.Name, m_scene.Name); |
||
1437 | |||
1438 | for (int i = 0; i < packet.Header.AckList.Length; i++) |
||
1439 | udpClient.NeedAcks.Acknowledge(packet.Header.AckList[i], now, packet.Header.Resent); |
||
1440 | } |
||
1441 | |||
1442 | // Handle PacketAck packets |
||
1443 | if (packet.Type == PacketType.PacketAck) |
||
1444 | { |
||
1445 | PacketAckPacket ackPacket = (PacketAckPacket)packet; |
||
1446 | |||
1447 | // m_log.DebugFormat( |
||
1448 | // "[LLUDPSERVER]: Handling {0} packet acks for {1} in {2}", |
||
1449 | // ackPacket.Packets.Length, client.Name, m_scene.Name); |
||
1450 | |||
1451 | for (int i = 0; i < ackPacket.Packets.Length; i++) |
||
1452 | udpClient.NeedAcks.Acknowledge(ackPacket.Packets[i].ID, now, packet.Header.Resent); |
||
1453 | |||
1454 | // We don't need to do anything else with PacketAck packets |
||
1455 | return; |
||
1456 | } |
||
1457 | |||
1458 | #endregion ACK Receiving |
||
1459 | |||
1460 | #region ACK Sending |
||
1461 | |||
1462 | if (packet.Header.Reliable) |
||
1463 | { |
||
1464 | // m_log.DebugFormat( |
||
1465 | // "[LLUDPSERVER]: Adding ack request for {0} {1} from {2} in {3}", |
||
1466 | // packet.Type, packet.Header.Sequence, client.Name, m_scene.Name); |
||
1467 | |||
1468 | udpClient.PendingAcks.Enqueue(packet.Header.Sequence); |
||
1469 | |||
1470 | // This is a somewhat odd sequence of steps to pull the client.BytesSinceLastACK value out, |
||
1471 | // add the current received bytes to it, test if 2*MTU bytes have been sent, if so remove |
||
1472 | // 2*MTU bytes from the value and send ACKs, and finally add the local value back to |
||
1473 | // client.BytesSinceLastACK. Lockless thread safety |
||
1474 | int bytesSinceLastACK = Interlocked.Exchange(ref udpClient.BytesSinceLastACK, 0); |
||
1475 | bytesSinceLastACK += buffer.DataLength; |
||
1476 | if (bytesSinceLastACK > LLUDPServer.MTU * 2) |
||
1477 | { |
||
1478 | bytesSinceLastACK -= LLUDPServer.MTU * 2; |
||
1479 | SendAcks(udpClient); |
||
1480 | } |
||
1481 | Interlocked.Add(ref udpClient.BytesSinceLastACK, bytesSinceLastACK); |
||
1482 | } |
||
1483 | |||
1484 | #endregion ACK Sending |
||
1485 | |||
1486 | #region Incoming Packet Accounting |
||
1487 | |||
1488 | // We're not going to worry about interlock yet since its not currently critical that this total count |
||
1489 | // is 100% correct |
||
1490 | if (packet.Header.Resent) |
||
1491 | IncomingPacketsResentCount++; |
||
1492 | |||
1493 | // Check the archive of received reliable packet IDs to see whether we already received this packet |
||
1494 | if (packet.Header.Reliable && !udpClient.PacketArchive.TryEnqueue(packet.Header.Sequence)) |
||
1495 | { |
||
1496 | if (packet.Header.Resent) |
||
1497 | m_log.DebugFormat( |
||
1498 | "[LLUDPSERVER]: Received a resend of already processed packet #{0}, type {1} from {2}", |
||
1499 | packet.Header.Sequence, packet.Type, client.Name); |
||
1500 | else |
||
1501 | m_log.WarnFormat( |
||
1502 | "[LLUDPSERVER]: Received a duplicate (not marked as resend) of packet #{0}, type {1} from {2}", |
||
1503 | packet.Header.Sequence, packet.Type, client.Name); |
||
1504 | |||
1505 | // Avoid firing a callback twice for the same packet |
||
1506 | return; |
||
1507 | } |
||
1508 | |||
1509 | #endregion Incoming Packet Accounting |
||
1510 | |||
1511 | #region BinaryStats |
||
1512 | LogPacketHeader(true, udpClient.CircuitCode, 0, packet.Type, (ushort)packet.Length); |
||
1513 | #endregion BinaryStats |
||
1514 | |||
1515 | if (packet.Type == PacketType.AgentUpdate) |
||
1516 | { |
||
1517 | if (m_discardAgentUpdates) |
||
1518 | return; |
||
1519 | |||
1520 | ((LLClientView)client).TotalAgentUpdates++; |
||
1521 | |||
1522 | AgentUpdatePacket agentUpdate = (AgentUpdatePacket)packet; |
||
1523 | |||
1524 | LLClientView llClient = client as LLClientView; |
||
1525 | if (agentUpdate.AgentData.SessionID != client.SessionId |
||
1526 | || agentUpdate.AgentData.AgentID != client.AgentId |
||
1527 | || !(llClient == null || llClient.CheckAgentUpdateSignificance(agentUpdate.AgentData)) ) |
||
1528 | { |
||
1529 | PacketPool.Instance.ReturnPacket(packet); |
||
1530 | return; |
||
1531 | } |
||
1532 | } |
||
1533 | |||
1534 | #region Ping Check Handling |
||
1535 | |||
1536 | if (packet.Type == PacketType.StartPingCheck) |
||
1537 | { |
||
1538 | // m_log.DebugFormat("[LLUDPSERVER]: Handling ping from {0} in {1}", client.Name, m_scene.Name); |
||
1539 | |||
1540 | // We don't need to do anything else with ping checks |
||
1541 | StartPingCheckPacket startPing = (StartPingCheckPacket)packet; |
||
1542 | CompletePing(udpClient, startPing.PingID.PingID); |
||
1543 | |||
1544 | if ((Environment.TickCount - m_elapsedMSSinceLastStatReport) >= 3000) |
||
1545 | { |
||
1546 | udpClient.SendPacketStats(); |
||
1547 | m_elapsedMSSinceLastStatReport = Environment.TickCount; |
||
1548 | } |
||
1549 | return; |
||
1550 | } |
||
1551 | else if (packet.Type == PacketType.CompletePingCheck) |
||
1552 | { |
||
1553 | // We don't currently track client ping times |
||
1554 | return; |
||
1555 | } |
||
1556 | |||
1557 | #endregion Ping Check Handling |
||
1558 | |||
1559 | IncomingPacket incomingPacket; |
||
1560 | |||
1561 | // Inbox insertion |
||
1562 | if (UsePools) |
||
1563 | { |
||
1564 | incomingPacket = m_incomingPacketPool.GetObject(); |
||
1565 | incomingPacket.Client = (LLClientView)client; |
||
1566 | incomingPacket.Packet = packet; |
||
1567 | } |
||
1568 | else |
||
1569 | { |
||
1570 | incomingPacket = new IncomingPacket((LLClientView)client, packet); |
||
1571 | } |
||
1572 | |||
1573 | packetInbox.Enqueue(incomingPacket); |
||
1574 | } |
||
1575 | |||
1576 | #region BinaryStats |
||
1577 | |||
1578 | public class PacketLogger |
||
1579 | { |
||
1580 | public DateTime StartTime; |
||
1581 | public string Path = null; |
||
1582 | public System.IO.BinaryWriter Log = null; |
||
1583 | } |
||
1584 | |||
1585 | public static PacketLogger PacketLog; |
||
1586 | |||
1587 | protected static bool m_shouldCollectStats = false; |
||
1588 | // Number of seconds to log for |
||
1589 | static TimeSpan binStatsMaxFilesize = TimeSpan.FromSeconds(300); |
||
1590 | static object binStatsLogLock = new object(); |
||
1591 | static string binStatsDir = ""; |
||
1592 | |||
1593 | //for Aggregated In/Out BW logging |
||
1594 | static bool m_aggregatedBWStats = false; |
||
1595 | static long m_aggregatedBytesIn = 0; |
||
1596 | static long m_aggregatedByestOut = 0; |
||
1597 | static object aggBWStatsLock = new object(); |
||
1598 | |||
1599 | public static long AggregatedLLUDPBytesIn |
||
1600 | { |
||
1601 | get { return m_aggregatedBytesIn; } |
||
1602 | } |
||
1603 | public static long AggregatedLLUDPBytesOut |
||
1604 | { |
||
1605 | get {return m_aggregatedByestOut;} |
||
1606 | } |
||
1607 | |||
1608 | public static void LogPacketHeader(bool incoming, uint circuit, byte flags, PacketType packetType, ushort size) |
||
1609 | { |
||
1610 | if (m_aggregatedBWStats) |
||
1611 | { |
||
1612 | lock (aggBWStatsLock) |
||
1613 | { |
||
1614 | if (incoming) |
||
1615 | m_aggregatedBytesIn += size; |
||
1616 | else |
||
1617 | m_aggregatedByestOut += size; |
||
1618 | } |
||
1619 | } |
||
1620 | |||
1621 | if (!m_shouldCollectStats) return; |
||
1622 | |||
1623 | // Binary logging format is TTTTTTTTCCCCFPPPSS, T=Time, C=Circuit, F=Flags, P=PacketType, S=size |
||
1624 | |||
1625 | // Put the incoming bit into the least significant bit of the flags byte |
||
1626 | if (incoming) |
||
1627 | flags |= 0x01; |
||
1628 | else |
||
1629 | flags &= 0xFE; |
||
1630 | |||
1631 | // Put the flags byte into the most significant bits of the type integer |
||
1632 | uint type = (uint)packetType; |
||
1633 | type |= (uint)flags << 24; |
||
1634 | |||
1635 | // m_log.Debug("1 LogPacketHeader(): Outside lock"); |
||
1636 | lock (binStatsLogLock) |
||
1637 | { |
||
1638 | DateTime now = DateTime.Now; |
||
1639 | |||
1640 | // m_log.Debug("2 LogPacketHeader(): Inside lock. now is " + now.Ticks); |
||
1641 | try |
||
1642 | { |
||
1643 | if (PacketLog == null || (now > PacketLog.StartTime + binStatsMaxFilesize)) |
||
1644 | { |
||
1645 | if (PacketLog != null && PacketLog.Log != null) |
||
1646 | { |
||
1647 | PacketLog.Log.Close(); |
||
1648 | } |
||
1649 | |||
1650 | // First log file or time has expired, start writing to a new log file |
||
1651 | PacketLog = new PacketLogger(); |
||
1652 | PacketLog.StartTime = now; |
||
1653 | PacketLog.Path = (binStatsDir.Length > 0 ? binStatsDir + System.IO.Path.DirectorySeparatorChar.ToString() : "") |
||
1654 | + String.Format("packets-{0}.log", now.ToString("yyyyMMddHHmmss")); |
||
1655 | PacketLog.Log = new BinaryWriter(File.Open(PacketLog.Path, FileMode.Append, FileAccess.Write)); |
||
1656 | } |
||
1657 | |||
1658 | // Serialize the data |
||
1659 | byte[] output = new byte[18]; |
||
1660 | Buffer.BlockCopy(BitConverter.GetBytes(now.Ticks), 0, output, 0, 8); |
||
1661 | Buffer.BlockCopy(BitConverter.GetBytes(circuit), 0, output, 8, 4); |
||
1662 | Buffer.BlockCopy(BitConverter.GetBytes(type), 0, output, 12, 4); |
||
1663 | Buffer.BlockCopy(BitConverter.GetBytes(size), 0, output, 16, 2); |
||
1664 | |||
1665 | // Write the serialized data to disk |
||
1666 | if (PacketLog != null && PacketLog.Log != null) |
||
1667 | PacketLog.Log.Write(output); |
||
1668 | } |
||
1669 | catch (Exception ex) |
||
1670 | { |
||
1671 | m_log.Error("Packet statistics gathering failed: " + ex.Message, ex); |
||
1672 | if (PacketLog.Log != null) |
||
1673 | { |
||
1674 | PacketLog.Log.Close(); |
||
1675 | } |
||
1676 | PacketLog = null; |
||
1677 | } |
||
1678 | } |
||
1679 | } |
||
1680 | |||
1681 | #endregion BinaryStats |
||
1682 | |||
1683 | private void HandleUseCircuitCode(object o) |
||
1684 | { |
||
1685 | IPEndPoint endPoint = null; |
||
1686 | IClientAPI client = null; |
||
1687 | |||
1688 | try |
||
1689 | { |
||
1690 | // DateTime startTime = DateTime.Now; |
||
1691 | object[] array = (object[])o; |
||
1692 | endPoint = (IPEndPoint)array[0]; |
||
1693 | UseCircuitCodePacket uccp = (UseCircuitCodePacket)array[1]; |
||
1694 | |||
1695 | m_log.DebugFormat( |
||
1696 | "[LLUDPSERVER]: Handling UseCircuitCode request for circuit {0} to {1} from IP {2}", |
||
1697 | uccp.CircuitCode.Code, m_scene.RegionInfo.RegionName, endPoint); |
||
1698 | |||
1699 | AuthenticateResponse sessionInfo; |
||
1700 | if (IsClientAuthorized(uccp, out sessionInfo)) |
||
1701 | { |
||
1702 | // Begin the process of adding the client to the simulator |
||
1703 | client |
||
1704 | = AddClient( |
||
1705 | uccp.CircuitCode.Code, |
||
1706 | uccp.CircuitCode.ID, |
||
1707 | uccp.CircuitCode.SessionID, |
||
1708 | endPoint, |
||
1709 | sessionInfo); |
||
1710 | |||
1711 | // Send ack straight away to let the viewer know that the connection is active. |
||
1712 | // The client will be null if it already exists (e.g. if on a region crossing the client sends a use |
||
1713 | // circuit code to the existing child agent. This is not particularly obvious. |
||
1714 | SendAckImmediate(endPoint, uccp.Header.Sequence); |
||
1715 | |||
1716 | // We only want to send initial data to new clients, not ones which are being converted from child to root. |
||
1717 | if (client != null) |
||
1718 | { |
||
1719 | AgentCircuitData aCircuit = m_scene.AuthenticateHandler.GetAgentCircuitData(uccp.CircuitCode.Code); |
||
1720 | bool tp = (aCircuit.teleportFlags > 0); |
||
1721 | // Let's delay this for TP agents, otherwise the viewer doesn't know where to get resources from |
||
1722 | if (!tp) |
||
1723 | client.SceneAgent.SendInitialDataToMe(); |
||
1724 | } |
||
1725 | } |
||
1726 | else |
||
1727 | { |
||
1728 | // Don't create clients for unauthorized requesters. |
||
1729 | m_log.WarnFormat( |
||
1730 | "[LLUDPSERVER]: Ignoring connection request for {0} to {1} with unknown circuit code {2} from IP {3}", |
||
1731 | uccp.CircuitCode.ID, m_scene.RegionInfo.RegionName, uccp.CircuitCode.Code, endPoint); |
||
1732 | } |
||
1733 | |||
1734 | // m_log.DebugFormat( |
||
1735 | // "[LLUDPSERVER]: Handling UseCircuitCode request from {0} took {1}ms", |
||
1736 | // buffer.RemoteEndPoint, (DateTime.Now - startTime).Milliseconds); |
||
1737 | |||
1738 | } |
||
1739 | catch (Exception e) |
||
1740 | { |
||
1741 | m_log.ErrorFormat( |
||
1742 | "[LLUDPSERVER]: UseCircuitCode handling from endpoint {0}, client {1} {2} failed. Exception {3}{4}", |
||
1743 | endPoint != null ? endPoint.ToString() : "n/a", |
||
1744 | client != null ? client.Name : "unknown", |
||
1745 | client != null ? client.AgentId.ToString() : "unknown", |
||
1746 | e.Message, |
||
1747 | e.StackTrace); |
||
1748 | } |
||
1749 | } |
||
1750 | |||
1751 | private void HandleCompleteMovementIntoRegion(object o) |
||
1752 | { |
||
1753 | IPEndPoint endPoint = null; |
||
1754 | IClientAPI client = null; |
||
1755 | |||
1756 | try |
||
1757 | { |
||
1758 | object[] array = (object[])o; |
||
1759 | endPoint = (IPEndPoint)array[0]; |
||
1760 | CompleteAgentMovementPacket packet = (CompleteAgentMovementPacket)array[1]; |
||
1761 | |||
1762 | m_log.DebugFormat( |
||
1763 | "[LLUDPSERVER]: Handling CompleteAgentMovement request from {0} in {1}", endPoint, m_scene.Name); |
||
1764 | |||
1765 | // Determine which agent this packet came from |
||
1766 | // We need to wait here because in when using the OpenSimulator V2 teleport protocol to travel to a destination |
||
1767 | // simulator with no existing child presence, the viewer (at least LL 3.3.4) will send UseCircuitCode |
||
1768 | // and then CompleteAgentMovement immediately without waiting for an ack. As we are now handling these |
||
1769 | // packets asynchronously, we need to account for this thread proceeding more quickly than the |
||
1770 | // UseCircuitCode thread. |
||
1771 | int count = 40; |
||
1772 | while (count-- > 0) |
||
1773 | { |
||
1774 | if (m_scene.TryGetClient(endPoint, out client)) |
||
1775 | { |
||
1776 | if (!client.IsActive) |
||
1777 | { |
||
1778 | // This check exists to catch a condition where the client has been closed by another thread |
||
1779 | // but has not yet been removed from the client manager (and possibly a new connection has |
||
1780 | // not yet been established). |
||
1781 | m_log.DebugFormat( |
||
1782 | "[LLUDPSERVER]: Received a CompleteAgentMovement from {0} for {1} in {2} but client is not active yet. Waiting.", |
||
1783 | endPoint, client.Name, m_scene.Name); |
||
1784 | } |
||
1785 | else if (client.SceneAgent == null) |
||
1786 | { |
||
1787 | // This check exists to catch a condition where the new client has been added to the client |
||
1788 | // manager but the SceneAgent has not yet been set in Scene.AddNewAgent(). If we are too |
||
1789 | // eager, then the new ScenePresence may not have registered a listener for this messsage |
||
1790 | // before we try to process it. |
||
1791 | // XXX: A better long term fix may be to add the SceneAgent before the client is added to |
||
1792 | // the client manager |
||
1793 | m_log.DebugFormat( |
||
1794 | "[LLUDPSERVER]: Received a CompleteAgentMovement from {0} for {1} in {2} but client SceneAgent not set yet. Waiting.", |
||
1795 | endPoint, client.Name, m_scene.Name); |
||
1796 | } |
||
1797 | else |
||
1798 | { |
||
1799 | break; |
||
1800 | } |
||
1801 | } |
||
1802 | else |
||
1803 | { |
||
1804 | m_log.DebugFormat( |
||
1805 | "[LLUDPSERVER]: Received a CompleteAgentMovement from {0} in {1} but no client exists yet. Waiting.", |
||
1806 | endPoint, m_scene.Name); |
||
1807 | } |
||
1808 | |||
1809 | Thread.Sleep(200); |
||
1810 | } |
||
1811 | |||
1812 | if (client == null) |
||
1813 | { |
||
1814 | m_log.DebugFormat( |
||
1815 | "[LLUDPSERVER]: No client found for CompleteAgentMovement from {0} in {1} after wait. Dropping.", |
||
1816 | endPoint, m_scene.Name); |
||
1817 | |||
1818 | return; |
||
1819 | } |
||
1820 | else if (!client.IsActive || client.SceneAgent == null) |
||
1821 | { |
||
1822 | // This check exists to catch a condition where the client has been closed by another thread |
||
1823 | // but has not yet been removed from the client manager. |
||
1824 | // The packet could be simply ignored but it is useful to know if this condition occurred for other debugging |
||
1825 | // purposes. |
||
1826 | m_log.DebugFormat( |
||
1827 | "[LLUDPSERVER]: Received a CompleteAgentMovement from {0} for {1} in {2} but client is not active after wait. Dropping.", |
||
1828 | endPoint, client.Name, m_scene.Name); |
||
1829 | |||
1830 | return; |
||
1831 | } |
||
1832 | |||
1833 | IncomingPacket incomingPacket1; |
||
1834 | |||
1835 | // Inbox insertion |
||
1836 | if (UsePools) |
||
1837 | { |
||
1838 | incomingPacket1 = m_incomingPacketPool.GetObject(); |
||
1839 | incomingPacket1.Client = (LLClientView)client; |
||
1840 | incomingPacket1.Packet = packet; |
||
1841 | } |
||
1842 | else |
||
1843 | { |
||
1844 | incomingPacket1 = new IncomingPacket((LLClientView)client, packet); |
||
1845 | } |
||
1846 | |||
1847 | packetInbox.Enqueue(incomingPacket1); |
||
1848 | } |
||
1849 | catch (Exception e) |
||
1850 | { |
||
1851 | m_log.ErrorFormat( |
||
1852 | "[LLUDPSERVER]: CompleteAgentMovement handling from endpoint {0}, client {1} {2} failed. Exception {3}{4}", |
||
1853 | endPoint != null ? endPoint.ToString() : "n/a", |
||
1854 | client != null ? client.Name : "unknown", |
||
1855 | client != null ? client.AgentId.ToString() : "unknown", |
||
1856 | e.Message, |
||
1857 | e.StackTrace); |
||
1858 | } |
||
1859 | } |
||
1860 | |||
1861 | /// <summary> |
||
1862 | /// Send an ack immediately to the given endpoint. |
||
1863 | /// </summary> |
||
1864 | /// <remarks> |
||
1865 | /// FIXME: Might be possible to use SendPacketData() like everything else, but this will require refactoring so |
||
1866 | /// that we can obtain the UDPClient easily at this point. |
||
1867 | /// </remarks> |
||
1868 | /// <param name="remoteEndpoint"></param> |
||
1869 | /// <param name="sequenceNumber"></param> |
||
1870 | private void SendAckImmediate(IPEndPoint remoteEndpoint, uint sequenceNumber) |
||
1871 | { |
||
1872 | PacketAckPacket ack = new PacketAckPacket(); |
||
1873 | ack.Header.Reliable = false; |
||
1874 | ack.Packets = new PacketAckPacket.PacketsBlock[1]; |
||
1875 | ack.Packets[0] = new PacketAckPacket.PacketsBlock(); |
||
1876 | ack.Packets[0].ID = sequenceNumber; |
||
1877 | |||
1878 | SendAckImmediate(remoteEndpoint, ack); |
||
1879 | } |
||
1880 | |||
1881 | public virtual void SendAckImmediate(IPEndPoint remoteEndpoint, PacketAckPacket ack) |
||
1882 | { |
||
1883 | byte[] packetData = ack.ToBytes(); |
||
1884 | int length = packetData.Length; |
||
1885 | |||
1886 | UDPPacketBuffer buffer = new UDPPacketBuffer(remoteEndpoint, length); |
||
1887 | buffer.DataLength = length; |
||
1888 | |||
1889 | Buffer.BlockCopy(packetData, 0, buffer.Data, 0, length); |
||
1890 | |||
1891 | AsyncBeginSend(buffer); |
||
1892 | } |
||
1893 | |||
1894 | private bool IsClientAuthorized(UseCircuitCodePacket useCircuitCode, out AuthenticateResponse sessionInfo) |
||
1895 | { |
||
1896 | UUID agentID = useCircuitCode.CircuitCode.ID; |
||
1897 | UUID sessionID = useCircuitCode.CircuitCode.SessionID; |
||
1898 | uint circuitCode = useCircuitCode.CircuitCode.Code; |
||
1899 | |||
1900 | sessionInfo = m_circuitManager.AuthenticateSession(sessionID, agentID, circuitCode); |
||
1901 | return sessionInfo.Authorised; |
||
1902 | } |
||
1903 | |||
1904 | /// <summary> |
||
1905 | /// Add a client. |
||
1906 | /// </summary> |
||
1907 | /// <param name="circuitCode"></param> |
||
1908 | /// <param name="agentID"></param> |
||
1909 | /// <param name="sessionID"></param> |
||
1910 | /// <param name="remoteEndPoint"></param> |
||
1911 | /// <param name="sessionInfo"></param> |
||
1912 | /// <returns>The client if it was added. Null if the client already existed.</returns> |
||
1913 | protected virtual IClientAPI AddClient( |
||
1914 | uint circuitCode, UUID agentID, UUID sessionID, IPEndPoint remoteEndPoint, AuthenticateResponse sessionInfo) |
||
1915 | { |
||
1916 | IClientAPI client = null; |
||
1917 | |||
1918 | // We currently synchronize this code across the whole scene to avoid issues such as |
||
1919 | // http://opensimulator.org/mantis/view.php?id=5365 However, once locking per agent circuit can be done |
||
1920 | // consistently, this lock could probably be removed. |
||
1921 | lock (this) |
||
1922 | { |
||
1923 | if (!m_scene.TryGetClient(agentID, out client)) |
||
1924 | { |
||
1925 | LLUDPClient udpClient = new LLUDPClient(this, ThrottleRates, m_throttle, circuitCode, agentID, remoteEndPoint, m_defaultRTO, m_maxRTO); |
||
1926 | |||
1927 | client = new LLClientView(m_scene, this, udpClient, sessionInfo, agentID, sessionID, circuitCode); |
||
1928 | client.OnLogout += LogoutHandler; |
||
1929 | client.DebugPacketLevel = DefaultClientPacketDebugLevel; |
||
1930 | |||
1931 | ((LLClientView)client).DisableFacelights = m_disableFacelights; |
||
1932 | |||
1933 | client.Start(); |
||
1934 | } |
||
1935 | } |
||
1936 | |||
1937 | return client; |
||
1938 | } |
||
1939 | |||
1940 | /// <summary> |
||
1941 | /// Deactivates the client if we don't receive any packets within a certain amount of time (default 60 seconds). |
||
1942 | /// </summary> |
||
1943 | /// <remarks> |
||
1944 | /// If a connection is active then we will always receive packets even if nothing else is happening, due to |
||
1945 | /// regular client pings. |
||
1946 | /// </remarks> |
||
1947 | /// <param name='client'></param> |
||
1948 | /// <param name='timeoutTicks'></param> |
||
1949 | private void DeactivateClientDueToTimeout(LLClientView client, int timeoutTicks) |
||
1950 | { |
||
1951 | lock (client.CloseSyncLock) |
||
1952 | { |
||
1953 | ClientLogoutsDueToNoReceives++; |
||
1954 | |||
1955 | m_log.WarnFormat( |
||
1956 | "[LLUDPSERVER]: No packets received from {0} agent of {1} for {2}ms in {3}. Disconnecting.", |
||
1957 | client.SceneAgent.IsChildAgent ? "child" : "root", client.Name, timeoutTicks, m_scene.Name); |
||
1958 | |||
1959 | if (!client.SceneAgent.IsChildAgent) |
||
1960 | client.Kick("Simulator logged you out due to connection timeout."); |
||
1961 | } |
||
1962 | |||
1963 | m_scene.CloseAgent(client.AgentId, true); |
||
1964 | } |
||
1965 | |||
1966 | private void IncomingPacketHandler() |
||
1967 | { |
||
1968 | // Set this culture for the thread that incoming packets are received |
||
1969 | // on to en-US to avoid number parsing issues |
||
1970 | Culture.SetCurrentCulture(); |
||
1971 | |||
1972 | while (IsRunningInbound) |
||
1973 | { |
||
1974 | try |
||
1975 | { |
||
1976 | IncomingPacket incomingPacket = null; |
||
1977 | |||
1978 | /* |
||
1979 | // HACK: This is a test to try and rate limit packet handling on Mono. |
||
1980 | // If it works, a more elegant solution can be devised |
||
1981 | if (Util.FireAndForgetCount() < 2) |
||
1982 | { |
||
1983 | //m_log.Debug("[LLUDPSERVER]: Incoming packet handler is sleeping"); |
||
1984 | Thread.Sleep(30); |
||
1985 | } |
||
1986 | */ |
||
1987 | |||
1988 | if (packetInbox.Dequeue(100, ref incomingPacket)) |
||
1989 | { |
||
1990 | ProcessInPacket(incomingPacket);//, incomingPacket); Util.FireAndForget(ProcessInPacket, incomingPacket); |
||
1991 | |||
1992 | if (UsePools) |
||
1993 | m_incomingPacketPool.ReturnObject(incomingPacket); |
||
1994 | } |
||
1995 | } |
||
1996 | catch (Exception ex) |
||
1997 | { |
||
1998 | m_log.Error("[LLUDPSERVER]: Error in the incoming packet handler loop: " + ex.Message, ex); |
||
1999 | } |
||
2000 | |||
2001 | Watchdog.UpdateThread(); |
||
2002 | } |
||
2003 | |||
2004 | if (packetInbox.Count > 0) |
||
2005 | m_log.Warn("[LLUDPSERVER]: IncomingPacketHandler is shutting down, dropping " + packetInbox.Count + " packets"); |
||
2006 | packetInbox.Clear(); |
||
2007 | |||
2008 | Watchdog.RemoveThread(); |
||
2009 | } |
||
2010 | |||
2011 | private void OutgoingPacketHandler() |
||
2012 | { |
||
2013 | // Set this culture for the thread that outgoing packets are sent |
||
2014 | // on to en-US to avoid number parsing issues |
||
2015 | Culture.SetCurrentCulture(); |
||
2016 | |||
2017 | // Typecast the function to an Action<IClientAPI> once here to avoid allocating a new |
||
2018 | // Action generic every round |
||
2019 | Action<IClientAPI> clientPacketHandler = ClientOutgoingPacketHandler; |
||
2020 | |||
2021 | while (base.IsRunningOutbound) |
||
2022 | { |
||
2023 | try |
||
2024 | { |
||
2025 | m_packetSent = false; |
||
2026 | |||
2027 | #region Update Timers |
||
2028 | |||
2029 | m_resendUnacked = false; |
||
2030 | m_sendAcks = false; |
||
2031 | m_sendPing = false; |
||
2032 | |||
2033 | // Update elapsed time |
||
2034 | int thisTick = Environment.TickCount & Int32.MaxValue; |
||
2035 | if (m_tickLastOutgoingPacketHandler > thisTick) |
||
2036 | m_elapsedMSOutgoingPacketHandler += ((Int32.MaxValue - m_tickLastOutgoingPacketHandler) + thisTick); |
||
2037 | else |
||
2038 | m_elapsedMSOutgoingPacketHandler += (thisTick - m_tickLastOutgoingPacketHandler); |
||
2039 | |||
2040 | m_tickLastOutgoingPacketHandler = thisTick; |
||
2041 | |||
2042 | // Check for pending outgoing resends every 100ms |
||
2043 | if (m_elapsedMSOutgoingPacketHandler >= 100) |
||
2044 | { |
||
2045 | m_resendUnacked = true; |
||
2046 | m_elapsedMSOutgoingPacketHandler = 0; |
||
2047 | m_elapsed100MSOutgoingPacketHandler += 1; |
||
2048 | } |
||
2049 | |||
2050 | // Check for pending outgoing ACKs every 500ms |
||
2051 | if (m_elapsed100MSOutgoingPacketHandler >= 5) |
||
2052 | { |
||
2053 | m_sendAcks = true; |
||
2054 | m_elapsed100MSOutgoingPacketHandler = 0; |
||
2055 | m_elapsed500MSOutgoingPacketHandler += 1; |
||
2056 | } |
||
2057 | |||
2058 | // Send pings to clients every 5000ms |
||
2059 | if (m_elapsed500MSOutgoingPacketHandler >= 10) |
||
2060 | { |
||
2061 | m_sendPing = true; |
||
2062 | m_elapsed500MSOutgoingPacketHandler = 0; |
||
2063 | } |
||
2064 | |||
2065 | #endregion Update Timers |
||
2066 | |||
2067 | // Use this for emergency monitoring -- bug hunting |
||
2068 | //if (m_scene.EmergencyMonitoring) |
||
2069 | // clientPacketHandler = MonitoredClientOutgoingPacketHandler; |
||
2070 | //else |
||
2071 | // clientPacketHandler = ClientOutgoingPacketHandler; |
||
2072 | |||
2073 | // Handle outgoing packets, resends, acknowledgements, and pings for each |
||
2074 | // client. m_packetSent will be set to true if a packet is sent |
||
2075 | m_scene.ForEachClient(clientPacketHandler); |
||
2076 | |||
2077 | m_currentOutgoingClient = null; |
||
2078 | |||
2079 | // If nothing was sent, sleep for the minimum amount of time before a |
||
2080 | // token bucket could get more tokens |
||
2081 | //if (!m_packetSent) |
||
2082 | // Thread.Sleep((int)TickCountResolution); |
||
2083 | // |
||
2084 | // Instead, now wait for data present to be explicitly signalled. Evidence so far is that with |
||
2085 | // modern mono it reduces CPU base load since there is no more continuous polling. |
||
2086 | if (!m_packetSent) |
||
2087 | m_dataPresentEvent.WaitOne(100); |
||
2088 | |||
2089 | Watchdog.UpdateThread(); |
||
2090 | } |
||
2091 | catch (Exception ex) |
||
2092 | { |
||
2093 | m_log.Error("[LLUDPSERVER]: OutgoingPacketHandler loop threw an exception: " + ex.Message, ex); |
||
2094 | } |
||
2095 | } |
||
2096 | |||
2097 | Watchdog.RemoveThread(); |
||
2098 | } |
||
2099 | |||
2100 | protected void ClientOutgoingPacketHandler(IClientAPI client) |
||
2101 | { |
||
2102 | m_currentOutgoingClient = client; |
||
2103 | |||
2104 | try |
||
2105 | { |
||
2106 | if (client is LLClientView) |
||
2107 | { |
||
2108 | LLClientView llClient = (LLClientView)client; |
||
2109 | LLUDPClient udpClient = llClient.UDPClient; |
||
2110 | |||
2111 | if (udpClient.IsConnected) |
||
2112 | { |
||
2113 | if (m_resendUnacked) |
||
2114 | HandleUnacked(llClient); |
||
2115 | |||
2116 | if (m_sendAcks) |
||
2117 | SendAcks(udpClient); |
||
2118 | |||
2119 | if (m_sendPing) |
||
2120 | SendPing(udpClient); |
||
2121 | |||
2122 | // Dequeue any outgoing packets that are within the throttle limits |
||
2123 | if (udpClient.DequeueOutgoing()) |
||
2124 | m_packetSent = true; |
||
2125 | } |
||
2126 | } |
||
2127 | } |
||
2128 | catch (Exception ex) |
||
2129 | { |
||
2130 | m_log.Error( |
||
2131 | string.Format("[LLUDPSERVER]: OutgoingPacketHandler iteration for {0} threw ", client.Name), ex); |
||
2132 | } |
||
2133 | } |
||
2134 | |||
2135 | #region Emergency Monitoring |
||
2136 | // Alternative packet handler fuull of instrumentation |
||
2137 | // Handy for hunting bugs |
||
2138 | private Stopwatch watch1 = new Stopwatch(); |
||
2139 | private Stopwatch watch2 = new Stopwatch(); |
||
2140 | |||
2141 | private float avgProcessingTicks = 0; |
||
2142 | private float avgResendUnackedTicks = 0; |
||
2143 | private float avgSendAcksTicks = 0; |
||
2144 | private float avgSendPingTicks = 0; |
||
2145 | private float avgDequeueTicks = 0; |
||
2146 | private long nticks = 0; |
||
2147 | private long nticksUnack = 0; |
||
2148 | private long nticksAck = 0; |
||
2149 | private long nticksPing = 0; |
||
2150 | private int npacksSent = 0; |
||
2151 | private int npackNotSent = 0; |
||
2152 | |||
2153 | /// <summary> |
||
2154 | /// Number of inbound packets processed since startup. |
||
2155 | /// </summary> |
||
2156 | public long IncomingPacketsProcessed { get; private set; } |
||
2157 | |||
2158 | private void MonitoredClientOutgoingPacketHandler(IClientAPI client) |
||
2159 | { |
||
2160 | nticks++; |
||
2161 | watch1.Start(); |
||
2162 | m_currentOutgoingClient = client; |
||
2163 | |||
2164 | try |
||
2165 | { |
||
2166 | if (client is LLClientView) |
||
2167 | { |
||
2168 | LLClientView llClient = (LLClientView)client; |
||
2169 | LLUDPClient udpClient = llClient.UDPClient; |
||
2170 | |||
2171 | if (udpClient.IsConnected) |
||
2172 | { |
||
2173 | if (m_resendUnacked) |
||
2174 | { |
||
2175 | nticksUnack++; |
||
2176 | watch2.Start(); |
||
2177 | |||
2178 | HandleUnacked(llClient); |
||
2179 | |||
2180 | watch2.Stop(); |
||
2181 | avgResendUnackedTicks = (nticksUnack - 1)/(float)nticksUnack * avgResendUnackedTicks + (watch2.ElapsedTicks / (float)nticksUnack); |
||
2182 | watch2.Reset(); |
||
2183 | } |
||
2184 | |||
2185 | if (m_sendAcks) |
||
2186 | { |
||
2187 | nticksAck++; |
||
2188 | watch2.Start(); |
||
2189 | |||
2190 | SendAcks(udpClient); |
||
2191 | |||
2192 | watch2.Stop(); |
||
2193 | avgSendAcksTicks = (nticksAck - 1) / (float)nticksAck * avgSendAcksTicks + (watch2.ElapsedTicks / (float)nticksAck); |
||
2194 | watch2.Reset(); |
||
2195 | } |
||
2196 | |||
2197 | if (m_sendPing) |
||
2198 | { |
||
2199 | nticksPing++; |
||
2200 | watch2.Start(); |
||
2201 | |||
2202 | SendPing(udpClient); |
||
2203 | |||
2204 | watch2.Stop(); |
||
2205 | avgSendPingTicks = (nticksPing - 1) / (float)nticksPing * avgSendPingTicks + (watch2.ElapsedTicks / (float)nticksPing); |
||
2206 | watch2.Reset(); |
||
2207 | } |
||
2208 | |||
2209 | watch2.Start(); |
||
2210 | // Dequeue any outgoing packets that are within the throttle limits |
||
2211 | if (udpClient.DequeueOutgoing()) |
||
2212 | { |
||
2213 | m_packetSent = true; |
||
2214 | npacksSent++; |
||
2215 | } |
||
2216 | else |
||
2217 | { |
||
2218 | npackNotSent++; |
||
2219 | } |
||
2220 | |||
2221 | watch2.Stop(); |
||
2222 | avgDequeueTicks = (nticks - 1) / (float)nticks * avgDequeueTicks + (watch2.ElapsedTicks / (float)nticks); |
||
2223 | watch2.Reset(); |
||
2224 | |||
2225 | } |
||
2226 | else |
||
2227 | { |
||
2228 | m_log.WarnFormat("[LLUDPSERVER]: Client is not connected"); |
||
2229 | } |
||
2230 | } |
||
2231 | } |
||
2232 | catch (Exception ex) |
||
2233 | { |
||
2234 | m_log.Error("[LLUDPSERVER]: OutgoingPacketHandler iteration for " + client.Name + |
||
2235 | " threw an exception: " + ex.Message, ex); |
||
2236 | } |
||
2237 | watch1.Stop(); |
||
2238 | avgProcessingTicks = (nticks - 1) / (float)nticks * avgProcessingTicks + (watch1.ElapsedTicks / (float)nticks); |
||
2239 | watch1.Reset(); |
||
2240 | |||
2241 | // reuse this -- it's every ~100ms |
||
2242 | if (m_scene.EmergencyMonitoring && nticks % 100 == 0) |
||
2243 | { |
||
2244 | m_log.InfoFormat("[LLUDPSERVER]: avg processing ticks: {0} avg unacked: {1} avg acks: {2} avg ping: {3} avg dequeue: {4} (TickCountRes: {5} sent: {6} notsent: {7})", |
||
2245 | avgProcessingTicks, avgResendUnackedTicks, avgSendAcksTicks, avgSendPingTicks, avgDequeueTicks, TickCountResolution, npacksSent, npackNotSent); |
||
2246 | npackNotSent = npacksSent = 0; |
||
2247 | } |
||
2248 | |||
2249 | } |
||
2250 | |||
2251 | #endregion |
||
2252 | |||
2253 | private void ProcessInPacket(IncomingPacket incomingPacket) |
||
2254 | { |
||
2255 | Packet packet = incomingPacket.Packet; |
||
2256 | LLClientView client = incomingPacket.Client; |
||
2257 | |||
2258 | if (client.IsActive) |
||
2259 | { |
||
2260 | m_currentIncomingClient = client; |
||
2261 | |||
2262 | try |
||
2263 | { |
||
2264 | // Process this packet |
||
2265 | client.ProcessInPacket(packet); |
||
2266 | } |
||
2267 | catch (ThreadAbortException) |
||
2268 | { |
||
2269 | // If something is trying to abort the packet processing thread, take that as a hint that it's time to shut down |
||
2270 | m_log.Info("[LLUDPSERVER]: Caught a thread abort, shutting down the LLUDP server"); |
||
2271 | Stop(); |
||
2272 | } |
||
2273 | catch (Exception e) |
||
2274 | { |
||
2275 | // Don't let a failure in an individual client thread crash the whole sim. |
||
2276 | m_log.Error( |
||
2277 | string.Format( |
||
2278 | "[LLUDPSERVER]: Client packet handler for {0} for packet {1} threw ", |
||
2279 | client.Name, packet.Type), |
||
2280 | e); |
||
2281 | } |
||
2282 | finally |
||
2283 | { |
||
2284 | m_currentIncomingClient = null; |
||
2285 | } |
||
2286 | } |
||
2287 | else |
||
2288 | { |
||
2289 | m_log.DebugFormat( |
||
2290 | "[LLUDPSERVER]: Dropped incoming {0} for dead client {1} in {2}", |
||
2291 | packet.Type, client.Name, m_scene.RegionInfo.RegionName); |
||
2292 | } |
||
2293 | |||
2294 | IncomingPacketsProcessed++; |
||
2295 | } |
||
2296 | |||
2297 | protected void LogoutHandler(IClientAPI client) |
||
2298 | { |
||
2299 | client.SendLogoutPacket(); |
||
2300 | |||
2301 | if (!client.IsLoggingOut) |
||
2302 | { |
||
2303 | client.IsLoggingOut = true; |
||
2304 | m_scene.CloseAgent(client.AgentId, false); |
||
2305 | } |
||
2306 | } |
||
2307 | } |
||
2308 | } |