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