1
0

LLUDPServer.cs 88 KB

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