Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merge MutableLoggerFactory and LoggingService. #21879

Merged

Conversation

azasypkin
Copy link
Member

@azasypkin azasypkin commented Aug 10, 2018

Having both MutableLoggerFactory and LoggingService brings unnecessary complexity, LoggingService seems to be the good candidate to manage loggers.

I also tried to rework Root's config updates management code (will become a bit cleaner once we start using RxJS directly).

Blocked by #21831
Unblocks #19994

@azasypkin azasypkin added blocked Team:Core Core services & architecture: plugins, logging, config, saved objects, http, ES client, i18n, etc Feature:New Platform v6.5.0 labels Aug 10, 2018
// We should try to upgrade logger as soon as the root starts and shut root
// down if we can't do that, and subscribe to the consequent updates only if
// initial upgrade succeeded.
const config$ = this.configService.atPath('logging', LoggingConfig);
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

note: It would be great if we can define the reference approach for things like that: block on first emission and then just listen. Or maybe I'm looking at it from the wrong angle... Please, let me know what you think.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I really hope that we don't have to do this type of thing in many places. I see the logging service as a special case because we want it to exist very early, we want its API to be synchronous, we want to know that when we call log.error() we can call process.exit() on the next line and the user will see the error (when possible), and we want it to be reactive to configuration changes without ever being recreated. I hope that in most other cases we can rely on mapping configuration to new instances of services when config changes rather than the complicated state management we have had to put into the logging service to make all this possible.

I would like to propose an alternative approach to what you have here though.

I think it makes a little more sense for this to use observable constructs as much as possible and only use promises when necessary, which lead me to two implementations that I'm struggling to pick between. Both implementations have a couple things going for them though:

  • There is never a point where we are unsubscribe from config updates, so even if a second update is sent synchronously it will be applied to the loggingService (current implementation would skip() it).
  • a call to this.stop() while this.setupLogging() is waiting for something will cause its promise to never resolve or reject, rather than having somewhat undefined behavior. Currently this can only happen if something calls stop() before the start() promise resolves, which has all sorts of other undefined effects, so not a big improvement.

personal favorite, but ConnectableObservable will probably confuse most readers:

private async setupLogging() {
  // stream that maps config updates to logging updates, including update failures
  const update$ = this.configService.atPath('logging', LoggingConfig).pipe(
    map(config => {
      this.loggingService.upgrade(config);
    }),
    tap({
      error: error => {
        // This specifically console.logs because we were not able to configure the logger.
        // tslint:disable-next-line no-console
        console.error('Configuring logger failed:', error);
      },
    }),
    publishReplay(1)
  ) as ConnectableObservable<void>;

  // connect update$ so that it will be subscribed and begins updating the logging service
  this.loggingConfigSubscription = update$.connect();

  // wait for the first update to complete, if it fails this will throw
  await update$.pipe(first()).toPromise();

  // send subsequent update failures to this.shutdown(), stopped via loggingConfigSubscription
  this.loggingConfigSubscription.add(
    update$.subscribe({
      error: error => {
        this.shutdown(error);
      },
    })
  );
}

pretty straightforward approach, can't think of any drawbacks:

private async setupLogging() {
  return new Promise<void>((resolve, reject) => {
    let firstUpgradeComplete = false;

    this.loggingConfigSubscription = this.configService
      .atPath('logging', LoggingConfig)
      .pipe(
        tap(config => {
          this.loggingService.upgrade(config);

          if (!firstUpgradeComplete) {
            // resolve our promise if the first upgrade is successfull
            firstUpgradeComplete = true;
            resolve();
          }
        })
      )
      .subscribe({
        error: error => {
          // This specifically console.logs because we were not able to configure the logger.
          // tslint:disable-next-line no-console
          console.error('Configuring logger failed:', error);

          if (!initialUpgradeComplete) {
            // reject the promise rather than shutting down if the first upgrade is unsuccessful
            reject(error);
          } else {
            this.shutdown();
          }
        },
      });
  });
}

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I hope that in most other cases we can rely on mapping configuration to new instances of services when config changes rather than the complicated state management we have had to put into the logging service to make all this possible.

Completely agree!

personal favorite, but ConnectableObservable will probably confuse most readers:

I'm not worried about "most readers" here to be honest :) It's a core thing that shouldn't be touched frequently.

Great approach, my weak RxJS-fu didn't allow me to come up with something like that! One question though, I'm not sure why we need connectable observable here as we connect immediately? It seems shareReplay(1) should do the job, or I am missing something very important? It didn't work as is (second error handler, that calls shutdown, was never called) so I tweaked your proposal a bit with catchError and shareReplay so that all tests pass.

pretty straightforward approach, can't think of any drawbacks:

Yeah, I tried this approach earlier and withdrew it :) Don't like these "giant" promises callbacks.

Copy link
Contributor

@spalger spalger Aug 20, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The problem with shareReplay(1) is that it doesn't unsubscribe from the parent stream when the child stream unsubscribes, so if the logging service was stopped the subscription to the config service would stay open until the config service completed the this.configService.atPath('logging', LoggingConfig) stream, so it would be open forever.

ConnectableObservables instead use a replay subject within the connectable subscription, so we get the benefits of shareReplay(1) but we also get full control over the subscription since we're calling .connect() ourselves.

@azasypkin azasypkin changed the title [skip ci] Merge MutableLoggerFactory and LoggingService. Merge MutableLoggerFactory and LoggingService. Aug 15, 2018
@azasypkin azasypkin force-pushed the issue-xxx-core-merge-mutable-factory-logger branch from c2d1388 to bd1304d Compare August 15, 2018 19:18
@azasypkin azasypkin removed the blocked label Aug 15, 2018
@elasticmachine
Copy link
Contributor

💔 Build Failed

@azasypkin
Copy link
Member Author

retest

@elasticmachine
Copy link
Contributor

💚 Build Succeeded

@azasypkin
Copy link
Member Author

It's ready for review @archanid, whenever you have some time. Mostly moving things around and adding more tests.

@azasypkin azasypkin requested a review from rhoboat August 16, 2018 06:33
throw err;
}

// This observable should use `skip(1)` instead of `filter` as soon as we can use it.
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should be when we have green on #21944

Copy link

@rhoboat rhoboat left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I like this initiative. Huge fan of simpler. Will pull and run soon.

@azasypkin azasypkin requested review from spalger and removed request for spalger August 17, 2018 06:41
@azasypkin azasypkin force-pushed the issue-xxx-core-merge-mutable-factory-logger branch from bd1304d to 1bb3d3d Compare August 17, 2018 13:01
@elasticmachine
Copy link
Contributor

💚 Build Succeeded

@azasypkin azasypkin requested a review from spalger August 17, 2018 14:47
@azasypkin
Copy link
Member Author

Rebased PR on the latest master to include kbn/observable --> rxjs migration and now it should be ready for review @spalger.

@spalger
Copy link
Contributor

spalger commented Aug 17, 2018

Taking a look now

Copy link
Contributor

@spalger spalger left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM. I didn't spot any real deviations from the original code, pulled it down and it runs great. I do have a couple questions which we can chat about on Monday, but if you feel like merging this now to unblock your other PR I say go for it.

}
this.appenders.clear();

for (const [appenderKey, appenderConfig] of config.appenders.entries()) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nit: no need for .entries() here or below, that is the default iterable when looping over a map.

public upgrade(config: LoggingConfig) {
// Config update is asynchronous and may require some time to complete, so we should invalidate
// config so that new loggers will be using BufferAppender until newly configured appenders are ready.
this.config = undefined;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I realize this is pretty much a port of what was happening in LoggerFactory, but is this really necessary? There doesn't seem to be any async logic here, and since we dispose and update the appenders before updating the loggerAdapters I think we should be fine if we updated this.config after the appenders were recreated and just relied on this.config in this.createLogger().

If there is a chance that loggingService.get() will be called while we are disposing adapters, or we are worried about log messages getting written while we are disposing appenders or updating loggerAdapters, then maybe the first thing we should do in upgrade() is update the existing loggerAdapters to write to the bufferAdapter, then we can dispose the existing adapters, recreate them, and update the loggerAdapters to point to the correct appenders. If we do that log messages written to the buffer will be written after any messages that get written as a side-effect of updating each loggerAdapter, so we would probably want each loggerAdapter to be able to buffer messages internally to ensure that ordering is consistent at least within a specific logger...

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I realize this is pretty much a port of what was happening in LoggerFactory, but is this really necessary?

I need some time to remember what concerns I had when I was writing that :)

If there is a chance that loggingService.get() will be called while we are disposing adapters, or we are worried about log messages getting written while we are disposing appenders or updating loggerAdapters, then maybe the first thing we should do in upgrade() is update the existing loggerAdapters to write to the bufferAdapter, then we can dispose the existing adapters, recreate them, and update the loggerAdapters to point to the correct appenders.

Yeah, we can do that if we feel this is a problem. I think I was mostly caring about loggers that are get requested from loggingService.get() (config has been updated so there is a chance that existing services can be restarted or new ones created so loggers will be requested once again).

But to your first point, it's all in theory, and we may not need to care about this corner case at all, I'd propose to wait a bit, see if this becomes a problem and sort it out if it's or simplify this code if it's not.

// We should try to upgrade logger as soon as the root starts and shut root
// down if we can't do that, and subscribe to the consequent updates only if
// initial upgrade succeeded.
const config$ = this.configService.atPath('logging', LoggingConfig);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I really hope that we don't have to do this type of thing in many places. I see the logging service as a special case because we want it to exist very early, we want its API to be synchronous, we want to know that when we call log.error() we can call process.exit() on the next line and the user will see the error (when possible), and we want it to be reactive to configuration changes without ever being recreated. I hope that in most other cases we can rely on mapping configuration to new instances of services when config changes rather than the complicated state management we have had to put into the logging service to make all this possible.

I would like to propose an alternative approach to what you have here though.

I think it makes a little more sense for this to use observable constructs as much as possible and only use promises when necessary, which lead me to two implementations that I'm struggling to pick between. Both implementations have a couple things going for them though:

  • There is never a point where we are unsubscribe from config updates, so even if a second update is sent synchronously it will be applied to the loggingService (current implementation would skip() it).
  • a call to this.stop() while this.setupLogging() is waiting for something will cause its promise to never resolve or reject, rather than having somewhat undefined behavior. Currently this can only happen if something calls stop() before the start() promise resolves, which has all sorts of other undefined effects, so not a big improvement.

personal favorite, but ConnectableObservable will probably confuse most readers:

private async setupLogging() {
  // stream that maps config updates to logging updates, including update failures
  const update$ = this.configService.atPath('logging', LoggingConfig).pipe(
    map(config => {
      this.loggingService.upgrade(config);
    }),
    tap({
      error: error => {
        // This specifically console.logs because we were not able to configure the logger.
        // tslint:disable-next-line no-console
        console.error('Configuring logger failed:', error);
      },
    }),
    publishReplay(1)
  ) as ConnectableObservable<void>;

  // connect update$ so that it will be subscribed and begins updating the logging service
  this.loggingConfigSubscription = update$.connect();

  // wait for the first update to complete, if it fails this will throw
  await update$.pipe(first()).toPromise();

  // send subsequent update failures to this.shutdown(), stopped via loggingConfigSubscription
  this.loggingConfigSubscription.add(
    update$.subscribe({
      error: error => {
        this.shutdown(error);
      },
    })
  );
}

pretty straightforward approach, can't think of any drawbacks:

private async setupLogging() {
  return new Promise<void>((resolve, reject) => {
    let firstUpgradeComplete = false;

    this.loggingConfigSubscription = this.configService
      .atPath('logging', LoggingConfig)
      .pipe(
        tap(config => {
          this.loggingService.upgrade(config);

          if (!firstUpgradeComplete) {
            // resolve our promise if the first upgrade is successfull
            firstUpgradeComplete = true;
            resolve();
          }
        })
      )
      .subscribe({
        error: error => {
          // This specifically console.logs because we were not able to configure the logger.
          // tslint:disable-next-line no-console
          console.error('Configuring logger failed:', error);

          if (!initialUpgradeComplete) {
            // reject the promise rather than shutting down if the first upgrade is unsuccessful
            reject(error);
          } else {
            this.shutdown();
          }
        },
      });
  });
}

@elasticmachine
Copy link
Contributor

💚 Build Succeeded

@azasypkin
Copy link
Member Author

Thanks for the thoughtful review! I've handled two your comments and going to merge this PR to unblock myself. I'd like to think a little bit more about your last point regarding necessity of buffer appender during config update.

@azasypkin azasypkin merged commit d1204a2 into elastic:master Aug 20, 2018
@azasypkin azasypkin deleted the issue-xxx-core-merge-mutable-factory-logger branch August 20, 2018 12:28
@azasypkin
Copy link
Member Author

6.x/6.5: e560934

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
backported Feature:New Platform Team:Core Core services & architecture: plugins, logging, config, saved objects, http, ES client, i18n, etc v6.5.0
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants