Turn more log messages into proper sentences.

This commit is contained in:
link2xt
2023-03-24 12:15:42 +00:00
parent 4f25edb1a1
commit 83af248068
7 changed files with 99 additions and 120 deletions

View File

@@ -262,7 +262,7 @@ impl Accounts {
pub async fn stop_io(&self) { pub async fn stop_io(&self) {
// Sending an event here wakes up event loop even // Sending an event here wakes up event loop even
// if there are no accounts. // if there are no accounts.
info!(self, "Stopping IO for all accounts"); info!(self, "Stopping IO for all accounts.");
for account in self.accounts.values() { for account in self.accounts.values() {
account.stop_io().await; account.stop_io().await;
} }

View File

@@ -417,7 +417,7 @@ impl<'a> BlobObject<'a> {
info!( info!(
context, context,
"Final scaled-down image size: {}B ({}px)", "Final scaled-down image size: {}B ({}px).",
encoded.len(), encoded.len(),
img_wh img_wh
); );
@@ -458,7 +458,7 @@ impl<'a> BlobObject<'a> {
Some(3) => return Ok(180), Some(3) => return Ok(180),
Some(6) => return Ok(90), Some(6) => return Ok(90),
Some(8) => return Ok(270), Some(8) => return Ok(270),
other => warn!(context, "exif orientation value ignored: {:?}", other), other => warn!(context, "Exif orientation value ignored: {other:?}."),
} }
} }
Ok(0) Ok(0)
@@ -490,7 +490,7 @@ impl<'a> BlobDirContents<'a> {
match entry { match entry {
Ok(entry) => Some(entry), Ok(entry) => Some(entry),
Err(err) => { Err(err) => {
error!(context, "Failed to read blob file: {err}"); error!(context, "Failed to read blob file: {err}.");
None None
} }
} }
@@ -501,7 +501,7 @@ impl<'a> BlobDirContents<'a> {
false => { false => {
warn!( warn!(
context, context,
"Export: Found blob dir entry {} that is not a file, ignoring", "Export: Found blob dir entry {} that is not a file, ignoring.",
entry.path().display() entry.path().display()
); );
None None
@@ -569,7 +569,7 @@ fn encoded_img_exceeds_bytes(
if encoded.len() > max_bytes { if encoded.len() > max_bytes {
info!( info!(
context, context,
"image size {}B ({}x{}px) exceeds {}B, need to scale down", "Image size {}B ({}x{}px) exceeds {}B, need to scale down.",
encoded.len(), encoded.len(),
img.width(), img.width(),
img.height(), img.height(),

View File

@@ -247,7 +247,7 @@ impl ChatId {
} else { } else {
warn!( warn!(
context, context,
"Cannot create chat, contact {} does not exist.", contact_id, "Cannot create chat, contact {contact_id} does not exist."
); );
bail!("Can not create chat for non-existing contact"); bail!("Can not create chat for non-existing contact");
} }
@@ -285,7 +285,7 @@ impl ChatId {
let chat_id = ChatId::new(u32::try_from(row_id)?); let chat_id = ChatId::new(u32::try_from(row_id)?);
info!( info!(
context, context,
"Created group/mailinglist '{}' grpid={} as {}, blocked={}", "Created group/mailinglist '{}' grpid={} as {}, blocked={}.",
grpname, grpname,
grpid, grpid,
chat_id, chat_id,
@@ -338,14 +338,14 @@ impl ChatId {
if contact_id != ContactId::SELF { if contact_id != ContactId::SELF {
info!( info!(
context, context,
"Blocking the contact {} to block 1:1 chat", contact_id "Blocking the contact {contact_id} to block 1:1 chat."
); );
Contact::block(context, contact_id).await?; Contact::block(context, contact_id).await?;
} }
} }
} }
Chattype::Group => { Chattype::Group => {
info!(context, "Can't block groups yet, deleting the chat"); info!(context, "Can't block groups yet, deleting the chat.");
self.delete(context).await?; self.delete(context).await?;
} }
Chattype::Mailinglist => { Chattype::Mailinglist => {
@@ -500,7 +500,7 @@ impl ChatId {
let chat = Chat::load_from_db(context, self).await?; let chat = Chat::load_from_db(context, self).await?;
if let Err(e) = self.inner_set_protection(context, protect).await { if let Err(e) = self.inner_set_protection(context, protect).await {
error!(context, "Cannot set protection: {}", e); // make error user-visible error!(context, "Cannot set protection: {e:#}."); // make error user-visible
return Err(e); return Err(e);
} }
@@ -1070,7 +1070,7 @@ impl ChatId {
); );
info!( info!(
context, context,
"set gossiped_timestamp for chat {} to {}.", self, timestamp, "Set gossiped_timestamp for chat {} to {}.", self, timestamp,
); );
context context
@@ -1211,7 +1211,7 @@ impl Chat {
Err(err) => { Err(err) => {
error!( error!(
context, context,
"failed to load contacts for {}: {:#}", chat.id, err "Failed to load contacts for {}: {:#}.", chat.id, err
); );
} }
} }
@@ -2032,8 +2032,11 @@ async fn prepare_msg_blob(context: &Context, msg: &mut Message) -> Result<()> {
.with_context(|| format!("attachment missing for message of type #{}", msg.viewtype))?; .with_context(|| format!("attachment missing for message of type #{}", msg.viewtype))?;
if msg.viewtype == Viewtype::Image { if msg.viewtype == Viewtype::Image {
if let Err(e) = blob.recode_to_image_size(context).await { if let Err(err) = blob.recode_to_image_size(context).await {
warn!(context, "Cannot recode image, using original data: {:?}", e); warn!(
context,
"Cannot recode image, using original data: {err:#}."
);
} }
} }
msg.param.set(Param::File, blob.as_name()); msg.param.set(Param::File, blob.as_name());
@@ -2256,7 +2259,7 @@ async fn create_send_msg_job(context: &Context, msg_id: MsgId) -> Result<Option<
let attach_selfavatar = match shall_attach_selfavatar(context, msg.chat_id).await { let attach_selfavatar = match shall_attach_selfavatar(context, msg.chat_id).await {
Ok(attach_selfavatar) => attach_selfavatar, Ok(attach_selfavatar) => attach_selfavatar,
Err(err) => { Err(err) => {
warn!(context, "job: cannot get selfavatar-state: {:#}", err); warn!(context, "SMTP job cannot get selfavatar-state: {err:#}.");
false false
} }
}; };
@@ -2283,7 +2286,7 @@ async fn create_send_msg_job(context: &Context, msg_id: MsgId) -> Result<Option<
// may happen eg. for groups with only SELF and bcc_self disabled // may happen eg. for groups with only SELF and bcc_self disabled
info!( info!(
context, context,
"message {} has no recipient, skipping smtp-send", msg_id "Message {msg_id} has no recipient, skipping smtp-send."
); );
msg_id.set_delivered(context).await?; msg_id.set_delivered(context).await?;
return Ok(None); return Ok(None);
@@ -2318,27 +2321,27 @@ async fn create_send_msg_job(context: &Context, msg_id: MsgId) -> Result<Option<
if 0 != rendered_msg.last_added_location_id { if 0 != rendered_msg.last_added_location_id {
if let Err(err) = location::set_kml_sent_timestamp(context, msg.chat_id, time()).await { if let Err(err) = location::set_kml_sent_timestamp(context, msg.chat_id, time()).await {
error!(context, "Failed to set kml sent_timestamp: {:#}", err); error!(context, "Failed to set kml sent_timestamp: {err:#}.");
} }
if !msg.hidden { if !msg.hidden {
if let Err(err) = if let Err(err) =
location::set_msg_location_id(context, msg.id, rendered_msg.last_added_location_id) location::set_msg_location_id(context, msg.id, rendered_msg.last_added_location_id)
.await .await
{ {
error!(context, "Failed to set msg_location_id: {:#}", err); error!(context, "Failed to set msg_location_id: {err:#}.");
} }
} }
} }
if let Some(sync_ids) = rendered_msg.sync_ids_to_delete { if let Some(sync_ids) = rendered_msg.sync_ids_to_delete {
if let Err(err) = context.delete_sync_ids(sync_ids).await { if let Err(err) = context.delete_sync_ids(sync_ids).await {
error!(context, "Failed to delete sync ids: {:#}", err); error!(context, "Failed to delete sync ids: {err:#}.");
} }
} }
if attach_selfavatar { if attach_selfavatar {
if let Err(err) = msg.chat_id.set_selfavatar_timestamp(context, time()).await { if let Err(err) = msg.chat_id.set_selfavatar_timestamp(context, time()).await {
error!(context, "Failed to set selfavatar timestamp: {:#}", err); error!(context, "Failed to set selfavatar timestamp: {err:#}.");
} }
} }
@@ -2693,8 +2696,7 @@ pub(crate) async fn mark_old_messages_as_noticed(
if !changed_chats.is_empty() { if !changed_chats.is_empty() {
info!( info!(
context, context,
"Marking chats as noticed because there are newer outgoing messages: {:?}", "Marking chats as noticed because there are newer outgoing messages: {changed_chats:?}."
changed_chats
); );
} }
@@ -3015,7 +3017,7 @@ pub(crate) async fn add_contact_to_chat_ex(
// if SELF is not in the group, members cannot be added at all. // if SELF is not in the group, members cannot be added at all.
warn!( warn!(
context, context,
"invalid attempt to add self e-mail address to group" "Invalid attempt to add self e-mail address to group."
); );
return Ok(false); return Ok(false);
} }
@@ -3562,7 +3564,7 @@ pub async fn add_device_msg_with_importance(
if let Some(label) = label { if let Some(label) = label {
if was_device_msg_ever_added(context, label).await? { if was_device_msg_ever_added(context, label).await? {
info!(context, "device-message {} already added", label); info!(context, "Device-message {label} already added.");
return Ok(msg_id); return Ok(msg_id);
} }
} }

View File

@@ -176,7 +176,7 @@ impl Chatlist {
// allow searching over special names that may change at any time // allow searching over special names that may change at any time
// when the ui calls set_stock_translation() // when the ui calls set_stock_translation()
if let Err(err) = update_special_chat_names(context).await { if let Err(err) = update_special_chat_names(context).await {
warn!(context, "cannot update special chat names: {:?}", err) warn!(context, "Cannot update special chat names: {err:#}.")
} }
let str_like_cmd = format!("%{query}%"); let str_like_cmd = format!("%{query}%");

View File

@@ -153,7 +153,7 @@ impl<'a> Connection<'a> {
} }
pub(crate) async fn perform_job(context: &Context, mut connection: Connection<'_>, mut job: Job) { pub(crate) async fn perform_job(context: &Context, mut connection: Connection<'_>, mut job: Job) {
info!(context, "job {} started...", &job); info!(context, "Job {} started...", &job);
let try_res = match perform_job_action(context, &mut job, &mut connection, 0).await { let try_res = match perform_job_action(context, &mut job, &mut connection, 0).await {
Status::RetryNow => perform_job_action(context, &mut job, &mut connection, 1).await, Status::RetryNow => perform_job_action(context, &mut job, &mut connection, 1).await,
@@ -165,7 +165,7 @@ pub(crate) async fn perform_job(context: &Context, mut connection: Connection<'_
let tries = job.tries + 1; let tries = job.tries + 1;
if tries < JOB_RETRIES { if tries < JOB_RETRIES {
info!(context, "increase job {} tries to {}", job, tries); info!(context, "Increase job {job} tries to {tries}.");
job.tries = tries; job.tries = tries;
let time_offset = get_backoff_time_offset(tries); let time_offset = get_backoff_time_offset(tries);
job.desired_timestamp = time() + time_offset; job.desired_timestamp = time() + time_offset;
@@ -177,26 +177,23 @@ pub(crate) async fn perform_job(context: &Context, mut connection: Connection<'_
time_offset time_offset
); );
job.save(context).await.unwrap_or_else(|err| { job.save(context).await.unwrap_or_else(|err| {
error!(context, "failed to save job: {:#}", err); error!(context, "Failed to save job: {err:#}.");
}); });
} else { } else {
info!( info!(
context, context,
"remove job {} as it exhausted {} retries", job, JOB_RETRIES "Remove job {job} as it exhausted {JOB_RETRIES} retries."
); );
job.delete(context).await.unwrap_or_else(|err| { job.delete(context).await.unwrap_or_else(|err| {
error!(context, "failed to delete job: {:#}", err); error!(context, "Failed to delete job: {err:#}.");
}); });
} }
} }
Status::Finished(res) => { Status::Finished(res) => {
if let Err(err) = res { if let Err(err) = res {
warn!( warn!(context, "Remove job {job} as it failed with error {err:#}.");
context,
"remove job {} as it failed with error {:#}", job, err
);
} else { } else {
info!(context, "remove job {} as it succeeded", job); info!(context, "Remove job {job} as it succeeded.");
} }
job.delete(context).await.unwrap_or_else(|err| { job.delete(context).await.unwrap_or_else(|err| {
@@ -212,13 +209,13 @@ async fn perform_job_action(
connection: &mut Connection<'_>, connection: &mut Connection<'_>,
tries: u32, tries: u32,
) -> Status { ) -> Status {
info!(context, "begin immediate try {} of job {}", tries, job); info!(context, "Begin immediate try {tries} of job {job}.");
let try_res = match job.action { let try_res = match job.action {
Action::DownloadMsg => job.download_msg(context, connection.inbox()).await, Action::DownloadMsg => job.download_msg(context, connection.inbox()).await,
}; };
info!(context, "Finished immediate try {} of job {}", tries, job); info!(context, "Finished immediate try {tries} of job {job}.");
try_res try_res
} }
@@ -250,7 +247,7 @@ pub(crate) async fn schedule_resync(context: &Context) -> Result<()> {
pub async fn add(context: &Context, job: Job) -> Result<()> { pub async fn add(context: &Context, job: Job) -> Result<()> {
job.save(context).await.context("failed to save job")?; job.save(context).await.context("failed to save job")?;
info!(context, "interrupt: imap"); info!(context, "Interrupt: IMAP.");
context context
.scheduler .scheduler
.interrupt_inbox(InterruptInfo::new(false)) .interrupt_inbox(InterruptInfo::new(false))
@@ -264,7 +261,7 @@ pub async fn add(context: &Context, job: Job) -> Result<()> {
/// jobs, this is tricky and probably wrong currently. Look at the /// jobs, this is tricky and probably wrong currently. Look at the
/// SQL queries for details. /// SQL queries for details.
pub(crate) async fn load_next(context: &Context, info: &InterruptInfo) -> Result<Option<Job>> { pub(crate) async fn load_next(context: &Context, info: &InterruptInfo) -> Result<Option<Job>> {
info!(context, "loading job"); info!(context, "Loading job.");
let query; let query;
let params; let params;
@@ -316,19 +313,19 @@ LIMIT 1;
Ok(job) => return Ok(job), Ok(job) => return Ok(job),
Err(err) => { Err(err) => {
// Remove invalid job from the DB // Remove invalid job from the DB
info!(context, "cleaning up job, because of {:#}", err); info!(context, "Cleaning up job, because of {err:#}.");
// TODO: improve by only doing a single query // TODO: improve by only doing a single query
let id = context let id = context
.sql .sql
.query_row(query, params.clone(), |row| row.get::<_, i32>(0)) .query_row(query, params.clone(), |row| row.get::<_, i32>(0))
.await .await
.context("Failed to retrieve invalid job ID from the database")?; .context("failed to retrieve invalid job ID from the database")?;
context context
.sql .sql
.execute("DELETE FROM jobs WHERE id=?;", paramsv![id]) .execute("DELETE FROM jobs WHERE id=?;", paramsv![id])
.await .await
.with_context(|| format!("Failed to delete invalid job {id}"))?; .with_context(|| format!("failed to delete invalid job {id}"))?;
} }
} }
} }

View File

@@ -96,7 +96,7 @@ pub(crate) async fn receive_imf_inner(
is_partial_download: Option<u32>, is_partial_download: Option<u32>,
fetching_existing_messages: bool, fetching_existing_messages: bool,
) -> Result<Option<ReceivedMsg>> { ) -> Result<Option<ReceivedMsg>> {
info!(context, "Receiving message, seen={}...", seen); info!(context, "Receiving message, seen={seen}...");
if std::env::var(crate::DCC_MIME_DEBUG).is_ok() { if std::env::var(crate::DCC_MIME_DEBUG).is_ok() {
info!( info!(
@@ -109,7 +109,7 @@ pub(crate) async fn receive_imf_inner(
let mut mime_parser = match MimeMessage::from_bytes(context, imf_raw, is_partial_download).await let mut mime_parser = match MimeMessage::from_bytes(context, imf_raw, is_partial_download).await
{ {
Err(err) => { Err(err) => {
warn!(context, "receive_imf: can't parse MIME: {:#}", err); warn!(context, "receive_imf: can't parse MIME: {err:#}.");
let msg_ids; let msg_ids;
if !rfc724_mid.starts_with(GENERATED_PREFIX) { if !rfc724_mid.starts_with(GENERATED_PREFIX) {
let row_id = context let row_id = context
@@ -138,11 +138,11 @@ pub(crate) async fn receive_imf_inner(
// we can not add even an empty record if we have no info whatsoever // we can not add even an empty record if we have no info whatsoever
if !mime_parser.has_headers() { if !mime_parser.has_headers() {
warn!(context, "receive_imf: no headers found"); warn!(context, "receive_imf: no headers found.");
return Ok(None); return Ok(None);
} }
info!(context, "received message has Message-Id: {}", rfc724_mid); info!(context, "Received message has Message-Id: {rfc724_mid}");
// check, if the mail is already in our database. // check, if the mail is already in our database.
// make sure, this check is done eg. before securejoin-processing. // make sure, this check is done eg. before securejoin-processing.
@@ -182,7 +182,7 @@ pub(crate) async fn receive_imf_inner(
None => { None => {
warn!( warn!(
context, context,
"receive_imf: From field does not contain an acceptable address" "receive_imf: From field does not contain an acceptable address."
); );
return Ok(None); return Ok(None);
} }
@@ -269,13 +269,13 @@ pub(crate) async fn receive_imf_inner(
if from_id == ContactId::SELF { if from_id == ContactId::SELF {
if mime_parser.was_encrypted() { if mime_parser.was_encrypted() {
if let Err(err) = context.execute_sync_items(sync_items).await { if let Err(err) = context.execute_sync_items(sync_items).await {
warn!(context, "receive_imf cannot execute sync items: {:#}", err); warn!(context, "receive_imf cannot execute sync items: {err:#}.");
} }
} else { } else {
warn!(context, "sync items are not encrypted."); warn!(context, "Sync items are not encrypted.");
} }
} else { } else {
warn!(context, "sync items not sent by self."); warn!(context, "Sync items not sent by self.");
} }
} }
@@ -284,7 +284,7 @@ pub(crate) async fn receive_imf_inner(
.receive_status_update(from_id, insert_msg_id, status_update) .receive_status_update(from_id, insert_msg_id, status_update)
.await .await
{ {
warn!(context, "receive_imf cannot update status: {:#}", err); warn!(context, "receive_imf cannot update status: {err:#}.");
} }
} }
@@ -302,10 +302,7 @@ pub(crate) async fn receive_imf_inner(
) )
.await .await
{ {
warn!( warn!(context, "receive_imf cannot update profile image: {err:#}.");
context,
"receive_imf cannot update profile image: {:#}", err
);
}; };
} }
} }
@@ -331,7 +328,7 @@ pub(crate) async fn receive_imf_inner(
) )
.await .await
{ {
warn!(context, "cannot update contact status: {:#}", err); warn!(context, "Cannot update contact status: {err:#}.");
} }
} }
@@ -394,7 +391,7 @@ pub async fn from_field_to_contact_id(
Err(err) => { Err(err) => {
warn!( warn!(
context, context,
"Cannot create a contact for the given From field: {:#}.", err "Cannot create a contact for the given From field: {err:#}."
); );
return Ok(None); return Ok(None);
} }
@@ -476,7 +473,7 @@ async fn add_parts(
// this message is a classic email not a chat-message nor a reply to one // this message is a classic email not a chat-message nor a reply to one
match show_emails { match show_emails {
ShowEmails::Off => { ShowEmails::Off => {
info!(context, "Classical email not shown (TRASH)"); info!(context, "Classical email not shown (TRASH).");
chat_id = Some(DC_CHAT_ID_TRASH); chat_id = Some(DC_CHAT_ID_TRASH);
allow_creation = false; allow_creation = false;
} }
@@ -519,7 +516,7 @@ async fn add_parts(
securejoin_seen = false; securejoin_seen = false;
} }
Err(err) => { Err(err) => {
warn!(context, "Error in Secure-Join message handling: {:#}", err); warn!(context, "Error in Secure-Join message handling: {err:#}.");
chat_id = Some(DC_CHAT_ID_TRASH); chat_id = Some(DC_CHAT_ID_TRASH);
securejoin_seen = true; securejoin_seen = true;
} }
@@ -536,7 +533,7 @@ async fn add_parts(
if chat_id.is_none() && mime_parser.delivery_report.is_some() { if chat_id.is_none() && mime_parser.delivery_report.is_some() {
chat_id = Some(DC_CHAT_ID_TRASH); chat_id = Some(DC_CHAT_ID_TRASH);
info!(context, "Message is a DSN (TRASH)",); info!(context, "Message is a DSN (TRASH).",);
} }
if chat_id.is_none() { if chat_id.is_none() {
@@ -754,7 +751,7 @@ async fn add_parts(
chat_id = None; chat_id = None;
} }
Err(err) => { Err(err) => {
warn!(context, "Error in Secure-Join watching: {:#}", err); warn!(context, "Error in Secure-Join watching: {err:#}.");
chat_id = Some(DC_CHAT_ID_TRASH); chat_id = Some(DC_CHAT_ID_TRASH);
} }
} }
@@ -771,7 +768,7 @@ async fn add_parts(
if is_draft { if is_draft {
// Most mailboxes have a "Drafts" folder where constantly new emails appear but we don't actually want to show them // Most mailboxes have a "Drafts" folder where constantly new emails appear but we don't actually want to show them
info!(context, "Email is probably just a draft (TRASH)"); info!(context, "Email is probably just a draft (TRASH).");
chat_id = Some(DC_CHAT_ID_TRASH); chat_id = Some(DC_CHAT_ID_TRASH);
} }
@@ -863,14 +860,14 @@ async fn add_parts(
if fetching_existing_messages && mime_parser.decrypting_failed { if fetching_existing_messages && mime_parser.decrypting_failed {
chat_id = Some(DC_CHAT_ID_TRASH); chat_id = Some(DC_CHAT_ID_TRASH);
// We are only gathering old messages on first start. We do not want to add loads of non-decryptable messages to the chats. // We are only gathering old messages on first start. We do not want to add loads of non-decryptable messages to the chats.
info!(context, "Existing non-decipherable message. (TRASH)"); info!(context, "Existing non-decipherable message (TRASH).");
} }
if mime_parser.webxdc_status_update.is_some() && mime_parser.parts.len() == 1 { if mime_parser.webxdc_status_update.is_some() && mime_parser.parts.len() == 1 {
if let Some(part) = mime_parser.parts.first() { if let Some(part) = mime_parser.parts.first() {
if part.typ == Viewtype::Text && part.msg.is_empty() { if part.typ == Viewtype::Text && part.msg.is_empty() {
chat_id = Some(DC_CHAT_ID_TRASH); chat_id = Some(DC_CHAT_ID_TRASH);
info!(context, "Message is a status update only (TRASH)"); info!(context, "Message is a status update only (TRASH).");
} }
} }
} }
@@ -880,7 +877,7 @@ async fn add_parts(
DC_CHAT_ID_TRASH DC_CHAT_ID_TRASH
} else { } else {
chat_id.unwrap_or_else(|| { chat_id.unwrap_or_else(|| {
info!(context, "No chat id for message (TRASH)"); info!(context, "No chat id for message (TRASH).");
DC_CHAT_ID_TRASH DC_CHAT_ID_TRASH
}) })
}; };
@@ -892,10 +889,7 @@ async fn add_parts(
match value.parse::<EphemeralTimer>() { match value.parse::<EphemeralTimer>() {
Ok(timer) => timer, Ok(timer) => timer,
Err(err) => { Err(err) => {
warn!( warn!(context, "Can't parse ephemeral timer \"{value}\": {err:#}.");
context,
"can't parse ephemeral timer \"{}\": {:#}", value, err
);
EphemeralTimer::Disabled EphemeralTimer::Disabled
} }
} }
@@ -915,12 +909,7 @@ async fn add_parts(
&& !mime_parser.parts.is_empty() && !mime_parser.parts.is_empty()
&& chat_id.get_ephemeral_timer(context).await? != ephemeral_timer && chat_id.get_ephemeral_timer(context).await? != ephemeral_timer
{ {
info!( info!(context, "Received new ephemeral timer value {ephemeral_timer:?} for chat {chat_id}, checking if it should be applied.");
context,
"received new ephemeral timer value {:?} for chat {}, checking if it should be applied",
ephemeral_timer,
chat_id
);
if is_dc_message == MessengerMessage::Yes if is_dc_message == MessengerMessage::Yes
&& get_previous_message(context, mime_parser) && get_previous_message(context, mime_parser)
.await? .await?
@@ -936,9 +925,7 @@ async fn add_parts(
// have seen or sent ourselves, so we ignore incoming timer to prevent a rollback. // have seen or sent ourselves, so we ignore incoming timer to prevent a rollback.
warn!( warn!(
context, context,
"ignoring ephemeral timer change to {:?} for chat {} to avoid rollback", "Ignoring ephemeral timer change to {ephemeral_timer:?} for chat {chat_id} to avoid rollback.",
ephemeral_timer,
chat_id
); );
} else if chat_id } else if chat_id
.update_timestamp(context, Param::EphemeralSettingsTimestamp, sent_timestamp) .update_timestamp(context, Param::EphemeralSettingsTimestamp, sent_timestamp)
@@ -950,12 +937,12 @@ async fn add_parts(
{ {
warn!( warn!(
context, context,
"failed to modify timer for chat {}: {:#}", chat_id, err "Failed to modify timer for chat {chat_id}: {err:#}."
); );
} else { } else {
info!( info!(
context, context,
"updated ephemeral timer to {:?} for chat {}", ephemeral_timer, chat_id "Updated ephemeral timer to {ephemeral_timer:?} for chat {chat_id}."
); );
if mime_parser.is_system_message != SystemMessage::EphemeralTimerChanged { if mime_parser.is_system_message != SystemMessage::EphemeralTimerChanged {
chat::add_info_msg( chat::add_info_msg(
@@ -970,7 +957,7 @@ async fn add_parts(
} else { } else {
warn!( warn!(
context, context,
"ignoring ephemeral timer change to {:?} because it's outdated", ephemeral_timer "Ignoring ephemeral timer change to {ephemeral_timer:?} because it is outdated."
); );
} }
} }
@@ -999,7 +986,7 @@ async fn add_parts(
if chat.is_protected() || new_status.is_some() { if chat.is_protected() || new_status.is_some() {
if let Err(err) = check_verified_properties(context, mime_parser, from_id, to_ids).await if let Err(err) = check_verified_properties(context, mime_parser, from_id, to_ids).await
{ {
warn!(context, "verification problem: {:#}", err); warn!(context, "Verification problem: {err:#}.");
let s = format!("{err}. See 'Info' for more details"); let s = format!("{err}. See 'Info' for more details");
mime_parser.repl_msg_by_error(&s); mime_parser.repl_msg_by_error(&s);
} else { } else {
@@ -1429,7 +1416,7 @@ async fn lookup_chat_by_reply(
info!( info!(
context, context,
"Assigning message to {} as it's a reply to {}", parent_chat.id, parent.rfc724_mid "Assigning message to {} as it's a reply to {}.", parent_chat.id, parent.rfc724_mid
); );
return Ok(Some((parent_chat.id, parent_chat.blocked))); return Ok(Some((parent_chat.id, parent_chat.blocked)));
} }
@@ -1499,7 +1486,7 @@ async fn create_or_lookup_group(
.map(|chat_id| (chat_id, create_blocked)); .map(|chat_id| (chat_id, create_blocked));
return Ok(res); return Ok(res);
} else { } else {
info!(context, "creating ad-hoc group prevented from caller"); info!(context, "Creating ad-hoc group prevented from caller.");
return Ok(None); return Ok(None);
}; };
@@ -1525,7 +1512,7 @@ async fn create_or_lookup_group(
let create_protected = if mime_parser.get_header(HeaderDef::ChatVerified).is_some() { let create_protected = if mime_parser.get_header(HeaderDef::ChatVerified).is_some() {
if let Err(err) = check_verified_properties(context, mime_parser, from_id, to_ids).await { if let Err(err) = check_verified_properties(context, mime_parser, from_id, to_ids).await {
warn!(context, "verification problem: {:#}", err); warn!(context, "Verification problem: {err:#}.");
let s = format!("{err}. See 'Info' for more details"); let s = format!("{err}. See 'Info' for more details");
mime_parser.repl_msg_by_error(&s); mime_parser.repl_msg_by_error(&s);
} }
@@ -1557,7 +1544,7 @@ async fn create_or_lookup_group(
{ {
// Group does not exist but should be created. // Group does not exist but should be created.
if !allow_creation { if !allow_creation {
info!(context, "creating group forbidden by caller"); info!(context, "Creating group forbidden by caller.");
return Ok(None); return Ok(None);
} }
@@ -1618,7 +1605,7 @@ async fn create_or_lookup_group(
} else { } else {
// The message was decrypted successfully, but contains a late "quit" or otherwise // The message was decrypted successfully, but contains a late "quit" or otherwise
// unwanted message. // unwanted message.
info!(context, "message belongs to unwanted group (TRASH)"); info!(context, "Message belongs to unwanted group (TRASH).");
Ok(Some((DC_CHAT_ID_TRASH, Blocked::Not))) Ok(Some((DC_CHAT_ID_TRASH, Blocked::Not)))
} }
} }
@@ -1658,7 +1645,7 @@ async fn apply_group_changes(
Some(stock_str::msg_del_member(context, &removed_addr, from_id).await) Some(stock_str::msg_del_member(context, &removed_addr, from_id).await)
}; };
} }
None => warn!(context, "removed {:?} has no contact_id", removed_addr), None => warn!(context, "Removed {removed_addr:?} has no contact_id."),
} }
} else { } else {
removed_id = None; removed_id = None;
@@ -1683,7 +1670,7 @@ async fn apply_group_changes(
.update_timestamp(context, Param::GroupNameTimestamp, sent_timestamp) .update_timestamp(context, Param::GroupNameTimestamp, sent_timestamp)
.await? .await?
{ {
info!(context, "updating grpname for chat {}", chat_id); info!(context, "Updating grpname for chat {chat_id}.");
context context
.sql .sql
.execute( .execute(
@@ -1723,7 +1710,7 @@ async fn apply_group_changes(
if mime_parser.get_header(HeaderDef::ChatVerified).is_some() { if mime_parser.get_header(HeaderDef::ChatVerified).is_some() {
if let Err(err) = check_verified_properties(context, mime_parser, from_id, to_ids).await { if let Err(err) = check_verified_properties(context, mime_parser, from_id, to_ids).await {
warn!(context, "verification problem: {:#}", err); warn!(context, "Verification problem: {err:#}.");
let s = format!("{err}. See 'Info' for more details"); let s = format!("{err}. See 'Info' for more details");
mime_parser.repl_msg_by_error(&s); mime_parser.repl_msg_by_error(&s);
} }
@@ -1743,9 +1730,7 @@ async fn apply_group_changes(
{ {
warn!( warn!(
context, context,
"Contact {} attempts to modify group chat {} member list without being a member.", "Contact {from_id} attempts to modify group chat {chat_id} member list without being a member."
from_id,
chat_id
); );
} else if chat_id } else if chat_id
.update_timestamp(context, Param::MemberListTimestamp, sent_timestamp) .update_timestamp(context, Param::MemberListTimestamp, sent_timestamp)
@@ -1778,10 +1763,7 @@ async fn apply_group_changes(
} }
members_to_add.dedup(); members_to_add.dedup();
info!( info!(context, "Adding {members_to_add:?} to chat id={chat_id}.");
context,
"adding {:?} to chat id={}", members_to_add, chat_id
);
chat::add_to_chat_contacts_table(context, chat_id, &members_to_add).await?; chat::add_to_chat_contacts_table(context, chat_id, &members_to_add).await?;
send_event_chat_modified = true; send_event_chat_modified = true;
} }
@@ -1791,17 +1773,15 @@ async fn apply_group_changes(
if !chat::is_contact_in_chat(context, chat_id, ContactId::SELF).await? { if !chat::is_contact_in_chat(context, chat_id, ContactId::SELF).await? {
warn!( warn!(
context, context,
"Received group avatar update for group chat {} we are not a member of.", chat_id "Received group avatar update for group chat {chat_id} we are not a member of."
); );
} else if !chat::is_contact_in_chat(context, chat_id, from_id).await? { } else if !chat::is_contact_in_chat(context, chat_id, from_id).await? {
warn!( warn!(
context, context,
"Contact {} attempts to modify group chat {} avatar without being a member.", "Contact {from_id} attempts to modify group chat {chat_id} avatar without being a member.",
from_id,
chat_id
); );
} else { } else {
info!(context, "group-avatar change for {}", chat_id); info!(context, "Group-avatar change for {chat_id}.");
if chat if chat
.param .param
.update_timestamp(Param::AvatarTimestamp, sent_timestamp)? .update_timestamp(Param::AvatarTimestamp, sent_timestamp)?
@@ -1935,7 +1915,7 @@ async fn create_or_lookup_mailinglist(
.await .await
.with_context(|| { .with_context(|| {
format!( format!(
"Failed to create mailinglist '{}' for grpid={}", "failed to create mailinglist '{}' for grpid={}",
&name, &listid &name, &listid
) )
})?; })?;
@@ -1943,7 +1923,7 @@ async fn create_or_lookup_mailinglist(
chat::add_to_chat_contacts_table(context, chat_id, &[ContactId::SELF]).await?; chat::add_to_chat_contacts_table(context, chat_id, &[ContactId::SELF]).await?;
Ok(Some((chat_id, blocked))) Ok(Some((chat_id, blocked)))
} else { } else {
info!(context, "creating list forbidden by caller"); info!(context, "Creating list forbidden by caller.");
Ok(None) Ok(None)
} }
} }
@@ -2035,7 +2015,7 @@ async fn create_adhoc_group(
if mime_parser.is_mailinglist_message() { if mime_parser.is_mailinglist_message() {
info!( info!(
context, context,
"not creating ad-hoc group for mailing list message" "Not creating ad-hoc group for mailing list message."
); );
return Ok(None); return Ok(None);
@@ -2052,13 +2032,13 @@ async fn create_adhoc_group(
// Instead, assign the message to 1:1 chat with the sender. // Instead, assign the message to 1:1 chat with the sender.
warn!( warn!(
context, context,
"not creating ad-hoc group for message that cannot be decrypted" "Not creating ad-hoc group for message that cannot be decrypted."
); );
return Ok(None); return Ok(None);
} }
if member_ids.len() < 3 { if member_ids.len() < 3 {
info!(context, "not creating ad-hoc group: too few contacts"); info!(context, "Not creating ad-hoc group: too few contacts.");
return Ok(None); return Ok(None);
} }
@@ -2165,7 +2145,7 @@ async fn check_verified_properties(
for (to_addr, mut is_verified) in rows { for (to_addr, mut is_verified) in rows {
info!( info!(
context, context,
"check_verified_properties: {:?} self={:?}", "check_verified_properties: {:?} self={:?}.",
to_addr, to_addr,
context.is_self_addr(&to_addr).await context.is_self_addr(&to_addr).await
); );

View File

@@ -699,26 +699,26 @@ pub async fn housekeeping(context: &Context) -> Result<()> {
if let Err(err) = remove_unused_files(context).await { if let Err(err) = remove_unused_files(context).await {
warn!( warn!(
context, context,
"Housekeeping: cannot remove unused files: {:#}", err "Housekeeping: cannot remove unused files: {:#}.", err
); );
} }
if let Err(err) = start_ephemeral_timers(context).await { if let Err(err) = start_ephemeral_timers(context).await {
warn!( warn!(
context, context,
"Housekeeping: cannot start ephemeral timers: {:#}", err "Housekeeping: cannot start ephemeral timers: {:#}.", err
); );
} }
if let Err(err) = prune_tombstones(&context.sql).await { if let Err(err) = prune_tombstones(&context.sql).await {
warn!( warn!(
context, context,
"Housekeeping: Cannot prune message tombstones: {:#}", err "Housekeeping: Cannot prune message tombstones: {:#}.", err
); );
} }
if let Err(err) = deduplicate_peerstates(&context.sql).await { if let Err(err) = deduplicate_peerstates(&context.sql).await {
warn!(context, "Failed to deduplicate peerstates: {:#}", err) warn!(context, "Failed to deduplicate peerstates: {:#}.", err)
} }
context.schedule_quota_update().await?; context.schedule_quota_update().await?;
@@ -731,7 +731,7 @@ pub async fn housekeeping(context: &Context) -> Result<()> {
.await .await
{ {
Err(err) => { Err(err) => {
warn!(context, "Failed to run incremental vacuum: {err:#}"); warn!(context, "Failed to run incremental vacuum: {err:#}.");
} }
Ok(Some(())) => { Ok(Some(())) => {
// Incremental vacuum returns a zero-column result if it did anything. // Incremental vacuum returns a zero-column result if it did anything.
@@ -747,7 +747,7 @@ pub async fn housekeeping(context: &Context) -> Result<()> {
.set_config(Config::LastHousekeeping, Some(&time().to_string())) .set_config(Config::LastHousekeeping, Some(&time().to_string()))
.await .await
{ {
warn!(context, "Can't set config: {}", e); warn!(context, "Can't set config: {e:#}.");
} }
context context
@@ -814,7 +814,7 @@ pub async fn remove_unused_files(context: &Context) -> Result<()> {
.await .await
.context("housekeeping: failed to SELECT value FROM config")?; .context("housekeeping: failed to SELECT value FROM config")?;
info!(context, "{} files in use.", files_in_use.len(),); info!(context, "{} files in use.", files_in_use.len());
/* go through directories and delete unused files */ /* go through directories and delete unused files */
let blobdir = context.get_blobdir(); let blobdir = context.get_blobdir();
for p in [&blobdir.join(BLOBS_BACKUP_NAME), blobdir] { for p in [&blobdir.join(BLOBS_BACKUP_NAME), blobdir] {
@@ -846,7 +846,7 @@ pub async fn remove_unused_files(context: &Context) -> Result<()> {
// environment f.e. So, no warning. // environment f.e. So, no warning.
info!( info!(
context, context,
"Housekeeping: Cannot rmdir {}: {:#}", "Housekeeping: Cannot rmdir {}: {:#}.",
entry.path().display(), entry.path().display(),
e e
); );
@@ -868,7 +868,7 @@ pub async fn remove_unused_files(context: &Context) -> Result<()> {
{ {
info!( info!(
context, context,
"Housekeeping: Keeping new unreferenced file #{}: {:?}", "Housekeeping: Keeping new unreferenced file #{}: {:?}.",
unreferenced_count, unreferenced_count,
entry.file_name(), entry.file_name(),
); );
@@ -879,7 +879,7 @@ pub async fn remove_unused_files(context: &Context) -> Result<()> {
} }
info!( info!(
context, context,
"Housekeeping: Deleting unreferenced file #{}: {:?}", "Housekeeping: Deleting unreferenced file #{}: {:?}.",
unreferenced_count, unreferenced_count,
entry.file_name() entry.file_name()
); );
@@ -897,7 +897,7 @@ pub async fn remove_unused_files(context: &Context) -> Result<()> {
Err(err) => { Err(err) => {
warn!( warn!(
context, context,
"Housekeeping: Cannot read dir {}: {:#}", "Housekeeping: Cannot read dir {}: {:#}.",
p.display(), p.display(),
err err
); );