Add os_signpost logs for render() and Workflow and Worker lifecycle #1134

AquaGeek · 2020-05-05T23:28:27Z

We are logging:

Workflow creation and destruction*
Worker creation and destruction*
Workflow render() calls
Sink events — note: The format strings specified for these does not include the "public" specifier, so they shouldn't show up in logs unless a debugger is attached. This is important, as you don't want to e.g. log password entry in text fields.

*Note: We're not instrumenting the Workflows or Workers themselves; we're instrumenting the infrastructure that gets created to hold onto them.

// If you don't subsequently render this workflow, it won't show up in Instruments:
let workflow = MyWorkflow()

AquaGeek · 2020-05-05T23:30:36Z

This is what it looks like in the Tic Tac Toe sample app:

AquaGeek · 2020-05-05T23:32:48Z

Testing failed:
	'init(subsystem:category:)' is only available in iOS 10.0 or newer
	'init(subsystem:category:)' is only available in iOS 10.0 or newer
	Testing cancelled because the build failed.

** TEST FAILED **

@dhavalshreyas Do we need to bump the spm tests to iOS 10?

JustinDSN · 2020-05-05T23:41:52Z

swift/Workflow/Sources/SubtreeManager.swift

+                .start { [weak self] event in
+                    switch event {
+                    case .value(let output):
+                        self?.handle(output: output)


Does it make sense to log an event to indicate a worker emitted a value and it's about to be handled? So you would see that the worker emitted the event, and then it was mapped and handled by a sink?

Maybe move the logging to a different function. logWorkerState(event:)?

I'm exploring using .on(…) in the stream (similar to what .logEvents does). I'll update this soon.

Did the .on(..) work out?

JustinDSN · 2020-05-05T23:43:31Z

swift/Workflow/Sources/Log.swift

+
+import os.signpost
+
+extension OSLog {


Nit: Should this file be called OSLog+Workflow or OSLog+LogSubsystems or something other than just "Log"?

JustinDSN · 2020-05-05T23:45:50Z

Sorry about the false close, I accidentally hit the button when I tried to cancel a comment.

dhavalshreyas · 2020-05-06T16:17:53Z

@dhavalshreyas Do we need to bump the spm tests to iOS 10?

Yes! Bumped it up here #1135

dhavalshreyas · 2020-05-06T16:23:21Z

This is awesome @AquaGeek! Thank you for getting this in!

dhavalshreyas · 2020-05-06T16:20:23Z

swift/Workflow/Sources/SubtreeManager.swift

+                .start { [weak self] event in
+                    switch event {
+                    case .value(let output):
+                        self?.handle(output: output)


Maybe move the logging to a different function. logWorkerState(event:)?

swift/Workflow/Sources/SubtreeManager.swift

AquaGeek · 2020-05-06T22:14:33Z

OK. Everything is on this branch now.

I think the last open question is: should we remove the event logging (i.e. sink and worker events) or make them more generic for now? One option would be to log the related Workflow/Worker type instead of the event type (as that's essentially useless, e.g. Action).

JustinDSN · 2020-05-06T22:29:44Z

OK. Everything is on this branch now.

I think the last open question is: should we remove the event logging (i.e. sink and worker events) or make them more generic for now? One option would be to log the related Workflow/Worker type instead of the event type (as that's essentially useless, e.g. Action).

I would vote for making them more generic "Action" along with a comment and a follow up task to log the more detail once we get the sign off from Mosec over removing the logging altogether.

AquaGeek · 2020-05-07T00:30:42Z

OK. Everything is on this branch now.
I think the last open question is: should we remove the event logging (i.e. sink and worker events) or make them more generic for now? One option would be to log the related Workflow/Worker type instead of the event type (as that's essentially useless, e.g. Action).

I would vote for making them more generic "Action" along with a comment and a follow up task to log the more detail once we get the sign off from Mosec over removing the logging altogether.

To clarify, when I say remove logging I mean remove event logging (for sink events and worker outputs). All the lifecycle stuff can stay.

dhavalshreyas · 2020-05-07T00:40:57Z

swift/Workflow/Sources/SubtreeManager.swift

+                .start { [weak self] event in
+                    switch event {
+                    case .value(let output):
+                        self?.handle(output: output)


Did the .on(..) work out?

dhavalshreyas · 2020-05-07T00:42:33Z

swift/Workflow/Sources/SubtreeManager.swift

@@ -204,7 +204,11 @@ extension WorkflowNode.SubtreeManager {
        func makeSink<Action>(of actionType: Action.Type) -> Sink<Action> where Action: WorkflowAction, WorkflowType == Action.WorkflowType {
            let reusableSink = sinkStore.findOrCreate(actionType: Action.self)

+            let signpostRef = NSObject()


Wonder if we should create a type which has the log... events and acts as a ref instead of creating an arbitrary object to act as ref.

🤷 I'm not overly-concerned about it. We could make the log... calls member functions instead of static functions (and use the object as the object we use to look up the signpost ID. We'd have to figure out how to plumb that object around to the various places that need it.

I think this is fine for now. Thoughts?

I meant, creating something like:

class SignpostRef: AnyObject { func log(...) }

But, this is just a nit, feel free to ship as-is!

JustinDSN · 2020-05-07T19:13:56Z

Regarding the actions, I'm fine with either way as long as someone takes DRI to try and get the approval to add them in. I think it's very valuable, and likely that we'll get approval. My vote would be to keep them in with a comment to the followup work.

…n of the event itself

AquaGeek · 2020-05-08T17:27:18Z

I changed the event logging to log the Workflow or Worker type instead of the event information.

Pros:

Can be public — we already log it with the other signposts
Easier to distinguish where an event came from (before you had to do the mapping yourself from event type -> Workflow/Worker type

Cons:

Less information

AquaGeek requested review from dhavalshreyas, timdonnelly, bencochran and JustinDSN May 5, 2020 23:28

AquaGeek added enhancement New feature or request swift Affects the Swift library. labels May 5, 2020

JustinDSN reviewed May 5, 2020

View reviewed changes

JustinDSN closed this May 5, 2020

JustinDSN reopened this May 5, 2020

dhavalshreyas reviewed May 6, 2020

View reviewed changes

JustinDSN approved these changes May 6, 2020

View reviewed changes

AquaGeek requested review from amorde and asthatrivedi May 6, 2020 22:17

AquaGeek added 6 commits May 6, 2020 15:19

Add os_signpost logs for render() and Workflow and Worker lifecycle

0443426

Rename Log.swift -> OSLog+Workflow.swift

bbd949a

Rename 'Worker Created' to 'Running'

cc261ac

Log Worker events

ebbfe08

Consolidate all the os_signpost calls

2239cc5

Rename OSLog+Workflow.swift -> WorkflowLogger.swift

935f09f

AquaGeek force-pushed the stromberg/os_signpost branch from 8a73d32 to 935f09f Compare May 6, 2020 22:22

dhavalshreyas reviewed May 7, 2020

View reviewed changes

dhavalshreyas approved these changes May 7, 2020

View reviewed changes

AquaGeek added 3 commits May 8, 2020 10:21

Change events to log the Workflow/Worker type instead of a descriptio…

169f6ff

…n of the event itself

Require status for 'worker finished' logging

7e250b0

Created a class to be used as a signpost ref instead of NSObject

8d53983

AquaGeek merged commit 18c78b4 into master May 8, 2020

AquaGeek deleted the stromberg/os_signpost branch May 8, 2020 17:35

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add os_signpost logs for render() and Workflow and Worker lifecycle #1134

Add os_signpost logs for render() and Workflow and Worker lifecycle #1134

AquaGeek commented May 5, 2020

AquaGeek commented May 5, 2020

AquaGeek commented May 5, 2020

JustinDSN May 5, 2020 •

edited

dhavalshreyas May 6, 2020

AquaGeek May 6, 2020

dhavalshreyas May 7, 2020

JustinDSN May 5, 2020

JustinDSN commented May 5, 2020

dhavalshreyas commented May 6, 2020

dhavalshreyas commented May 6, 2020

dhavalshreyas May 6, 2020

AquaGeek commented May 6, 2020 •

edited

JustinDSN commented May 6, 2020 •

edited

AquaGeek commented May 7, 2020

dhavalshreyas May 7, 2020

dhavalshreyas May 7, 2020

AquaGeek May 7, 2020

dhavalshreyas May 7, 2020

JustinDSN commented May 7, 2020

AquaGeek commented May 8, 2020

Add os_signpost logs for render() and Workflow and Worker lifecycle #1134

Add os_signpost logs for render() and Workflow and Worker lifecycle #1134

Conversation

AquaGeek commented May 5, 2020

AquaGeek commented May 5, 2020

AquaGeek commented May 5, 2020

JustinDSN May 5, 2020 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

JustinDSN commented May 5, 2020

dhavalshreyas commented May 6, 2020

dhavalshreyas commented May 6, 2020

Choose a reason for hiding this comment

AquaGeek commented May 6, 2020 • edited

JustinDSN commented May 6, 2020 • edited

AquaGeek commented May 7, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

JustinDSN commented May 7, 2020

AquaGeek commented May 8, 2020

JustinDSN May 5, 2020 •

edited

AquaGeek commented May 6, 2020 •

edited

JustinDSN commented May 6, 2020 •

edited