1 #include "stdafx.h"
2 #include <regex>
3 #include "TraceLogger.h"
4 #include "DisassemblyInfo.h"
5 #include "DebuggerTypes.h"
6 #include "Console.h"
7 #include "Debugger.h"
8 #include "MemoryManager.h"
9 #include "LabelManager.h"
10 #include "EmulationSettings.h"
11 #include "ExpressionEvaluator.h"
12 #include "../Utilities/HexUtilities.h"
13 #include "../Utilities/FolderUtilities.h"
14
15 string TraceLogger::_executionTrace = "";
16
TraceLogger(Debugger * debugger,shared_ptr<MemoryManager> memoryManager,shared_ptr<LabelManager> labelManager)17 TraceLogger::TraceLogger(Debugger* debugger, shared_ptr<MemoryManager> memoryManager, shared_ptr<LabelManager> labelManager)
18 {
19 _expEvaluator = shared_ptr<ExpressionEvaluator>(new ExpressionEvaluator(debugger));
20 _memoryManager = memoryManager;
21 _labelManager = labelManager;
22 _currentPos = 0;
23 _logCount = 0;
24 _logToFile = false;
25 _pendingLog = false;
26 }
27
~TraceLogger()28 TraceLogger::~TraceLogger()
29 {
30 StopLogging();
31 }
32
33 template<typename T>
WriteValue(string & output,T value,RowPart & rowPart)34 void TraceLogger::WriteValue(string &output, T value, RowPart& rowPart)
35 {
36 string str = rowPart.DisplayInHex ? HexUtilities::ToHex(value) : std::to_string(value);
37 output += str;
38 if(rowPart.MinWidth > (int)str.size()) {
39 output += std::string(rowPart.MinWidth - str.size(), ' ');
40 }
41 }
42
43 template<>
WriteValue(string & output,string value,RowPart & rowPart)44 void TraceLogger::WriteValue(string &output, string value, RowPart& rowPart)
45 {
46 output += value;
47 if(rowPart.MinWidth > (int)value.size()) {
48 output += std::string(rowPart.MinWidth - value.size(), ' ');
49 }
50 }
51
SetOptions(TraceLoggerOptions options)52 void TraceLogger::SetOptions(TraceLoggerOptions options)
53 {
54 _options = options;
55 string condition = _options.Condition;
56 string format = _options.Format;
57
58 auto lock = _lock.AcquireSafe();
59 _conditionData = ExpressionData();
60 if(!condition.empty()) {
61 bool success = false;
62 ExpressionData rpnList = _expEvaluator->GetRpnList(condition, success);
63 if(success) {
64 _conditionData = rpnList;
65 }
66 }
67
68 _rowParts.clear();
69
70 std::regex formatRegex = std::regex("(\\[\\s*([^[]*?)\\s*(,\\s*([\\d]*)\\s*(h){0,1}){0,1}\\s*\\])|([^[]*)", std::regex_constants::icase);
71 std::sregex_iterator start = std::sregex_iterator(format.cbegin(), format.cend(), formatRegex);
72 std::sregex_iterator end = std::sregex_iterator();
73
74 for(std::sregex_iterator it = start; it != end; it++) {
75 const std::smatch& match = *it;
76
77 if(match.str(1) == "") {
78 RowPart part = {};
79 part.DataType = RowDataType::Text;
80 part.Text = match.str(6);
81 _rowParts.push_back(part);
82 } else {
83 RowPart part = {};
84
85 string dataType = match.str(2);
86 if(dataType == "ByteCode") {
87 part.DataType = RowDataType::ByteCode;
88 } else if(dataType == "Disassembly") {
89 part.DataType = RowDataType::Disassembly;
90 } else if(dataType == "EffectiveAddress") {
91 part.DataType = RowDataType::EffectiveAddress;
92 } else if(dataType == "MemoryValue") {
93 part.DataType = RowDataType::MemoryValue;
94 } else if(dataType == "Align") {
95 part.DataType = RowDataType::Align;
96 } else if(dataType == "PC") {
97 part.DataType = RowDataType::PC;
98 } else if(dataType == "A") {
99 part.DataType = RowDataType::A;
100 } else if(dataType == "X") {
101 part.DataType = RowDataType::X;
102 } else if(dataType == "Y") {
103 part.DataType = RowDataType::Y;
104 } else if(dataType == "P") {
105 part.DataType = RowDataType::PS;
106 } else if(dataType == "SP") {
107 part.DataType = RowDataType::SP;
108 } else if(dataType == "Cycle") {
109 part.DataType = RowDataType::Cycle;
110 } else if(dataType == "Scanline") {
111 part.DataType = RowDataType::Scanline;
112 } else if(dataType == "FrameCount") {
113 part.DataType = RowDataType::FrameCount;
114 } else if(dataType == "CycleCount") {
115 part.DataType = RowDataType::CycleCount;
116 } else {
117 part.DataType = RowDataType::Text;
118 part.Text = "[Invalid tag]";
119 }
120
121 if(!match.str(4).empty()) {
122 try {
123 part.MinWidth = std::stoi(match.str(4));
124 } catch(std::exception) {
125 }
126 }
127 part.DisplayInHex = match.str(5) == "h";
128
129 _rowParts.push_back(part);
130 }
131 }
132 }
133
StartLogging(string filename)134 void TraceLogger::StartLogging(string filename)
135 {
136 _outputBuffer.clear();
137 _outputFile.open(filename, ios::out | ios::binary);
138 _logToFile = true;
139 }
140
StopLogging()141 void TraceLogger::StopLogging()
142 {
143 if(_logToFile) {
144 _logToFile = false;
145 if(_outputFile) {
146 if(!_outputBuffer.empty()) {
147 _outputFile << _outputBuffer;
148 }
149 _outputFile.close();
150 }
151 }
152 }
153
LogExtraInfo(const char * log,uint64_t cycleCount)154 void TraceLogger::LogExtraInfo(const char *log, uint64_t cycleCount)
155 {
156 if(_logToFile && _options.ShowExtraInfo) {
157 //Flush current buffer
158 _outputFile << _outputBuffer;
159 _outputBuffer.clear();
160 _outputFile << "[" << log << " - Cycle: " << std::to_string(cycleCount) << "]" << (_options.UseWindowsEol ? "\r\n" : "\n");
161 }
162 }
163
GetStatusFlag(string & output,uint8_t ps,RowPart & part)164 void TraceLogger::GetStatusFlag(string &output, uint8_t ps, RowPart& part)
165 {
166 if(part.DisplayInHex) {
167 WriteValue(output, ps, part);
168 } else {
169 constexpr char activeStatusLetters[8] = { 'N', 'V', '-', '-', 'D', 'I', 'Z', 'C' };
170 constexpr char inactiveStatusLetters[8] = { 'n', 'v', '-', '-', 'd', 'i', 'z', 'c' };
171 string flags;
172 for(int i = 0; i < 8; i++) {
173 if(ps & 0x80) {
174 flags += activeStatusLetters[i];
175 } else if(part.MinWidth >= 8) {
176 flags += inactiveStatusLetters[i];
177 }
178 ps <<= 1;
179 }
180 WriteValue(output, flags, part);
181 }
182 }
183
GetTraceRow(string & output,State & cpuState,PPUDebugState & ppuState,DisassemblyInfo & disassemblyInfo)184 void TraceLogger::GetTraceRow(string &output, State &cpuState, PPUDebugState &ppuState, DisassemblyInfo &disassemblyInfo)
185 {
186 int originalSize = (int)output.size();
187 for(RowPart& rowPart : _rowParts) {
188 switch(rowPart.DataType) {
189 case RowDataType::Text: output += rowPart.Text; break;
190
191 case RowDataType::ByteCode: {
192 string byteCode;
193 disassemblyInfo.GetByteCode(byteCode);
194 if(!rowPart.DisplayInHex) {
195 //Remove $ marks if not in "hex" mode (but still display the bytes as hex)
196 byteCode.erase(std::remove(byteCode.begin(), byteCode.end(), '$'), byteCode.end());
197 }
198 WriteValue(output, byteCode, rowPart);
199 break;
200 }
201
202 case RowDataType::Disassembly: {
203 int indentLevel = 0;
204 string code;
205
206 if(_options.IndentCode) {
207 indentLevel = 0xFF - cpuState.SP;
208 code = std::string(indentLevel, ' ');
209 }
210
211 LabelManager* labelManager = _options.UseLabels ? _labelManager.get() : nullptr;
212 disassemblyInfo.ToString(code, cpuState.DebugPC, _memoryManager.get(), labelManager, _options.ExtendZeroPage);
213 WriteValue(output, code, rowPart);
214 break;
215 }
216
217 case RowDataType::EffectiveAddress:{
218 string effectiveAddress;
219 disassemblyInfo.GetEffectiveAddressString(effectiveAddress, cpuState, _memoryManager.get(), _options.UseLabels ? _labelManager.get() : nullptr);
220 WriteValue(output, effectiveAddress, rowPart);
221 break;
222 }
223
224 case RowDataType::MemoryValue:{
225 int32_t value = disassemblyInfo.GetMemoryValue(cpuState, _memoryManager.get());
226 if(value >= 0) {
227 output += rowPart.DisplayInHex ? "= $" : "= ";
228 WriteValue(output, (uint8_t)value, rowPart);
229 }
230 break;
231 }
232
233 case RowDataType::Align:
234 if((int)output.size() - originalSize < rowPart.MinWidth) {
235 output += std::string(rowPart.MinWidth - (output.size() - originalSize), ' ');
236 }
237 break;
238
239 case RowDataType::PC: WriteValue(output, cpuState.DebugPC, rowPart); break;
240 case RowDataType::A: WriteValue(output, cpuState.A, rowPart); break;
241 case RowDataType::X: WriteValue(output, cpuState.X, rowPart); break;
242 case RowDataType::Y: WriteValue(output, cpuState.Y, rowPart); break;
243 case RowDataType::SP: WriteValue(output, cpuState.SP, rowPart); break;
244 case RowDataType::PS: GetStatusFlag(output, cpuState.PS, rowPart); break;
245 case RowDataType::Cycle: WriteValue(output, ppuState.Cycle, rowPart); break;
246 case RowDataType::Scanline: WriteValue(output, ppuState.Scanline, rowPart); break;
247 case RowDataType::FrameCount: WriteValue(output, ppuState.FrameCount, rowPart); break;
248 case RowDataType::CycleCount: WriteValue(output, cpuState.CycleCount, rowPart); break;
249 }
250 }
251 output += _options.UseWindowsEol ? "\r\n" : "\n";
252 }
253
ConditionMatches(DebugState & state,DisassemblyInfo & disassemblyInfo,OperationInfo & operationInfo)254 bool TraceLogger::ConditionMatches(DebugState &state, DisassemblyInfo &disassemblyInfo, OperationInfo &operationInfo)
255 {
256 if(!_conditionData.RpnQueue.empty()) {
257 EvalResultType type;
258 if(!_expEvaluator->Evaluate(_conditionData, state, type, operationInfo)) {
259 if(operationInfo.OperationType == MemoryOperationType::ExecOpCode) {
260 //Condition did not match, keep state/disassembly info for instruction's subsequent cycles
261 _lastState = state;
262 _lastDisassemblyInfo = disassemblyInfo;
263 _pendingLog = true;
264 }
265 return false;
266 }
267 }
268 return true;
269 }
270
AddRow(DisassemblyInfo & disassemblyInfo,DebugState & state)271 void TraceLogger::AddRow(DisassemblyInfo &disassemblyInfo, DebugState &state)
272 {
273 _disassemblyCache[_currentPos] = disassemblyInfo;
274 _cpuStateCache[_currentPos] = state.CPU;
275 _ppuStateCache[_currentPos] = state.PPU;
276 _currentPos = (_currentPos + 1) % ExecutionLogSize;
277 _pendingLog = false;
278
279 if(_logCount < ExecutionLogSize) {
280 _logCount++;
281 }
282
283 if(_logToFile) {
284 GetTraceRow(_outputBuffer, state.CPU, state.PPU, disassemblyInfo);
285 if(_outputBuffer.size() > 32768) {
286 _outputFile << _outputBuffer;
287 _outputBuffer.clear();
288 }
289 }
290 }
291
LogNonExec(OperationInfo & operationInfo)292 void TraceLogger::LogNonExec(OperationInfo& operationInfo)
293 {
294 if(_pendingLog) {
295 auto lock = _lock.AcquireSafe();
296 if(ConditionMatches(_lastState, _lastDisassemblyInfo, operationInfo)) {
297 AddRow(_lastDisassemblyInfo, _lastState);
298 }
299 }
300 }
301
Log(DebugState & state,DisassemblyInfo & disassemblyInfo,OperationInfo & operationInfo)302 void TraceLogger::Log(DebugState &state, DisassemblyInfo &disassemblyInfo, OperationInfo &operationInfo)
303 {
304 auto lock = _lock.AcquireSafe();
305 if(ConditionMatches(state, disassemblyInfo, operationInfo)) {
306 AddRow(disassemblyInfo, state);
307 }
308 }
309
Clear()310 void TraceLogger::Clear()
311 {
312 _logCount = 0;
313 }
314
GetExecutionTrace(uint32_t lineCount)315 const char* TraceLogger::GetExecutionTrace(uint32_t lineCount)
316 {
317 int startPos;
318
319 _executionTrace.clear();
320 {
321 auto lock = _lock.AcquireSafe();
322 lineCount = std::min(lineCount, _logCount);
323 memcpy(_cpuStateCacheCopy, _cpuStateCache, sizeof(_cpuStateCache));
324 memcpy(_ppuStateCacheCopy, _ppuStateCache, sizeof(_ppuStateCache));
325 memcpy(_disassemblyCacheCopy, _disassemblyCache, sizeof(_disassemblyCache));
326 startPos = _currentPos + ExecutionLogSize - lineCount;
327 }
328
329 for(int i = 0; i < (int)lineCount; i++) {
330 int index = (startPos + i) % ExecutionLogSize;
331 _executionTrace += HexUtilities::ToHex(_cpuStateCacheCopy[index].DebugPC) + "\x1";
332 string byteCode;
333 _disassemblyCacheCopy[index].GetByteCode(byteCode);
334 _executionTrace += byteCode + "\x1";
335 GetTraceRow(_executionTrace, _cpuStateCacheCopy[index], _ppuStateCacheCopy[index], _disassemblyCacheCopy[index]);
336 }
337
338 return _executionTrace.c_str();
339 }