Line | Branch | Decision | Exec | Source |
---|---|---|---|---|
1 | /* | |||
2 | * @file tooth_logger.cpp | |||
3 | * | |||
4 | * At least some of the code here is related to xxx.teeth files | |||
5 | * See also misc\tooth_log_converter\log_convert.cpp | |||
6 | * | |||
7 | * @date Jul 7, 2019 | |||
8 | * @author Matthew Kennedy | |||
9 | */ | |||
10 | ||||
11 | #include "pch.h" | |||
12 | ||||
13 | #if EFI_TOOTH_LOGGER | |||
14 | #if !EFI_SHAFT_POSITION_INPUT | |||
15 | fail("EFI_SHAFT_POSITION_INPUT required to have EFI_EMULATE_POSITION_SENSORS") | |||
16 | #endif | |||
17 | ||||
18 | /** | |||
19 | * Engine idles around 20Hz and revs up to 140Hz, at 60/2 and 8 cylinders we have about 20Khz events | |||
20 | * If we can read buffer at 50Hz we want buffer to be about 400 elements. | |||
21 | */ | |||
22 | ||||
23 | static_assert(sizeof(composite_logger_s) == COMPOSITE_PACKET_SIZE, "composite packet size"); | |||
24 | ||||
25 | static volatile bool ToothLoggerEnabled = false; | |||
26 | //static uint32_t lastEdgeTimestamp = 0; | |||
27 | ||||
28 | static bool currentTrigger1 = false; | |||
29 | static bool currentTrigger2 = false; | |||
30 | static bool currentTdc = false; | |||
31 | // any coil, all coils thrown together | |||
32 | static bool currentCoilState = false; | |||
33 | // same about injectors | |||
34 | static bool currentInjectorState = false; | |||
35 | ||||
36 | #if EFI_UNIT_TEST | |||
37 | ||||
38 | 98711 | void jsonTraceEntry(const char* name, int pid, bool isEnter, efitick_t timestamp) { | ||
39 | extern FILE *jsonTrace; | |||
40 |
2/2✓ Branch 0 taken 98461 times.
✓ Branch 1 taken 250 times.
|
2/2✓ Decision 'true' taken 98461 times.
✓ Decision 'false' taken 250 times.
|
98711 | if (jsonTrace != nullptr) { |
41 | 98461 | fprintf(jsonTrace, ",\n"); | ||
42 |
2/2✓ Branch 0 taken 44709 times.
✓ Branch 1 taken 53752 times.
|
98461 | fprintf(jsonTrace, "{\"name\":\"%s\",\"ph\":\"%s\",\"tid\":0,\"pid\":%d,\"ts\":%f}", | |
43 | name, | |||
44 | isEnter ? "B" : "E", | |||
45 | pid, | |||
46 | timestamp / 1000.0); | |||
47 | } | |||
48 | 98711 | } | ||
49 | ||||
50 | #include "logicdata.h" | |||
51 | ||||
52 | static std::vector<CompositeEvent> events; | |||
53 | ||||
54 | 1166 | const std::vector<CompositeEvent>& getCompositeEvents() { | ||
55 | 1166 | return events; | ||
56 | } | |||
57 | ||||
58 | 77977 | void SetNextCompositeEntry(efitick_t timestamp) { | ||
59 | 77977 | CompositeEvent event; | ||
60 | ||||
61 | 77977 | event.timestamp = timestamp; | ||
62 | 77977 | event.primaryTrigger = currentTrigger1; | ||
63 | 77977 | event.secondaryTrigger = currentTrigger2; | ||
64 | 77977 | event.isTDC = currentTdc; | ||
65 |
1/1✓ Branch 1 taken 77977 times.
|
77977 | event.sync = engine->triggerCentral.triggerState.getShaftSynchronized(); | |
66 | 77977 | event.coil = currentCoilState; | ||
67 | 77977 | event.injector = currentInjectorState; | ||
68 | ||||
69 |
1/1✓ Branch 1 taken 77977 times.
|
77977 | events.push_back(event); | |
70 | 77977 | } | ||
71 | ||||
72 | 677 | void EnableToothLogger() { | ||
73 | 677 | ToothLoggerEnabled = true; | ||
74 | 677 | events.clear(); | ||
75 | 677 | } | ||
76 | ||||
77 | ✗ | void DisableToothLogger() { | ||
78 | ✗ | ToothLoggerEnabled = false; | ||
79 | ✗ | } | ||
80 | ||||
81 | #else // not EFI_UNIT_TEST | |||
82 | ||||
83 | static constexpr size_t BUFFER_COUNT = BIG_BUFFER_SIZE / sizeof(CompositeBuffer); | |||
84 | static_assert(BUFFER_COUNT >= 2); | |||
85 | ||||
86 | static CompositeBuffer* buffers = nullptr; | |||
87 | static chibios_rt::Mailbox<CompositeBuffer*, BUFFER_COUNT> freeBuffers CCM_OPTIONAL; | |||
88 | static chibios_rt::Mailbox<CompositeBuffer*, BUFFER_COUNT> filledBuffers CCM_OPTIONAL; | |||
89 | ||||
90 | static CompositeBuffer* currentBuffer = nullptr; | |||
91 | ||||
92 | static void setToothLogReady(bool value) { | |||
93 | #if EFI_TUNER_STUDIO && (EFI_PROD_CODE || EFI_SIMULATOR) | |||
94 | engine->outputChannels.toothLogReady = value; | |||
95 | #endif // EFI_TUNER_STUDIO | |||
96 | } | |||
97 | ||||
98 | static BigBufferHandle bufferHandle; | |||
99 | ||||
100 | void EnableToothLogger() { | |||
101 | chibios_rt::CriticalSectionLocker csl; | |||
102 | ||||
103 | bufferHandle = getBigBuffer(BigBufferUser::ToothLogger); | |||
104 | if (!bufferHandle) { | |||
105 | return; | |||
106 | } | |||
107 | ||||
108 | buffers = bufferHandle.get<CompositeBuffer>(); | |||
109 | ||||
110 | // Reset all buffers | |||
111 | for (size_t i = 0; i < BUFFER_COUNT; i++) { | |||
112 | buffers[i].nextIdx = 0; | |||
113 | } | |||
114 | ||||
115 | // Reset state | |||
116 | currentBuffer = nullptr; | |||
117 | ||||
118 | // Empty the filled buffer list | |||
119 | CompositeBuffer* dummy; | |||
120 | while (MSG_TIMEOUT != filledBuffers.fetchI(&dummy)) ; | |||
121 | ||||
122 | // Put all buffers in the free list | |||
123 | for (size_t i = 0; i < BUFFER_COUNT; i++) { | |||
124 | freeBuffers.postI(&buffers[i]); | |||
125 | } | |||
126 | ||||
127 | // Reset the last edge to now - this prevents the first edge logged from being bogus | |||
128 | //lastEdgeTimestamp = getTimeNowUs(); | |||
129 | ||||
130 | // Enable logging of edges as they come | |||
131 | ToothLoggerEnabled = true; | |||
132 | ||||
133 | setToothLogReady(false); | |||
134 | } | |||
135 | ||||
136 | void DisableToothLogger() { | |||
137 | chibios_rt::CriticalSectionLocker csl; | |||
138 | ||||
139 | ToothLoggerEnabled = false; | |||
140 | setToothLogReady(false); | |||
141 | ||||
142 | // Release the big buffer for another user | |||
143 | // C++ magic: here we are calling BigBufferHandle::operator=() with empty instance | |||
144 | bufferHandle = {}; | |||
145 | buffers = nullptr; | |||
146 | } | |||
147 | ||||
148 | static CompositeBuffer* GetToothLoggerBufferImpl(sysinterval_t timeout) { | |||
149 | CompositeBuffer* buffer; | |||
150 | msg_t msg = filledBuffers.fetch(&buffer, timeout); | |||
151 | ||||
152 | if (msg == MSG_TIMEOUT) { | |||
153 | setToothLogReady(false); | |||
154 | return nullptr; | |||
155 | } | |||
156 | ||||
157 | if (msg != MSG_OK) { | |||
158 | // What even happened if we didn't get timeout, but also didn't get OK? | |||
159 | return nullptr; | |||
160 | } | |||
161 | ||||
162 | chibios_rt::CriticalSectionLocker csl; | |||
163 | ||||
164 | // If the used list is empty, clear the ready flag | |||
165 | if (filledBuffers.getUsedCountI() == 0) { | |||
166 | setToothLogReady(false); | |||
167 | } | |||
168 | ||||
169 | return buffer; | |||
170 | } | |||
171 | ||||
172 | CompositeBuffer* GetToothLoggerBufferNonblocking() { | |||
173 | return GetToothLoggerBufferImpl(TIME_IMMEDIATE); | |||
174 | } | |||
175 | ||||
176 | CompositeBuffer* GetToothLoggerBufferBlocking() { | |||
177 | return GetToothLoggerBufferImpl(TIME_INFINITE); | |||
178 | } | |||
179 | ||||
180 | void ReturnToothLoggerBuffer(CompositeBuffer* buffer) { | |||
181 | chibios_rt::CriticalSectionLocker csl; | |||
182 | ||||
183 | msg_t msg = freeBuffers.postI(buffer); | |||
184 | criticalAssertVoid(msg == MSG_OK, "Composite logger post to free buffer fail"); | |||
185 | } | |||
186 | ||||
187 | static CompositeBuffer* findBuffer(efitick_t timestamp) { | |||
188 | CompositeBuffer* buffer; | |||
189 | ||||
190 | if (!currentBuffer) { | |||
191 | // try and find a buffer, if none available, we can't log | |||
192 | if (MSG_OK != freeBuffers.fetchI(&buffer)) { | |||
193 | return nullptr; | |||
194 | } | |||
195 | ||||
196 | // Record the time of the last buffer swap so we can force a swap after a minimum period of time | |||
197 | // This ensures the user sees *something* even if they don't have enough trigger events | |||
198 | // to fill the buffer. | |||
199 | buffer->startTime.reset(timestamp); | |||
200 | buffer->nextIdx = 0; | |||
201 | ||||
202 | currentBuffer = buffer; | |||
203 | } | |||
204 | ||||
205 | return currentBuffer; | |||
206 | } | |||
207 | ||||
208 | static void SetNextCompositeEntry(efitick_t timestamp) { | |||
209 | // This is called from multiple interrupts/threads, so we need a lock. | |||
210 | chibios_rt::CriticalSectionLocker csl; | |||
211 | ||||
212 | CompositeBuffer* buffer = findBuffer(timestamp); | |||
213 | ||||
214 | if (!buffer) { | |||
215 | // All buffers are full, nothing to do here. | |||
216 | return; | |||
217 | } | |||
218 | ||||
219 | size_t idx = buffer->nextIdx; | |||
220 | auto nextIdx = idx + 1; | |||
221 | buffer->nextIdx = nextIdx; | |||
222 | ||||
223 | if (idx < efi::size(buffer->buffer)) { | |||
224 | composite_logger_s* entry = &buffer->buffer[idx]; | |||
225 | ||||
226 | uint32_t nowUs = NT2US(timestamp); | |||
227 | ||||
228 | // TS uses big endian, grumble | |||
229 | entry->timestamp = SWAP_UINT32(nowUs); | |||
230 | entry->priLevel = currentTrigger1; | |||
231 | entry->secLevel = currentTrigger2; | |||
232 | entry->trigger = currentTdc; | |||
233 | entry->sync = engine->triggerCentral.triggerState.getShaftSynchronized(); | |||
234 | entry->coil = currentCoilState; | |||
235 | entry->injector = currentInjectorState; | |||
236 | } | |||
237 | ||||
238 | // if the buffer is full... | |||
239 | bool bufferFull = nextIdx >= efi::size(buffer->buffer); | |||
240 | // ... or it's been too long since the last flush | |||
241 | bool bufferTimedOut = buffer->startTime.hasElapsedSec(5); | |||
242 | ||||
243 | // Then cycle buffers and set the ready flag. | |||
244 | if (bufferFull || bufferTimedOut) { | |||
245 | // Post to the output queue | |||
246 | filledBuffers.postI(buffer); | |||
247 | ||||
248 | // Null the current buffer so we get a new one next time | |||
249 | currentBuffer = nullptr; | |||
250 | ||||
251 | // Flag that we are ready | |||
252 | setToothLogReady(true); | |||
253 | } | |||
254 | } | |||
255 | ||||
256 | #endif // not EFI_UNIT_TEST | |||
257 | ||||
258 | #define JSON_TRG_PID 4 | |||
259 | #define JSON_CAM_PID 10 | |||
260 | ||||
261 | 2402 | void LogTriggerSync(bool isSync, efitick_t timestamp) { | ||
262 | #if EFI_UNIT_TEST | |||
263 | 2402 | jsonTraceEntry("sync", 3, /*isEnter*/isSync, timestamp); | ||
264 | #else | |||
265 | UNUSED(isSync); UNUSED(timestamp); | |||
266 | #endif | |||
267 | 2402 | } | ||
268 | ||||
269 | 3711 | void LogTriggerCamTooth(bool isRising, efitick_t timestamp, int index) { | ||
270 | #if EFI_UNIT_TEST | |||
271 | 3711 | jsonTraceEntry("cam", JSON_CAM_PID + index, /*isEnter*/isRising, timestamp); | ||
272 | #else | |||
273 | UNUSED(isRising); UNUSED(timestamp); UNUSED(index); | |||
274 | #endif | |||
275 | 3711 | } | ||
276 | ||||
277 | 74971 | void LogTriggerTooth(trigger_event_e tooth, efitick_t timestamp) { | ||
278 | #if EFI_UNIT_TEST | |||
279 |
2/2✓ Branch 0 taken 37153 times.
✓ Branch 1 taken 37818 times.
|
2/2✓ Decision 'true' taken 37153 times.
✓ Decision 'false' taken 37818 times.
|
74971 | if (tooth == SHAFT_PRIMARY_RISING) { |
280 |
1/1✓ Branch 1 taken 37153 times.
|
37153 | jsonTraceEntry("trg0", JSON_TRG_PID, /*isEnter*/true, timestamp); | |
281 |
2/2✓ Branch 0 taken 37092 times.
✓ Branch 1 taken 726 times.
|
2/2✓ Decision 'true' taken 37092 times.
✓ Decision 'false' taken 726 times.
|
37818 | } else if (tooth == SHAFT_PRIMARY_FALLING) { |
282 |
1/1✓ Branch 1 taken 37092 times.
|
37092 | jsonTraceEntry("trg0", JSON_TRG_PID, /*isEnter*/false, timestamp); | |
283 | } | |||
284 | #endif // EFI_UNIT_TEST | |||
285 | ||||
286 | efiAssertVoid(ObdCode::CUSTOM_ERR_6650, hasLotsOfRemainingStack(), "l-t-t"); | |||
287 | // bail if we aren't enabled | |||
288 |
1/2✗ Branch 0 not taken.
✓ Branch 1 taken 74971 times.
|
1/2✗ Decision 'true' not taken.
✓ Decision 'false' taken 74971 times.
|
74971 | if (!ToothLoggerEnabled) { |
289 | ✗ | return; | ||
290 | } | |||
291 | ||||
292 | // Don't log at significant engine speed | |||
293 |
2/3✓ Branch 1 taken 74971 times.
✗ Branch 3 not taken.
✓ Branch 4 taken 74971 times.
|
1/2✗ Decision 'true' not taken.
✓ Decision 'false' taken 74971 times.
|
74971 | if (!getTriggerCentral()->isEngineSnifferEnabled) { |
294 | ✗ | return; | ||
295 | } | |||
296 | ||||
297 | 74971 | ScopePerf perf(PE::LogTriggerTooth); | ||
298 | ||||
299 | /* | |||
300 | // We currently only support the primary trigger falling edge | |||
301 | // (this is the edge that VR sensors are accurate on) | |||
302 | // Since VR sensors are the most useful case here, this is okay for now. | |||
303 | if (tooth != SHAFT_PRIMARY_FALLING) { | |||
304 | return; | |||
305 | } | |||
306 | ||||
307 | uint32_t nowUs = NT2US(timestamp); | |||
308 | // 10us per LSB - this gives plenty of accuracy, yet fits 655.35 ms in to a uint16 | |||
309 | uint16_t delta = static_cast<uint16_t>((nowUs - lastEdgeTimestamp) / 10); | |||
310 | lastEdgeTimestamp = nowUs; | |||
311 | ||||
312 | SetNextEntry(delta); | |||
313 | */ | |||
314 | ||||
315 |
4/5✓ Branch 0 taken 37092 times.
✓ Branch 1 taken 37153 times.
✓ Branch 2 taken 363 times.
✓ Branch 3 taken 363 times.
✗ Branch 4 not taken.
|
74971 | switch (tooth) { | |
316 |
1/1✓ Decision 'true' taken 37092 times.
|
37092 | case SHAFT_PRIMARY_FALLING: | |
317 | 37092 | currentTrigger1 = false; | ||
318 | 37092 | break; | ||
319 |
1/1✓ Decision 'true' taken 37153 times.
|
37153 | case SHAFT_PRIMARY_RISING: | |
320 | 37153 | currentTrigger1 = true; | ||
321 | 37153 | break; | ||
322 |
1/1✓ Decision 'true' taken 363 times.
|
363 | case SHAFT_SECONDARY_FALLING: | |
323 | 363 | currentTrigger2 = false; | ||
324 | 363 | break; | ||
325 |
1/1✓ Decision 'true' taken 363 times.
|
363 | case SHAFT_SECONDARY_RISING: | |
326 | 363 | currentTrigger2 = true; | ||
327 | 363 | break; | ||
328 | ✗ | default: | ||
329 | ✗ | break; | ||
330 | } | |||
331 | ||||
332 |
1/1✓ Branch 1 taken 74971 times.
|
74971 | SetNextCompositeEntry(timestamp); | |
333 | } | |||
334 | ||||
335 | 1503 | void LogTriggerTopDeadCenter(efitick_t timestamp) { | ||
336 | // bail if we aren't enabled | |||
337 |
1/2✗ Branch 0 not taken.
✓ Branch 1 taken 1503 times.
|
1/2✗ Decision 'true' not taken.
✓ Decision 'false' taken 1503 times.
|
1503 | if (!ToothLoggerEnabled) { |
338 | ✗ | return; | ||
339 | } | |||
340 | 1503 | currentTdc = true; | ||
341 | 1503 | SetNextCompositeEntry(timestamp); | ||
342 | 1503 | currentTdc = false; | ||
343 | 1503 | SetNextCompositeEntry(timestamp + 10); | ||
344 | } | |||
345 | ||||
346 | 11645 | void LogTriggerCoilState(efitick_t timestamp, size_t index, bool state) { | ||
347 | #if EFI_UNIT_TEST | |||
348 | 11645 | jsonTraceEntry("coil", 20 + index, state, timestamp); | ||
349 | #endif // EFI_UNIT_TEST | |||
350 |
1/2✗ Branch 0 not taken.
✓ Branch 1 taken 11645 times.
|
1/2✗ Decision 'true' not taken.
✓ Decision 'false' taken 11645 times.
|
11645 | if (!ToothLoggerEnabled) { |
351 | ✗ | return; | ||
352 | } | |||
353 | 11645 | currentCoilState = state; | ||
354 | UNUSED(timestamp); UNUSED(index); | |||
355 | //SetNextCompositeEntry(timestamp, trigger1, trigger2, trigger); | |||
356 | } | |||
357 | ||||
358 | 6708 | void LogTriggerInjectorState(efitick_t timestamp, size_t index, bool state) { | ||
359 | #if EFI_UNIT_TEST | |||
360 | 6708 | jsonTraceEntry("inj", 30 + index, state, timestamp); | ||
361 | #endif // EFI_UNIT_TEST | |||
362 |
1/2✗ Branch 0 not taken.
✓ Branch 1 taken 6708 times.
|
1/2✗ Decision 'true' not taken.
✓ Decision 'false' taken 6708 times.
|
6708 | if (!ToothLoggerEnabled) { |
363 | ✗ | return; | ||
364 | } | |||
365 | 6708 | currentInjectorState = state; | ||
366 | UNUSED(timestamp); UNUSED(index); | |||
367 | //SetNextCompositeEntry(timestamp, trigger1, trigger2, trigger); | |||
368 | } | |||
369 | ||||
370 | ✗ | void EnableToothLoggerIfNotEnabled() { | ||
371 | ✗ | if (!ToothLoggerEnabled) { | ||
372 | ✗ | EnableToothLogger(); | ||
373 | } | |||
374 | ✗ | } | ||
375 | ||||
376 | ✗ | bool IsToothLoggerEnabled() { | ||
377 | ✗ | return ToothLoggerEnabled; | ||
378 | } | |||
379 | ||||
380 | #endif /* EFI_TOOTH_LOGGER */ | |||
381 |