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

Add env var for debugging profiling native extension compilation issues + Log PKG_CONFIG_PATH to mkmf.log #2069

Merged
merged 3 commits into from
Jun 8, 2022

Conversation

ivoanjo
Copy link
Member

@ivoanjo ivoanjo commented Jun 7, 2022

To avoid impacting customers, whenever we detect an issue which would've led to the profiling native extension compilation to fail, we instead skip the compilation.

This ensures that customers (especially those not using profiling) don't get impacted at installation time.

Instead, at execution time, if they do try to enable profiling, they'll get a message such as

WARN -- ddtrace: [ddtrace] Profiling was requested but is not supported,
profiling disabled: Your ddtrace installation is missing support for the
Continuous Profiler because there was a problem in setting up the
libddprof dependency. For help solving this issue, please contact
Datadog support at https://docs.datadoghq.com/help/.

But while investigating one such issue reported by a customer (#2068), I found that it's helpful to have a way to break during installation, because that will make Ruby print extra debug information, including the location of the mkmf.log log file which can be useful when debugging issues.

Thus, I've added a new DD_PROFILING_FAIL_INSTALL_IF_MISSING_EXTENSION environment variable that support can request customers set to true to force a failure at installation time.

Here's how it looks when I simulate a broken libddprof setup by renaming a file:

 # Installs successfully, but profiling will not work:

$ gem install pkg/ddtrace-1.1.0.gem
Building native extensions. This could take a while...
Successfully installed ddtrace-1.1.0
Parsing documentation for ddtrace-1.1.0
Done installing documentation for ddtrace after 3 seconds
1 gem installed

 # Force failure to show up at gem installation time:

$ DD_PROFILING_FAIL_INSTALL_IF_MISSING_EXTENSION=true gem install pkg/ddtrace-1.1.0.gem
Building native extensions. This could take a while...
ERROR:  Error installing pkg/ddtrace-1.1.0.gem:
  ERROR: Failed to build gem native extension.

    current directory: ~/.rvm/gems/ruby-2.7.6/gems/ddtrace-1.1.0/ext/ddtrace_profiling_native_extension
~/.rvm/rubies/ruby-2.7.6/bin/ruby -I ~/.rvm/rubies/ruby-2.7.6/lib/ruby/2.7.0 -r ./siteconf20220607-83731-8dqh3w.rb extconf.rb

+------------------------------------------------------------------------------+
| ** Preparing to build the ddtrace profiling native extension... **           |
|                                                                              |
| If you run into any failures during this step, you can set the               |
| `DD_PROFILING_NO_EXTENSION` environment variable to `true` e.g.              |
| `$ DD_PROFILING_NO_EXTENSION=true bundle install` to skip this step.         |
|                                                                              |
| If you disable this extension, the Datadog Continuous Profiler will          |
| not be available, but all other ddtrace features will work fine!             |
|                                                                              |
| If you needed to use this, please tell us why on                             |
| <https://github.com/DataDog/dd-trace-rb/issues/new> so we can fix it :)      |
|                                                                              |
| Thanks for using ddtrace! You rock!                                          |
+------------------------------------------------------------------------------+

+------------------------------------------------------------------------------+
| Could not compile the Datadog Continuous Profiler because                    |
| there was a problem in setting up the `libddprof` dependency.                |
|                                                                              |
| Failing installation immediately because the                                 |
| `DD_PROFILING_FAIL_INSTALL_IF_MISSING_EXTENSION` environment variable is set |
| to `true`.                                                                   |
| When contacting support, please include the <mkmf.log> file that is shown    |
| below.                                                                       |
|                                                                              |
| For help solving this issue, please contact Datadog support at               |
| <https://docs.datadoghq.com/help/>.                                          |
+------------------------------------------------------------------------------+

*** extconf.rb failed ***
Could not create Makefile due to some reason, probably lack of necessary
libraries and/or headers.  Check the mkmf.log file for more details.  You may
need configuration options.

Provided configuration options:
  --with-opt-dir
  --with-opt-include
  --without-opt-include=${opt-dir}/include
  --with-opt-lib
  --without-opt-lib=${opt-dir}/lib
  --with-make-prog
  --without-make-prog
  --srcdir=.
  --curdir
  --ruby=~/.rvm/rubies/ruby-2.7.6/bin/$(RUBY_BASE_NAME)
  --with-ddprof_ffi_with_rpath_x-config
  --without-ddprof_ffi_with_rpath_x-config
  --with-pkg-config
  --without-pkg-config

To see why this extension failed to compile, please check the mkmf.log which can be found here:

  ~/.rvm/gems/ruby-2.7.6/extensions/x86_64-darwin-20/2.7.0/ddtrace-1.1.0/mkmf.log

extconf failed, exit code 1

Gem files will remain installed in ~/.rvm/gems/ruby-2.7.6/gems/ddtrace-1.1.0 for inspection.
Results logged to ~/.rvm/gems/ruby-2.7.6/extensions/x86_64-darwin-20/2.7.0/ddtrace-1.1.0/gem_make.out

You'll notice that a bunch more useful information shows up, including the path to mkmf.log, which can provide extra information.


As part of this PR, I've also added logging of the PKG_CONFIG_PATH to the mkmf.log, so that we can use it to investigate #2068.

To avoid impacting customers, whenever we detect an issue which
would've led to the profiling native extension compilation to fail, we
instead skip the compilation.

This ensures that customers (especially those *not* using profiling)
don't get impacted at installation time.

Instead, at execution time, if they do try to enable profiling,
they'll get a message such as

```
WARN -- ddtrace: [ddtrace] Profiling was requested but is not supported,
profiling disabled: Your ddtrace installation is missing support for the
Continuous Profiler because there was a problem in setting up the
libddprof dependency. For help solving this issue, please contact
Datadog support at https://docs.datadoghq.com/help/.
```

But while investigating one such issue reported by a customer
(<#2068>), I found that
it's helpful to have a way to break during installation, because
that will make Ruby print extra debug information, including the
location of the `mkmf.log` log file which can be useful when
debugging issues.

Thus, I've added a new `DD_PROFILING_FAIL_INSTALL_IF_MISSING_EXTENSION`
environment variable that support can request customers set to `true`
to force a failure at installation time.

Here's how it looks when I simulate a broken `libddprof` setup by
renaming a file:

```
 # Installs successfully, but profiling will not work:

$ gem install pkg/ddtrace-1.1.0.gem
Building native extensions. This could take a while...
Successfully installed ddtrace-1.1.0
Parsing documentation for ddtrace-1.1.0
Done installing documentation for ddtrace after 3 seconds
1 gem installed

 # Force failure to show up at gem installation time:

$ DD_PROFILING_FAIL_INSTALL_IF_MISSING_EXTENSION=true gem install pkg/ddtrace-1.1.0.gem
Building native extensions. This could take a while...
ERROR:  Error installing pkg/ddtrace-1.1.0.gem:
  ERROR: Failed to build gem native extension.

    current directory: ~/.rvm/gems/ruby-2.7.6/gems/ddtrace-1.1.0/ext/ddtrace_profiling_native_extension
~/.rvm/rubies/ruby-2.7.6/bin/ruby -I ~/.rvm/rubies/ruby-2.7.6/lib/ruby/2.7.0 -r ./siteconf20220607-83731-8dqh3w.rb extconf.rb

+------------------------------------------------------------------------------+
| ** Preparing to build the ddtrace profiling native extension... **           |
|                                                                              |
| If you run into any failures during this step, you can set the               |
| `DD_PROFILING_NO_EXTENSION` environment variable to `true` e.g.              |
| `$ DD_PROFILING_NO_EXTENSION=true bundle install` to skip this step.         |
|                                                                              |
| If you disable this extension, the Datadog Continuous Profiler will          |
| not be available, but all other ddtrace features will work fine!             |
|                                                                              |
| If you needed to use this, please tell us why on                             |
| <https://github.com/DataDog/dd-trace-rb/issues/new> so we can fix it :)      |
|                                                                              |
| Thanks for using ddtrace! You rock!                                          |
+------------------------------------------------------------------------------+

+------------------------------------------------------------------------------+
| Could not compile the Datadog Continuous Profiler because                    |
| there was a problem in setting up the `libddprof` dependency.                |
|                                                                              |
| Failing installation immediately because the                                 |
| `DD_PROFILING_FAIL_INSTALL_IF_MISSING_EXTENSION` environment variable is set |
| to `true`.                                                                   |
| When contacting support, please include the <mkmf.log> file that is shown    |
| below.                                                                       |
|                                                                              |
| For help solving this issue, please contact Datadog support at               |
| <https://docs.datadoghq.com/help/>.                                          |
+------------------------------------------------------------------------------+

*** extconf.rb failed ***
Could not create Makefile due to some reason, probably lack of necessary
libraries and/or headers.  Check the mkmf.log file for more details.  You may
need configuration options.

Provided configuration options:
  --with-opt-dir
  --with-opt-include
  --without-opt-include=${opt-dir}/include
  --with-opt-lib
  --without-opt-lib=${opt-dir}/lib
  --with-make-prog
  --without-make-prog
  --srcdir=.
  --curdir
  --ruby=~/.rvm/rubies/ruby-2.7.6/bin/$(RUBY_BASE_NAME)
  --with-ddprof_ffi_with_rpath_x-config
  --without-ddprof_ffi_with_rpath_x-config
  --with-pkg-config
  --without-pkg-config

To see why this extension failed to compile, please check the mkmf.log which can be found here:

  ~/.rvm/gems/ruby-2.7.6/extensions/x86_64-darwin-20/2.7.0/ddtrace-1.1.0/mkmf.log

extconf failed, exit code 1

Gem files will remain installed in ~/.rvm/gems/ruby-2.7.6/gems/ddtrace-1.1.0 for inspection.
Results logged to ~/.rvm/gems/ruby-2.7.6/extensions/x86_64-darwin-20/2.7.0/ddtrace-1.1.0/gem_make.out
```

You'll notice that a bunch more useful information shows up, including the
path to `mkmf.log`, which can provide extra information.
This will help us investigate #2068 .
@ivoanjo ivoanjo requested a review from a team June 7, 2022 12:38
@codecov-commenter
Copy link

codecov-commenter commented Jun 7, 2022

Codecov Report

Merging #2069 (455a808) into master (2237a8b) will decrease coverage by 0.00%.
The diff coverage is 60.00%.

@@            Coverage Diff             @@
##           master    #2069      +/-   ##
==========================================
- Coverage   97.49%   97.48%   -0.01%     
==========================================
  Files        1031     1031              
  Lines       53213    53214       +1     
==========================================
- Hits        51878    51877       -1     
- Misses       1335     1337       +2     
Impacted Files Coverage Δ
...iling_native_extension/native_extension_helpers.rb 95.23% <60.00%> (-1.43%) ⬇️
spec/datadog/profiling/ext/forking_spec.rb 99.39% <0.00%> (-0.61%) ⬇️
lib/datadog/tracing/tracer.rb 97.36% <0.00%> (-0.02%) ⬇️
lib/datadog/tracing/trace_operation.rb 98.81% <0.00%> (-0.01%) ⬇️

📣 Codecov can now indicate which changes are the most critical in Pull Requests. Learn more

Copy link
Contributor

@lloeki lloeki left a comment

Choose a reason for hiding this comment

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

A couple comments, otherwise LGTM

@@ -122,6 +140,7 @@ def add_compiler_flag(flag)

# If we got here, libddprof is available and loaded
ENV['PKG_CONFIG_PATH'] = "#{ENV['PKG_CONFIG_PATH']}:#{Libddprof.pkgconfig_folder}"
Logging.message(" [ddtrace] PKG_CONFIG_PATH set to '#{ENV['PKG_CONFIG_PATH']}'\n")
Copy link
Contributor

Choose a reason for hiding this comment

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

I usually favour calling #inspect when logging values: when they're strings they'll be automatically wrapped in quotes, and if they happen to be an unexpected value it becomes very obvious (e.g distinguishing nil vs empty string)

Just a note, as here it's obviously a string.

Copy link
Member Author

Choose a reason for hiding this comment

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

Yeap, good point and good rule of thumb, fixed in 455a808

@@ -122,6 +140,7 @@ def add_compiler_flag(flag)

# If we got here, libddprof is available and loaded
ENV['PKG_CONFIG_PATH'] = "#{ENV['PKG_CONFIG_PATH']}:#{Libddprof.pkgconfig_folder}"
Copy link
Contributor

Choose a reason for hiding this comment

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

Can ENV['PKG_CONFIG_PATH'] be nil, or ''? This would result in a leading :.

Copy link
Member Author

Choose a reason for hiding this comment

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

Yes, it can. That's actually what happens almost always, since nothing in Ruby sets PKG_CONFIG_PATH by default. I can confirm pkg-config is OK with having the leading :.

@ivoanjo ivoanjo merged commit 56195f5 into master Jun 8, 2022
@ivoanjo ivoanjo deleted the ivoanjo/improve-native-extension-debugging branch June 8, 2022 11:46
@github-actions github-actions bot added this to the 1.2.0 milestone Jun 8, 2022
ivoanjo added a commit that referenced this pull request Jul 7, 2022
In #2068 a customer reported that they were not getting profiling
with the message:

> Profiling was requested but is not supported, profiling disabled:
> Your ddtrace installation is missing support for the Continuous
> Profiler because there was a problem in setting up the libddprof
> dependency.

After investigating this issue (and adding extra tools to debug it,
see #2069) it turns out that the customer was missing the `pkg-config`
tool.

This tool is currently invoked indirectly via Ruby's `mkmf` helper,
and is used to configure linking to libddprof/libdatadog.

I must admit I was surprised that there's not better error logging
in `mkmf` when the `pkg-config` tool is actually missing
(vs it being installed but returning an error when being called).

Thus, to hopefully avoid other customers running into this issue,
I've added a bit of code to detect it, and hopefully present a
better error message in that situation.

I've also learned that `pkg-config` is "old news" on some Linux
distributions, and instead they ship something called `pkgconf`
which is a reimplementation of `pkg-config`.

Beyond the RSpec tests, this can be triggered for testing by:

1. Changing the `pkg_config` call on extconf.rb

```diff
-unless pkg_config('ddprof_ffi_with_rpath')
+unless pkg_config('ddprof_ffi_with_rpath_broken')
```

which triggers the generic message (because pkg-config is
available but returns an error since the configuration file
is not found):

```
+------------------------------------------------------------------------------+
| Could not compile the Datadog Continuous Profiler because                    |
| there was a problem in setting up the `libddprof` dependency.                |
|                                                                              |
| The Datadog Continuous Profiler will not be available,                       |
| but all other ddtrace features will work fine!                               |
|                                                                              |
| For help solving this issue, please contact Datadog support at               |
| <https://docs.datadoghq.com/help/>.                                          |
+------------------------------------------------------------------------------+
```

2. Crippling `pkg_config`:

```bash
$ docker-compose run --no-deps --rm tracer-2.1 /bin/bash
  # doing this inside docker is fine because it doesn't persist
$ rm /usr/bin/pkg-config
$ bundle exec rake clean compile
 # ...
+------------------------------------------------------------------------------+
| Could not compile the Datadog Continuous Profiler because                    |
| the `pkg-config` system tool is missing.                                     |
| This issue can usually be fixed by installing:                               |
| 1. the `pkg-config` package on Homebrew and Debian/Ubuntu-based Linux;       |
| 2. the `pkgconf` package on Arch and Alpine-based Linux;                     |
| 3. the `pkgconf-pkg-config` package on Fedora/Red Hat-based Linux.           |
|                                                                              |
| The Datadog Continuous Profiler will not be available,                       |
| but all other ddtrace features will work fine!                               |
|                                                                              |
| For help solving this issue, please contact Datadog support at               |
| <https://docs.datadoghq.com/help/>.                                          |
+------------------------------------------------------------------------------+
```

Closes #2068
ivoanjo added a commit that referenced this pull request Jul 7, 2022
In #2068 a customer reported that they were not getting profiling
with the message:

> Profiling was requested but is not supported, profiling disabled:
> Your ddtrace installation is missing support for the Continuous
> Profiler because there was a problem in setting up the libddprof
> dependency.

After investigating this issue (and adding extra tools to debug it,
see #2069) it turns out that the customer was missing the `pkg-config`
tool.

This tool is currently invoked indirectly via Ruby's `mkmf` helper,
and is used to configure linking to libddprof/libdatadog.

I must admit I was surprised that there's not better error logging
in `mkmf` when the `pkg-config` tool is actually missing
(vs it being installed but returning an error when being called).

Thus, to hopefully avoid other customers running into this issue,
I've added a bit of code to detect it, and hopefully present a
better error message in that situation.

I've also learned that `pkg-config` is "old news" on some Linux
distributions, and instead they ship something called `pkgconf`
which is a reimplementation of `pkg-config`.

Beyond the RSpec tests, this can be triggered for testing by:

1. Changing the `pkg_config` call on extconf.rb

```diff
-unless pkg_config('ddprof_ffi_with_rpath')
+unless pkg_config('ddprof_ffi_with_rpath_broken')
```

which triggers the generic message (because pkg-config is
available but returns an error since the configuration file
is not found):

```
+------------------------------------------------------------------------------+
| Could not compile the Datadog Continuous Profiler because                    |
| there was a problem in setting up the `libddprof` dependency.                |
|                                                                              |
| The Datadog Continuous Profiler will not be available,                       |
| but all other ddtrace features will work fine!                               |
|                                                                              |
| For help solving this issue, please contact Datadog support at               |
| <https://docs.datadoghq.com/help/>.                                          |
+------------------------------------------------------------------------------+
```

2. Crippling `pkg_config`:

```bash
$ docker-compose run --no-deps --rm tracer-2.1 /bin/bash
  # doing this inside docker is fine because it doesn't persist
$ rm /usr/bin/pkg-config
$ bundle exec rake clean compile
 # ...
+------------------------------------------------------------------------------+
| Could not compile the Datadog Continuous Profiler because                    |
| the `pkg-config` system tool is missing.                                     |
| This issue can usually be fixed by installing:                               |
| 1. the `pkg-config` package on Homebrew and Debian/Ubuntu-based Linux;       |
| 2. the `pkgconf` package on Arch and Alpine-based Linux;                     |
| 3. the `pkgconf-pkg-config` package on Fedora/Red Hat-based Linux.           |
|                                                                              |
| The Datadog Continuous Profiler will not be available,                       |
| but all other ddtrace features will work fine!                               |
|                                                                              |
| For help solving this issue, please contact Datadog support at               |
| <https://docs.datadoghq.com/help/>.                                          |
+------------------------------------------------------------------------------+
```

Closes #2068
ivoanjo added a commit that referenced this pull request Jul 7, 2022
In #2068 a customer reported that they were not getting profiling
with the message:

> Profiling was requested but is not supported, profiling disabled:
> Your ddtrace installation is missing support for the Continuous
> Profiler because there was a problem in setting up the libddprof
> dependency.

After investigating this issue (and adding extra tools to debug it,
see #2069) it turns out that the customer was missing the `pkg-config`
tool.

This tool is currently invoked indirectly via Ruby's `mkmf` helper,
and is used to configure linking to libddprof/libdatadog.

I must admit I was surprised that there's not better error logging
in `mkmf` when the `pkg-config` tool is actually missing
(vs it being installed but returning an error when being called).

Thus, to hopefully avoid other customers running into this issue,
I've added a bit of code to detect it, and hopefully present a
better error message in that situation.

I've also learned that `pkg-config` is "old news" on some Linux
distributions, and instead they ship something called `pkgconf`
which is a reimplementation of `pkg-config`.

Beyond the RSpec tests, this can be triggered for testing by:

1. Changing the `pkg_config` call on extconf.rb

```diff
-unless pkg_config('ddprof_ffi_with_rpath')
+unless pkg_config('ddprof_ffi_with_rpath_broken')
```

which triggers the generic message (because pkg-config is
available but returns an error since the configuration file
is not found):

```
+------------------------------------------------------------------------------+
| Could not compile the Datadog Continuous Profiler because                    |
| there was a problem in setting up the `libddprof` dependency.                |
|                                                                              |
| The Datadog Continuous Profiler will not be available,                       |
| but all other ddtrace features will work fine!                               |
|                                                                              |
| For help solving this issue, please contact Datadog support at               |
| <https://docs.datadoghq.com/help/>.                                          |
+------------------------------------------------------------------------------+
```

2. Crippling `pkg_config`:

```bash
$ docker-compose run --no-deps --rm tracer-2.1 /bin/bash
  # doing this inside docker is fine because it doesn't persist
$ rm /usr/bin/pkg-config
$ bundle exec rake clean compile
 # ...
+------------------------------------------------------------------------------+
| Could not compile the Datadog Continuous Profiler because                    |
| the `pkg-config` system tool is missing.                                     |
| This issue can usually be fixed by installing:                               |
| 1. the `pkg-config` package on Homebrew and Debian/Ubuntu-based Linux;       |
| 2. the `pkgconf` package on Arch and Alpine-based Linux;                     |
| 3. the `pkgconf-pkg-config` package on Fedora/Red Hat-based Linux.           |
|                                                                              |
| The Datadog Continuous Profiler will not be available,                       |
| but all other ddtrace features will work fine!                               |
|                                                                              |
| For help solving this issue, please contact Datadog support at               |
| <https://docs.datadoghq.com/help/>.                                          |
+------------------------------------------------------------------------------+
```

Closes #2068
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants