Unable to debug

I'd +1 this concern. I see the debug info for an instant, and then it's gone.

I did manage to pull the data after wailing away on Ctrl+A Ctrl+C and grabbing it in the buffer.

The final like of the debug that I did manage to get was as follows.

SMTP -> FROM SERVER:250 2.0.0 Resetting
SMTP Error: Could not authenticate. Redirecting to https://**mysite**/en/admin/config/system/smtp.

Looks like this is fired off by a combo of PHPMailer->SmtpConnect() throwing an exception, and SMTP->Reset()

It would be preferable if the debug info was displayed either as Drupal error message, or if there wasn't a redirect on a failure.

I'd +1 this concern. As the debug info is shown only for an instant and it is quite difficult to catch it, is there a workaround to save this debug info in a log file or into watchdog?
"enable debugging" in /admin/config/system/smtp is set,
but the "details" in admin/reports/dblog/ shows only:
Error sending email (from abc@mail.de to abc@mail.de with reply-to not set).

Is it possible to send all these nice EHLO-, STARTTLS-, PLAIN LOGIN-messages from smtp to a logfile?

I am facing the same issue as per #3 comment.
Also in my case even not coming for an instant the logs after email debugger on.

is there any update on this?

Hi

I'd +1 this concern.

Recently we have had to address numerous issues with sites using the SMTP module, due to increasing security prevention measures.

The 7.17 version of this module provides much better debugging support. see attached screenshots

There are two points here, one is about where to log, and the other is the level of debug.

SMTP module uses PHPMailer, and does not specific where to log, by default, PHPMailer use 'echo' to output the log, we need alter it with Drupal logger to log in Recent log messages page(admin/reports/dblog). We can do this when initialize PHPMailer, and set its logger with Drupal logger.

For the level of debug, PHPMailer support 5 levels of debug.

1. DEBUG_OFF: No output
2. DEBUG_CLIENT: Client messages
3. DEBUG_SERVER: Client and server messages
4. DEBUG_CONNECTION: As SERVER plus connection status
5. DEBUG_LOWLEVEL: Noisy, low-level data output, rarely needed

we can implement this feature, and change the SMTP config form to config this, add a link to Recent log messages(admin/reports/dblog) in description to tell us where to review the logs, and initial PHPMailer with configured level of debug.

log.png demonstrates the result of the log in Recent log messages page.

config.png demonstrates the changes of SMTP config form.

I would find it much more useful to have all the log messages grouped into one dblog output, which seems to me an achievable aim. What do other people think about that?

I too would find it more useful if all the messages were in one log entry. The patch does this:
+ $mailer->Debugoutput = $logger;
where $mailer is the PHPMailer and $logger is the Drupal 'smtp' logger channel.

I find it interesting that PHPMailer accepts a \Psr\Log\LoggerInterface as an output destination! In Drupal, all registered loggers will receive the output of every logger channel. Thus, the Dblog logger will get every entry sent to the 'smtp' channel.

But the problem here is that it's PHPMailer, not the SMTP module, which is sending each individual log entry. In order to change this, instead of:
+ $mailer->Debugoutput = $logger;
you will have to do something like:

+      $mailer->Debugoutput = function($message, $debug_level) {
+        // add $message to temporary storage  
+      };

This will force PHPMailer to execute that anonymous function for every entry, and instead of sending each entry individually you can use the anonymous function to accumulate all the messages into a place I call "temporary storage". After the sending is completed (I'm not sure when/where that is ...) you would then have to send the contents of the temporary storage to the 'smtp' logger channel using $this->logger->log().

Sounds good to use one dblog entry, and I've implement it as @TR suggestion.

fix test issues.

@drupalfan79's code looks like a good starting point, but would be improved by using containers/injection from the main code path. I haven't looked into how that might be done, sorry.

I would particularly suggest that a "try{} finally{}" wrapper was used here in some way, so that even should an exception be thrown the temporary storage would be sent to log before the exception propagated out of the code.

Please also fix the missing newline (line 140) in the patch.

[[ try/finally is similar to try { stmts; } catch($ex) { stmts; throw $ex;} ]]

@rivimey Thanks for your review, add I've updated the patch.

would be improved by using containers/injection from the main code path

I've moved debug function to the container to use injection.

try{} finally{}

I've put it into finally{}

fix the missing newline (line 140)

I've fixed it.

@drupalfan79 I tested the patch and it worked great for me.

Thanks, much better now, just a couple of other issues.

1. +++ b/src/Form/SMTPConfigForm.php
   @@ -63,13 +65,22 @@ class SMTPConfigForm extends ConfigFormBase {
   +    $this->renderer = $renderer;
   
   @@ -302,11 +314,32 @@ class SMTPConfigForm extends ConfigFormBase {
   +    $list = $this->renderer->render($item_list);
   

   Why this is call to render() needed? Normally D8/9 practice is to never explicitly call render because if nothing else will, twig will call it. I believe this is only used in the list, and so I think it would be very much worth commenting why the renderer is being included. For example, it's got nothing to do with rendering the mail body (which is of course already rendered)...

2. +++ b/src/Form/SMTPConfigForm.php
   @@ -302,11 +314,32 @@ class SMTPConfigForm extends ConfigFormBase {
   +      '#items' => [
   +        'Debug off -- it will disable all logging for this module.',
   +        'Debug client -- it will log client messages when an email is sent.',
   +        'Debug server -- it will log client and server messages when an email is sent.',
   +        'Debug connection -- it will log server plus connection status.',
   +        'Debug lowlevel -- Noisy, low-level data output, rarely needed.',
   +      ],
   ...
   +      '#options' => [
   +        '0' => $this->t('Debug off'),
   +        '1' => $this->t('Debug client'),
   +        '2' => $this->t('Debug server'),
   +        '3' => $this->t('Debug connection'),
   +        '4' => $this->t('Debug lowlevel'),
   

   I think maintainability would be improved if the #items list, and the #options lines 335..339, be refactored into an assoc array, with the Key from 335.. and the Value from 321 (stripping the first part which should not be duplicated).. And in passing, either both sets of strings need t() or neither do, so could we add this->t() around the #items values?

   Then use array_values() / array_keys() on that to get the right version? For example, array_keys() will automatically create indexes 0..4 for you.

   It would ensure that the two lists kept in sync and the correct meaning was attached to both.

@rivimey Thanks for your review, and I've updated it.

it would be very much worth commenting why the renderer is being included.

I've commented it.

maintainability would be improved if the #items list be refactored into an assoc array

I've refactored it to the assoc array.

drupalfan, many thanks for your work on this. I hope I am being useful! :)

I can see you have included my comment about the renderer, but I was hoping you would be able to fill in the actual reason the renderer is needed:
As I said earlier, I don't think calling the renderer was needed here at all?

I presume you decided not to translate the (new) debug array intentionally. As I said, one or the other, but I was expecting t() for all the strings?

@rivimey Thanks for your review, and sure, you are much helpful!

I was hoping you would be able to fill in the actual reason the renderer is needed:
As I said earlier, I don't think calling the renderer was needed here at all?

Yeah, the actual reason need the renderer is to render two item_list, one is in the description of debug_level form element:

    $item_list = [
      '#theme' => 'item_list',
      '#items' => array_values($debug_levels),
    ];
    $list = $this->renderer->render($item_list);
    ...
    $form['smtp_debugging'] = [
      '#type' => 'select',
      '#options' => array_keys($debug_levels),
      '#title' => $this->t('Debugging and logging'),
      '#default_value' => $config->get('smtp_debugging'),
      '#description' => $this->t('Choose the appropriate log level, and you can check the log messages in @log', ['@log' => $link]) . $list,
      '#disabled' => $this->isOverridden('smtp_debugging'),
    ];

The other one is to render messages in logger.

      $item_list = [
        '#theme' => 'item_list',
        '#items' => [],
      ];
      foreach ($debug_logs as $debug_log) {
        $item_list['#items'][] = $debug_log['message'];
      }
      $debug_logs_message = $this->renderer->render($item_list);
      $logger->log('debug', $debug_logs_message);

If we don't use renderer, then how we render these item_list ?

I was expecting t() for all the strings

If we use t() in the array keys like this:

    $debug_levels = [
      $this->t('Debug off') => $this->t('Debug off -- it will disable all logging for this module.'),
      $this->t('Debug client') => $this->t('Debug client -- it will log client messages when an email is sent.'),
      $this->t('Debug server') => $this->t('Debug server -- it will log client and server messages when an email is sent.'),
      $this->t('Debug connection') => $this->t('Debug connection -- it will log server plus connection status.'),
      $this->t('Debug lowlevel') => $this->t('Debug lowlevel -- Noisy, low-level data output, rarely needed.'),
    ];

it throw warning:

Warning: Illegal offset type in Drupal\smtp\Form\SMTPConfigForm->buildForm()

and break the form, alternatively, we need use it like this:

    $debug_levels = [
      [
        'level' => $this->t('Debug off'),
        'description' => $this->t('Debug off -- it will disable all logging for this module.'),
      ],
      [
        'level' => $this->t('Debug client'),
        'description' => $this->t('Debug client -- it will log client messages when an email is sent.'),
      ],
      [
        'level' => $this->t('Debug server'),
        'description' => $this->t('Debug server -- it will log client and server messages when an email is sent.'),
      ],
      [
        'level' => $this->t('Debug connection'),
        'description' => $this->t('Debug connection -- it will log server plus connection status.'),
      ],
      [
        'level' => $this->t('Debug lowlevel'),
        'description' => $this->t('Debug lowlevel -- Noisy, low-level data output, rarely needed.'),
      ],
    ];
    $levels = [];
    $descriptions = [];
    foreach ($debug_levels as $debug_level){
      $levels[] = $debug_level['level'];
      $descriptions[] = $debug_level['description'];
    }

Thanks for your encouragement :-) and sorry it's been a while. It's just been so hot here in the last few days I couldn't think.

+++ b/src/Form/SMTPConfigForm.php
@@ -302,11 +316,27 @@ class SMTPConfigForm extends ConfigFormBase {
+      '#description' => $this->t('Choose the appropriate log level, and you can check the log messages in @log', ['@log' => $link]) . $list,

I now see how $list is being used, and consequently understand why render() was used. Previously I was using the Dreditor tool, which for me chops off lines after the first 100-ish characters. So I didn't see there was a sneaky ". $list" at the end of the line.

So, Please could you format this line so that the ". $list" at the end of it is not out of sight!! I hate long lines for precisely this reason.

Returning to the matter at hand, I hadn't really realized that the '#description' field was capable of accepting fully rendered html (as opposed to simple plain text). Can it accept a render array too? That is, would it work with:

'#description# => $item_list,

... if so, the text on this line 'Choose the app...' could be moved into the definition of $item_list, and then we don't need render()! Result!

Re: and break the form, alternatively, we need use it like this:

I had not expected this. Hey ho.

I understand that the second (long) form is hardly any better, though you can improve on the loop at the end using the array filtering tools to select first just the 'level' and second just the 'description' sub-elements.

Lets leave it without t() for the moment, as in your last patch, in the name of making useful progress. I don't think this is a critical point. Perhaps add an Issue describing it and marking it for further work, once this issue is closed.

Changed my mind: lets go with the long version, as you wrote it. While it is a bit lengthy it is very clear and simple and it's unlikely there will be any issues with it.

@rivimey you are right, we can use render array to #description attribute of the form element directly, so we do not need render service in the config form any more. Thank you!

The above patch doesn't apply cleanly to the 1.0 release. Rerolled.

Also made the link to "recent log messages" conditional as the "dblog.overview" route only exists if the dblog module is enabled and a lot of production sites don't have that module enabled and rely on syslog instead.

Attaching rerolled patch for review.

A lot of the changes to the tests seem to have already been added to the new release so didn't change much there other than what the patch applied cleanly and a minor code style change.

Adapt the tests.

Can you post an interdiff.txt please?

Whoops.

Here's an interdiff between #34 and #36.

Not sure how to capture an interdiff from #33 as it doesn't apply cleanly.

A big problem with the patch is that it changes the 'smtp_debugging' configuration variable from a boolean to a string holding a log level, with a corresponding change in the form element from a checkbox to a select, but the patch does not change the default configuration in smtp.settings.yml or the configuration schema in smtp.schema.yml. Additionally, there is no hook_update_N() to update existing sites to the new value/meaning of 'smtp_debugging', and 'smtp_debugging' is still treated as a boolean in some places.

I suggest, instead of re-purposing this configuration variable, there should be a new configuration variable called something like 'smtp_log_level' to hold the string log level. The old configuration variable 'smtp_debugging' should remain unchanged. The configuration form should use a little Ajax to expose the new select box for the log levels if the 'smtp_debugging' checkbox is checked. The configuration file and schema would still need to be updated, and we would still need a hook_update_N() but it would be easy - just set the new configuration variable to its default setting.

I don't think it's necessary or desirable to list the log levels in the #description of the select - all the levels are there in the select, why list them again in the description? I don't think we need the @link either, maybe just add a statement that the logs are sent to the 'smtp' logger channel - where the logger channels store information is site-specific as stated in #34.

Also, be careful not to introduce new coding standards errors - there are two new ones here ("Unused use statement" and the finally{ needs a space). You don't have to correct existing coding standards errors, in fact I would prefer you didn't because it just obscures the actual functional changes being made by the patch, and increases the probability that the patch will conflict with others and/or need to be re-rolled. In general coding standards fixes should be handled in their own issue and not mixed into other issues.

@TR, good points.

Code changes:

1. added ajax to smtp_debugging element in configure form
2. created a new element smtp_debug_level
3. updated smtp.settings.yml with smtp_debug_level
4. updated smtp.schema.yml with smtp_debug_level
5. cretaed smtp_update_8005() to update setting
6. removed the log levels and link in the #description for clean

Hello @drupalfan79. Thank you for the updates.

I applied the patch via composer and ran drush updb but still can't see error details.

This is a screenshot of the error message that flashes on the screen: (I screen captured before applying patch.)

I tried all levels of debug with no success.

@cesarg, could you try this patch updated.

if you enabled dblog module, you will see the message with:

CLIENT -> SERVER: EHLO d8.mac
...

and you may need to run /update.php after apply the patch.

Hello, after applying patch #44 via composer. Error now appears on log... Not sure why it is displayed this way tho.

the message is from phpmailer, you can report this issue to phpmailer.

Tested the patch in #44 and it works well! Thank you!

At a minimum, the update should be in the post update hook not in the install file. Otherwise looking pretty good, lets have a few more people manually test before committing.

@japerry, in Drupal 8, hook_update_N() should be put in *.install file to add a configuration key, it's different than Drupal 7.

I've spent some time debugging with this patch installed (because of another bug recently introduced but I'm not sure where!).

I am uploading a new patch, but please consider this as a Request for Comments rather than a definite improvement over patch -44 above. Have I overlooked a good reason the code is as it is?

I noticed that the $config override was not working properly, and so have implemented a some changes for that. In outline, the config function getEditable never shows overrides but we want them to be visible when isOverridden is true, so users can see the settings as they are applied now. At least, that's true for me.

So a summary of the changes - at the end of the constructor in SMTPConfigForm.php

+    $this->config_read = $this->configFactory->get('smtp.settings');
+    $this->config_edit = $this->configFactory->getEditable('smtp.settings');

and then for each place that uses a '#default_value' key, make a change of this type:

-      '#default_value' => $config->get('smtp_keepalive'),
+      '#default_value' => $this->config_read->get('smtp_keepalive'),

Also, add private local variables config_read and config_edit. Where we used to call `$config->set()`, now call `$this->config_edit->set()`. And finally use the new objects in the isOverridden() function, and remove the other calls to configFactory->get...

Other Observations:

1. I did notice that the code around smtp_protocol looks a bit smelly, calling $config->set just so that a config->get a few lines later would do the right thing; I changed it to read from config_read->get() into a local var, override the local if needed, and set #default_value from that.

2. In the submitForm callback, there is a comment "Set as default mail system if module is enabled", and I really feel the code following has a misfeature. The effect of the current code is to read the getEditable() value of `smtp_on` (i.e. no overrides), and if either that is ON, or that it has been overridden, and the submitted form value is ON, then to install the mail system. Firstly, the #disabled form values should stop this ever happening, but if it did, the user's intent was to switch the module on, but `smtp_on` is still overridden, and so even if installed as the mailsystem, smtp will be off again next time.
I feel the proper action is to regard this situation as a validation error: either remove the override, or don't try to change the value. In other words, the if statement following that comment should just be `if ($this->config_read->get('smtp_on')) {`

3. Lastly, I noticed that the variable $mail_config is written twice in submitForm(); once at the start of the function and once in the default_system_mail = 'php_mail' block. I've let this be for now as there could be a good reason for this.

@rivimey
About $config override, there is a separate issue: https://www.drupal.org/project/smtp/issues/2826189

Any movement on this. I'm using the #44 patch happily on a site at the moment.

This should fix the test failure in #51.

Ah, the variable name was wrong also.

Even with the debug option checked the latest patch doesn't make any difference - no debug output is added when you try sending a test message.

I also think it'd work better to just use Form API #state to control whether the debug level field is displayed.

After testing it some more I worked out the problem - the debugging output is stored in Watchdog, not displayed to the screen. So "Logs the output from the server for every email that is sent" would be a better description on the checkbox.

The AJAX logic is unnecessary, just use the states system.

This resolves the tests locally.

And the tests are green! Woot!

I have installed the latest dev version and applied the latest reroll by DamienMcKenna from #65
While the patch applies and an error message is logged to in watchdog, there are no details from the debug output in the watchdog messages.
As debug level I have used "Debug server" which should give quite some details.

Re-rolled against latest dev. I don't have quite a setup to test this, so going to keep needs review.

Drupal\Tests\smtp\Unit\Plugin\Mail\SMTPMailSystemTest::testMailHeader() is failing because this is something new that was committed just today (see #3174535: Invalid address: (cc): PHPMailer Issue) and the above patch doesn't know about it yet. testMailHeader() needs to be modified for the new constructor parameters that this patch introduces.

Rerolled again.

Patch needs to be re-rolled again because of #3298110: Automated Drupal 10 compatibility fixes

And the test fail still needs to be addressed. See #70.

Just a reroll.

I'll take a look at the non-passing tests.

Some new params were missing from the constructor.

-    $mailSystem = new SMTPMailSystemTestHelper(
+    $mailSystem = new
+    SMTPMailSystemTestHelper(

This change is wrong. Not sure why this was done.

Additionally, this patch adds some coding standards violations which need to be fixed. For example:
+ finally{
and

+   * * @param \Drupal\Core\Render\RendererInterface $renderer
+   *   The renderer.

Note, the patch doesn't need to fix pre-existing coding standards violations, but it should not be introducing new violations like these.

Sorry for that.
I'll take a look at some CS problems on this patch.

I've corrected the PHPCS violations introduced in this patch.

If you set the issue back to "Needs review" the testbot will automatically run the tests.

Hi everyone, I rerolled the patch due to rejection on application.

For anyone looking for a workaround to easily debug SMTP issues on your Drupal environment. I was able to get the output by inspecting the POST request in my web developer console when sending a test email from /admin/config/system/smtp. If you right click on the POST request, Copy -> Copy as cUrl. Then paste that in your terminal, you will see the SMTP Debug output.

The reason #83 has a failed test and #80 didn't is because in between these patches there was a new test case added by #3308653: SMTP From address meta issue. This new test case needs to be modified to add constructor parameters in the same way that #80 and #83 modify the other test cases.

This is a simple fix, here's a re-roll.

Whoops my fault. I spelled something wrong. Here's a patch that corrects that.