Implement monitoring - please review

[felixb-wix]

Capabilities we want to achieve

• Track and report outcome of operations (success/error)
• Measure and report duration of operations
• Label all reported events with operation name, plus the names of related bundle, package, and entry point
• Application-specific behavior: based on message ID and priority, route events to different infrastructure mechanisms, e.g. sentry / New Relic / etc. This layer will be implemented by application and injected into AppHost.

Proposed API

Examples

• Call an asynchronous function and report its duration and outcome:

  const saveResult = await shell.log.span(LOG_EVID_PUBLISH, () => {
     return shell.GetAPI(SaveAPI).save()
  })   

  This will wrap the promise returned by SaveAPI.save() and track its duration and outcome. It will report events of 'start' and 'finish' to application-specific logging layer. These events will be automatically labeled with related bundle/package/entry point. The app-specific logging layer will route the events to application-specific infrastructure services.

• Call a synchronous function and report its duration and outcome:

  const selection = shell.log.span(LOG_EVID_SELECT_COMP, () => {
     return shell.GetAPI(SelectionAPI).select(inputEvent)
  })   

  This will track its duration and outcome of the passed arrow function. It will report events of 'start' and 'finish' to application-specific logging layer. These events will be automatically labeled with related bundle/package/entry point. The app-specific logging layer will route the events to application-specific infrastructure services.

• Report a one-off event:

  shell.log.warning(LOG_EVID_COMP_NOT_FOUND, { compRef: myCompRef })

  This will report the event and to application-specific logging layer. The event will be automatically labeled with related bundle/package/entry point. The app-specific logging layer will route the event to application-specific infrastructure services.

Full listing

export type LogSeverity = 'debug' | 'info' | 'warning' | 'error';
export type LogSpanFlag = 'open' | 'close';

export interface HostLogger {
    event(
        severity: LogSeverity,
        source: string,
        id: string,
        keyValuePairs?: Object,
        spanFlag?: LogSpanFlag): void;
}

export interface ShellLogger {
    debug(messageId: string, keyValuePairs?: Object): void;
    info(messageId: string, keyValuePairs?: Object): void;
    warning(messageId: string, keyValuePairs?: Object): void;
    error(messageId: string, keyValuePairs?: Object): void;
    // report duration+outcome of an operation:
    span(messageId: string, keyValuePairs: Object, action: () => void): void;
    asyncSpan(messageId: string, keyValuePairs: Object, action: () => Promise<any>): void;
}

New interfaces and properties:

• HostLogger interface: the application-specific logging layer. Its responsibility is route events to application-specific infrastructure services, e.g. sentry, New Relic, etc. Main application will inject its custom HostLogger object into AppHost by passing it to createAppHost().
• ShellLogger interface: a fine-grained interface for use by packages. It will be exposed from the Shell object, as a new property named log. The ShellLogger will delegate to HostLogger of the AppHost. So basically ShellLogger is a syntactic sugar over HostLogger.  

[salickc]

@felixb-wix

const saveResult = await shell.log.span(LOG_EVID_PUBLISH, () => { return shell.GetAPI(SaveAPI).save() })

I really don't think we should place BL inside framework logging functions. Logging is part of BL and not the opposite. I also believe there will be cases where an action can start in one place and end in another, where this kind of solution won't be relevant.

What's wrong with

const save = () => {
   shell.log.start(LOG_EVID_SAVE)
   // do something
   shell.log.end(LOG_EVID_SAVE)
}

Few other questions/issues I see here:

• Where do we keep the mapping between messageId and all of the different settings we need for it?
• Is this mapping being configured on a package level (messageId to src/evid) or the entire responsive-editor?
• Part of the mapping is to define which parameters are part of the BI log and what are the defaults
• When reporting interactions to feopds we need to send a string that represents this interaction and this interaction must be explicitly specified in fedops configuration (fedops.json)
• How do we implement fedops.appLoaded()?
• How do we implement fedops.reportLoadingPhase('phase-name')?

[felixb-wix]

@salickc

What I planned was this:

shell.log.start(LOG_EVID_SAVE)
try {
   // do something
   shell.log.end(LOG_EVID_SAVE, true)
} catch (err) {
   shell.log.end(LOG_EVID_SAVE, false, err)
}

So basically I am trying to reduce 6 lines of boilerplate to 3. I agree that it is good to have shell.log.start() and shell.log.end(), so we also cover the case where start and end are in different places in code.

Where do we keep the mapping between messageId and all of the different settings we need for it? Is this mapping being configured on a package level (messageId to src/evid) or the entire responsive-editor?

We'll create a new npm package (library) we'll name repluggable-wix. Its responsibility will be adaptation of repluggable's abstractions to specifics of Wix. For instance, it will implement HostLogger. I think we want to define a convention of namespace in message IDs, e.g. BI/save or SYS/render. We'll be able to apply event settings and routes on namespace level, rather than for each individual event. The namespaces will be well-known and defined in repluggable-wix. This should be a good default. We can also allow settings/routes for individual events, as an advanced use case.

Part of the mapping is to define which parameters are part of the BI log and what are the defaults When reporting interactions to feopds we need to send a string that represents this interaction and this interaction must be explicitly specified in fedops configuration (fedops.json)

We'll take care of these in repluggable-wix.

How do we implement fedops.appLoaded()?

I think AppHost will log a predefined event like SYS/app-loaded -- I'll learn more about fedops.appLoaded() and give an answer.

How do we implement fedops.reportLoadingPhase('phase-name')?

I think that AppHost will log predefined events at different phases of initialization, and HostLogger in repluggable-wix will take care of these. I'll learn more about fedops.reportLoadingPhase('phase-name') and provide a more complete answer.

[salickc]

@felixb-wix

So basically I am trying to reduce 6 lines of boilerplate to 3. I agree that it is good to have shell.log.start() and shell.log.end(), so we also cover the case where start and end are in different places in code.

Understand completely, but placing BL into logging functions seems like an overkill. In addition, I don't think we're going to have that many interactions we're going to monitor. If you want to reduce boilerplate how about using decorators?

@measure('interaction-name')
function syncOperation(): void {
///
}

@measureAsync('interaction-name')
function asyncOperation(): Promise<void> {
///
}

We'll create a new npm package (library) we'll name repluggable-wix. Its responsibility will be adaptation of repluggable's abstractions to specifics of Wix. For instance, it will implement HostLogger. I think we want to define a convention of namespace in message IDs, e.g. BI/save or SYS/render. We'll be able to apply event settings and routes on namespace level, rather than for each individual event. The namespaces will be well-known and defined in repluggable-wix. This should be a good default. We can also allow settings/routes for individual events, as an advanced use case.

Does this mean that if we'll want to add a new BI event in a panel we'll need to GA 2 artifacts: the panel's and the one containing the mapping?

[felixb-wix]

@salickc

OK, I see what you mean - lets agree on shell.log.start() and shell.log.end(). We can also use decorators (although they require classes AFAIK?)

Does this mean that if we'll want to add a new BI event in a panel we'll need to GA 2 artifacts: the panel's and the one containing the mapping?

Only in a rare case when a new namespace has to be defined. Most of the time messages will belong to existing namespaces. We'll also allow settings per specific message to be defined by a package, or even passed ad-hoc to shell.log.*. So it should be very rare, similarly to when we add a new bundle to responsive-editor list.

[salickc]

We can also use decorators (although they require classes AFAIK?)

Yes, you can decorate classes or class methods/objects

[alexandre-roitman]

Hi, I think we are missing the following objectives: 1 - ability to track and differentiate all errors/exceptions thrown across the application 2 - ability to track old/new errors per release

Regarding fedops and user interactions:

In addition, I don't think we're going to have that many interactions we're going to monitor.

@salickc I don't agree - in principle we want to aim to monitor EVERY user interaction possible just as we did in santa-editor - @BenPorat can attest on how easy it is to identify issues that way (see santa-editor fedops here: https://grafana.wixpress.com/d/3a3WtpIiz/auto-fedops-santa-editor)

lets agree on shell.log.start() and shell.log.end()

@felixb-wix when measuring user interactions the start should be as close as possible to the event handler (click, keypress, etc) and the end should be wherever the developer of the feature thinks that it is enough that the code reached that point in order for it to be considered a "working flow". I'm not sure we can wrap automatically since the developer of the feature has a decision to make here by himself and he knows best how the feature works.

Regarding BI events: Where are we defining the source, esi, site id, etc that are parameters that should be sent with every event?

[felixb-wix]

@alexandre-roitman

1 - ability to track and differentiate all errors/exceptions thrown across the application

We will label all logged events with entry point/package/bundle. If it's inside an API call, the event will also has an API label (see "API monitoring" I'll post below separately).

ability to track old/new errors per release

This is a feature of sentry, IMO. In addition, some of reported events will map to KPIs (technical and business). The KPIs will be monitored by comparison during rollout (for example by detonomy). Our goal is primarily enriching reported errors with all the necessary labels.

Where are we defining the source, esi, site id, etc that are parameters that should be sent with every event?

WixHostLogger from repluggable-wix will enrich all reported events with global labels. Parameters specific to events will be defined in application-specific logger interfaces (see "App Loggers" that I'll post below separately).

[felixb-wix]

API monitoring

We want to be able to monitor all API calls, e.g. shell.getAPI(someAPI).doSomething(...). This can be great help during root cause analysis, and also it will make easy for API authors to understand their APIs usage in production. Since API monitoring is a cross-cutting concern, we want it to happen on infrastructure level, not in application code.

Implementation: in shell.getAPI(someAPI).doSomething(...) the doSomething will actually be a proxy that intercepts calls for logging, and wraps returned promises, if any. API proxy will report all events to HostLogger. For instance, WixHostLogger will be able to report breadcrumbs and errors to sentry.

Later we may use API proxy for more aspects, such as authorization.

[felixb-wix]

App Loggers

Formalizing logged events greatly helps in later analysis. We want to make sure that every place in code that reports an event, includes all required parameters with it. We also want to make it easy for a developer who wants to report an event, to know which parameters are expected.

Proposal: application-specific loggers:

export interface CompPanelLogger {
    //...

    maxScrollPanel(maxScroll: number, panelTotalScrollPx: number, panelName: string)

    //...
}

Loggers can be contributed as APIs (should it be named CompPanelLoggerAPI?). So that code that logs an event will look like this:

// in mapDispatchToProps
{
    compPanelLogger: shell.getAPI(CompPanelLogger)
}

// in pure component
this.props.compPanelLogger.maxScrollPanel(
    this.panelMaximumScroll,
    this.panelTotalScrollInPixels,
    this.props.panelName);

The implementation of the logger will use shell.log.event() to send events, like this:

function maxScrollPanel(maxScroll: number, panelTotalScrollPx: number, panelName: string) {
    _this.shell.log.event(
        'BI/MAX_SCROLL_PANEL',
        {
            evid: 795,
            fields: {
                max_scroll: maxScroll,
                panel_total_scroll_px: panelTotalScrollPx,
                panel_name: panelName
            }
        }
    )
}

App loggers will be generated by a tool, based on JSON that describes events. Every package will have JSON of relevant events. The JSON should be in existing format, so we can copy it, for example from Classic editor:

{
    "MAX_SCROLL_PANEL": {
        "evid": 795,
        "fields": {
             "max_scroll": "numeric",
             "panel_total_scroll_px": "numeric",
             "panel_name": "string"
         } 
    }
}

[salickc]

@felixb-wix

App loggers will be generated by a tool, based on JSON that describes events. Every package will have JSON of relevant events. The JSON should be in existing format, so we can copy it, for example from Classic editor:

I think that our JSON should be based on the actual raw JSON format that is being generated by Wix's BI catalog. It will make the addition/modification of events super simple. That's how we do it in ADI and it's proven to be friction-less.

Another concern that we need to address is default getters. There a lot of parameters that repeat themselves in multiple events and we can avoid passing them to each log function. For example, metasiteId is a parameter that will exist on almost every event schema, so it will be redundant to pass it on each logger function. The proper way would be to define for each parameter a default implementation that retrieves it's value. This behaviour is also supported by Wix's BI Logger.