Issue #357: Problem with smtplib with gmail accounts

Reported by:	vyom
State:	resolved
Created on:	2020-02-07 03:41
Updated on:	2020-02-18 02:52

Description

With python 2 Kallithea smtplib works fine with smtp_tls is set to true with username and password. But once update to python 3 with new kallithea 0.5.2 it gives an error of starttls.

‌

Due to this error creating a fork of repository fails, as it needs to send mail before creating a fork. Due to this could not update to new version and it blocks the usage.

Attachments

Comments

Comment by Thomas De Schampheleire, on 2020-02-07 06:08

Could you please paste the error and traceback here?

Comment by Mads Kiilerich, on 2020-02-08 02:03

Also: Exactly how is mail configured in your .ini (with username/password anonymized)?

FWIW, the following works fine on kallithea-scm.org:

smtp_server = smtp.gmail.com
smtp_username = something@example.com
smtp_password = password
smtp_port = 587
smtp_use_tls = true

‌

Comment by vyom, on 2020-02-09 23:11

My settings are exactly the same. I have a doubt that with gunicorn 20 and python 3 paste configuration do not start. It does not start the server in port 5000 but takes default port 8000. I think similar way it does not take the smtp settings with gunicorn, not sure though:

‌

[Unit]
Description=kallithea-scm
After=network.target

[Service]
PIDFile=/run/gunicorn/pid
User=www-data
Group=www-data
RuntimeDirectory=gunicorn
WorkingDirectory=/home/kallithea/projects/kallithea
Environment=VIRTUAL_ENV=/home/kallithea/projects/kallithea/venv3
Environment=PATH=$VIRTUAL_ENV/bin:$PATH
ExecStart=/home/kallithea/projects/kallithea/venv3/bin/gunicorn --pid /run/gunicorn/pid --paste scm.ini
ExecReload=/bin/kill -s HUP $MAINPID
ExecStop=/bin/kill -s TERM $MAINPID
PrivateTmp=true

[Install]
WantedBy=multi-user.target

‌

The ini file for scm.ini has settings:

‌

## SMTP server settings
## If specifying credentials, make sure to use secure connections.
## Default: Send unencrypted unauthenticated mails to the specified smtp_server.
## For "SSL", use smtp_use_ssl = true and smtp_port = 465.
## For "STARTTLS", use smtp_use_tls = true and smtp_port = 587.

smtp_server = smtp.gmail.com
smtp_username = admin@test.com
smtp_password = xxxxxxxxx
smtp_port = 587
#smtp_use_ssl = true
smtp_use_tls = true

[server:main]
## WAITRESS ##
use = egg:gunicorn#main
## number of worker threads
threads = 2
## MAX BODY SIZE 100GB
max_request_body_size = 107374182400
## use poll instead of select, fixes fd limits, may not work on old
## windows systems.
#asyncore_use_poll = True

## COMMON ##
host = 0.0.0.0
port = 5000

## middleware for hosting the WSGI application under a URL prefix
#[filter:proxy-prefix]
#use = egg:PasteDeploy#prefix
#prefix = /<your-prefix>

‌

Comment by Mads Kiilerich, on 2020-02-10 00:18

Nice systemd service file. We should probably ship/document something like that.

It seems like gunicorn (like uwsgi) by design doesn't read "meta" information (such as listen port) form the .ini file. It must be specified when launching gunicorn (in your systemd service file). Again: perhaps something the Kallithea documentation perhaps should mention, in an attempt of giving a fair description of the most common web/wsgi server choices.

I can however not imagine that this is related to the mail problems.

The question from Thomas about error / traceback has not been answered, and we do thus not have enough information to help. Check the server log. Either in the systemd service journal, or by launching gunicorn manually. Perhaps temporarily set use_celery=false, set debug=true and set debug log levels.

Comment by vyom, on 2020-02-10 01:16

This works fine in Python 2 but did not work with Python 3. Actually in Python 3 I did specify port with -b option as shown below, but it did not work.

‌

Also will attach the mail log. Exactly same settings works perfectly fine with gunicorn in Python2 but does not work in Python 3. Just for the purpose of the bug I changed the mail address.

‌

[Unit]
Description=kallithea-scm
After=network.target

[Service]
PIDFile=/run/gunicorn/pid
User=www-data
Group=www-data
RuntimeDirectory=gunicorn
WorkingDirectory=/home/kallithea/projects/kallithea
Environment=VIRTUAL_ENV=/home/kallithea/projects/kallithea/venv3
Environment=PATH=$VIRTUAL_ENV/bin:$PATH
ExecStart=/home/kallithea/projects/kallithea/venv3/bin/gunicorn --pid /run/gunicorn/pid --paste scm.ini -b 0.0.0.0:5000
ExecReload=/bin/kill -s HUP $MAINPID
ExecStop=/bin/kill -s TERM $MAINPID
PrivateTmp=true

[Install]
WantedBy=multi-user.target

The server logs for mail shows issue STARTTLS error 530. This will only happen when the worker cannot get the settings from ini file for TLS, this is my guess. Exactly same settings work fine with Python 2, so not sure if it’s due to gunicorn or application code.

Feb 10 06:54:37 kallithea-5-2 gunicorn[6562]: [2020-02-10 06:54:37 +0800] [6562] [INFO] Starting gunicorn 20.0.4
Feb 10 06:54:37 kallithea-5-2 gunicorn[6562]: [2020-02-10 06:54:37 +0800] [6562] [INFO] Listening at: http://0.0.0.0:5000 (6562)
Feb 10 06:54:37 kallithea-5-2 gunicorn[6562]: [2020-02-10 06:54:37 +0800] [6562] [INFO] Using worker: sync
Feb 10 06:54:37 kallithea-5-2 gunicorn[6562]: [2020-02-10 06:54:37 +0800] [6564] [INFO] Booting worker with pid: 6564
Feb 10 06:55:05 kallithea-5-2 gunicorn[6562]: Error while reporting exception with <backlash.tracing.reporters.mail.EmailReporter object at 0x7f1b2affc080>
Feb 10 06:55:05 kallithea-5-2 gunicorn[6562]: Traceback (most recent call last):
Feb 10 06:55:05 kallithea-5-2 gunicorn[6562]:   File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/backlash/tracing/reporters/mail.py", line 49, in report
Feb 10 06:55:05 kallithea-5-2 gunicorn[6562]:     result = server.sendmail(self.from_address, self.error_email, msg.as_string())
Feb 10 06:55:05 kallithea-5-2 gunicorn[6562]:   File "/usr/lib/python3.6/smtplib.py", line 867, in sendmail
Feb 10 06:55:05 kallithea-5-2 gunicorn[6562]:     raise SMTPSenderRefused(code, resp, from_addr)
Feb 10 06:57:52 kallithea-5-2 systemd[1]: Stopping kallithea-scm...
Feb 10 06:57:52 kallithea-5-2 gunicorn[6562]: smtplib.SMTPSenderRefused: (530, b'5.7.0 Must issue a STARTTLS command first. e22sm13318371wme.45 - gsmtp', 'test@test.com')[2020-02-10 06:57:52 +0800] [6564] [INFO] Worker exiting (pid:

‌

Comment by Mads Kiilerich, on 2020-02-10 14:32

That is “backlash” (a part of the TurboGears framework that Kallithea is using) failing trying to send an error message - not Kallithea itself. Can you check with http://localhost:5000/_admin/settings/email , just to verify that Kallithea mails works?

Are you sure backlash error reporting worked before? I guess it never worked, and now you are hitting some other py3 problem which triggers the backlash problem.

It seems like we need the following in .ini to make backlash work with secure mail:

get trace_errors.smtp_server = smtp_server
get trace_errors.smtp_port = smtp_port
get trace_errors.from_address = error_email_from
get trace_errors.error_email = email_to
get trace_errors.smtp_username = smtp_username
get trace_errors.smtp_password = smtp_password
get trace_errors.smtp_use_tls = smtp_use_tls

Can you confirm that works … and tell what root cause problem it then reveals?

‌

Comment by vyom, on 2020-02-10 15:27

This is the result after trying to send email via Kallithea.

You can see at the end is backlesh in loggers.

################################
### LOGGING CONFIGURATION   ####
################################

[loggers]
keys = root, routes, kallithea, sqlalchemy, tg, gearbox, beaker, templates, whoosh_indexer, werkzeug, backlash

After doing this the settings for backlash still gets an error and received an email with error. This error is same as what I get in Python 2. In case of Python 2 in spite of this error the fork of the repository will be created, but in Python 3 the fork is not created. So I cannot use Python 3 with Kallithea and still get errors.

TRACEBACK:
Traceback (most recent call last):
  File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/tg/appwrappers/session.py", line 71, in __call__
    response = self.next_handler(controller, environ, context)
  File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/tg/appwrappers/i18n.py", line 71, in __call__
    return self.next_handler(controller, environ, context)
  File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/tg/wsgiapp.py", line 243, in _dispatch
    return controller(environ, context)
  File "/home/kallithea/projects/hg/kallithea/kallithea/lib/base.py", line 536, in __call__
    return super(BaseController, self).__call__(environ, context)
  File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/tg/controllers/dispatcher.py", line 118, in __call__
    response = self._perform_call(context)
  File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/tg/controllers/dispatcher.py", line 107, in _perform_call
    r = self._call(action, params, remainder=remainder, context=context)
  File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/tg/controllers/decoratedcontroller.py", line 129, in _call
    output = controller_caller(context_config, bound_controller_callable, remainder, params)
  File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/tg/controllers/decoration.py", line 21, in _decorated_controller_caller
    return application_controller_caller(tg_config, controller, remainder, params)
  File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/tg/configurator/components/dispatch.py", line 114, in _call_controller
    return controller(*remainder, **params)
  File "</home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/decorator.py:decorator-gen-37>", line 2, in repo_check

  File "/home/kallithea/projects/hg/kallithea/kallithea/lib/auth.py", line 648, in __wrapper
    return func(*fargs, **fkwargs)
  File "</home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/decorator.py:decorator-gen-36>", line 2, in repo_check

  File "/home/kallithea/projects/hg/kallithea/kallithea/lib/base.py", line 624, in jsonify
    data = func(*args, **kwargs)
  File "/home/kallithea/projects/hg/kallithea/kallithea/controllers/admin/repos.py", line 188, in repo_check
    if task.failed():
  File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/celery/result.py", line 267, in failed
    return self.state == states.FAILURE
  File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/celery/result.py", line 394, in state
    return self._get_task_meta()['status']
  File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/celery/result.py", line 339, in _get_task_meta
    return self._maybe_set_cache(self.backend.get_task_meta(self.id))
  File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/celery/backends/base.py", line 307, in get_task_meta
    meta = self._get_task_meta_for(task_id)
AttributeError: 'DisabledBackend' object has no attribute '_get_task_meta_for'

‌

In Python 2 it gives error

The settings for celery are correct as I am using it in another project.

‌

####################################
###        CELERY CONFIG        ####
####################################

use_celery = true

## Example: connect to the virtual host 'rabbitmqhost' on localhost as rabbitmq:
broker.url = amqp://sourcecontrol:bitbucket@localhost:5672/kallithea

celery.imports = kallithea.lib.celerylib.tasks
celery.accept.content = pickle
celery.result.backend = redis://localhost:6379/0
#celery.result.dburi =
celery.result.serialier = json

#celery.send.task.error.emails = true
#celery.amqp.task.result.expires = 18000

celeryd.concurrency = 2
celeryd.max.tasks.per.child = 1

## If true, tasks will never be sent to the queue, but executed locally instead.
celery.always.eager = false

‌

Comment by Mads Kiilerich, on 2020-02-11 03:24

We have a communication problem. I’m not entirely sure what you see in which cases. For example whether you applied the trace_errors lines to your .ini and if it made any difference.

Also, the latest problem mentioned here is evidently a problem related to using celery. Celery hasn’t been mentioned before, except that I above asked to try use_celery=false - did you try that? It could seem like we have a general problem with celery, so let’s try to take that out of the equation.

Comment by vyom, on 2020-02-12 02:42

Ok let me complete as follows:

In case of errors Kallithea sends an email. So if I disable celery and ini do not have settings for backtrace it encounters an error. So for Kallithea to send mail and use secure SMTP it will need to have backlash settings:

get trace_errors.smtp_server = smtp_server
get trace_errors.smtp_port = smtp_port
get trace_errors.from_address = error_email_from
get trace_errors.error_email = email_to
get trace_errors.smtp_username = smtp_username
get trace_errors.smtp_password = smtp_password
get trace_errors.smtp_use_tls = smtp_use_tls

Once I disable celery and have above settings it works fine with secure SMTP.

Once I enable celery it gives an error whether I have above settings or not. In Python 2 it will still finish the task after error but in Python 3 it will not e.g. creating a fork.

For celery I see there is another ticket open for disabled backend error. Just for information my systemd file for celery is following:

[Unit]
Description=kallithea-celery
After=network.target

[Service]
User=www-data
Group=www-data
WorkingDirectory=/home/kallithea/projects/kallithea
Environment=VIRTUAL_ENV=/home/kallithea/projects/kallithea/venv3
Environment=PATH=$VIRTUAL_ENV/bin:$PATH
ExecStart=/home/kallithea/projects/kallithea/venv3/bin/kallithea-cli celery-run -c new.ini

[Install]
WantedBy=multi-user.target

‌

Comment by Mads Kiilerich, on 2020-02-12 13:25

Thanks for clarifying. Thanks for helpling nailing the problem and testing the first fix - we will land that asap.

Yes, the problem now looks like the other one. But the other problem is with python2, so if the root cause of your remaining problem is the py3 port, then it might just by coincidense have the same symptom: hitting broken error handling in celery.

Are you using python 3.6 or 3.7? And is there anything in the celery-run output / log?

Comment by vyom, on 2020-02-13 14:53

I am using Python 3.6 and celery-run output/log is normal.

‌

Feb 13 22:40:18 kallithea-5-2 systemd[1]: Started kallithea-celery.
-- Subject: Unit kallithea-celery.service has finished start-up
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Unit kallithea-celery.service has finished starting up.
--
-- The start-up result is RESULT.
Feb 13 22:51:24 kallithea-5-2 systemd[1]: Started kallithea-celery.
-- Subject: Unit kallithea-celery.service has finished start-up
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Unit kallithea-celery.service has finished starting up.
--
-- The start-up result is RESULT.

‌

Comment by vyom, on 2020-02-13 15:20

Just for additional information. Gunicorn 20 has breaking changes and paste deploy configuration is deprecated.

https://docs.gunicorn.org/en/stable/news.html

Breaking Change

Removed gaiohttp worker
Drop support for Python 2.x
Drop support for EOL Python 3.2 and 3.3
Drop support for Paste Deploy server blocks

‌

Comment by Mads Kiilerich, on 2020-02-14 14:01

https://kallithea-scm.org/repos/kallithea/pull-request/237/_/Remove_tech_debt_and_fix_Celery_on_python_3.6 should fix Celery in 3.6 - can you pull and verify?

Comment by vyom, on 2020-02-18 02:52

Resolved with suggested changes, for Celery going through another thread to fix issues.

Kallithea issues archive