aboutsummaryrefslogtreecommitdiffstatshomepage
path: root/OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs
diff options
context:
space:
mode:
authorUbitUmarov2015-09-01 11:43:07 +0100
committerUbitUmarov2015-09-01 11:43:07 +0100
commitfb78b182520fc9bb0f971afd0322029c70278ea6 (patch)
treeb4e30d383938fdeef8c92d1d1c2f44bb61d329bd /OpenSim/Region/ClientStack/Linden/UDP/LLUDPServer.cs
parentlixo (diff)
parentMantis #7713: fixed bug introduced by 1st MOSES patch. (diff)
downloadopensim-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.cs2216
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
28using System;
29using System.Collections.Generic;
30using System.Diagnostics;
31using System.IO;
32using System.Net;
33using System.Net.Sockets;
34using System.Reflection;
35using System.Threading;
36using log4net;
37using Nini.Config;
38using OpenMetaverse.Packets;
39using OpenSim.Framework;
40using OpenSim.Framework.Console;
41using OpenSim.Framework.Monitoring;
42using OpenSim.Region.Framework.Scenes;
43using OpenMetaverse;
44
45using TokenBucket = OpenSim.Region.ClientStack.LindenUDP.TokenBucket;
46
47namespace 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}