Skip to content

Add log_level spec#332

Merged
basepi merged 4 commits intoelastic:masterfrom
felixbarny:log_level
Oct 5, 2020
Merged

Add log_level spec#332
basepi merged 4 commits intoelastic:masterfrom
felixbarny:log_level

Conversation

@felixbarny
Copy link
Copy Markdown
Member

@felixbarny felixbarny commented Aug 26, 2020 •
edited by russcam
Loading

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

@felixbarny felixbarny mentioned this pull request Aug 26, 2020
Closed
@felixbarny felixbarny linked an issue Aug 26, 2020 that may be closed by this pull request
Align log_level option + central config #321
Closed
@felixbarny felixbarny mentioned this pull request Aug 26, 2020
Closed
@ghost
Copy link
Copy Markdown

ghost commented Aug 26, 2020 •
edited by ghost
Loading

💔 Build Failed

Pipeline View Test View Changes Artifacts preview

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 git@github.com: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 git@github.com: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 -- git@github.com:elastic/apm.git +refs/heads/*:refs/remotes/origin/* # timeout=15
[2020-10-05T05:30:14.820Z]  > git config remote.origin.url git@github.com: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 git@github.com: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 git@github.com: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 -- git@github.com: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 git@github.com: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 git@github.com: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 -- git@github.com:elastic/apm.git +refs/heads/*:refs/remotes/origin/* # timeout=10
[2020-10-05T05:30:31.289Z]  > git config remote.origin.url git@github.com: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 git@github.com:elastic/apm.git # timeout=10
[2020-10-05T05:30:31.316Z] Fetching upstream changes from git@github.com: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 -- git@github.com: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...

@felixbarny 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
@basepi
Copy link
Copy Markdown
Contributor

basepi commented Aug 26, 2020

@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
Copy link
Copy Markdown
Member Author

felixbarny commented Aug 26, 2020

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.

@basepi basepi requested a review from a team August 26, 2020 19:25
This was referenced Aug 26, 2020
Closed
Closed
vigneshshanmugam
vigneshshanmugam reviewed Aug 27, 2020
View reviewed changes
@gregkalapos
Copy link
Copy Markdown
Contributor

gregkalapos commented Sep 22, 2020

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
Copy link
Copy Markdown
Contributor

gregkalapos commented Sep 22, 2020

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
Copy link
Copy Markdown
Contributor

basepi commented Sep 22, 2020

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

@basepi basepi marked this pull request as ready for review September 22, 2020 16:13
@basepi basepi requested review from a team as code owners September 22, 2020 16:13
nehaduggal
nehaduggal approved these changes Sep 28, 2020
View reviewed changes
Copy link
Copy Markdown

@nehaduggal nehaduggal left a comment

Choose a reason for hiding this comment

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

Looks good to me!

@basepi
Copy link
Copy Markdown
Contributor

basepi commented Sep 29, 2020

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.

@basepi basepi added this to the 7.11 milestone Sep 29, 2020
@basepi basepi merged commit a36ca34 into elastic:master Oct 5, 2020
This was referenced Oct 5, 2020
Closed
Closed
Closed
Closed
Closed
Closed
Closed
Open
@felixbarny felixbarny deleted the log_level branch October 7, 2020 10:21
@AlexanderWert AlexanderWert mentioned this pull request Nov 17, 2020
Closed
@SergeyKleyman SergeyKleyman mentioned this pull request Nov 30, 2020
Closed
2 tasks
@trentm trentm mentioned this pull request Dec 8, 2020
Merged
2 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@basepi basepi basepi approved these changes

@axw axw axw approved these changes

@gregkalapos gregkalapos gregkalapos approved these changes

@vigneshshanmugam vigneshshanmugam vigneshshanmugam approved these changes

@SergeyKleyman SergeyKleyman SergeyKleyman approved these changes

+3 more reviewers

@mikker mikker mikker approved these changes

@eyalkoren eyalkoren eyalkoren approved these changes

@nehaduggal nehaduggal nehaduggal approved these changes

Reviewers whose approvals may not affect merge requirements

Assignees

@basepi basepi

Labels

None yet

Projects

None yet

Milestone

7.11

Development

Successfully merging this pull request may close these issues.

Align log_level option + central config Adding more config options to central config for backend agents

9 participants

@felixbarny @basepi @gregkalapos @mikker @axw @vigneshshanmugam @SergeyKleyman @eyalkoren @nehaduggal