1 //
2 // Copyright (c) 2010-2022 Antmicro
3 //
4 // This file is licensed under the MIT License.
5 // Full license text is available in 'licenses/MIT.txt'.
6 //
7 using System;
8 using System.Collections.Generic;
9 using System.IO;
10 using System.Linq;
11 using System.Text;
12 using Antmicro.Renode.Debugging;
13 using Antmicro.Renode.Exceptions;
14 using Antmicro.Renode.Logging;
15 using Antmicro.Renode.Peripherals.Bus;
16 using Antmicro.Renode.Utilities.Binding;
17 using PerfettoTraceWriter = Antmicro.Renode.Peripherals.CPU.GuestProfiling.ProtoBuf.PerfettoTraceWriter;
18 
19 namespace Antmicro.Renode.Peripherals.CPU.GuestProfiling
20 {
21     public class PerfettoProfiler : BaseProfiler
22     {
PerfettoProfiler(TranslationCPU cpu, string filename, bool flushInstantly, bool enableMultipleTracks, long? fileSizeLimit = null, int? maximumNestedContexts = null)23         public PerfettoProfiler(TranslationCPU cpu, string filename, bool flushInstantly, bool enableMultipleTracks, long? fileSizeLimit = null, int? maximumNestedContexts = null)
24             : base(cpu, flushInstantly, maximumNestedContexts)
25         {
26             this.fileSizeLimit = fileSizeLimit;
27             this.enableMultipleTracks = enableMultipleTracks;
28             lastInterruptExitTime = ulong.MaxValue;
29             fileStream = File.Open(filename, FileMode.OpenOrCreate);
30             writer = new PerfettoTraceWriter();
31             currentTrack = MainTrack;
32             writer.CreateTrack(cpu.GetName(), currentTrack);
33         }
34 
Dispose()35         public override void Dispose()
36         {
37             base.Dispose();
38             fileStream.Close();
39         }
40 
StackFrameAdd(ulong currentAddress, ulong returnAddress, ulong instructionsCount)41         public override void StackFrameAdd(ulong currentAddress, ulong returnAddress, ulong instructionsCount)
42         {
43             var currentSymbol = GetSymbolName(currentAddress);
44             cpu.Log(LogLevel.Debug, "Profiler: Pushing new frame with symbol: {0}; returnAddress: 0x{1:X}; currentAddress: 0x{2:X}", currentSymbol, returnAddress, currentAddress);
45 
46             if(isFirstFrame)
47             {
48                 isFirstFrame = false;
49                 // We have to add the first frame, form which the first jump happened
50                 // To infer this frame we use the current PC value, which should point to the jump instruction that triggered this event
51                 var prevSymbol = GetSymbolName(cpu.PC.RawValue);
52                 currentStack.Push(prevSymbol);
53                 writer.CreateEventBegin(0, prevSymbol, currentTrack);
54             }
55 
56             currentStack.Push(currentSymbol);
57             ulong time = InstructionCountToNs(instructionsCount);
58             writer.CreateEventBegin(time, currentSymbol, currentTrack);
59             CheckAndFlush(time);
60         }
61 
StackFramePop(ulong currentAddress, ulong returnAddress, ulong instructionsCount)62         public override void StackFramePop(ulong currentAddress, ulong returnAddress, ulong instructionsCount)
63         {
64             cpu.Log(LogLevel.Debug, "Profiler: Trying to pop frame with returnAddress: 0x{0:X} ({1}); currentAddress: 0x{2:X}", returnAddress, GetSymbolName(returnAddress), currentAddress);
65             if(currentStack.Count == 0)
66             {
67                 cpu.Log(LogLevel.Error, "Profiler: Trying to return from frame while internal stack tracking is empty");
68                 return;
69             }
70 
71             ulong time = InstructionCountToNs(instructionsCount);
72             writer.CreateEventEnd(time, currentTrack);
73             currentStack.Pop();
74             CheckAndFlush(time);
75         }
76 
OnContextChange(ulong newContextId)77         public override void OnContextChange(ulong newContextId)
78         {
79             if(newContextId == currentContextId)
80             {
81                 return;
82             }
83 
84             cpu.Log(LogLevel.Debug, "Profiler: Changing context from: 0x{0:X} to 0x{1:X}", currentContextId, newContextId);
85 
86             ulong track = enableMultipleTracks ? currentContextId : MainTrack;
87             ulong time = InstructionCountToNs(cpu.ExecutedInstructions);
88 
89             // End the current thread's stack frame
90             for(int i = 0; i < currentStack.Count; i++)
91             {
92                 writer.CreateEventEnd(time, track);
93             }
94             PushCurrentContextSafe();
95 
96             // Get the new thread's execution and restore the events
97             if(!wholeExecution.ContainsKey(newContextId))
98             {
99                 wholeExecution.Add(newContextId, new ProfilerContext());
100                 if(enableMultipleTracks)
101                 {
102                     writer.CreateTrack($"Track: 0x{newContextId:X}", newContextId);
103                 }
104             }
105 
106             currentContextId = newContextId;
107 
108             ulong newTrack = enableMultipleTracks ? newContextId : MainTrack;
109             if(currentContext.Count > 0)
110             {
111                 currentContext.PopCurrentStack();
112                 // Restore events from the previous visit to this context
113                 foreach(var frame in currentStack.Reverse())
114                 {
115                     writer.CreateEventBegin(time, frame, newTrack);
116                 }
117             }
118             else
119             {
120                 currentContext.PopCurrentStack();
121             }
122 
123             currentTrack = newTrack;
124 
125             CheckAndFlush(time);
126         }
127 
InterruptEnter(ulong interruptIndex)128         public override void InterruptEnter(ulong interruptIndex)
129         {
130             ulong time = InstructionCountToNs(cpu.ExecutedInstructions);
131             if(lastInterruptExitTime == time)
132             {
133                 // If we entered another interrupt just after exiting the previous one
134                 // We have to remove the start packets so the trace doesn't show a stack
135                 // with the duration of 0
136                 writer.RemoveLastNPackets(currentStack.Count);
137             }
138             else
139             {
140                 // If there is no need to remove the events then we want to finish
141                 // the current stack before creating a new one for the interrupt
142                 FinishCurrentStack(time, currentTrack);
143             }
144 
145             PushCurrentContextSafe();
146             cpu.Log(LogLevel.Debug, "Profiler: Interrupt entry (pc 0x{0:X})- saving the stack", cpu.PC);
147             CheckAndFlush(time);
148         }
149 
InterruptExit(ulong interruptIndex)150         public override void InterruptExit(ulong interruptIndex)
151         {
152             ulong time = InstructionCountToNs(cpu.ExecutedInstructions);
153             FinishCurrentStack(time, currentTrack);
154             lastInterruptExitTime = time;
155             // We have to temporarily disable flushing to a file, since the next few packets can be removed
156             blockFlush = true;
157 
158             cpu.Log(LogLevel.Debug, "Profiler: Interrupt exit - restoring the stack");
159             if(currentContext.Count > 0)
160             {
161                 currentContext.PopCurrentStack();
162                 // Restart functions on the current stack
163                 foreach(var frame in currentStack.Reverse())
164                 {
165                     writer.CreateEventBegin(time, frame, currentTrack);
166                 }
167             }
168             else
169             {
170                 currentContext.PopCurrentStack();
171             }
172             CheckAndFlush(time);
173         }
174 
FlushBuffer()175         public override void FlushBuffer()
176         {
177             // DisableProfiler() calls Dispose() which calls FlushBuffer()
178             // `isDisposing` flag is required to prevent an infinite loop
179             if(blockFlush || isDisposing)
180             {
181                 return;
182             }
183 
184             lock(bufferLock)
185             {
186                 // Write to MemoryStream first so we can check the serialized length against the limit
187                 var memoryStream = new MemoryStream();
188                 writer.FlushBuffer(memoryStream);
189 
190                 if(fileSizeLimit.HasValue && (fileStream.Length + memoryStream.Length) > fileSizeLimit)
191                 {
192                     isDisposing = true;
193                     cpu.Log(LogLevel.Warning, "Profiler: Maximum file size exceeded, removing profiler");
194                     cpu.DisableProfiler();
195                     return;
196                 }
197 
198                 memoryStream.WriteTo(fileStream);
199             }
200         }
201 
FinishCurrentStack(ulong time, ulong trackId)202         private void FinishCurrentStack(ulong time, ulong trackId)
203         {
204             for(int i = 0; i < currentStack.Count; i++)
205             {
206                 writer.CreateEventEnd(time, trackId);
207             }
208         }
209 
CheckAndFlush(ulong time)210         private void CheckAndFlush(ulong time)
211         {
212             if(blockFlush && time > lastInterruptExitTime)
213             {
214                 // If the time advanced pass the last interrupt exit the flushing can be turned back on
215                 blockFlush = false;
216             }
217 
218             if(flushInstantly || writer.PacketCount > BufferFlushLevel)
219             {
220                 FlushBuffer();
221             }
222         }
223 
InstructionCountToNs(ulong instructionCount)224         private ulong InstructionCountToNs(ulong instructionCount)
225         {
226             // 1 ins takes 1s / (MIPS * 10^6)
227             // So 1 ins = 10^9ns / (MIPS * 10^6) => (1000 / MIPS) ns
228             return (1000 * instructionCount) / cpu.PerformanceInMips;
229         }
230 
231         private readonly PerfettoTraceWriter writer;
232         private readonly bool enableMultipleTracks;
233         private readonly FileStream fileStream;
234         private readonly long? fileSizeLimit;
235 
236         private bool isDisposing;
237         private bool blockFlush;
238         private ulong lastInterruptExitTime;
239         private ulong currentTrack;
240 
241         private const ulong MainTrack = 0;
242         private const int BufferFlushLevel = 10000;
243     }
244 }
245