diff --git a/X2WOTCCommunityHighlander/Config/XComCHProfiling.ini b/X2WOTCCommunityHighlander/Config/XComCHProfiling.ini new file mode 100644 index 000000000..302572c5a --- /dev/null +++ b/X2WOTCCommunityHighlander/Config/XComCHProfiling.ini @@ -0,0 +1,2 @@ +[XComGame.CHProfiler] +;+ExtendedProfileAbilityNames="SwordSlice" \ No newline at end of file diff --git a/X2WOTCCommunityHighlander/Src/X2WOTCCommunityHighlander/Classes/X2DownloadableContentInfo_X2WOTCCommunityHighlander.uc b/X2WOTCCommunityHighlander/Src/X2WOTCCommunityHighlander/Classes/X2DownloadableContentInfo_X2WOTCCommunityHighlander.uc index 3c6da1aba..fc695e15d 100644 --- a/X2WOTCCommunityHighlander/Src/X2WOTCCommunityHighlander/Classes/X2DownloadableContentInfo_X2WOTCCommunityHighlander.uc +++ b/X2WOTCCommunityHighlander/Src/X2WOTCCommunityHighlander/Classes/X2DownloadableContentInfo_X2WOTCCommunityHighlander.uc @@ -91,4 +91,35 @@ exec function CHLSimulateReacquireHQWeapons() exec function CHLDumpRunOrderInternals() { CHOnlineEventMgr(`ONLINEEVENTMGR).DumpInternals(); -} \ No newline at end of file +} + +exec function CHLBeginAbilityProfiling() +{ + if (class'CHProfiler' != none) + { + class'CHProfiler'.static.ClearAbilityProfile(); + class'CHProfiler'.static.SetAbilityProfiling(true); + } + else + { + `warn("XComGame replacement with CHProfiler missing"); + } +} + +exec function CHLEndAbilityProfiling() +{ + if (class'CHProfiler' != none) + { + class'CHProfiler'.static.DumpAbilityProfile(); + class'CHProfiler'.static.SetAbilityProfiling(false); + } + else + { + `warn("XComGame replacement with CHProfiler missing"); + } +} + +exec function CHLEcho(string Msg) +{ + `log(Msg, , 'X2WOTCCommunityHighlander'); +} diff --git a/X2WOTCCommunityHighlander/Src/XComGame/Classes/CHHelpers.uc b/X2WOTCCommunityHighlander/Src/XComGame/Classes/CHHelpers.uc index 9d1188bf4..33158901a 100644 --- a/X2WOTCCommunityHighlander/Src/XComGame/Classes/CHHelpers.uc +++ b/X2WOTCCommunityHighlander/Src/XComGame/Classes/CHHelpers.uc @@ -833,7 +833,8 @@ simulated function bool ShouldDisplayMultiSlotItemInTactical(XComGameState_Unit static function CHHelpers GetCDO() { - return CHHelpers(class'XComEngine'.static.GetClassDefaultObjectByName(default.Class.Name)); + // This is hot code, so use an optimized function here + return CHHelpers(FindObject("XComGame.Default__CHHelpers", class'CHHelpers')); } // End Issue #885 diff --git a/X2WOTCCommunityHighlander/Src/XComGame/Classes/CHProfiler.uc b/X2WOTCCommunityHighlander/Src/XComGame/Classes/CHProfiler.uc new file mode 100644 index 000000000..557f170ab --- /dev/null +++ b/X2WOTCCommunityHighlander/Src/XComGame/Classes/CHProfiler.uc @@ -0,0 +1,158 @@ +/// HL-Docs: feature:CHProfiler; issue:1044; tags: +/// While you can profile the game's and mods' UnrealScript code with the +/// [Gameplay Profiler](https://www.reddit.com/r/xcom2mods/wiki/index/profiling), +/// the profiles lack semantic information. The CHProfiler facilitates recording +/// and dumping **additional** performance information, usually requiring user +/// configuration to do so (console commands, config). +/// +/// ## Ability Profiling +/// +/// Sometimes, the gameplay profiler may yield performance issues in ability target +/// collection and condition checking. It's often hard to figure out which ability +/// in particular is at fault, since all native conditions are usually invisible +/// in the gameplay profiler and many abilities share conditions. +/// +/// The ability profiler records the time it takes for an ability to collect +/// targets and check conditions. The currently used timer has a **millisecond** +/// resolution due to a missing higher-resolution timer, so it may only be +/// useful to identify egregious issues. +/// +/// The console command `CHLBeginAbilityProfiling` begins event collection, +/// while `CHLEndAbilityProfiling` ends it and prints the collected data +/// to the log and console. +/// The resulting string conforms to the following grammar: +/// +/// ```abnf +/// ::= | ( ";" ) | E +/// ::= ":" +/// ::= | ( "," ) +/// ::= [0-9]+ +/// ::= ([A-Z] | [a-z] | [0-9] | "_")+ +/// ``` +/// +/// i.e. a semicolon-separated list of AbilityName, colon, comma-separated numbers sequences. +/// Every time the game calls `UpdateAbilityAvailability`, it measures the time it took the call. +/// Every number in the output corresponds to one call. +/// +/// You can then analyze the results with an external tool, for example by [visualizing them +/// using matplotlib](https://gist.github.com/robojumper/1ee2de9bd38377b9c57e6ff684075780): +/// +/// ![matplotlib ability profile](https://i.imgur.com/VHWJAqs.png) +/// +/// **The exact output format and the clock resolution are subject to change.** +class CHProfiler extends Object config(CHProfiling); + +struct AbilityEvents +{ + var name AbilityName; + var array Events; +}; + +var private array AbilityTimings; + +var privatewrite bool bAbilityProfileEnabled; + +var config privatewrite array ExtendedProfileAbilityNames; +var privatewrite bool bExtendedProfilingUnconditional; + +private static function CHProfiler GetCDO() +{ + // This is hot code, so use an optimized function here + return CHProfiler(FindObject("XComGame.Default__CHProfiler", class'CHProfiler')); +} + +static function AddAbilityTiming(name AbilityName, int Millis) +{ + local CHProfiler Prof; + + Prof = static.GetCDO(); + AddAbilityEvent(Prof.AbilityTimings, AbilityName, Millis); +} + +static private function AddAbilityEvent(out array arr, name AbilityName, int Num) +{ + local int idx; + + idx = arr.Find('AbilityName', AbilityName); + if (idx == INDEX_NONE) + { + idx = arr.Length; + arr.Add(1); + arr[idx].AbilityName = AbilityName; + } + arr[idx].Events.AddItem(Num); +} + +static function bool ShouldExtendedProfileActivity(name AbilityName) +{ + return default.bExtendedProfilingUnconditional || default.ExtendedProfileAbilityNames.Find(AbilityName) != INDEX_NONE; +} + +static function EnableExtendedAbilityProfiling(name AbilityName) +{ + local CHProfiler Prof; + + Prof = static.GetCDO(); + if (string(AbilityName) ~= "all") + { + Prof.bExtendedProfilingUnconditional = true; + } + else + { + Prof.ExtendedProfileAbilityNames.AddItem(AbilityName); + } +} + +static function ClearAbilityProfile() +{ + local CHProfiler Prof; + Prof = static.GetCDO(); + Prof.AbilityTimings.Length = 0; +} + +static function SetAbilityProfiling(bool bEnabled) +{ + local CHProfiler Prof; + Prof = static.GetCDO(); + Prof.bAbilityProfileEnabled = bEnabled; +} + +static function DumpAbilityProfile() +{ + local CHProfiler Prof; + + Prof = static.GetCDO(); + + class'X2TacticalGameRuleset'.static.ReleaseScriptLog("CHProfiler: Ability timings"); + class'X2TacticalGameRuleset'.static.ReleaseScriptLog(FormatEvents(Prof.AbilityTimings)); +} + +static private function string FormatEvents(const out array arr) +{ + local string DataString; + local int idx, eidx; + + DataString = ""; + for (idx = 0; idx < arr.Length; idx++) + { + DataString $= arr[idx].AbilityName; + DataString $= ":"; + + for (eidx = 0; eidx < arr[idx].Events.Length; eidx++) + { + DataString $= arr[idx].Events[eidx]; + + if (eidx != arr[idx].Events.Length - 1) + { + DataString $= ","; + } + } + + if (idx != arr.Length - 1) + { + DataString $= ";"; + } + } + + return DataString; +} \ No newline at end of file diff --git a/X2WOTCCommunityHighlander/Src/XComGame/Classes/UITacticalHUD_SoldierInfo.uc b/X2WOTCCommunityHighlander/Src/XComGame/Classes/UITacticalHUD_SoldierInfo.uc index 3bec1eaf0..37bf51cca 100644 --- a/X2WOTCCommunityHighlander/Src/XComGame/Classes/UITacticalHUD_SoldierInfo.uc +++ b/X2WOTCCommunityHighlander/Src/XComGame/Classes/UITacticalHUD_SoldierInfo.uc @@ -7,7 +7,7 @@ // Copyright (c) 2016 Firaxis Games, Inc. All rights reserved. //--------------------------------------------------------------------------------------- -class UITacticalHUD_SoldierInfo extends UIPanel implements(X2VisualizationMgrObserverInterface); // Issue #257 -- correct update calls +class UITacticalHUD_SoldierInfo extends UIPanel; var string HackingToolTipTargetPath; var localized string FocusLevelLabel; @@ -38,8 +38,6 @@ simulated function OnInit() WorldInfo.MyWatchVariableMgr.RegisterWatchVariable( UITacticalHUD(screen), 'm_isMenuRaised', self, UpdateStats); WorldInfo.MyWatchVariableMgr.RegisterWatchVariable( XComPresentationLayer(Movie.Pres), 'm_kInventoryTactical', self, UpdateStats); - `XCOMVISUALIZATIONMGR.RegisterObserver(self); // Issue #257 - HackingToolTipTargetPath = MCPath$".HackingInfoGroup.HackingInfo"; FocusToolTipTargetPath = MCPath$".FocusLevel"; @@ -112,7 +110,7 @@ simulated function UpdateStats() else { //UITacticalHUD(Screen).m_kInventory.m_kBackpack.Update( kActiveUnit ); - if( LastVisibleActiveUnitID != kActiveUnit.ObjectID ) + if( /*LastVisibleActiveUnitID != kActiveUnit.ObjectID*/ true ) // Issue #257, this is also called when refreshing after action { SetStats(kActiveUnit); SetHackingInfo(kActiveUnit); @@ -420,17 +418,6 @@ public function AS_SetBondInfo(int BondLevel, bool bOnMission) MC.EndOp(); } -// Start Issue #257 -- Better update calls -event OnVisualizationBlockComplete(XComGameState AssociatedGameState) -{ - LastVisibleActiveUnitID = 0; - UpdateStats(); -} - -event OnActiveUnitChanged(XComGameState_Unit NewActiveUnit); -event OnVisualizationIdle(); -// End Issue #257 - defaultproperties { MCName = "soldierInfo"; diff --git a/X2WOTCCommunityHighlander/Src/XComGame/Classes/X2TacticalGameRuleset.uc b/X2WOTCCommunityHighlander/Src/XComGame/Classes/X2TacticalGameRuleset.uc index 989f1f79a..30da4ba58 100644 --- a/X2WOTCCommunityHighlander/Src/XComGame/Classes/X2TacticalGameRuleset.uc +++ b/X2WOTCCommunityHighlander/Src/XComGame/Classes/X2TacticalGameRuleset.uc @@ -122,10 +122,34 @@ function UpdateUnitAbility( XComGameState_Unit kUnit, name strAbilityName ) if (AbilityRef.ObjectID > 0) { kAbility = XComGameState_Ability(CachedHistory.GetGameStateForObjectID(AbilityRef.ObjectID)); - kAbility.UpdateAbilityAvailability(kAction); + ProfileUpdateAbilityAvailability(kAbility, kAction); } } +// Only millisecond resolution, so only useful for identifying egregious cases +/// HL-Docs: ref:CHProfiler +simulated function ProfileUpdateAbilityAvailability(XComGameState_Ability kAbility, out AvailableAction kAction) +{ + local name AbilityTemplateName; + local int Year1, Month1, DayOfWeek1, Day1, Hour1, Min1, Sec1, MSec1; + local int Year2, Month2, DayOfWeek2, Day2, Hour2, Min2, Sec2, MSec2; + + AbilityTemplateName = kAbility.GetMyTemplateName(); + GetSystemTime(Year1, Month1, DayOfWeek1, Day1, Hour1, Min1, Sec1, MSec1); + kAbility.UpdateAbilityAvailability(kAction); + GetSystemTime(Year2, Month2, DayOfWeek2, Day2, Hour2, Min2, Sec2, MSec2); + + // Handling all this properly would require accounting for leap years, different numbers of days in a month, etc. + // so we just say that this function cannot run for longer than 1 hour. + if (Hour1 != Hour2) + { + Min2 += 60; + } + Sec2 += (Min2 - Min1) * 60; + MSec2 += (Sec2 - Sec1) * 1000; + class'CHProfiler'.static.AddAbilityTiming(AbilityTemplateName, MSec2 - MSec1); +} + function UpdateAndAddUnitAbilities( out GameRulesCache_Unit kUnitCache, XComGameState_Unit kUnit, out array CheckAvailableAbility, out array UpdateAvailableIcon) { local XComGameState_Ability kAbility; @@ -141,7 +165,14 @@ function UpdateAndAddUnitAbilities( out GameRulesCache_Unit kUnitCache, XComGame kAbility = XComGameState_Ability(CachedHistory.GetGameStateForObjectID(kUnit.Abilities[i].ObjectID)); if (kAbility != none) //kAbility can be none if abilities are being added removed during dev { - kAbility.UpdateAbilityAvailability(kAction); + if (class'CHProfiler'.default.bAbilityProfileEnabled) + { + ProfileUpdateAbilityAvailability(kAbility, kAction); + } + else + { + kAbility.UpdateAbilityAvailability(kAction); + } kUnitCache.AvailableActions.AddItem(kAction); kUnitCache.bAnyActionsAvailable = kUnitCache.bAnyActionsAvailable || kAction.AvailableCode == 'AA_Success'; if (kAction.eAbilityIconBehaviorHUD == eAbilityIconBehavior_HideIfOtherAvailable) @@ -618,6 +649,7 @@ simulated function bool GetGameRulesCache_Unit(StateObjectReference UnitStateRef } } + ReleaseScriptLog("CHL GetGameRulesCache_Unit race debugging: START " $ kUnit.ObjectID $ ", IsDoingLatentSubmission: " $ IsDoingLatentSubmission()); // build the cache data OutCacheData.UnitObjectRef = kUnit.GetReference(); OutCacheData.LastUpdateHistoryIndex = CurrentHistoryIndex; @@ -649,6 +681,7 @@ simulated function bool GetGameRulesCache_Unit(StateObjectReference UnitStateRef { UnitsCache[ExistingCacheIndex] = OutCacheData; } + ReleaseScriptLog("CHL GetGameRulesCache_Unit race debugging: END " $ kUnit.ObjectID $ ", IsDoingLatentSubmission: " $ IsDoingLatentSubmission()); return true; } diff --git a/X2WOTCCommunityHighlander/Src/XComGame/Classes/XComGameState_Ability.uc b/X2WOTCCommunityHighlander/Src/XComGame/Classes/XComGameState_Ability.uc index 922a55efa..ee694b149 100644 --- a/X2WOTCCommunityHighlander/Src/XComGame/Classes/XComGameState_Ability.uc +++ b/X2WOTCCommunityHighlander/Src/XComGame/Classes/XComGameState_Ability.uc @@ -83,7 +83,16 @@ simulated function UpdateAbilityAvailability(out AvailableAction Action) if (Action.AvailableCode == 'AA_Success') { Action.bFreeAim = IsAbilityFreeAiming(); - Action.AvailableCode = GatherAbilityTargets(Action.AvailableTargets); + // Note: Cheap short-circuiting + if (class'CHProfiler'.default.bAbilityProfileEnabled + && class'CHProfiler'.static.ShouldExtendedProfileActivity(GetMyTemplateName())) + { + Action.AvailableCode = CHGatherAbilityTargetsScript(Action.AvailableTargets); + } + else + { + Action.AvailableCode = GatherAbilityTargets(Action.AvailableTargets); + } Action.bInputTriggered = IsAbilityInputTriggered(); } } @@ -384,6 +393,105 @@ simulated function int SortAvailableTargets(AvailableTarget TargetA, AvailableTa } */ +simulated function name CHGatherAbilityTargetsScript(out array Targets, optional XComGameState_Unit OverrideOwnerState) +{ + local int i, j; + local XComGameState_Unit kOwner; + local name AvailableCode; + local XComGameStateHistory History; + + GetMyTemplate(); + History = `XCOMHISTORY; + kOwner = XComGameState_Unit(History.GetGameStateForObjectID(OwnerStateObject.ObjectID)); + if (OverrideOwnerState != none) + kOwner = OverrideOwnerState; + + if (m_Template != None) + { + AvailableCode = m_Template.AbilityTargetStyle.GetPrimaryTargetOptions(self, Targets); + if (AvailableCode != 'AA_Success') + return AvailableCode; + + for (i = Targets.Length - 1; i >= 0; --i) + { + AvailableCode = m_Template.CheckTargetConditions(self, kOwner, History.GetGameStateForObjectID(Targets[i].PrimaryTarget.ObjectID)); + if (AvailableCode != 'AA_Success') + { + Targets.Remove(i, 1); + } + } + + if (m_Template.AbilityMultiTargetStyle != none) + { + m_Template.AbilityMultiTargetStyle.GetMultiTargetOptions(self, Targets); + for (i = Targets.Length - 1; i >= 0; --i) + { + for (j = Targets[i].AdditionalTargets.Length - 1; j >= 0; --j) + { + AvailableCode = m_Template.CheckMultiTargetConditions(self, kOwner, History.GetGameStateForObjectID(Targets[i].AdditionalTargets[j].ObjectID)); + if (AvailableCode != 'AA_Success' || (Targets[i].AdditionalTargets[j].ObjectID == Targets[i].PrimaryTarget.ObjectID) && !m_Template.AbilityMultiTargetStyle.bAllowSameTarget) + { + Targets[i].AdditionalTargets.Remove(j, 1); + } + } + + AvailableCode = m_Template.AbilityMultiTargetStyle.CheckFilteredMultiTargets(self, Targets[i]); + if (AvailableCode != 'AA_Success') + Targets.Remove(i, 1); + } + } + + //The Multi-target style may have deemed some primary targets invalid in calls to CheckFilteredMultiTargets - so CheckFilteredPrimaryTargets must come afterwards. + AvailableCode = m_Template.AbilityTargetStyle.CheckFilteredPrimaryTargets(self, Targets); + if (AvailableCode != 'AA_Success') + return AvailableCode; + + Targets.Sort(SortAvailableTargets); + } + return 'AA_Success'; +} + +simulated function int SortAvailableTargets(AvailableTarget TargetA, AvailableTarget TargetB) +{ + local XComGameStateHistory History; + local XComGameState_Destructible DestructibleA, DestructibleB; + local int HitChanceA, HitChanceB; + local ShotBreakdown BreakdownA, BreakdownB; + + if (TargetA.PrimaryTarget.ObjectID != 0 && TargetB.PrimaryTarget.ObjectID == 0) + { + return -1; + } + if (TargetB.PrimaryTarget.ObjectID != 0 && TargetA.PrimaryTarget.ObjectID == 0) + { + return 1; + } + if (TargetA.PrimaryTarget.ObjectID == 0 && TargetB.PrimaryTarget.ObjectID == 0) + { + return 1; + } + History = `XCOMHISTORY; + DestructibleA = XComGameState_Destructible(History.GetGameStateForObjectID(TargetA.PrimaryTarget.ObjectID)); + DestructibleB = XComGameState_Destructible(History.GetGameStateForObjectID(TargetB.PrimaryTarget.ObjectID)); + if (DestructibleA != none && DestructibleB == none) + { + return -1; + } + if (DestructibleB != none && DestructibleA == none) + { + return 1; + } + + HitChanceA = GetShotBreakdown(TargetA, BreakdownA); + HitChanceB = GetShotBreakdown(TargetB, BreakdownB); + if (HitChanceA < HitChanceB) + { + return -1; + } + + return 1; +} + simulated function GatherAbilityTargetLocationsForLocation(const vector Location, const AvailableTarget Targets, out array TargetLocations) { local X2AbilityMultiTarget_BlazingPinions BlazingPinionsMultiTarget; diff --git a/X2WOTCCommunityHighlander/Src/XComGame/Classes/XComGameState_Ability_CH.uc b/X2WOTCCommunityHighlander/Src/XComGame/Classes/XComGameState_Ability_CH.uc index ee75cc781..e30123716 100644 --- a/X2WOTCCommunityHighlander/Src/XComGame/Classes/XComGameState_Ability_CH.uc +++ b/X2WOTCCommunityHighlander/Src/XComGame/Classes/XComGameState_Ability_CH.uc @@ -33,99 +33,5 @@ class XComGameState_Ability_CH extends XComGameState_Ability; simulated function name GatherAbilityTargets(out array Targets, optional XComGameState_Unit OverrideOwnerState) { - local int i, j; - local XComGameState_Unit kOwner; - local name AvailableCode; - local XComGameStateHistory History; - - GetMyTemplate(); - History = `XCOMHISTORY; - kOwner = XComGameState_Unit(History.GetGameStateForObjectID(OwnerStateObject.ObjectID)); - if (OverrideOwnerState != none) - kOwner = OverrideOwnerState; - - if (m_Template != None) - { - AvailableCode = m_Template.AbilityTargetStyle.GetPrimaryTargetOptions(self, Targets); - if (AvailableCode != 'AA_Success') - return AvailableCode; - - for (i = Targets.Length - 1; i >= 0; --i) - { - AvailableCode = m_Template.CheckTargetConditions(self, kOwner, History.GetGameStateForObjectID(Targets[i].PrimaryTarget.ObjectID)); - if (AvailableCode != 'AA_Success') - { - Targets.Remove(i, 1); - } - } - - if (m_Template.AbilityMultiTargetStyle != none) - { - m_Template.AbilityMultiTargetStyle.GetMultiTargetOptions(self, Targets); - for (i = Targets.Length - 1; i >= 0; --i) - { - for (j = Targets[i].AdditionalTargets.Length - 1; j >= 0; --j) - { - AvailableCode = m_Template.CheckMultiTargetConditions(self, kOwner, History.GetGameStateForObjectID(Targets[i].AdditionalTargets[j].ObjectID)); - if (AvailableCode != 'AA_Success' || (Targets[i].AdditionalTargets[j].ObjectID == Targets[i].PrimaryTarget.ObjectID) && !m_Template.AbilityMultiTargetStyle.bAllowSameTarget) - { - Targets[i].AdditionalTargets.Remove(j, 1); - } - } - - AvailableCode = m_Template.AbilityMultiTargetStyle.CheckFilteredMultiTargets(self, Targets[i]); - if (AvailableCode != 'AA_Success') - Targets.Remove(i, 1); - } - } - - //The Multi-target style may have deemed some primary targets invalid in calls to CheckFilteredMultiTargets - so CheckFilteredPrimaryTargets must come afterwards. - AvailableCode = m_Template.AbilityTargetStyle.CheckFilteredPrimaryTargets(self, Targets); - if (AvailableCode != 'AA_Success') - return AvailableCode; - - Targets.Sort(SortAvailableTargets); - } - return 'AA_Success'; -} - -simulated function int SortAvailableTargets(AvailableTarget TargetA, AvailableTarget TargetB) -{ - local XComGameStateHistory History; - local XComGameState_Destructible DestructibleA, DestructibleB; - local int HitChanceA, HitChanceB; - local ShotBreakdown BreakdownA, BreakdownB; - - if (TargetA.PrimaryTarget.ObjectID != 0 && TargetB.PrimaryTarget.ObjectID == 0) - { - return -1; - } - if (TargetB.PrimaryTarget.ObjectID != 0 && TargetA.PrimaryTarget.ObjectID == 0) - { - return 1; - } - if (TargetA.PrimaryTarget.ObjectID == 0 && TargetB.PrimaryTarget.ObjectID == 0) - { - return 1; - } - History = `XCOMHISTORY; - DestructibleA = XComGameState_Destructible(History.GetGameStateForObjectID(TargetA.PrimaryTarget.ObjectID)); - DestructibleB = XComGameState_Destructible(History.GetGameStateForObjectID(TargetB.PrimaryTarget.ObjectID)); - if (DestructibleA != none && DestructibleB == none) - { - return -1; - } - if (DestructibleB != none && DestructibleA == none) - { - return 1; - } - - HitChanceA = GetShotBreakdown(TargetA, BreakdownA); - HitChanceB = GetShotBreakdown(TargetB, BreakdownB); - if (HitChanceA < HitChanceB) - { - return -1; - } - - return 1; + return CHGatherAbilityTargetsScript(Targets, OverrideOwnerState); } \ No newline at end of file