Add os_signpost logs for render() and Workflow and Worker lifecycle by AquaGeek · Pull Request #1134 · square/workflow

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

+                .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

+
+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

+                .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:)?

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

+                .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

        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 JustinDSN, bencochran, dhavalshreyas and timdonnelly 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


		import os.signpost

		extension OSLog {

Conversation

AquaGeek commented May 5, 2020

Uh oh!

AquaGeek commented May 5, 2020

Uh oh!

AquaGeek commented May 5, 2020

Uh oh!

JustinDSN May 5, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

JustinDSN commented May 5, 2020

Uh oh!

dhavalshreyas commented May 6, 2020

Uh oh!

dhavalshreyas commented May 6, 2020

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

AquaGeek commented May 6, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

JustinDSN commented May 6, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

AquaGeek commented May 7, 2020

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

JustinDSN commented May 7, 2020

Uh oh!

AquaGeek commented May 8, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

JustinDSN May 5, 2020 •

edited

Loading

AquaGeek commented May 6, 2020 •

edited

Loading

JustinDSN commented May 6, 2020 •

edited

Loading