Actual source code: lognested.c

  1: #include <petscviewer.h>
  2: #include "lognested.h"

  4: PETSC_INTERN PetscErrorCode PetscLogHandlerNestedSetThreshold(PetscLogHandler h, PetscLogDouble newThresh, PetscLogDouble *oldThresh)
  5: {
  6:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)h->data;

  8:   PetscFunctionBegin;
  9:   if (oldThresh) *oldThresh = nested->threshold;
 10:   if (newThresh == (PetscLogDouble)PETSC_DECIDE) newThresh = 0.01;
 11:   if (newThresh == (PetscLogDouble)PETSC_DEFAULT) newThresh = 0.01;
 12:   nested->threshold = PetscMax(newThresh, 0.0);
 13:   PetscFunctionReturn(PETSC_SUCCESS);
 14: }

 16: static PetscErrorCode PetscLogEventGetNestedEvent(PetscLogHandler h, PetscLogEvent e, PetscLogEvent *nested_event)
 17: {
 18:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)h->data;
 19:   NestedIdPair           key;
 20:   PetscHashIter          iter;
 21:   PetscBool              missing;
 22:   PetscLogState          state;

 24:   PetscFunctionBegin;
 25:   PetscCall(PetscLogHandlerGetState(h, &state));
 26:   PetscCall(PetscIntStackTop(nested->nested_stack, &key.root));
 27:   key.leaf = NestedIdFromEvent(e);
 28:   PetscCall(PetscNestedHashPut(nested->pair_map, key, &iter, &missing));
 29:   if (missing) {
 30:     // register a new nested event
 31:     char              name[BUFSIZ];
 32:     PetscLogEventInfo event_info;
 33:     PetscLogEventInfo nested_event_info;

 35:     PetscCall(PetscLogStateEventGetInfo(state, e, &event_info));
 36:     PetscCall(PetscLogStateEventGetInfo(nested->state, key.root, &nested_event_info));
 37:     PetscCall(PetscSNPrintf(name, sizeof(name) - 1, "%s;%s", nested_event_info.name, event_info.name));
 38:     PetscCall(PetscLogStateEventRegister(nested->state, name, event_info.classid, nested_event));
 39:     PetscCall(PetscLogStateEventSetCollective(nested->state, *nested_event, event_info.collective));
 40:     PetscCall(PetscNestedHashIterSet(nested->pair_map, iter, *nested_event));
 41:   } else {
 42:     PetscCall(PetscNestedHashIterGet(nested->pair_map, iter, nested_event));
 43:   }
 44:   PetscFunctionReturn(PETSC_SUCCESS);
 45: }

 47: static PetscErrorCode PetscLogStageGetNestedEvent(PetscLogHandler h, PetscLogStage stage, PetscLogEvent *nested_event)
 48: {
 49:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)h->data;
 50:   NestedIdPair           key;
 51:   PetscHashIter          iter;
 52:   PetscBool              missing;
 53:   PetscLogState          state;

 55:   PetscFunctionBegin;
 56:   PetscCall(PetscLogHandlerGetState(h, &state));
 57:   PetscCall(PetscIntStackTop(nested->nested_stack, &key.root));
 58:   key.leaf = NestedIdFromStage(stage);
 59:   PetscCall(PetscNestedHashPut(nested->pair_map, key, &iter, &missing));
 60:   if (missing) {
 61:     PetscLogStageInfo stage_info;
 62:     char              name[BUFSIZ];
 63:     PetscBool         collective = PETSC_TRUE;

 65:     PetscCall(PetscLogStateStageGetInfo(state, stage, &stage_info));
 66:     if (key.root >= 0) {
 67:       PetscLogEventInfo nested_event_info;

 69:       PetscCall(PetscLogStateEventGetInfo(nested->state, key.root, &nested_event_info));
 70:       PetscCall(PetscSNPrintf(name, sizeof(name) - 1, "%s;%s", nested_event_info.name, stage_info.name));
 71:       collective = nested_event_info.collective;
 72:     } else {
 73:       PetscCall(PetscSNPrintf(name, sizeof(name) - 1, "%s", stage_info.name));
 74:     }
 75:     PetscCall(PetscLogStateEventRegister(nested->state, name, nested->nested_stage_id, nested_event));
 76:     PetscCall(PetscLogStateEventSetCollective(nested->state, *nested_event, collective));
 77:     PetscCall(PetscNestedHashIterSet(nested->pair_map, iter, *nested_event));
 78:   } else {
 79:     PetscCall(PetscNestedHashIterGet(nested->pair_map, iter, nested_event));
 80:   }
 81:   PetscFunctionReturn(PETSC_SUCCESS);
 82: }

 84: static PetscErrorCode PetscLogNestedFindNestedId(PetscLogHandler h, NestedId orig_id, PetscInt *pop_count)
 85: {
 86:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)h->data;
 87:   PetscInt               count, i;

 89:   PetscFunctionBegin;
 90:   // stop before zero cause there is a null event at the bottom of the stack
 91:   for (i = nested->orig_stack->top, count = 0; i > 0; i--) {
 92:     count++;
 93:     if (nested->orig_stack->stack[i] == orig_id) break;
 94:   }
 95:   *pop_count = count;
 96:   if (count == 1) PetscFunctionReturn(PETSC_SUCCESS); // Normal function, just the top of the stack is being popped.
 97:   if (orig_id > 0) {
 98:     PetscLogEvent     event_id = NestedIdToEvent(orig_id);
 99:     PetscLogState     state;
100:     PetscLogEventInfo event_info;

102:     PetscCall(PetscLogHandlerGetState(h, &state));
103:     PetscCall(PetscLogStateEventGetInfo(state, event_id, &event_info));
104:     PetscCheck(i > 0, PETSC_COMM_SELF, PETSC_ERR_ARG_WRONGSTATE, "Tried to end event %s, but it is not in the event stack", event_info.name);
105:   } else {
106:     PetscLogStage     stage_id = NestedIdToStage(orig_id);
107:     PetscLogState     state;
108:     PetscLogStageInfo stage_info;

110:     PetscCall(PetscLogHandlerGetState(h, &state));
111:     PetscCall(PetscLogStateStageGetInfo(state, stage_id, &stage_info));
112:     PetscCheck(i > 0, PETSC_COMM_SELF, PETSC_ERR_ARG_WRONGSTATE, "Tried to pop stage %s, but it is not in the stage stack", stage_info.name);
113:   }
114:   PetscFunctionReturn(PETSC_SUCCESS);
115: }

117: static PetscErrorCode PetscLogNestedCheckNested(PetscLogHandler h, NestedId leaf, PetscLogEvent nested_event)
118: {
119:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)h->data;
120:   NestedIdPair           key;
121:   NestedId               val;

123:   PetscFunctionBegin;
124:   PetscCall(PetscIntStackTop(nested->nested_stack, &key.root));
125:   key.leaf = leaf;
126:   PetscCall(PetscNestedHashGet(nested->pair_map, key, &val));
127:   PetscCheck(val == nested_event, PETSC_COMM_SELF, PETSC_ERR_ARG_WRONGSTATE, "Logging events and stages are not nested, nested logging cannot be used");
128:   PetscFunctionReturn(PETSC_SUCCESS);
129: }

131: static PetscErrorCode PetscLogHandlerEventBegin_Nested(PetscLogHandler h, PetscLogEvent e, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
132: {
133:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)h->data;
134:   PetscLogEvent          nested_event;

136:   PetscFunctionBegin;
137:   PetscCall(PetscLogEventGetNestedEvent(h, e, &nested_event));
138:   PetscCall(PetscLogHandlerEventBegin(nested->handler, nested_event, o1, o2, o3, o4));
139:   PetscCall(PetscIntStackPush(nested->nested_stack, nested_event));
140:   PetscCall(PetscIntStackPush(nested->orig_stack, NestedIdFromEvent(e)));
141:   PetscFunctionReturn(PETSC_SUCCESS);
142: }

144: static PetscErrorCode PetscLogHandlerNestedEventEnd(PetscLogHandler h, NestedId id, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
145: {
146:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)h->data;
147:   PetscInt               pop_count;

149:   PetscFunctionBegin;
150:   PetscCall(PetscLogNestedFindNestedId(h, id, &pop_count));
151:   for (PetscInt c = 0; c < pop_count; c++) {
152:     PetscLogEvent nested_event;
153:     PetscLogEvent nested_id;

155:     PetscCall(PetscIntStackPop(nested->nested_stack, &nested_event));
156:     PetscCall(PetscIntStackPop(nested->orig_stack, &nested_id));
157:     if (PetscDefined(USE_DEBUG)) PetscCall(PetscLogNestedCheckNested(h, nested_id, nested_event));
158:     if ((pop_count > 1) && (c + 1 < pop_count)) {
159:       if (nested_id > 0) {
160:         PetscLogEvent     event_id = NestedIdToEvent(nested_id);
161:         PetscLogState     state;
162:         PetscLogEventInfo event_info;

164:         PetscCall(PetscLogHandlerGetState(h, &state));
165:         PetscCall(PetscLogStateEventGetInfo(state, event_id, &event_info));
166:         PetscCall(PetscInfo(h, "Log event %s wasn't ended, ending it to maintain stack property for nested log handler\n", event_info.name));
167:       }
168:     }
169:     PetscCall(PetscLogHandlerEventEnd(nested->handler, nested_event, o1, o2, o3, o4));
170:   }
171:   PetscFunctionReturn(PETSC_SUCCESS);
172: }

174: static PetscErrorCode PetscLogHandlerEventEnd_Nested(PetscLogHandler h, PetscLogEvent e, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
175: {
176:   PetscFunctionBegin;
177:   PetscCall(PetscLogHandlerNestedEventEnd(h, NestedIdFromEvent(e), o1, o2, o3, o4));
178:   PetscFunctionReturn(PETSC_SUCCESS);
179: }

181: static PetscErrorCode PetscLogHandlerEventSync_Nested(PetscLogHandler h, PetscLogEvent e, MPI_Comm comm)
182: {
183:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)h->data;
184:   PetscLogEvent          nested_event;

186:   PetscFunctionBegin;
187:   PetscCall(PetscLogEventGetNestedEvent(h, e, &nested_event));
188:   PetscCall(PetscLogHandlerEventSync(nested->handler, nested_event, comm));
189:   PetscFunctionReturn(PETSC_SUCCESS);
190: }

192: static PetscErrorCode PetscLogHandlerStagePush_Nested(PetscLogHandler h, PetscLogStage stage)
193: {
194:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)h->data;
195:   PetscLogEvent          nested_event;

197:   PetscFunctionBegin;
198:   if (nested->nested_stage_id == -1) PetscCall(PetscClassIdRegister("LogNestedStage", &nested->nested_stage_id));
199:   PetscCall(PetscLogStageGetNestedEvent(h, stage, &nested_event));
200:   PetscCall(PetscLogHandlerEventBegin(nested->handler, nested_event, NULL, NULL, NULL, NULL));
201:   PetscCall(PetscIntStackPush(nested->nested_stack, nested_event));
202:   PetscCall(PetscIntStackPush(nested->orig_stack, NestedIdFromStage(stage)));
203:   PetscFunctionReturn(PETSC_SUCCESS);
204: }

206: static PetscErrorCode PetscLogHandlerStagePop_Nested(PetscLogHandler h, PetscLogStage stage)
207: {
208:   PetscFunctionBegin;
209:   PetscCall(PetscLogHandlerNestedEventEnd(h, NestedIdFromStage(stage), NULL, NULL, NULL, NULL));
210:   PetscFunctionReturn(PETSC_SUCCESS);
211: }

213: static PetscErrorCode PetscLogHandlerContextCreate_Nested(MPI_Comm comm, PetscLogHandler_Nested *nested_p)
214: {
215:   PetscLogStage          root_stage;
216:   PetscLogHandler_Nested nested;

218:   PetscFunctionBegin;
219:   PetscCall(PetscNew(nested_p));
220:   nested = *nested_p;
221:   PetscCall(PetscLogStateCreate(&nested->state));
222:   PetscCall(PetscIntStackCreate(&nested->nested_stack));
223:   PetscCall(PetscIntStackCreate(&nested->orig_stack));
224:   nested->nested_stage_id = -1;
225:   nested->threshold       = 0.01;
226:   PetscCall(PetscNestedHashCreate(&nested->pair_map));
227:   PetscCall(PetscLogHandlerCreate(comm, &nested->handler));
228:   PetscCall(PetscLogHandlerSetType(nested->handler, PETSCLOGHANDLERDEFAULT));
229:   PetscCall(PetscLogHandlerSetState(nested->handler, nested->state));
230:   PetscCall(PetscLogStateStageRegister(nested->state, "", &root_stage));
231:   PetscAssert(root_stage == 0, PETSC_COMM_SELF, PETSC_ERR_PLIB, "root stage not zero");
232:   PetscCall(PetscLogHandlerStagePush(nested->handler, root_stage));
233:   PetscCall(PetscLogStateStagePush(nested->state, root_stage));
234:   PetscCall(PetscIntStackPush(nested->nested_stack, -1));
235:   PetscCall(PetscIntStackPush(nested->orig_stack, -1));
236:   PetscFunctionReturn(PETSC_SUCCESS);
237: }

239: PETSC_PRAGMA_DIAGNOSTIC_IGNORED_BEGIN("-Wconversion")
240: static PetscErrorCode PetscLogHandlerObjectCreate_Nested(PetscLogHandler h, PetscObject obj)
241: {
242:   PetscClassId           classid;
243:   PetscInt               num_registered, num_nested_registered;
244:   PetscLogState          state;
245:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)h->data;

247:   PetscFunctionBegin;
248:   // register missing objects
249:   PetscCall(PetscObjectGetClassId(obj, &classid));
250:   PetscCall(PetscLogHandlerGetState(h, &state));
251:   PetscCall(PetscLogStateGetNumClasses(nested->state, &num_nested_registered));
252:   PetscCall(PetscLogStateGetNumClasses(state, &num_registered));
253:   for (PetscLogClass c = num_nested_registered; c < num_registered; c++) {
254:     PetscLogClassInfo class_info;
255:     PetscLogClass     nested_c;

257:     PetscCall(PetscLogStateClassGetInfo(state, c, &class_info));
258:     PetscCall(PetscLogStateClassRegister(nested->state, class_info.name, class_info.classid, &nested_c));
259:   }
260:   PetscCall(PetscLogHandlerObjectCreate(nested->handler, obj));
261:   PetscFunctionReturn(PETSC_SUCCESS);
262: }

264: static PetscErrorCode PetscLogHandlerObjectDestroy_Nested(PetscLogHandler h, PetscObject obj)
265: {
266:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)h->data;

268:   PetscFunctionBegin;
269:   PetscCall(PetscLogHandlerObjectDestroy(nested->handler, obj));
270:   PetscFunctionReturn(PETSC_SUCCESS);
271: }

273: static PetscErrorCode PetscLogHandlerDestroy_Nested(PetscLogHandler h)
274: {
275:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)h->data;

277:   PetscFunctionBegin;
278:   PetscCall(PetscLogStateStagePop(nested->state));
279:   PetscCall(PetscLogHandlerStagePop(nested->handler, 0));
280:   PetscCall(PetscLogStateDestroy(&nested->state));
281:   PetscCall(PetscIntStackDestroy(nested->nested_stack));
282:   PetscCall(PetscIntStackDestroy(nested->orig_stack));
283:   PetscCall(PetscNestedHashDestroy(&nested->pair_map));
284:   PetscCall(PetscLogHandlerDestroy(&nested->handler));
285:   PetscCall(PetscFree(nested));
286:   PetscFunctionReturn(PETSC_SUCCESS);
287: }

289: static PetscErrorCode PetscLogNestedEventNodesOrderDepthFirst(PetscInt num_nodes, PetscInt parent, PetscNestedEventNode tree[], PetscInt *num_descendants)
290: {
291:   PetscInt node, start_loc;

293:   PetscFunctionBegin;
294:   node      = 0;
295:   start_loc = 0;
296:   while (node < num_nodes) {
297:     if (tree[node].parent == parent) {
298:       PetscInt             num_this_descendants = 0;
299:       PetscNestedEventNode tmp                  = tree[start_loc];
300:       tree[start_loc]                           = tree[node];
301:       tree[node]                                = tmp;
302:       PetscCall(PetscLogNestedEventNodesOrderDepthFirst(num_nodes - start_loc - 1, tree[start_loc].id, &tree[start_loc + 1], &num_this_descendants));
303:       tree[start_loc].num_descendants = num_this_descendants;
304:       *num_descendants += 1 + num_this_descendants;
305:       start_loc += 1 + num_this_descendants;
306:       node = start_loc;
307:     } else {
308:       node++;
309:     }
310:   }
311:   PetscFunctionReturn(PETSC_SUCCESS);
312: }

314: static PetscErrorCode PetscLogNestedCreatePerfNodes(MPI_Comm comm, PetscLogHandler_Nested nested, PetscLogGlobalNames global_events, PetscNestedEventNode **tree_p, PetscEventPerfInfo **perf_p)
315: {
316:   PetscMPIInt           size;
317:   PetscInt              num_nodes;
318:   PetscInt              num_map_entries;
319:   PetscEventPerfInfo   *perf;
320:   NestedIdPair         *keys;
321:   NestedId             *vals;
322:   PetscInt              offset;
323:   PetscInt              num_descendants;
324:   PetscNestedEventNode *tree;

326:   PetscFunctionBegin;
327:   PetscCall(PetscLogGlobalNamesGetSize(global_events, NULL, &num_nodes));
328:   PetscCall(PetscCalloc1(num_nodes, &tree));
329:   for (PetscInt node = 0; node < num_nodes; node++) {
330:     tree[node].id = node;
331:     PetscCall(PetscLogGlobalNamesGlobalGetName(global_events, node, &tree[node].name));
332:     tree[node].parent = -1;
333:   }
334:   PetscCall(PetscNestedHashGetSize(nested->pair_map, &num_map_entries));
335:   PetscCall(PetscMalloc2(num_map_entries, &keys, num_map_entries, &vals));
336:   offset = 0;
337:   PetscCall(PetscNestedHashGetPairs(nested->pair_map, &offset, keys, vals));
338:   for (PetscInt k = 0; k < num_map_entries; k++) {
339:     NestedId root_local = keys[k].root;
340:     NestedId leaf_local = vals[k];
341:     PetscInt root_global;
342:     PetscInt leaf_global;

344:     PetscCall(PetscLogGlobalNamesLocalGetGlobal(global_events, leaf_local, &leaf_global));
345:     if (root_local >= 0) {
346:       PetscCall(PetscLogGlobalNamesLocalGetGlobal(global_events, root_local, &root_global));
347:       tree[leaf_global].parent = root_global;
348:     }
349:   }
350:   PetscCall(PetscFree2(keys, vals));
351:   PetscCallMPI(MPI_Comm_size(comm, &size));
352:   if (size > 1) { // get missing parents from other processes
353:     PetscInt *parents;

355:     PetscCall(PetscMalloc1(num_nodes, &parents));
356:     for (PetscInt node = 0; node < num_nodes; node++) parents[node] = tree[node].parent;
357:     PetscCallMPI(MPIU_Allreduce(MPI_IN_PLACE, parents, num_nodes, MPIU_INT, MPI_MAX, comm));
358:     for (PetscInt node = 0; node < num_nodes; node++) tree[node].parent = parents[node];
359:     PetscCall(PetscFree(parents));
360:   }

362:   num_descendants = 0;
363:   PetscCall(PetscLogNestedEventNodesOrderDepthFirst(num_nodes, -1, tree, &num_descendants));
364:   PetscAssert(num_descendants == num_nodes, comm, PETSC_ERR_PLIB, "Failed tree ordering invariant");

366:   PetscCall(PetscCalloc1(num_nodes, &perf));
367:   for (PetscInt tree_node = 0; tree_node < num_nodes; tree_node++) {
368:     PetscInt global_id = tree[tree_node].id;
369:     PetscInt event_id;

371:     PetscCall(PetscLogGlobalNamesGlobalGetLocal(global_events, global_id, &event_id));
372:     if (event_id >= 0) {
373:       PetscEventPerfInfo *event_info;

375:       PetscCall(PetscLogHandlerGetEventPerfInfo(nested->handler, 0, event_id, &event_info));
376:       perf[tree_node] = *event_info;
377:     } else {
378:       PetscCall(PetscArrayzero(&perf[tree_node], 1));
379:     }
380:   }
381:   *tree_p = tree;
382:   *perf_p = perf;
383:   PetscFunctionReturn(PETSC_SUCCESS);
384: }
385: PETSC_PRAGMA_DIAGNOSTIC_IGNORED_END()

387: static PetscErrorCode PetscLogHandlerView_Nested(PetscLogHandler handler, PetscViewer viewer)
388: {
389:   PetscLogHandler_Nested nested = (PetscLogHandler_Nested)handler->data;
390:   PetscNestedEventNode  *nodes;
391:   PetscEventPerfInfo    *perf;
392:   PetscLogGlobalNames    global_events;
393:   PetscNestedEventTree   tree;
394:   PetscViewerFormat      format;
395:   MPI_Comm               comm = PetscObjectComm((PetscObject)viewer);

397:   PetscFunctionBegin;
398:   PetscCall(PetscLogRegistryCreateGlobalEventNames(comm, nested->state->registry, &global_events));
399:   PetscCall(PetscLogNestedCreatePerfNodes(comm, nested, global_events, &nodes, &perf));
400:   tree.comm          = comm;
401:   tree.global_events = global_events;
402:   tree.perf          = perf;
403:   tree.nodes         = nodes;
404:   PetscCall(PetscViewerGetFormat(viewer, &format));
405:   if (format == PETSC_VIEWER_ASCII_XML) {
406:     PetscCall(PetscLogHandlerView_Nested_XML(nested, &tree, viewer));
407:   } else if (format == PETSC_VIEWER_ASCII_FLAMEGRAPH) {
408:     PetscCall(PetscLogHandlerView_Nested_Flamegraph(nested, &tree, viewer));
409:   } else SETERRQ(comm, PETSC_ERR_ARG_INCOMP, "No nested viewer for this format");
410:   PetscCall(PetscLogGlobalNamesDestroy(&global_events));
411:   PetscCall(PetscFree(tree.nodes));
412:   PetscCall(PetscFree(tree.perf));
413:   PetscFunctionReturn(PETSC_SUCCESS);
414: }

416: /*MC
417:   PETSCLOGHANDLERNESTED - PETSCLOGHANDLERNESTED = "nested" -  A `PetscLogHandler` that collects data for PETSc's
418:   XML and flamegraph profiling log viewers.  A log handler of this type is created and started by
419:   by `PetscLogNestedBegin()`.

421:   Level: developer

423: .seealso: [](ch_profiling), `PetscLogHandler`
424: M*/

426: PETSC_INTERN PetscErrorCode PetscLogHandlerCreate_Nested(PetscLogHandler handler)
427: {
428:   PetscFunctionBegin;
429:   PetscCall(PetscLogHandlerContextCreate_Nested(PetscObjectComm((PetscObject)handler), (PetscLogHandler_Nested *)&handler->data));
430:   handler->ops->destroy       = PetscLogHandlerDestroy_Nested;
431:   handler->ops->stagepush     = PetscLogHandlerStagePush_Nested;
432:   handler->ops->stagepop      = PetscLogHandlerStagePop_Nested;
433:   handler->ops->eventbegin    = PetscLogHandlerEventBegin_Nested;
434:   handler->ops->eventend      = PetscLogHandlerEventEnd_Nested;
435:   handler->ops->eventsync     = PetscLogHandlerEventSync_Nested;
436:   handler->ops->objectcreate  = PetscLogHandlerObjectCreate_Nested;
437:   handler->ops->objectdestroy = PetscLogHandlerObjectDestroy_Nested;
438:   handler->ops->view          = PetscLogHandlerView_Nested;
439:   PetscFunctionReturn(PETSC_SUCCESS);
440: }