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