Even if the watchdog call is just a notice, any call to watchdog, will not only create an entry in the syslog or watchdog table (depending on how the site is configured), but will ALSO create an entry in the migrate_message_* table.

It would be nice if migrate_watchdog() filtered any calls to watchdog to only record certain events. If an event happens during migration due to a nodeapi call in another contributed module, we have no way of telling migrate to not ALSO log that event.

What I think would be a sane compromise would be to modify migrate_watchdog() so that:

1. Most basic modification: Any severity level of NOTICE, DEBUG, or INFO is simply ignored by migrate module. This is crude, but it would be the simplest to implement.

2. Change the INT values of the MIGRATION constants to be in a range where there would be NO conflict with the drupal watchdog severity level constants, and in migrate_watchdog() only log messages that have been provided with migration-based severity levels. Ie, if the severity level is a drupal severity level, *ignore* the message; if the severity level is a migration severity constant, log the message. This is more complex, but wouldn't be much work, and would ensure that messages that a migration developer *wanted* logged to the message tables would go there, and messages that did not need to go to the migrate_message_* table would not pollute that table.

If this makes sense to the maintainers, I would be happy to roll a patch for this. This could be phases in iteratively. For example, in solution 2, the constants could simply be redefined, and a filter put in place in the watchdog hook. Then migration code that might, perhaps, be using drupal severity constants could be modified over time, as seen fit, due to context, to use migration based severity constants instead.

Issue fork migrate-1594678

Command icon Show commands

Start within a Git clone of the project using the version control instructions.

Or, if you do not have SSH keys set up on git.drupalcode.org:

Comments

apotek’s picture

Here is a way for me to implement this myself, by overriding the parent class. However, since the severity level constants can not be distinguished from drupal level severity constants (since they share integer values in some cases), the implementation is much more limited and primitive than it should be:

<?php
  /**
   * Pass messages through to the map class.
   *
   * We are overriding the default behavior here since we don't want
   * ALL watchdog notices or alerts to be placed in the migrate
   * message tables, but only important ones.
   *
   * @param string $message
   *  The message to record.
   * @param int $level
   *  Optional message severity (defaults to MESSAGE_ERROR).
   */
  public function saveMessage($message, $level = MigrationBase::MESSAGE_ERROR) {
    switch ($level) {
      case MigrationBase::MESSAGE_ERROR:
      case MigrationBase::MESSAGE_WARNING:
      case WATCHDOG_EMERG:
      case WATCHDOG_ALERT:
      case WATCHDOG_CRITICAL:
      case WATCHDOG_ERROR:
      case WATCHDOG_WARNING:
        parent::saveMessage($message, $level);
        break;
      default:
        Migration::displayMessage($message);
        break;
    }
  }

?>
apotek’s picture

The problem with my approach is this:

<?php
/* The WATCHDOG_* constant definitions correspond to the logging severity levels
 * defined in RFC 3164, section 4.1.1: http://www.faqs.org/rfcs/rfc3164.html */
define('WATCHDOG_EMERG', 0);
define('WATCHDOG_ALERT', 1);
define('WATCHDOG_CRITICAL', 2);
define('WATCHDOG_ERROR', 3);
define('WATCHDOG_WARNING', 4);
define('WATCHDOG_NOTICE', 5);
define('WATCHDOG_INFO', 6);
define('WATCHDOG_DEBUG', 7);

const MESSAGE_ERROR = 1;
const MESSAGE_WARNING = 2;
const MESSAGE_NOTICE = 3;
const MESSAGE_INFORMATIONAL = 4;

?>

In other words, a WATCHDOG_ERROR (3) is the same as a MigrationBase::MESSAGE_NOTICE, and there is no way for me to distinguish between the two in my code.

So I'm tempted to change this to a bug report along the lines of: Ensure Migrate module also follows RFC 3164 in defining its severity levels, OR ensure Migrate module uses a non-clashing set of integer values so that users can distinguish between severity levels that are WATCHDOG error levels and which are MigrationBase messages.

It seems to me the patch would be one of two things, depending on implications (need input from maintainers here, I think):

Either my patch will be:

<?php
const MESSAGE_ERROR = 3;
const MESSAGE_WARNING = 4;
const MESSAGE_NOTICE = 5;
const MESSAGE_INFORMATIONAL = 6;
?>

or something like:

<?php
const MESSAGE_ERROR = 1000;
const MESSAGE_WARNING = 2000;
const MESSAGE_NOTICE = 3000;
const MESSAGE_INFORMATIONAL = 4000;
?>

The weakness of approach 1, is that migrate module will have to continually adjust to drupal's watchdog levels (although since they're tied to an RFC, I don't think that's a big issue).

The weakness of approach 2 is that it's an ugly, non-failsafe kludge :-)

mikeryan’s picture

Status: Active » Postponed (maintainer needs more info)

Let's back up a minute here - I want to see notices in the message log. It's not redundant, it's contextual - this makes the notices visible immediately to the migration developer, and they're tied to the specific source items triggering the notices (so they can be debugged).

If it really bothers you, we could implement a configuration setting to disable it, but I don't think ignoring notices should be the default behavior.

apotek’s picture

but I don't think ignoring notices should be the default behavior.

I agree with you mikeryan. I'm trying to deal with several contributed modules (whose source code I don't control) who send out watchdog() calls all over the place, some for good reason, and most for no good reason at all. If the module developers would have set the $severity param to DEBUG, things would be easier, but they often just call watchdog() with no $severity param attached.

Which means, in the specific case I'm dealing with, that I get 20+ rows in my migrate_message_* table per item migrated. If I migrate a thousand items, I have 20,000 new rows in that table... most of it sheer junk. This is where the noise actually starts to obscure any utility the migrate_message_* tables have. At this point, there is so much junk data in there, I don't even want to look at them.

Since I can't control what contributed modules are doing with watchdog, and since migrate module is hooking into watchdog rather than relying on its own logging system, I need to be able to silence the messages that are actually not relevant to the migration task at hand.

In the end, I managed to do this without modifying any migrate code, so will paste my eventual solution in here as documentation in case someone else is also fighting their way through tons of watchdog notices being thrown into migrate_message_* tables.

In my basic migration class (extends Migration, and is the parent for my specific migration classes), I ended up doing this:

<?php
  public function saveMessage($message, $level = MigrationBase::MESSAGE_ERROR) {
    switch ($level) {
      case MigrationBase::MESSAGE_ERROR:
      case MigrationBase::MESSAGE_WARNING:
        parent::saveMessage($message, $level);
        break;
      case MigrationBase::MESSAGE_NOTICE:
        Migration::displayMessage($message);
        break;
      default:
        // Ignore INFORMATIONAL messages unless verbose mode is
        // enabled.
        if (function_exists('drush_get_context') && drush_get_context(DRUSH_VERBOSE)) {
          Migration::displayMessage($message);
        }
        break;
    }
  }
?>
mikeryan’s picture

Yes, while I've frequently seen some contrib module drop one notice for every node, easy enough to drop a patch in their queue, dealing with 20 is a bit much...

A real simple thing we could do is just support a variable like 'migrate_suppress_notices', and if set to 1 migrate_watchdog() would silently ignore the low-level stuff. Then you can set $conf['migrate_suppress_notices'] in your migration constructor if you're running into this type of issue.

moshe weitzman’s picture

FYI, drush already lets user control this. Perhaps migrate could honor drush's global option? From drush topic core-global-options

 --watchdog                                    Control logging of Drupal's watchdog() to drush log. Recognized values are 'log', 'print', 'disabled'. Defaults 
                                               to log. 'print' shows calls to admin but does not add them to the log. 
apotek’s picture

FYI, drush already lets user control this. Perhaps migrate could honor drush's global option?

This strikes me as the "correct" way to move forward. I was, I see now, already kind of moving in that direction by making my code listen to the drush --verbose option. Responding to the drush --watchdog=log|print|disabled option might be even better.

The only thing we lose here, of course, is that this is specific only to running migrations from the command line.

mikeryan’s picture

Title: All calls to watchdog() function during a migration get entered into the migrate_message tables, which is redundant. » Option to suppress notices
Version: 6.x-2.3 » 7.x-2.x-dev
Status: Postponed (maintainer needs more info) » Active
apotek’s picture

--watchdog Control logging of Drupal's watchdog() to drush log. Recognized values are 'log', 'print', 'disabled'. Defaults
to log. 'print' shows calls to admin but does not add them to the log.

A real world test, however, brings no joy. Using --watchdog=disabled does absolutely nothing to suppress the hundreds of watchdog entries from other modules being spit out during a migration. Many of the messages originate in watchdog() calls, but many of them are also the output to drupal_set_message going to the terminal.

The only thing that works is --quiet, which, however, has the unfortunate side effect of silencing all output except the output from --instrument.

apotek’s picture

Doing this helped silence the output from other modules' drupal_set_message calls....

/**
   * Implements Migration->postImport();
   */
  public function postImport() {
    // Get rid of any drupal_set_message output from modules so we
    // don't clutter a drush-initiated migration.
    if (function_exists('drush_get_option') && !drush_get_option('verbose')) {
      drupal_get_messages(NULL, TRUE);
    }
    parent::postImport();
  }

stevesirois@gmail.com’s picture

I didn't see a case that handle the fact that you can call watchdog yourself in your migration code and got so problem with the output. One case that is probably a bug is when you call watchdog inside the postImport() method. This result in a output with the wrong level of message. Let's say you call watchdog with a WATCHDOG_INFO level, you end up with a [error] message output of migrate. Looking a the code of saveMessage() in sqlmap.inc give you some hints. There's a test at the beginning for the $source_key but when your are in postImport, this variable is empty and you then fall into the ELSE that don't know what to do with this (as mention directly in the TODO source) and simply call Migration::displayMessage($message). The problem is that displayMessage default level is 'error'. So what could have been done at least is to pass a translated $level to displayMessage (because $level is a numeric constant define in Migrate (1 to 4) vs 'status', 'warning, or 'error' as define in drupal_set_message) and get the right level message in the output of migrate (drush command line here). Personnality, I end up doing the same approach as apotek and override the saveMessage instead of modifying the source of Migrate. I simply ignored INFORMATIONAL level.

sarjeet.singh’s picture

Please use below code to solve this issue.

diff --git a/plugins/sources/sqlmap.inc b/plugins/sources/sqlmap.inc
index ccfacd4..6fae00e 100644
--- a/plugins/sources/sqlmap.inc
+++ b/plugins/sources/sqlmap.inc
@@ -484,7 +484,8 @@ class MigrateSQLMap extends MigrateMap {
}
else {
// TODO: What else can we do?
- Migration::displayMessage($message);
+ // Display Message with correct level instead of default level 'error'.
+ MigrationBase::saveMessage($message, $level);
}
}

lwalley made their first commit to this issue’s fork.

lwalley’s picture