This commit is contained in:
Son Nguyen Kim 2021-09-08 11:29:55 +02:00
parent a6e8684afb
commit 5ac78f2694
39 changed files with 157 additions and 181 deletions

View File

@ -31,9 +31,7 @@ from app.models import (
def try_auto_create(address: str) -> Optional[Alias]:
"""Try to auto-create the alias using directory or catch-all domain"""
if address.startswith(f"{BOUNCE_PREFIX_FOR_REPLY_PHASE}+"):
LOG.exception(
"alias %s can't start with %s", address, BOUNCE_PREFIX_FOR_REPLY_PHASE
)
LOG.e("alias %s can't start with %s", address, BOUNCE_PREFIX_FOR_REPLY_PHASE)
return None
alias = try_auto_create_catch_all_domain(address)
@ -101,7 +99,7 @@ def try_auto_create_directory(address: str) -> Optional[Alias]:
db.session.commit()
return alias
except AliasInTrashError:
LOG.warning(
LOG.w(
"Alias %s was deleted before, cannot auto-create using directory %s, user %s",
address,
directory_name,
@ -109,7 +107,7 @@ def try_auto_create_directory(address: str) -> Optional[Alias]:
)
return None
except IntegrityError:
LOG.warning("Alias %s already exists", address)
LOG.w("Alias %s already exists", address)
db.session.rollback()
alias = Alias.get_by(email=address)
return alias
@ -156,7 +154,7 @@ def try_auto_create_catch_all_domain(address: str) -> Optional[Alias]:
db.session.commit()
return alias
except AliasInTrashError:
LOG.warning(
LOG.w(
"Alias %s was deleted before, cannot auto-create using domain catch-all %s, user %s",
address,
custom_domain,
@ -164,12 +162,12 @@ def try_auto_create_catch_all_domain(address: str) -> Optional[Alias]:
)
return None
except IntegrityError:
LOG.warning("Alias %s already exists", address)
LOG.w("Alias %s already exists", address)
db.session.rollback()
alias = Alias.get_by(email=address)
return alias
except DataError:
LOG.warning("Cannot create alias %s", address)
LOG.w("Cannot create alias %s", address)
db.session.rollback()
return None
@ -184,7 +182,7 @@ def delete_alias(alias: Alias, user: User):
if not DomainDeletedAlias.get_by(
email=alias.email, domain_id=alias.custom_domain_id
):
LOG.debug("add %s to domain %s trash", alias, alias.custom_domain_id)
LOG.d("add %s to domain %s trash", alias, alias.custom_domain_id)
db.session.add(
DomainDeletedAlias(
user_id=user.id, email=alias.email, domain_id=alias.custom_domain_id

View File

@ -36,7 +36,7 @@ def apple_process_payment():
200 of the payment is successful, i.e. user is upgraded to premium
"""
LOG.debug("request for /apple/process_payment")
LOG.d("request for /apple/process_payment")
user = g.user
data = request.get_json()
receipt_data = data.get("receipt_data")
@ -229,7 +229,7 @@ def apple_update_notification():
# "auto_renew_product_id": "io.simplelogin.ios_app.subscription.premium.yearly",
# "notification_type": "DID_CHANGE_RENEWAL_STATUS",
# }
LOG.debug("request for /api/apple/update_notification")
LOG.d("request for /api/apple/update_notification")
data = request.get_json()
if not (
data
@ -282,7 +282,7 @@ def apple_update_notification():
db.session.commit()
return jsonify(ok=True), 200
else:
LOG.warning(
LOG.w(
"No existing AppleSub for original_transaction_id %s",
original_transaction_id,
)
@ -305,16 +305,16 @@ def verify_receipt(receipt_data, user, password) -> Optional[AppleSubscription]:
_PROD_URL, json={"receipt-data": receipt_data, "password": password}
)
except RequestException:
LOG.warning("cannot call Apple server %s", _PROD_URL)
LOG.w("cannot call Apple server %s", _PROD_URL)
return None
if r.status_code >= 500:
LOG.warning("Apple server error, response:%s %s", r, r.content)
LOG.w("Apple server error, response:%s %s", r, r.content)
return None
if r.json() == {"status": 21007}:
# try sandbox_url
LOG.warning("Use the sandbox url instead")
LOG.w("Use the sandbox url instead")
r = requests.post(
_SANDBOX_URL,
json={"receipt-data": receipt_data, "password": password},
@ -472,7 +472,7 @@ def verify_receipt(receipt_data, user, password) -> Optional[AppleSubscription]:
# }
if data["status"] != 0:
LOG.warning(
LOG.w(
"verifyReceipt status !=0, probably invalid receipt. User %s",
user,
)
@ -499,7 +499,7 @@ def verify_receipt(receipt_data, user, password) -> Optional[AppleSubscription]:
# }
transactions = data["receipt"]["in_app"]
if not transactions:
LOG.warning("Empty transactions in data %s", data)
LOG.w("Empty transactions in data %s", data)
return None
latest_transaction = max(transactions, key=lambda t: int(t["expires_date_ms"]))
@ -527,7 +527,7 @@ def verify_receipt(receipt_data, user, password) -> Optional[AppleSubscription]:
else:
# the same original_transaction_id has been used on another account
if AppleSubscription.get_by(original_transaction_id=original_transaction_id):
LOG.exception("Same Apple Sub has been used before, current user %s", user)
LOG.e("Same Apple Sub has been used before, current user %s", user)
return None
LOG.d(

View File

@ -96,7 +96,7 @@ def auth_register():
if not password or len(password) < 8:
return jsonify(error="password too short"), 400
LOG.debug("create user %s", email)
LOG.d("create user %s", email)
user = User.create(email=email, name="", password=password)
db.session.flush()
@ -166,7 +166,7 @@ def auth_activate():
return jsonify(error="Wrong email or code"), 400
LOG.debug("activate user %s", user)
LOG.d("activate user %s", user)
user.activated = True
AccountActivation.delete(account_activation.id)
db.session.commit()

View File

@ -69,10 +69,10 @@ def new_custom_alias_v2():
try:
alias_suffix = signer.unsign(signed_suffix, max_age=600).decode()
except SignatureExpired:
LOG.warning("Alias creation time expired for %s", user)
LOG.w("Alias creation time expired for %s", user)
return jsonify(error="Alias creation time is expired, please retry"), 412
except Exception:
LOG.warning("Alias suffix is tampered, user %s", user)
LOG.w("Alias suffix is tampered, user %s", user)
return jsonify(error="Tampered suffix"), 400
if not verify_prefix_suffix(user, alias_prefix, alias_suffix):
@ -184,10 +184,10 @@ def new_custom_alias_v3():
try:
alias_suffix = signer.unsign(signed_suffix, max_age=600).decode()
except SignatureExpired:
LOG.warning("Alias creation time expired for %s", user)
LOG.w("Alias creation time expired for %s", user)
return jsonify(error="Alias creation time is expired, please retry"), 412
except Exception:
LOG.warning("Alias suffix is tampered, user %s", user)
LOG.w("Alias suffix is tampered, user %s", user)
return jsonify(error="Tampered suffix"), 400
if not verify_prefix_suffix(user, alias_prefix, alias_suffix):

View File

@ -87,7 +87,7 @@ def update_setting():
# sanity check
if custom_domain.user_id != user.id or not custom_domain.verified:
LOG.exception("%s cannot use domain %s", user, default_domain)
LOG.e("%s cannot use domain %s", user, default_domain)
return jsonify(error="invalid domain"), 400
else:
user.default_alias_custom_domain_id = custom_domain.id

View File

@ -57,8 +57,8 @@ def activate():
# The activation link contains the original page, for ex authorize page
if "next" in request.args:
next_url = request.args.get("next")
LOG.debug("redirect user to %s", next_url)
LOG.d("redirect user to %s", next_url)
return redirect(next_url)
else:
LOG.debug("redirect user to dashboard")
LOG.d("redirect user to dashboard")
return redirect(url_for("dashboard.index"))

View File

@ -115,7 +115,7 @@ def facebook_callback():
# The activation link contains the original page, for ex authorize page
if "facebook_next_url" in session:
next_url = session["facebook_next_url"]
LOG.debug("redirect user to %s", next_url)
LOG.d("redirect user to %s", next_url)
# reset the next_url to avoid user getting redirected at each login :)
session.pop("facebook_next_url", None)

View File

@ -95,7 +95,7 @@ def fido():
)
new_sign_count = webauthn_assertion_response.verify()
except Exception as e:
LOG.warning(f"An error occurred in WebAuthn verification process: {e}")
LOG.w(f"An error occurred in WebAuthn verification process: {e}")
flash("Key verification failed.", "warning")
# Trigger rate limiter
g.deduct_limit = True

View File

@ -75,7 +75,7 @@ def github_callback():
break
if not email:
LOG.exception(f"cannot get email for github user {github_user_data} {emails}")
LOG.e(f"cannot get email for github user {github_user_data} {emails}")
flash(
"Cannot get a valid email from Github, please another way to login/sign up",
"error",

View File

@ -101,7 +101,7 @@ def google_callback():
# The activation link contains the original page, for ex authorize page
if "google_next_url" in session:
next_url = session["google_next_url"]
LOG.debug("redirect user to %s", next_url)
LOG.d("redirect user to %s", next_url)
# reset the next_url to avoid user getting redirected at each login :)
session.pop("google_next_url", None)

View File

@ -25,7 +25,7 @@ def login():
if current_user.is_authenticated:
if next_url:
LOG.debug("user is already authenticated, redirect to %s", next_url)
LOG.d("user is already authenticated, redirect to %s", next_url)
return redirect(next_url)
else:
LOG.d("user is already authenticated, redirect to dashboard")

View File

@ -29,15 +29,15 @@ def after_login(user, next_url):
else:
return redirect(url_for("auth.mfa"))
else:
LOG.debug("log user %s in", user)
LOG.d("log user %s in", user)
login_user(user)
# User comes to login page from another page
if next_url:
LOG.debug("redirect user to %s", next_url)
LOG.d("redirect user to %s", next_url)
return redirect(next_url)
else:
LOG.debug("redirect user to dashboard")
LOG.d("redirect user to dashboard")
return redirect(url_for("dashboard.index"))

View File

@ -58,10 +58,10 @@ def recovery_route():
# User comes to login page from another page
if next_url:
LOG.debug("redirect user to %s", next_url)
LOG.d("redirect user to %s", next_url)
return redirect(next_url)
else:
LOG.debug("redirect user to dashboard")
LOG.d("redirect user to dashboard")
return redirect(url_for("dashboard.index"))
else:
# Trigger rate limiter

View File

@ -53,7 +53,7 @@ def register():
# 'challenge_ts': '2020-07-23T10:03:25',
# 'hostname': '127.0.0.1'}
if not hcaptcha_res["success"]:
LOG.warning(
LOG.w(
"User put wrong captcha %s %s",
form.email.data,
hcaptcha_res,
@ -74,7 +74,7 @@ def register():
if personal_email_already_used(email):
flash(f"Email {email} already used", "error")
else:
LOG.debug("create user %s", email)
LOG.d("create user %s", email)
user = User.create(
email=email,
name="",

View File

@ -31,7 +31,7 @@ def batch_import_route():
bi = BatchImport.create(user_id=current_user.id, file_id=file.id)
db.session.flush()
LOG.debug("Add a batch import job %s for %s", bi, current_user)
LOG.d("Add a batch import job %s for %s", bi, current_user)
# Schedule batch import job
Job.create(

View File

@ -21,7 +21,7 @@ def billing():
if request.method == "POST":
if request.form.get("form-name") == "cancel":
LOG.warning(f"User {current_user} cancels their subscription")
LOG.w(f"User {current_user} cancels their subscription")
success = cancel_subscription(sub.subscription_id)
if success:
@ -37,7 +37,7 @@ def billing():
return redirect(url_for("dashboard.billing"))
elif request.form.get("form-name") == "change-monthly":
LOG.debug(f"User {current_user} changes to monthly plan")
LOG.d(f"User {current_user} changes to monthly plan")
success, msg = change_plan(
current_user, sub.subscription_id, PADDLE_MONTHLY_PRODUCT_ID
)
@ -58,7 +58,7 @@ def billing():
return redirect(url_for("dashboard.billing"))
elif request.form.get("form-name") == "change-yearly":
LOG.debug(f"User {current_user} changes to yearly plan")
LOG.d(f"User {current_user} changes to yearly plan")
success, msg = change_plan(
current_user, sub.subscription_id, PADDLE_YEARLY_PRODUCT_ID
)

View File

@ -249,11 +249,11 @@ def custom_alias():
signed_alias_suffix_decoded
)
except SignatureExpired:
LOG.warning("Alias creation time expired for %s", current_user)
LOG.w("Alias creation time expired for %s", current_user)
flash("Alias creation time is expired, please retry", "warning")
return redirect(url_for("dashboard.custom_alias"))
except Exception:
LOG.warning("Alias suffix is tampered, user %s", current_user)
LOG.w("Alias suffix is tampered, user %s", current_user)
flash("Unknown error, refresh the page", "error")
return redirect(url_for("dashboard.custom_alias"))
@ -281,7 +281,7 @@ def custom_alias():
)
else:
# should never happen as user can only choose their domains
LOG.exception(
LOG.e(
"Deleted Alias %s does not belong to user %s",
domain_deleted_alias,
)
@ -309,7 +309,7 @@ def custom_alias():
)
db.session.flush()
except IntegrityError:
LOG.warning("Alias %s already exists", full_alias)
LOG.w("Alias %s already exists", full_alias)
db.session.rollback()
flash("Unknown error, please retry", "error")
return redirect(url_for("dashboard.custom_alias"))
@ -351,7 +351,7 @@ def verify_prefix_suffix(user: User, alias_prefix, alias_suffix) -> bool:
# alias_domain must be either one of user custom domains or built-in domains
if alias_domain not in user.available_alias_domains():
LOG.exception("wrong alias suffix %s, user %s", alias_suffix, user)
LOG.e("wrong alias suffix %s, user %s", alias_suffix, user)
return False
# SimpleLogin domain case:
@ -365,17 +365,17 @@ def verify_prefix_suffix(user: User, alias_prefix, alias_suffix) -> bool:
):
if not alias_domain_prefix.startswith("."):
LOG.exception("User %s submits a wrong alias suffix %s", user, alias_suffix)
LOG.e("User %s submits a wrong alias suffix %s", user, alias_suffix)
return False
else:
if alias_domain not in user_custom_domains:
if not DISABLE_ALIAS_SUFFIX:
LOG.exception("wrong alias suffix %s, user %s", alias_suffix, user)
LOG.e("wrong alias suffix %s, user %s", alias_suffix, user)
return False
if alias_domain not in user.available_sl_domains():
LOG.exception("wrong alias suffix %s, user %s", alias_suffix, user)
LOG.e("wrong alias suffix %s, user %s", alias_suffix, user)
return False
return True

View File

@ -30,10 +30,10 @@ def enter_sudo():
# User comes to sudo page from another page
next_url = request.args.get("next")
if next_url:
LOG.debug("redirect user to %s", next_url)
LOG.d("redirect user to %s", next_url)
return redirect(next_url)
else:
LOG.debug("redirect user to dashboard")
LOG.d("redirect user to dashboard")
return redirect(url_for("dashboard.index"))
else:
flash("Incorrect password", "warning")

View File

@ -55,7 +55,7 @@ def fido_setup():
try:
fido_credential = fido_reg_response.verify()
except Exception as e:
LOG.warning(f"An error occurred in WebAuthn registration process: {e}")
LOG.w(f"An error occurred in WebAuthn registration process: {e}")
flash("Key registration failed.", "warning")
return redirect(url_for("dashboard.index"))

View File

@ -69,7 +69,7 @@ def index():
try:
highlight_alias_id = int(request.args.get("highlight_alias_id"))
except ValueError:
LOG.warning(
LOG.w(
"highlight_alias_id must be a number, received %s",
request.args.get("highlight_alias_id"),
)

View File

@ -15,7 +15,7 @@ def refused_email_route():
try:
highlight_id = int(highlight_id)
except ValueError:
LOG.warning("Cannot parse highlight_id %s", highlight_id)
LOG.w("Cannot parse highlight_id %s", highlight_id)
highlight_id = None
email_logs: [EmailLog] = (

View File

@ -105,7 +105,7 @@ def setting():
other_email_change: EmailChange = EmailChange.get_by(
new_email=new_email
)
LOG.warning(
LOG.w(
"Another user has a pending %s with the same email address. Current user:%s",
other_email_change,
current_user,
@ -193,7 +193,7 @@ def setting():
return redirect(url_for("dashboard.setting"))
# Schedule delete account job
LOG.warning("schedule delete account job for %s", current_user)
LOG.w("schedule delete account job for %s", current_user)
Job.create(
name=JOB_DELETE_ACCOUNT,
payload={"user_id": current_user.id},
@ -236,7 +236,7 @@ def setting():
custom_domain.user_id != current_user.id
or not custom_domain.verified
):
LOG.exception(
LOG.e(
"%s cannot use domain %s", current_user, default_domain
)
else:

View File

@ -59,5 +59,5 @@ def get_spam_score(
return get_spam_score(message, email_log, can_retry=False)
else:
# return a negative score so the message is always considered as ham
LOG.exception("SpamAssassin exception, ignore spam check")
LOG.e("SpamAssassin exception, ignore spam check")
return -999, None

View File

@ -323,7 +323,7 @@ def send_email_with_rate_control(
)
if nb_alert >= max_nb_alert:
LOG.warning(
LOG.w(
"%s emails were sent to %s in the last %s days, alert type %s",
nb_alert,
to_email,
@ -359,7 +359,7 @@ def send_email_at_most_times(
).count()
if nb_alert >= max_times:
LOG.warning(
LOG.w(
"%s emails were sent to %s alert type %s",
nb_alert,
to_email,
@ -645,7 +645,7 @@ def get_spam_from_header(spam_status_header, max_score=None) -> (bool, str):
)
score = float(score_section[len("score=") :])
if score >= max_score:
LOG.warning("Spam score %s exceeds %s", score, max_score)
LOG.w("Spam score %s exceeds %s", score, max_score)
return True, spam_status_header
return spamassassin_answer.lower() == "yes", spam_status_header
@ -660,13 +660,13 @@ def get_header_unicode(header: str) -> str:
try:
return decoded_string.decode(charset)
except UnicodeDecodeError:
LOG.warning("Cannot decode header %s", header)
LOG.w("Cannot decode header %s", header)
except LookupError: # charset is unknown
LOG.warning("Cannot decode %s with %s, use utf-8", decoded_string, charset)
LOG.w("Cannot decode %s with %s, use utf-8", decoded_string, charset)
try:
return decoded_string.decode("utf-8")
except UnicodeDecodeError:
LOG.warning("Cannot UTF-8 decode %s", decoded_string)
LOG.w("Cannot UTF-8 decode %s", decoded_string)
return decoded_string.decode("utf-8", errors="replace")
return header
@ -687,16 +687,16 @@ def parseaddr_unicode(addr) -> (str, str):
try:
decoded_string, charset = decode_header(name)[0]
except HeaderParseError: # fail in case
LOG.warning("Can't decode name %s", name)
LOG.w("Can't decode name %s", name)
else:
if charset is not None:
try:
name = decoded_string.decode(charset)
except UnicodeDecodeError:
LOG.warning("Cannot decode addr name %s", name)
LOG.w("Cannot decode addr name %s", name)
name = ""
except LookupError: # charset is unknown
LOG.warning(
LOG.w(
"Cannot decode %s with %s, use utf-8", decoded_string, charset
)
name = decoded_string.decode("utf-8")
@ -713,11 +713,11 @@ def copy(msg: Message) -> Message:
try:
return deepcopy(msg)
except Exception:
LOG.warning("deepcopy fails, try string parsing")
LOG.w("deepcopy fails, try string parsing")
try:
return email.message_from_string(msg.as_string())
except (UnicodeEncodeError, KeyError, LookupError):
LOG.warning("as_string() fails, try bytes parsing")
LOG.w("as_string() fails, try bytes parsing")
return email.message_from_bytes(to_bytes(msg))
@ -726,17 +726,15 @@ def to_bytes(msg: Message):
try:
return msg.as_bytes()
except UnicodeEncodeError:
LOG.warning("as_bytes fails with default policy, try SMTP policy")
LOG.w("as_bytes fails with default policy, try SMTP policy")
try:
return msg.as_bytes(policy=email.policy.SMTP)
except UnicodeEncodeError:
LOG.warning("as_bytes fails with SMTP policy, try SMTPUTF8 policy")
LOG.w("as_bytes fails with SMTP policy, try SMTPUTF8 policy")
try:
return msg.as_bytes(policy=email.policy.SMTPUTF8)
except UnicodeEncodeError:
LOG.warning(
"as_bytes fails with SMTPUTF8 policy, try converting to string"
)
LOG.w("as_bytes fails with SMTPUTF8 policy, try converting to string")
msg_string = msg.as_string()
try:
return msg_string.encode()
@ -790,7 +788,7 @@ def get_encoding(msg: Message) -> EmailEncoding:
if cte in ("amazonses.com",):
return EmailEncoding.NO
LOG.exception("Unknown encoding %s", cte)
LOG.e("Unknown encoding %s", cte)
return EmailEncoding.NO
@ -915,7 +913,7 @@ def replace(msg: Message, old, new) -> Message:
clone_msg.set_payload(new_parts)
return clone_msg
LOG.exception("Cannot replace text for %s", msg.get_content_type())
LOG.e("Cannot replace text for %s", msg.get_content_type())
return msg
@ -991,7 +989,7 @@ def should_disable(alias: Alias) -> bool:
"""Disable an alias if it has too many bounces recently"""
# Bypass the bounce rule
if alias.cannot_be_disabled:
LOG.warning("%s cannot be disabled", alias)
LOG.w("%s cannot be disabled", alias)
return False
yesterday = arrow.now().shift(days=-1)
@ -1025,7 +1023,7 @@ def should_disable(alias: Alias) -> bool:
.count()
)
if nb_bounced_7d_1d > 1:
LOG.debug(
LOG.d(
"more than 5 bounces in the last 24h and more than 1 bounces in the last 7 days, "
"disable alias %s",
alias,
@ -1105,7 +1103,7 @@ def spf_pass(
try:
r = spf.check2(i=ip, s=envelope.mail_from, h=None)
except Exception:
LOG.exception("SPF error, mailbox %s, ip %s", mailbox.email, ip)
LOG.e("SPF error, mailbox %s, ip %s", mailbox.email, ip)
else:
# TODO: Handle temperr case (e.g. dns timeout)
# only an absolute pass, or no SPF policy at all is 'valid'

View File

@ -25,7 +25,7 @@ def handle_batch_import(batch_import: BatchImport):
batch_import.processed = True
db.session.commit()
LOG.debug("Start batch import for %s %s", batch_import, user)
LOG.d("Start batch import for %s %s", batch_import, user)
file_url = s3.get_url(batch_import.file.path)
LOG.d("Download file %s from %s", batch_import.file, file_url)
@ -43,7 +43,7 @@ def import_from_csv(batch_import: BatchImport, user: User, lines):
full_alias = sanitize_email(row["alias"])
note = row["note"]
except KeyError:
LOG.warning("Cannot parse row %s", row)
LOG.w("Cannot parse row %s", row)
continue
alias_domain = get_email_domain_part(full_alias)
@ -54,7 +54,7 @@ def import_from_csv(batch_import: BatchImport, user: User, lines):
or not custom_domain.verified
or custom_domain.user_id != user.id
):
LOG.debug("domain %s can't be used %s", alias_domain, user)
LOG.d("domain %s can't be used %s", alias_domain, user)
continue
if (

View File

@ -62,7 +62,7 @@ def verify_id_token(id_token) -> bool:
try:
jwt.JWT(key=_key, jwt=id_token)
except Exception:
LOG.exception("id token not verified")
LOG.e("id token not verified")
return False
else:
return True

View File

@ -685,7 +685,7 @@ class User(db.Model, ModelMixin, UserMixin, PasswordOracle):
or not custom_domain.verified
or custom_domain.user_id != self.id
):
LOG.warning("Problem with %s default random alias domain", self)
LOG.w("Problem with %s default random alias domain", self)
return FIRST_ALIAS_DOMAIN
return custom_domain.domain
@ -694,11 +694,11 @@ class User(db.Model, ModelMixin, UserMixin, PasswordOracle):
sl_domain = SLDomain.get(self.default_alias_public_domain_id)
# sanity check
if not sl_domain:
LOG.exception("Problem with %s public random alias domain", self)
LOG.e("Problem with %s public random alias domain", self)
return FIRST_ALIAS_DOMAIN
if sl_domain.premium_only and not self.is_premium():
LOG.warning(
LOG.w(
"%s is not premium and cannot use %s. Reset default random alias domain setting",
self,
sl_domain,
@ -863,13 +863,11 @@ def generate_oauth_client_id(client_name) -> str:
# check that the client does not exist yet
if not Client.get_by(oauth_client_id=oauth_client_id):
LOG.debug("generate oauth_client_id %s", oauth_client_id)
LOG.d("generate oauth_client_id %s", oauth_client_id)
return oauth_client_id
# Rerun the function
LOG.warning(
"client_id %s already exists, generate a new client_id", oauth_client_id
)
LOG.w("client_id %s already exists, generate a new client_id", oauth_client_id)
return generate_oauth_client_id(client_name)
@ -1041,11 +1039,11 @@ def generate_email(
if not Alias.get_by(email=random_email) and not DeletedAlias.get_by(
email=random_email
):
LOG.debug("generate email %s", random_email)
LOG.d("generate email %s", random_email)
return random_email
# Rerun the function
LOG.warning("email %s already exists, generate a new email", random_email)
LOG.w("email %s already exists, generate a new email", random_email)
return generate_email(scheme=scheme, in_hex=in_hex)
@ -1240,7 +1238,7 @@ class Alias(db.Model, ModelMixin):
elif user.default_alias_public_domain_id:
sl_domain: SLDomain = SLDomain.get(user.default_alias_public_domain_id)
if sl_domain.premium_only and not user.is_premium():
LOG.warning("%s not premium, cannot use %s", user, sl_domain)
LOG.w("%s not premium, cannot use %s", user, sl_domain)
else:
random_email = generate_email(
scheme=scheme, in_hex=in_hex, alias_domain=sl_domain.domain
@ -1355,7 +1353,7 @@ class ClientUser(db.Model, ModelMixin):
elif scope == Scope.EMAIL:
# Use generated email
if self.alias_id:
LOG.debug(
LOG.d(
"Use gen email for user %s, client %s", self.user, self.client
)
res[Scope.EMAIL.value] = self.alias.email
@ -1454,7 +1452,7 @@ class Contact(db.Model, ModelMixin):
name, _ = parseaddr_unicode(self.website_from)
except Exception:
# Skip if website_from is wrongly formatted
LOG.warning(
LOG.w(
"Cannot parse contact %s website_from %s", self, self.website_from
)
name = ""

View File

@ -102,7 +102,7 @@ def authorize():
)
user_info = {}
if client_user:
LOG.debug("user %s has already allowed client %s", current_user, client)
LOG.d("user %s has already allowed client %s", current_user, client)
user_info = client_user.get_user_info()
else:
suggested_email, other_emails = current_user.suggested_emails(
@ -131,11 +131,11 @@ def authorize():
)
else: # POST - user allows or denies
if request.form.get("button") == "deny":
LOG.debug("User %s denies Client %s", current_user, client)
LOG.d("User %s denies Client %s", current_user, client)
final_redirect_uri = f"{redirect_uri}?error=deny&state={state}"
return redirect(final_redirect_uri)
LOG.debug("User %s allows Client %s", current_user, client)
LOG.d("User %s allows Client %s", current_user, client)
client_user = ClientUser.get_by(client_id=client.id, user_id=current_user.id)
# user has already allowed this client, user cannot change information
@ -167,11 +167,11 @@ def authorize():
try:
alias_suffix = signer.unsign(signed_suffix, max_age=600).decode()
except SignatureExpired:
LOG.warning("Alias creation time expired for %s", current_user)
LOG.w("Alias creation time expired for %s", current_user)
flash("Alias creation time is expired, please retry", "warning")
return redirect(request.url)
except Exception:
LOG.warning("Alias suffix is tampered, user %s", current_user)
LOG.w("Alias suffix is tampered, user %s", current_user)
flash("Unknown error, refresh the page", "error")
return redirect(request.url)
@ -189,7 +189,7 @@ def authorize():
or DeletedAlias.get_by(email=full_alias)
or DomainDeletedAlias.get_by(email=full_alias)
):
LOG.exception("alias %s already used, very rare!", full_alias)
LOG.e("alias %s already used, very rare!", full_alias)
flash(f"Alias {full_alias} already used", "error")
return redirect(request.url)
else:
@ -255,9 +255,7 @@ def authorize():
if state:
redirect_args["state"] = state
else:
LOG.warning(
"more security reason, state should be added. client %s", client
)
LOG.w("more security reason, state should be added. client %s", client)
if scope:
redirect_args["scope"] = scope
@ -339,7 +337,7 @@ def generate_access_token() -> str:
return access_token
# Rerun the function
LOG.warning("access token already exists, generate a new one")
LOG.w("access token already exists, generate a new one")
return generate_access_token()

View File

@ -56,9 +56,7 @@ def token():
if auth_code.client_id != client.id:
return jsonify(error="are you sure this code belongs to you?"), 400
LOG.debug(
"Create Oauth token for user %s, client %s", auth_code.user, auth_code.client
)
LOG.d("Create Oauth token for user %s, client %s", auth_code.user, auth_code.client)
# Create token
oauth_token = OauthToken.create(

View File

@ -72,9 +72,7 @@ def cancel_subscription(subscription_id: str) -> bool:
)
res = r.json()
if not res["success"]:
LOG.exception(
f"cannot cancel subscription {subscription_id}, paddle response: {res}"
)
LOG.e(f"cannot cancel subscription {subscription_id}, paddle response: {res}")
return res["success"]
@ -102,7 +100,7 @@ def change_plan(user: User, subscription_id: str, plan_id) -> (bool, str):
)
return False, "Your card cannot be charged"
except KeyError:
LOG.exception(
LOG.e(
f"cannot change subscription {subscription_id} to {plan_id}, paddle response: {res}"
)
return False, ""

View File

@ -43,7 +43,7 @@ def load_public_key_and_check(public_key: str) -> str:
try:
encrypt_file(dummy_data, fingerprint)
except Exception as e:
LOG.warning(
LOG.w(
"Cannot encrypt using the imported key %s %s", fingerprint, public_key
)
# remove the fingerprint
@ -55,7 +55,7 @@ def load_public_key_and_check(public_key: str) -> str:
def hard_exit():
pid = os.getpid()
LOG.warning("kill pid %s", pid)
LOG.w("kill pid %s", pid)
os.kill(pid, 9)

View File

@ -115,7 +115,7 @@ class SpamAssassin(object):
"description": " ".join(wordlist[1:]),
}
except ValueError:
LOG.warning("Cannot parse %s %s", wordlist[0], wordlist)
LOG.w("Cannot parse %s %s", wordlist[0], wordlist)
headers = (
headers.decode("utf-8")

38
cron.py
View File

@ -151,7 +151,7 @@ def notify_manual_sub_end():
if need_reminder:
user = manual_sub.user
LOG.debug("Remind user %s that their manual sub is ending soon", user)
LOG.d("Remind user %s that their manual sub is ending soon", user)
send_email(
user.email,
f"Your subscription will end soon",
@ -185,7 +185,7 @@ def notify_manual_sub_end():
if need_reminder:
user = coinbase_subscription.user
LOG.debug(
LOG.d(
"Remind user %s that their coinbase subscription is ending soon", user
)
send_email(
@ -443,9 +443,7 @@ def migrate_domain_trash():
if not SLDomain.get_by(domain=alias_domain):
custom_domain = CustomDomain.get_by(domain=alias_domain)
if custom_domain:
LOG.exception(
"move %s to domain %s trash", deleted_alias, custom_domain
)
LOG.e("move %s to domain %s trash", deleted_alias, custom_domain)
db.session.add(
DomainDeletedAlias(
user_id=custom_domain.user_id,
@ -470,7 +468,7 @@ def set_custom_domain_for_alias():
alias_domain = get_email_domain_part(alias.email)
custom_domain = CustomDomain.get_by(domain=alias_domain)
if custom_domain:
LOG.exception("set %s for %s", custom_domain, alias)
LOG.e("set %s for %s", custom_domain, alias)
alias.custom_domain_id = custom_domain.id
else: # phantom domain
LOG.d("phantom domain %s %s %s", alias.user, alias, alias.enabled)
@ -533,7 +531,7 @@ def sanity_check():
render("transactional/disable-mailbox.html", mailbox=mailbox),
)
LOG.warning(
LOG.w(
"issue with mailbox %s domain. #alias %s, nb email log %s",
mailbox,
mailbox.nb_alias(),
@ -546,40 +544,40 @@ def sanity_check():
for user in User.filter_by(activated=True).all():
if sanitize_email(user.email) != user.email:
LOG.exception("%s does not have sanitized email", user)
LOG.e("%s does not have sanitized email", user)
for alias in Alias.query.all():
if sanitize_email(alias.email) != alias.email:
LOG.exception("Alias %s email not sanitized", alias)
LOG.e("Alias %s email not sanitized", alias)
if alias.name and "\n" in alias.name:
alias.name = alias.name.replace("\n", "")
db.session.commit()
LOG.exception("Alias %s name contains linebreak %s", alias, alias.name)
LOG.e("Alias %s name contains linebreak %s", alias, alias.name)
contact_email_sanity_date = arrow.get("2021-01-12")
for contact in Contact.query.all():
if sanitize_email(contact.reply_email) != contact.reply_email:
LOG.exception("Contact %s reply-email not sanitized", contact)
LOG.e("Contact %s reply-email not sanitized", contact)
if (
sanitize_email(contact.website_email) != contact.website_email
and contact.created_at > contact_email_sanity_date
):
LOG.exception("Contact %s website-email not sanitized", contact)
LOG.e("Contact %s website-email not sanitized", contact)
if not contact.invalid_email and not is_valid_email(contact.website_email):
LOG.exception("%s invalid email", contact)
LOG.e("%s invalid email", contact)
contact.invalid_email = True
db.session.commit()
for mailbox in Mailbox.query.all():
if sanitize_email(mailbox.email) != mailbox.email:
LOG.exception("Mailbox %s address not sanitized", mailbox)
LOG.e("Mailbox %s address not sanitized", mailbox)
for contact in Contact.query.all():
if normalize_reply_email(contact.reply_email) != contact.reply_email:
LOG.exception(
LOG.e(
"Contact %s reply email is not normalized %s",
contact,
contact.reply_email,
@ -587,7 +585,7 @@ def sanity_check():
for domain in CustomDomain.query.all():
if domain.name and "\n" in domain.name:
LOG.exception("Domain %s name contain linebreak %s", domain, domain.name)
LOG.e("Domain %s name contain linebreak %s", domain, domain.name)
migrate_domain_trash()
set_custom_domain_for_alias()
@ -605,7 +603,7 @@ def check_custom_domain():
if sorted(mx_domains) != sorted(EMAIL_SERVERS_WITH_PRIORITY):
user = custom_domain.user
LOG.warning(
LOG.w(
"The MX record is not correctly set for %s %s %s",
custom_domain,
user,
@ -617,9 +615,7 @@ def check_custom_domain():
# send alert if fail for 5 consecutive days
if custom_domain.nb_failed_checks > 5:
domain_dns_url = f"{URL}/dashboard/domains/{custom_domain.id}/dns"
LOG.warning(
"Alert domain MX check fails %s about %s", user, custom_domain
)
LOG.w("Alert domain MX check fails %s about %s", user, custom_domain)
send_email_with_rate_control(
user,
AlERT_WRONG_MX_RECORD_CUSTOM_DOMAIN,
@ -728,7 +724,7 @@ async def check_hibp():
LOG.d("Checking HIBP API for aliases in breaches")
if len(HIBP_API_KEYS) == 0:
LOG.exception("No HIBP API keys")
LOG.e("No HIBP API keys")
return
LOG.d("Updating list of known breaches")

View File

@ -347,7 +347,7 @@ def replace_header_when_forward(msg: Message, alias: Alias, header: str):
contact.name = contact_name
db.session.commit()
else:
LOG.debug(
LOG.d(
"create contact for alias %s and email %s, header %s",
alias,
contact_email,
@ -488,7 +488,7 @@ def sign_msg(msg: Message) -> Message:
try:
signature.set_payload(sign_data(to_bytes(msg).replace(b"\n", b"\r\n")))
except Exception:
LOG.exception("Cannot sign, try using pgpy")
LOG.e("Cannot sign, try using pgpy")
signature.set_payload(
sign_data_with_pgpy(to_bytes(msg).replace(b"\n", b"\r\n"))
)
@ -871,14 +871,14 @@ def handle_reply(envelope, msg: Message, rcpt_to: str) -> (bool, str):
# Sanity check: verify alias domain is managed by SimpleLogin
# scenario: a user have removed a domain but due to a bug, the aliases are still there
if not is_valid_alias_address_domain(alias.email):
LOG.exception("%s domain isn't known", alias)
LOG.e("%s domain isn't known", alias)
return False, status.E503
user = alias.user
mail_from = envelope.mail_from
if user.disabled:
LOG.exception(
LOG.e(
"User %s disabled, disable sending emails from %s to %s",
user,
alias,
@ -1094,7 +1094,7 @@ def get_mailbox_from_mail_from(mail_from: str, alias) -> Optional[Mailbox]:
for address in mailbox.authorized_addresses:
if address.email == mail_from:
LOG.debug(
LOG.d(
"Found an authorized address for %s %s %s", alias, mailbox, address
)
return mailbox
@ -1172,12 +1172,12 @@ def handle_bounce_forward_phase(msg: Message, email_log: EmailLog):
# email_log.mailbox should be set during the forward phase
if not mailbox:
LOG.exception("Use %s default mailbox %s", alias, alias.mailbox)
LOG.e("Use %s default mailbox %s", alias, alias.mailbox)
mailbox = alias.mailbox
Bounce.create(email=mailbox.email, commit=True)
LOG.debug(
LOG.d(
"Handle forward bounce %s -> %s -> %s. %s", contact, alias, mailbox, email_log
)
@ -1325,9 +1325,7 @@ def handle_bounce_reply_phase(envelope, msg: Message, email_log: EmailLog):
user = alias.user
mailbox = email_log.mailbox or alias.mailbox
LOG.debug(
"Handle reply bounce %s -> %s -> %s.%s", mailbox, alias, contact, email_log
)
LOG.d("Handle reply bounce %s -> %s -> %s.%s", mailbox, alias, contact, email_log)
Bounce.create(email=sanitize_email(contact.website_email), commit=True)
@ -1548,11 +1546,11 @@ def handle_unsubscribe_user(user_id: int, mail_from: str) -> str:
"""return the SMTP status"""
user = User.get(user_id)
if not user:
LOG.exception("No such user %s %s", user_id, mail_from)
LOG.e("No such user %s %s", user_id, mail_from)
return status.E510
if mail_from != user.email:
LOG.exception("Unauthorized mail_from %s %s", user, mail_from)
LOG.e("Unauthorized mail_from %s %s", user, mail_from)
return status.E511
user.notification = False

View File

@ -15,9 +15,7 @@ def load_pgp_public_keys():
# sanity check
if fingerprint != mailbox.pgp_finger_print:
LOG.exception(
"fingerprint %s different for mailbox %s", fingerprint, mailbox
)
LOG.e("fingerprint %s different for mailbox %s", fingerprint, mailbox)
mailbox.pgp_finger_print = fingerprint
db.session.commit()
@ -27,9 +25,7 @@ def load_pgp_public_keys():
# sanity check
if fingerprint != contact.pgp_finger_print:
LOG.exception(
"fingerprint %s different for contact %s", fingerprint, contact
)
LOG.e("fingerprint %s different for contact %s", fingerprint, contact)
contact.pgp_finger_print = fingerprint
db.session.commit()
@ -42,14 +38,14 @@ def add_sl_domains():
if SLDomain.get_by(domain=alias_domain):
LOG.d("%s is already a SL domain", alias_domain)
else:
LOG.info("Add %s to SL domain", alias_domain)
LOG.i("Add %s to SL domain", alias_domain)
SLDomain.create(domain=alias_domain)
for premium_domain in PREMIUM_ALIAS_DOMAINS:
if SLDomain.get_by(domain=premium_domain):
LOG.d("%s is already a SL domain", premium_domain)
else:
LOG.info("Add %s to SL domain", premium_domain)
LOG.i("Add %s to SL domain", premium_domain)
SLDomain.create(domain=premium_domain, premium_only=True)
db.session.commit()

View File

@ -159,7 +159,7 @@ if __name__ == "__main__":
continue
user_email = user.email
LOG.warning("Delete user %s", user)
LOG.w("Delete user %s", user)
User.delete(user.id)
db.session.commit()
@ -170,6 +170,6 @@ if __name__ == "__main__":
render("transactional/account-delete.html"),
)
else:
LOG.exception("Unknown job name %s", job.name)
LOG.e("Unknown job name %s", job.name)
time.sleep(10)

View File

@ -43,7 +43,7 @@ def get_stats():
# reset
_nb_failed = 0
LOG.exception(
LOG.e(
"Too many emails in incoming & active queue %s %s",
incoming_queue,
active_queue,

View File

@ -485,7 +485,7 @@ def set_index_page(app):
and not request.path.startswith("/admin/static")
and not request.path.startswith("/_debug_toolbar")
):
LOG.debug(
LOG.d(
"%s %s %s %s %s, takes %s",
request.remote_addr,
request.method,
@ -563,7 +563,7 @@ def setup_error_page(app):
@app.errorhandler(429)
def rate_limited(e):
LOG.warning(
LOG.w(
"Client hit rate limit on path %s, user:%s",
request.path,
get_current_user(),
@ -589,7 +589,7 @@ def setup_error_page(app):
@app.errorhandler(Exception)
def error_handler(e):
LOG.exception(e)
LOG.e(e)
if request.path.startswith("/api/"):
return jsonify(error="Internal error"), 500
else:
@ -632,13 +632,11 @@ def jinja2_filter(app):
def setup_paddle_callback(app: Flask):
@app.route("/paddle", methods=["GET", "POST"])
def paddle():
LOG.debug(f"paddle callback {request.form.get('alert_name')} {request.form}")
LOG.d(f"paddle callback {request.form.get('alert_name')} {request.form}")
# make sure the request comes from Paddle
if not paddle_utils.verify_incoming_request(dict(request.form)):
LOG.exception(
"request not coming from paddle. Request data:%s", dict(request.form)
)
LOG.e("request not coming from paddle. Request data:%s", dict(request.form))
return "KO", 400
if (
@ -657,7 +655,7 @@ def setup_paddle_callback(app: Flask):
elif subscription_plan_id in PADDLE_YEARLY_PRODUCT_IDS:
plan = PlanEnum.yearly
else:
LOG.exception(
LOG.e(
"Unknown subscription_plan_id %s %s",
subscription_plan_id,
request.form,
@ -694,13 +692,13 @@ def setup_paddle_callback(app: Flask):
# in case user cancels a plan and subscribes a new plan
sub.cancelled = False
LOG.debug("User %s upgrades!", user)
LOG.d("User %s upgrades!", user)
db.session.commit()
elif request.form.get("alert_name") == "subscription_payment_succeeded":
subscription_id = request.form.get("subscription_id")
LOG.debug("Update subscription %s", subscription_id)
LOG.d("Update subscription %s", subscription_id)
sub: Subscription = Subscription.get_by(subscription_id=subscription_id)
# when user subscribes, the "subscription_payment_succeeded" can arrive BEFORE "subscription_created"
@ -719,7 +717,7 @@ def setup_paddle_callback(app: Flask):
sub: Subscription = Subscription.get_by(subscription_id=subscription_id)
if sub:
# cancellation_effective_date should be the same as next_bill_date
LOG.warning(
LOG.w(
"Cancel subscription %s %s on %s, next bill date %s",
subscription_id,
sub.user,
@ -749,7 +747,7 @@ def setup_paddle_callback(app: Flask):
sub: Subscription = Subscription.get_by(subscription_id=subscription_id)
if sub:
LOG.debug(
LOG.d(
"Update subscription %s %s on %s, next bill date %s",
subscription_id,
sub.user,
@ -795,7 +793,7 @@ def setup_coinbase_commerce(app):
request_data, request_sig, COINBASE_WEBHOOK_SECRET
)
except (WebhookInvalidPayload, SignatureVerificationError) as e:
LOG.exception("Invalid Coinbase webhook")
LOG.e("Invalid Coinbase webhook")
return str(e), 400
LOG.d("Coinbase event %s", event)
@ -814,7 +812,7 @@ def handle_coinbase_event(event) -> bool:
code = event["data"]["code"]
user = User.get(user_id)
if not user:
LOG.exception("User not found %s", user_id)
LOG.e("User not found %s", user_id)
return False
coinbase_subscription: CoinbaseSubscription = CoinbaseSubscription.get_by(
@ -922,7 +920,7 @@ def register_custom_commands(app):
def dummy_data():
from init_app import add_sl_domains
LOG.warning("reset db, add fake data")
LOG.w("reset db, add fake data")
with app.app_context():
fake_data()
add_sl_domains()

View File

@ -23,7 +23,7 @@ from server import create_app
def create_db():
if not database_exists(DB_URI):
LOG.debug("db not exist, create database")
LOG.d("db not exist, create database")
create_database(DB_URI)
# Create all tables
@ -56,7 +56,7 @@ def send_mailbox_newsletter():
)
sleep(1)
except Exception:
LOG.warning("Cannot send to user %s", user)
LOG.w("Cannot send to user %s", user)
def send_pgp_newsletter():
@ -72,7 +72,7 @@ def send_pgp_newsletter():
)
sleep(1)
except Exception:
LOG.warning("Cannot send to user %s", user)
LOG.w("Cannot send to user %s", user)
def send_mobile_newsletter():
@ -89,7 +89,7 @@ def send_mobile_newsletter():
render("com/newsletter/mobile-darkmode.html", user=user),
)
except Exception:
LOG.warning("Cannot send to user %s", user)
LOG.w("Cannot send to user %s", user)
if count % 5 == 0:
# sleep every 5 sends to avoid hitting email limits
@ -125,7 +125,7 @@ def disable_mailbox(mailbox_id):
email_msg.replace("\n", "<br>"),
)
except Exception:
LOG.exception("Cannot send disable mailbox email to %s", mailbox.user)
LOG.e("Cannot send disable mailbox email to %s", mailbox.user)
def send_onboarding_emails(user):