Katello deprecation warnings not showing up in production.log

cintrix84 · March 9, 2020, 4:27pm

Hi All,

We were looking through some things in Katello to see why deprecation warnings were not showing up and we found that they were sliceneded in a production environment.

I have raised this issue about it:

I made a pr to switch to Rails Logger, since we do rely on users seeing the warnings.

Justin_Sherrill · March 9, 2020, 4:29pm

To make it clear, https://github.com/theforeman/foreman/blob/develop/config/initializers/deprecations.rb is what is silencing the deprecation warnings. Removing this would expose all the internal rails-related deprecation warnings to production users, so it made sense to not do that, and instead rewrite api_deprecation_warning() to log directly IMO

ekohl · March 9, 2020, 4:53pm

I’ve been thinking about this and we have a notification framework. Should we trigger that (as well or instead of) so admins get a notification? Maybe it’s too intrusive, but most admins don’t scan the logs that often and this pushes them more actively.

Justin_Sherrill · March 9, 2020, 5:36pm

In katello we typically try to add UI deprecation notices for features
so that the user will see them before they take any particular action.

I’m not sure UI notifications are the best way either, but i’ll leave
that to others to support/oppose.

ekohl · March 9, 2020, 5:53pm

My thinking about about scripts that use the API. Currently that’s hard to track

Jonathon_Turel · March 9, 2020, 6:57pm

UI notifications would be good provided that they don’t spam notifications upon each API call and have very clear messaging on the call made and how to remedy. Sending the messages currently being logged as notifications would probably not be useful.

ekohl · March 9, 2020, 8:39pm

As a user I’d like to know:

When was it sent (timestamp)
Where did it come from (IP + user agent)
Which endpoint (API path + method)

This should help me with finding out which script or tool was making the API call.

Thinking out loud now. We can log this to a file named deprecations-MAJOR.MINOR.log. If the file is created, a notification is created that the file can be read. It’s only appended to and not rotated. If a user thinks they’ve fixed all deprecations, they remove/rotate the file. When a new file is created, a new notification pops up again and the user knows to look into it. By including the version number, we ensure that when a user upgrades a new file is created.

Jonathon_Turel · March 9, 2020, 9:09pm

I really like this idea. By increasing the visibility we can feel more secure in removing deprecated code. Right now it makes me a little apprehensive even for very old deprecations as I’m sure there are users who never would have seen them in the production log (regardless of $SUBJECT). Not to mention possible gaps in omitting deprecations from release notes or making the appropriate API doc amendments.

tbrisker · March 10, 2020, 8:50am

In the past few versions we have used UI notifications for deprecation notification, for example:

github.com

theforeman/foreman/blob/1.24-stable/config/initializers/deprecations.rb

ActiveSupport::Deprecation.behavior = :silence if Rails.env.production?

Foreman::Application.configure do |app|
  config.after_initialize do
    next if Foreman.in_rake?
    next unless ActiveRecord::Base.connection.adapter_name.downcase.starts_with?('mysql')
    blueprint = NotificationBlueprint.find_by_name('feature_deprecation')
    next unless blueprint
    message = UINotifications::StringParser.new(blueprint.message, {feature: 'MySQL as a backend database', version: '2.0'}).to_s
    next if blueprint.notifications.where(message: message).any?
    Notification.create!(
      audience: Notification::AUDIENCE_ADMIN,
      message: message,
      notification_blueprint: blueprint,
      initiator: User.anonymous_admin,
      :actions => {
        :links => [
          {
            :href => 'https://theforeman.org/2019/09/dropping-support-for-mysql.html',
            :title => _('Further Information'),

This file has been truncated. show original

We have two blueprints already for deprecation notifications that can be used for features and settings at:

github.com

theforeman/foreman/blob/develop/db/seeds.d/170-notification_blueprints.rb#L50-L63


{
  group: N_('Deprecations'),
  name: 'setting_deprecation',
  level: 'warning',
  message: N_('The %{setting} setting has been deprecated and will be removed in version %{version}'),
  expires_in: 30.days,
},
{
  group: N_('Deprecations'),
  name: 'feature_deprecation',
  level: 'warning',
  message: N_('Support for %{feature} has been deprecated and will be removed in version %{version}'),
  expires_in: 30.days,
},

and it is easy to add more if needed (e.g. for API deprecations).

Instead of having to deal with files to track these and identify when a notification should be presented, why not generalize the code that was used to create the notifications before into something that is reusable and only creates a notification once if it doesn’t exist that can be trigger from anywhere? in this case, a deprecated api call will create a notification that will only be shown once. The notification can contain further information if we want it to - for example, which user used the call or what was the request id of the first call, or even send the notification to the user as well as the admins.

lzap · March 10, 2020, 9:08am

No, this is not a good idea. Users have nothing to do with code deprecations, they are simply not good target group. We are. And deprecations already have a good feature - they actually fail in test environment.

I am actually against this PR, this is designed well I think:

deprecation warnings do nothing in production mode
deprecation warnings do show up in development mode
deprecation warnings do raise exception in test mode (if they pass version threshold)

We have the best of all three worlds. It’s important to realize that we will always have some deprecation warnings - that’s why they do exits: to warn developers and to span for some time so plugin authors can adopt.

Marek_Hulan · March 10, 2020, 9:57am

I think it’s not black or white only. There are deprecations which are important for admins (not regular users). Admins should know their scripts or users are using e.g. deprecated API endpoints and should migrate the tooling to use new ones. That’s what I believe @ekohl suggests.

Then there are deprecations of internal API (aka deprecated rubyge methods etc) which admins can’t really do much about. This is what I believe @lzap has in mind.

Therefore I think we need to distinguish in between the two types of deprecations - code deprecations and API deprecations. Does that make sense?

ekohl · March 10, 2020, 10:09am

And just to be explicit, we are also considering the REST API. Not only the internal API.

John_Mitsch · March 10, 2020, 1:16pm

+1

I think we are talking about multiple things:

Internal API deprecations that only devs should know about
External REST API deprecations that foreman users who use the API with some client should know about
Functionality that is being removed in both the API and UI that users should know about (like the settings example above where they get a notification)

It seems like the code should reflect these differences and the logging problems may come from us treating these as the same.

lzap · March 11, 2020, 12:14pm

Yeah I actually changed my mind in the PR comment as I digged deeper into the problem. I think a warning message would be fine, but I’d like to keep using ActiveRecords deprecations, thus only adding the warning message on top of that. In Rails 6 it will be possible to specify warnings which are treated differently - this could be useful.

lzap · March 11, 2020, 12:25pm

I agree, I see no reason for closing the PR. I was quite pessimistic with the change in the first place, but this was because it comes without any description and I had no context. I think it’s quite reasonable to remove ActiveSupport::Deprecation.behavior = :silence if Rails.env.production? from our codebase but since I expect that customers will complain about millions of warning messages in logs, we should create a setting that will silence those if needed.

So it could be a two-liner patch. Change of the line mentioned and new setting in settings.yaml.example explaining the new value. Preferably a new installer/puppet option but here is the issue I’ve pointed on already - putting every single detail into installer makes it overhelming. I believe we should have two tiers of settings - one managed by the installer and one for very detalied things like this one. This is another discussion I guess.

Justin_Sherrill · March 11, 2020, 12:35pm

I don’t know how we silence those without also silencing our own deprecation warnings currently. And I think most users will just turn them off if the ones they care about are a small % compared to ones they don’t care about.

lzap · March 11, 2020, 1:05pm

Isn’t the goal to actually show them? What I suggest is:

if Rails.env.production? && Settings[:silence_deprecation_warnings]
  ActiveSupport::Deprecation.behavior = :silence 
end

Another approach is to create a new named logger and make sure all deprecations get logged through it. It can be turned on by default but users would be able to turn it off just like any other logger like sql or ldap.

Justin_Sherrill · March 11, 2020, 2:05pm

The goal is to show our own api deprecations, but NOT show the underlying library (rails) deprecation warnings.

It doesn’t seem possible to hide library deprecation but still show our own deprecation warnings without using Rails.logger. But yes, we could create a new logger for this, that is a decent idea.

lzap · March 11, 2020, 2:13pm

Finally an explanation of the problem that makes sense to me.

Yeah, well it’s possible in Rails 6 but that’s not on table at the moment.

I am good with doing the original proposal but into a separate logger. Let’s use a separate name like “deprecated_api” so we can add “deprecated_rails” or “deprecated_app” later on as it might be useful to show these too.