Problem with smtplib with gmail accounts

Issue #357 resolved
vyom created an issue

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.

Comments (14)

  1. Mads Kiilerich

    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
    

  2. vyom reporter

    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>
    

  3. Mads Kiilerich

    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.

  4. vyom reporter

    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:
    

  5. Mads Kiilerich

    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?

  6. vyom reporter

    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
    

  7. Mads Kiilerich

    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.

  8. vyom reporter

    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
    

  9. Mads Kiilerich

    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?

  10. vyom reporter

    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.
    

  11. Log in to comment