Add log_level spec #332

felixbarny · 2020-08-26T09:34:09Z

Supersedes #321

Note that the implementation of this spec also includes adding the option to Kibana.

Agent	Milestone	Link to agent implementation issue
dotnet	7.11	elastic/apm-agent-dotnet#970
go		elastic/apm-agent-go#829
java	7.10	elastic/apm-agent-java#1426
nodejs	7.11	elastic/apm-agent-nodejs#1826
php		elastic/apm-agent-php#210
python	7.10	elastic/apm-agent-python#941
ruby	7.11	elastic/apm-agent-ruby#878
rum-js		elastic/apm-agent-rum-js#910

apmmachine · 2020-08-26T09:36:59Z

💔 Build Failed

Expand to view the summary

Build stats

Build Cause: [Started by timer]
Start Time: 2020-10-05T05:28:00.998+0000
Duration: 3 min 39 sec

Steps errors

Expand to view the steps failures

Name: Shell Script
- Description: [2020-10-05T05:30:38.828Z] + git diff --name-only 761d0bc549147707c3cb457378832bdc1bdf70ee...b56fabb
- Duration: 0 min 0 sec
- Start Time: 2020-10-05T05:30:38.532+0000
- log

Log output

Expand to view the last 100 lines of log output

[2020-10-05T05:30:01.163Z] Running on apm-ci-immutable-ubuntu-1804-1601875695423989120 in /var/lib/jenkins/workspace/ared_apm-update-specs-mbp_PR-332
[2020-10-05T05:30:01.270Z] �[39;49m[INFO] Override default checkout�[0m
[2020-10-05T05:30:01.315Z] Sleeping for 10 sec
[2020-10-05T05:30:13.873Z] using credential f6c7695a-671e-4f4f-a331-acdce44ff9ba
[2020-10-05T05:30:13.944Z] Wiping out workspace first.
[2020-10-05T05:30:13.973Z] Cloning the remote Git repository
[2020-10-05T05:30:13.973Z] Using shallow clone with depth 4
[2020-10-05T05:30:13.973Z] Avoid fetching tags
[2020-10-05T05:30:14.849Z] Cleaning workspace
[2020-10-05T05:30:14.867Z] Using shallow fetch with depth 4
[2020-10-05T05:30:14.867Z] Pruning obsolete local branches
[2020-10-05T05:30:13.998Z] Cloning repository [email protected]:elastic/apm.git
[2020-10-05T05:30:14.053Z]  > git init /var/lib/jenkins/workspace/ared_apm-update-specs-mbp_PR-332 # timeout=10
[2020-10-05T05:30:14.109Z] Fetching upstream changes from [email protected]:elastic/apm.git
[2020-10-05T05:30:14.109Z]  > git --version # timeout=10
[2020-10-05T05:30:14.118Z]  > git --version # 'git version 2.17.1'
[2020-10-05T05:30:14.119Z] using GIT_SSH to set credentials GitHub user @elasticmachine SSH key
[2020-10-05T05:30:14.143Z]  > git fetch --no-tags --progress -- [email protected]:elastic/apm.git +refs/heads/*:refs/remotes/origin/* # timeout=15
[2020-10-05T05:30:14.820Z]  > git config remote.origin.url [email protected]:elastic/apm.git # timeout=10
[2020-10-05T05:30:14.825Z]  > git config --add remote.origin.fetch +refs/heads/*:refs/remotes/origin/* # timeout=10
[2020-10-05T05:30:14.840Z]  > git config remote.origin.url [email protected]:elastic/apm.git # timeout=10
[2020-10-05T05:30:14.853Z]  > git rev-parse --verify HEAD # timeout=10
[2020-10-05T05:30:14.858Z] No valid HEAD. Skipping the resetting
[2020-10-05T05:30:14.858Z]  > git clean -fdx # timeout=10
[2020-10-05T05:30:14.873Z] Fetching upstream changes from [email protected]:elastic/apm.git
[2020-10-05T05:30:14.873Z] using GIT_SSH to set credentials GitHub user @elasticmachine SSH key
[2020-10-05T05:30:14.878Z]  > git fetch --no-tags --progress --prune -- [email protected]:elastic/apm.git +refs/pull/332/head:refs/remotes/origin/PR-332 +refs/heads/master:refs/remotes/origin/master # timeout=15
[2020-10-05T05:30:15.478Z] Merging remotes/origin/master commit adc3d3746c218bdfd7979de468ecfbaa50a9988d into PR head commit b56fabbaf46d30c73c4e9698ac40d4fc3c2cdfb6
[2020-10-05T05:30:15.582Z] Merge succeeded, producing 4886b66fa61334861472abd11e42759ede8209cd
[2020-10-05T05:30:15.582Z] Checking out Revision 4886b66fa61334861472abd11e42759ede8209cd (PR-332)
[2020-10-05T05:30:15.488Z]  > git config core.sparsecheckout # timeout=10
[2020-10-05T05:30:15.501Z]  > git checkout -f b56fabbaf46d30c73c4e9698ac40d4fc3c2cdfb6 # timeout=15
[2020-10-05T05:30:15.534Z]  > git remote # timeout=10
[2020-10-05T05:30:15.542Z]  > git config --get remote.origin.url # timeout=10
[2020-10-05T05:30:15.550Z] using GIT_SSH to set credentials GitHub user @elasticmachine SSH key
[2020-10-05T05:30:15.555Z]  > git merge adc3d3746c218bdfd7979de468ecfbaa50a9988d # timeout=10
[2020-10-05T05:30:15.576Z]  > git rev-parse HEAD^{commit} # timeout=10
[2020-10-05T05:30:15.587Z]  > git config core.sparsecheckout # timeout=10
[2020-10-05T05:30:15.594Z]  > git checkout -f 4886b66fa61334861472abd11e42759ede8209cd # timeout=15
[2020-10-05T05:30:19.214Z] Commit message: "Merge commit 'adc3d3746c218bdfd7979de468ecfbaa50a9988d' into HEAD"
[2020-10-05T05:30:19.234Z] First time build. Skipping changelog.
[2020-10-05T05:30:19.234Z] Cleaning workspace
[2020-10-05T05:30:19.219Z]  > git rev-list --no-walk 5a59b181b5c54a330ab007211cf5f5e877dd1b56 # timeout=10
[2020-10-05T05:30:19.238Z]  > git rev-parse --verify HEAD # timeout=10
[2020-10-05T05:30:19.246Z] Resetting working tree
[2020-10-05T05:30:19.246Z]  > git reset --hard # timeout=10
[2020-10-05T05:30:19.253Z]  > git clean -fdx # timeout=10
[2020-10-05T05:30:19.982Z] Masking supported pattern matches of $JOB_GCS_BUCKET or $NOTIFY_TO
[2020-10-05T05:30:20.013Z] Timeout set to expire in 3 hr 0 min
[2020-10-05T05:30:20.020Z] The timestamps step is unnecessary when timestamps are enabled for all Pipeline builds.
[2020-10-05T05:30:20.310Z] [INFO] 'shallow' is forced to be disabled when running on PullRequests
[2020-10-05T05:30:20.318Z] Running in /var/lib/jenkins/workspace/ared_apm-update-specs-mbp_PR-332/src/github.com/elastic/apm
[2020-10-05T05:30:20.328Z] [INFO] gitCheckout: Checkout SCM PR-332 with some customisation.
[2020-10-05T05:30:20.341Z] [INFO] Override default checkout
[2020-10-05T05:30:20.361Z] Sleeping for 10 sec
[2020-10-05T05:30:30.509Z] using credential f6c7695a-671e-4f4f-a331-acdce44ff9ba
[2020-10-05T05:30:30.587Z] Cloning the remote Git repository
[2020-10-05T05:30:30.607Z] Cloning repository [email protected]:elastic/apm.git
[2020-10-05T05:30:30.635Z]  > git init /var/lib/jenkins/workspace/ared_apm-update-specs-mbp_PR-332/src/github.com/elastic/apm # timeout=10
[2020-10-05T05:30:30.644Z] Fetching upstream changes from [email protected]:elastic/apm.git
[2020-10-05T05:30:30.644Z]  > git --version # timeout=10
[2020-10-05T05:30:30.650Z]  > git --version # 'git version 2.17.1'
[2020-10-05T05:30:30.650Z] using GIT_SSH to set credentials GitHub user @elasticmachine SSH key
[2020-10-05T05:30:30.655Z]  > git fetch --tags --progress -- [email protected]:elastic/apm.git +refs/heads/*:refs/remotes/origin/* # timeout=10
[2020-10-05T05:30:31.289Z]  > git config remote.origin.url [email protected]:elastic/apm.git # timeout=10
[2020-10-05T05:30:31.298Z]  > git config --add remote.origin.fetch +refs/heads/*:refs/remotes/origin/* # timeout=10
[2020-10-05T05:30:31.308Z]  > git config remote.origin.url [email protected]:elastic/apm.git # timeout=10
[2020-10-05T05:30:31.316Z] Fetching upstream changes from [email protected]:elastic/apm.git
[2020-10-05T05:30:31.317Z] using GIT_SSH to set credentials GitHub user @elasticmachine SSH key
[2020-10-05T05:30:31.321Z]  > git fetch --tags --progress -- [email protected]:elastic/apm.git +refs/pull/332/head:refs/remotes/origin/PR-332 +refs/heads/master:refs/remotes/origin/master # timeout=10
[2020-10-05T05:30:31.909Z] Checking out Revision b56fabbaf46d30c73c4e9698ac40d4fc3c2cdfb6 (origin/PR-332)
[2020-10-05T05:30:31.934Z] Commit message: "Update default"
[2020-10-05T05:30:31.934Z] First time build. Skipping changelog.
[2020-10-05T05:30:31.906Z]  > git rev-parse origin/PR-332^{commit} # timeout=10
[2020-10-05T05:30:31.914Z]  > git config core.sparsecheckout # timeout=10
[2020-10-05T05:30:31.917Z]  > git checkout -f b56fabbaf46d30c73c4e9698ac40d4fc3c2cdfb6 # timeout=10
[2020-10-05T05:30:32.969Z] Masking supported pattern matches of $GIT_USERNAME or $GIT_PASSWORD
[2020-10-05T05:30:33.595Z] + git fetch https://****:****@github.com/elastic/apm.git +refs/pull/*/head:refs/remotes/origin/pr/*
[2020-10-05T05:30:34.220Z] Archiving artifacts
[2020-10-05T05:30:34.864Z] + git rev-parse HEAD
[2020-10-05T05:30:35.222Z] + git rev-parse HEAD
[2020-10-05T05:30:35.530Z] + git rev-parse origin/pr/332
[2020-10-05T05:30:35.561Z] [INFO] githubEnv: Found Git Build Cause: pr
[2020-10-05T05:30:36.116Z] Masking supported pattern matches of $GITHUB_TOKEN
[2020-10-05T05:30:37.300Z] [INFO] githubPrCheckApproved: Title: Add log_level spec - User: felixbarny - Author Association: MEMBER
[2020-10-05T05:30:37.961Z] Stashed 270 file(s)
[2020-10-05T05:30:38.408Z] Running in /var/lib/jenkins/workspace/ared_apm-update-specs-mbp_PR-332/src/github.com/elastic/apm
[2020-10-05T05:30:38.828Z] + git diff --name-only 761d0bc549147707c3cb457378832bdc1bdf70ee...b56fabbaf46d30c73c4e9698ac40d4fc3c2cdfb6
[2020-10-05T05:30:38.828Z] fatal: Invalid symmetric difference expression 761d0bc549147707c3cb457378832bdc1bdf70ee...b56fabbaf46d30c73c4e9698ac40d4fc3c2cdfb6
[2020-10-05T05:30:38.880Z] Stage "Send Pull Request for BDD specs" skipped due to earlier failure(s)
[2020-10-05T05:30:38.899Z] Stage "Send Pull Request for JSON specs" skipped due to earlier failure(s)
[2020-10-05T05:30:39.087Z] Running on Jenkins in /var/lib/jenkins/workspace/ared_apm-update-specs-mbp_PR-332
[2020-10-05T05:30:39.162Z] [INFO] getVaultSecret: Getting secrets
[2020-10-05T05:30:39.314Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID
[2020-10-05T05:30:39.866Z] + chmod 755 generate-build-data.sh
[2020-10-05T05:30:39.866Z] + ./generate-build-data.sh https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-shared/apm-update-specs-mbp/PR-332/ https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-shared/apm-update-specs-mbp/PR-332/runs/15 FAILURE 158610
[2020-10-05T05:30:40.116Z] INFO: curl https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-shared/apm-update-specs-mbp/PR-332/runs/15/steps/?limit=10000 -o steps-info.json
[2020-10-05T05:30:41.027Z] INFO: curl https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-shared/apm-update-specs-mbp/PR-332/runs/15/tests/?status=FAILED -o tests-errors.json
[2020-10-05T05:30:41.027Z] Retry 1/3 exited 22, retrying in 1 seconds...
[2020-10-05T05:30:41.939Z] Retry 2/3 exited 22, retrying in 2 seconds...

basepi · 2020-08-26T17:31:01Z

@felixbarny This looks excellent to me as-is. Is there more to do before we take is out of draft and start getting individual teams to review?

felixbarny · 2020-08-26T19:21:07Z

I’d usually try to get feedback from an agent that did not give feedback so far or were it might be tricky for them to implement the spec. In this case, I’d suggest asking the RUM team for a review before opening it up to a wider audience.

specs/agents/logging.md

gregkalapos · 2020-09-22T13:45:33Z

This is a bit problematic for .NET.

On .NET Core we integrate with Microsoft.Extensions.Configuration - the defined levels are listed here and the values in .NET are inspired by this list.

The reason we integrate with Microsoft.Extensions.Configuration is that this way configuring logging for the .NET Agent is the same as configuring logging to any other library. Users can have this in their config file:

{
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Elastic.Apm": "Error",
      "Microsoft.AspNetCore":  "Debug"
    }
  },
//...more configs
}

This means, everything logs on Information level, but the Elastic .NET APM Agent logs on Error level, and the ASP.NET Core framework itself logs on Debug level. Now - the agent does not parse the log level it gets - it just creates a logger with the corresponding log level, like this:

public NetCoreLogger(ILoggerFactory loggerFactory) =>
			_logger = loggerFactory?.CreateLogger("Elastic.Apm") ?? throw new ArgumentNullException(nameof(loggerFactory))

So the ILoggerFactory creates the logger and there is no chance for us to map log level config values before the logger is created. So if I do this (spot that I use info which is invalid for this config system, but is proposed in this PR):

  "Logging": {
    "LogLevel": {
      "Default": "Warning",
      "Elastic.Apm": "info",
    }

Then here is what happens:

Unhandled exception. System.InvalidOperationException: Configuration value 'info' is not supported.
   at Microsoft.Extensions.Logging.LoggerFilterConfigureOptions.TryGetSwitch(String value, LogLevel& level)
   at Microsoft.Extensions.Logging.LoggerFilterConfigureOptions.LoadRules(LoggerFilterOptions options, IConfigurationSection configurationSection, String logger)
   at Microsoft.Extensions.Logging.LoggerFilterConfigureOptions.LoadDefaultConfigValues(LoggerFilterOptions options)
   at Microsoft.Extensions.Logging.LoggerFilterConfigureOptions.Configure(LoggerFilterOptions options)
   at Microsoft.Extensions.Options.OptionsFactory`1.Create(String name)
   at Microsoft.Extensions.Options.OptionsMonitor`1.<>c__DisplayClass11_0.<Get>b__0()
   at System.Lazy`1.ViaFactory(LazyThreadSafetyMode mode)
   at System.Lazy`1.ExecutionAndPublication(LazyHelper executionAndPublication, Boolean useDefaultConstructor)
   at System.Lazy`1.CreateValue()
   at System.Lazy`1.get_Value()
   at Microsoft.Extensions.Options.OptionsCache`1.GetOrAdd(String name, Func`1 createOptions)
   at Microsoft.Extensions.Options.OptionsMonitor`1.Get(String name)
   at Microsoft.Extensions.Options.OptionsMonitor`1.get_CurrentValue()
   at Microsoft.Extensions.Logging.LoggerFactory..ctor(IEnumerable`1 providers, IOptionsMonitor`1 filterOption)

It crashes way before we could do anything.

I don't wanna push back and if needed I'm ok with digging deeper, but for .NET this would mean that

We'll use config values that are absolutely not neutral for .NET applications
I'm sure we could implement it somehow, but it would be significant work.

gregkalapos · 2020-09-22T13:57:20Z

Now.. having said that above: of course that only happens when the values are coming from a known config file. We can still fetch the suggested defaults from central config and map those. So from my point of view, having something common for central config is possible.

But then for .NET

We either adapt every other scenario to use these default values (to me sounds like less of a good thing)
Or we say if you configure the agent through a well known config files, then use the values of that config system, and if you do it through central config then use one of the suggested defaults (a bit confusion if you hear it first, but natural both for Kibana and for .NET devs configuring directly in the config file).

I leave out here the combination of the two, for that, there is already an issue in the .NET repo.

basepi · 2020-09-22T16:05:56Z

@gregkalapos Thanks for the insights. I think your second solution will be fine, as we discussed in the agents meeting today.

nehaduggal

Looks good to me!

basepi · 2020-09-29T16:13:03Z

We seem to have a critical mass of approvals here, so let this be a last call for comment: This spec will be merged and approved October 5, 2020.

Add log_level spec

dacb8fa

felixbarny mentioned this pull request Aug 26, 2020

Align log_level option + central config #321

Closed

felixbarny linked an issue Aug 26, 2020 that may be closed by this pull request

Align log_level option + central config #321

Closed

felixbarny mentioned this pull request Aug 26, 2020

Adding more config options to central config for backend agents #318

Closed

felixbarny linked an issue Aug 26, 2020 that may be closed by this pull request

Adding more config options to central config for backend agents #318

Closed

felixbarny assigned basepi Aug 26, 2020

basepi requested a review from a team August 26, 2020 19:25

This was referenced Aug 26, 2020

Remote Config: Add callbacks on config change elastic/apm-agent-python#908

Closed

Add log_level config (dynamic) elastic/apm-agent-python#909

Closed

vigneshshanmugam reviewed Aug 27, 2020

View reviewed changes

specs/agents/logging.md Outdated Show resolved Hide resolved

specs/agents/logging.md Show resolved Hide resolved

specs/agents/logging.md Show resolved Hide resolved

specs/agents/logging.md Show resolved Hide resolved

specs/agents/logging.md Show resolved Hide resolved

Default to warning, clarify a few points

16ac828

basepi added 2 commits September 22, 2020 10:09

Merge remote-tracking branch 'upstream/master' into log_level

699f439

Update default

b56fabb

basepi marked this pull request as ready for review September 22, 2020 16:13

basepi requested review from a team as code owners September 22, 2020 16:13

basepi approved these changes Sep 22, 2020

View reviewed changes

eyalkoren approved these changes Sep 23, 2020

View reviewed changes

vigneshshanmugam approved these changes Sep 23, 2020

View reviewed changes

SergeyKleyman approved these changes Sep 23, 2020

View reviewed changes

gregkalapos approved these changes Sep 24, 2020

View reviewed changes

mikker approved these changes Sep 28, 2020

View reviewed changes

nehaduggal approved these changes Sep 28, 2020

View reviewed changes

basepi added this to the 7.11 milestone Sep 29, 2020

axw approved these changes Sep 30, 2020

View reviewed changes

basepi merged commit a36ca34 into elastic:master Oct 5, 2020

felixbarny deleted the log_level branch October 7, 2020 10:21

AlexanderWert mentioned this pull request Nov 17, 2020

Add/adapt central config options for Agents in Kibana #369

Closed

SergeyKleyman mentioned this pull request Nov 30, 2020

Remove NOTICE log level elastic/apm-agent-php#307

Closed

2 tasks

trentm mentioned this pull request Dec 8, 2020

[APM] Add log_level config option to the Node.js Agent elastic/kibana#85346

Merged

2 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add log_level spec #332

Add log_level spec #332

felixbarny commented Aug 26, 2020 •

edited by russcam

Loading

apmmachine commented Aug 26, 2020 •

edited

Loading

Build stats

basepi commented Aug 26, 2020

felixbarny commented Aug 26, 2020

gregkalapos commented Sep 22, 2020

gregkalapos commented Sep 22, 2020

basepi commented Sep 22, 2020

nehaduggal left a comment

basepi commented Sep 29, 2020

Add log_level spec #332

Add log_level spec #332

Conversation

felixbarny commented Aug 26, 2020 • edited by russcam Loading

apmmachine commented Aug 26, 2020 • edited Loading

💔 Build Failed

Build stats

Steps errors

Log output

basepi commented Aug 26, 2020

felixbarny commented Aug 26, 2020

gregkalapos commented Sep 22, 2020

gregkalapos commented Sep 22, 2020

basepi commented Sep 22, 2020

nehaduggal left a comment

Choose a reason for hiding this comment

basepi commented Sep 29, 2020

felixbarny commented Aug 26, 2020 •

edited by russcam

Loading

apmmachine commented Aug 26, 2020 •

edited

Loading