Compare commits

...

7 Commits

Author SHA1 Message Date
holger krekel
21f1afa94a address @link2xt error comment 2019-11-30 23:09:06 +01:00
holger krekel
8cefbd227e introduce a select_with_uidvalidity function that helps us during configuration to know about last_seen_uid 2019-11-30 20:56:46 +01:00
holger krekel
ebf6c10dd7 refine uid_next handling and rename and resultify configure_folder to ensure_configurer_folders 2019-11-30 20:56:46 +01:00
holger krekel
1382c506cb revert logic to get last_seen_uid 2019-11-30 20:56:46 +01:00
holger krekel
d9f2b60e5a remove commented errors and fix fmt 2019-11-30 20:56:46 +01:00
holger krekel
db22992ede when first looking at a folder, look at "uid_next" as returned from server
and otherwise properly fetch the last messages to determine the last seen uid.
also add some tracing.
2019-11-30 20:56:46 +01:00
holger krekel
12187f3176 rework select_folder error handling (thanks @flub and @link2xt for helping along) 2019-11-30 20:56:46 +01:00
4 changed files with 265 additions and 227 deletions

View File

@@ -794,6 +794,7 @@ class TestOnlineAccount:
chat2 = ac2.qr_join_chat(qr)
assert chat2.id >= 10
wait_securejoin_inviter_progress(ac1, 1000)
ac1._evlogger.get_matching("DC_EVENT_SECUREJOIN_MEMBER_ADDED")
lp.sec("ac2: read member added message")
msg = ac2.wait_next_incoming_message()

View File

@@ -355,13 +355,19 @@ pub fn JobConfigureImap(context: &Context) {
progress!(context, 900);
let create_mvbox = context.get_config_bool(Config::MvboxWatch)
|| context.get_config_bool(Config::MvboxMove);
context
.inbox_thread
.read()
.unwrap()
.imap
.configure_folders(context, create_mvbox);
true
let imap = &context.inbox_thread.read().unwrap().imap;
if let Err(err) = imap.ensure_configured_folders(context, create_mvbox) {
error!(context, "configuring folders failed: {:?}", err);
false
} else {
let res = imap.select_with_uidvalidity(context, "INBOX");
if let Err(err) = res {
error!(context, "could not read INBOX status: {:?}", err);
false
} else {
true
}
}
}
17 => {
progress!(context, 910);
@@ -383,11 +389,10 @@ pub fn JobConfigureImap(context: &Context) {
// (~30 seconds on a Moto G4 play) and might looks as if message sending is always that slow.
e2ee::ensure_secret_key_exists(context);
success = true;
info!(context, "Configure completed.");
info!(context, "key generation completed");
progress!(context, 940);
break; // We are done here
}
_ => {
error!(context, "Internal error: step counter out of bound",);
break;
@@ -410,24 +415,6 @@ pub fn JobConfigureImap(context: &Context) {
context.smtp.clone().lock().unwrap().disconnect();
}
/*
if !success {
// disconnect if configure did not succeed
if imap_connected_here {
// context.inbox.read().unwrap().disconnect(context);
}
if smtp_connected_here {
// context.smtp.clone().lock().unwrap().disconnect();
}
} else {
assert!(imap_connected_here && smtp_connected_here);
info!(
context,
0, "Keeping IMAP/SMTP connections open after successful configuration"
);
}
*/
// remember the entered parameters on success
// and restore to last-entered on failure.
// this way, the parameters visible to the ui are always in-sync with the current configuration.

View File

@@ -18,7 +18,7 @@ use async_std::task;
use crate::constants::*;
use crate::context::Context;
use crate::dc_receive_imf::dc_receive_imf;
use crate::error::{Error, Result};
use crate::error::Error;
use crate::events::Event;
use crate::imap_client::*;
use crate::job::{job_add, Action};
@@ -40,6 +40,7 @@ pub enum ImapActionResult {
}
const PREFETCH_FLAGS: &str = "(UID ENVELOPE)";
const JUST_UID: &str = "(UID)";
const BODY_FLAGS: &str = "(FLAGS BODY.PEEK[])";
const SELECT_ALL: &str = "1:*";
@@ -114,6 +115,24 @@ impl Default for ImapConfig {
}
}
#[derive(Debug, Fail)]
enum SelectError {
#[fail(display = "Could not obtain imap-session object.")]
NoSession,
#[fail(display = "Connection Lost or no connection established")]
ConnectionLost,
#[fail(display = "imap-close (to expunge messages) failed: {}", _0)]
CloseExpungeFailed(#[cause] async_imap::error::Error),
#[fail(display = "Folder name invalid: {:?}", _0)]
BadFolderName(String),
#[fail(display = "async-imap select error: {:?}", _0)]
Other(String),
}
impl Imap {
pub fn new() -> Self {
Imap {
@@ -138,7 +157,7 @@ impl Imap {
self.should_reconnect.store(true, Ordering::Relaxed)
}
fn setup_handle_if_needed(&self, context: &Context) -> Result<()> {
fn setup_handle_if_needed(&self, context: &Context) -> Result<(), Error> {
task::block_on(async move {
if self.config.read().await.imap_server.is_empty() {
return Err(Error::ImapInTeardown);
@@ -285,7 +304,7 @@ impl Imap {
}
/// Connects to imap account using already-configured parameters.
pub fn connect_configured(&self, context: &Context) -> Result<()> {
pub fn connect_configured(&self, context: &Context) -> Result<(), Error> {
if async_std::task::block_on(async move {
self.is_connected().await && !self.should_reconnect()
}) {
@@ -299,19 +318,12 @@ impl Imap {
// the trailing underscore is correct
if self.connect(context, &param) {
if context
.sql
.get_raw_config_int(context, "folders_configured")
.unwrap_or_default()
< 3
{
self.configure_folders(context, true);
}
return Ok(());
self.ensure_configured_folders(context, true)
} else {
Err(Error::ImapConnectionFailed(
format!("{}", param).to_string(),
))
}
return Err(Error::ImapConnectionFailed(
format!("{}", param).to_string(),
));
}
/// tries connecting to imap account using the specific login
@@ -396,7 +408,7 @@ impl Imap {
});
}
pub fn fetch(&self, context: &Context, watch_folder: &str) -> Result<()> {
pub fn fetch(&self, context: &Context, watch_folder: &str) -> Result<(), Error> {
task::block_on(async move {
if !context.sql.is_open() {
// probably shutdown
@@ -406,24 +418,24 @@ impl Imap {
.fetch_from_single_folder(context, &watch_folder)
.await?
{
// During the fetch commands new messages may arrive. So we fetch until we do not
// get any more. If IDLE is called directly after, there is only a small chance that
// messages are missed and delayed until the next IDLE call
// We fetch until no more new messages are there.
}
Ok(())
})
}
/// select a folder, possibly update uid_validity and, if needed,
/// expunge the folder to remove delete-marked messages.
async fn select_folder<S: AsRef<str>>(
&self,
context: &Context,
folder: Option<S>,
) -> ImapActionResult {
) -> Result<(), SelectError> {
if self.session.lock().await.is_none() {
let mut cfg = self.config.write().await;
cfg.selected_folder = None;
cfg.selected_folder_needs_expunge = false;
return ImapActionResult::Failed;
return Err(SelectError::NoSession);
}
// if there is a new folder and the new folder is equal to the selected one, there's nothing to do.
@@ -431,7 +443,7 @@ impl Imap {
if let Some(ref folder) = folder {
if let Some(ref selected_folder) = self.config.read().await.selected_folder {
if folder.as_ref() == selected_folder {
return ImapActionResult::AlreadyDone;
return Ok(());
}
}
}
@@ -450,12 +462,11 @@ impl Imap {
info!(context, "close/expunge succeeded");
}
Err(err) => {
warn!(context, "failed to close session: {:?}", err);
return ImapActionResult::Failed;
return Err(SelectError::CloseExpungeFailed(err));
}
}
} else {
return ImapActionResult::Failed;
return Err(SelectError::NoSession);
}
}
self.config.write().await.selected_folder_needs_expunge = false;
@@ -464,31 +475,39 @@ impl Imap {
// select new folder
if let Some(ref folder) = folder {
if let Some(ref mut session) = &mut *self.session.lock().await {
match session.select(folder).await {
let res = session.select(folder).await;
// https://tools.ietf.org/html/rfc3501#section-6.3.1
// says that if the server reports select failure we are in
// authenticated (not-select) state.
match res {
Ok(mailbox) => {
let mut config = self.config.write().await;
config.selected_folder = Some(folder.as_ref().to_string());
config.selected_mailbox = Some(mailbox);
Ok(())
}
Err(async_imap::error::Error::ConnectionLost) => {
self.trigger_reconnect();
self.config.write().await.selected_folder = None;
Err(SelectError::ConnectionLost)
}
Err(async_imap::error::Error::Validate(_)) => {
Err(SelectError::BadFolderName(folder.as_ref().to_string()))
}
Err(err) => {
warn!(
context,
"Cannot select folder: {}; {:?}.",
folder.as_ref(),
err
);
self.config.write().await.selected_folder = None;
self.trigger_reconnect();
return ImapActionResult::Failed;
Err(SelectError::Other(err.to_string()))
}
}
} else {
unreachable!();
Err(SelectError::NoSession)
}
} else {
Ok(())
}
ImapActionResult::Success
}
fn get_config_last_seen_uid<S: AsRef<str>>(&self, context: &Context, folder: S) -> (u32, u32) {
@@ -513,89 +532,95 @@ impl Imap {
}
}
async fn fetch_from_single_folder<S: AsRef<str>>(
/// return Result with (uid_validity, last_seen_uid) tuple.
pub(crate) fn select_with_uidvalidity(
&self,
context: &Context,
folder: S,
) -> Result<bool> {
match self.select_folder(context, Some(&folder)).await {
ImapActionResult::Failed | ImapActionResult::RetryLater => {
bail!("Cannot select folder {:?} for fetching.", folder.as_ref());
folder: &str,
) -> Result<(u32, u32), Error> {
task::block_on(async move {
if let Err(err) = self.select_folder(context, Some(folder)).await {
bail!("could not select folder {:?}: {:?}", folder, err);
}
ImapActionResult::Success | ImapActionResult::AlreadyDone => {}
}
// compare last seen UIDVALIDITY against the current one
let (mut uid_validity, mut last_seen_uid) = self.get_config_last_seen_uid(context, &folder);
// compare last seen UIDVALIDITY against the current one
let (uid_validity, last_seen_uid) = self.get_config_last_seen_uid(context, &folder);
let config = self.config.read().await;
let mailbox = config.selected_mailbox.as_ref().expect("just selected");
let config = self.config.read().await;
let mailbox = config.selected_mailbox.as_ref().expect("just selected");
ensure!(
mailbox.uid_validity.is_some(),
"Cannot get UIDVALIDITY for folder {:?}",
folder.as_ref()
);
let new_uid_validity = match mailbox.uid_validity {
Some(v) => v,
None => bail!("Cannot get UIDVALIDITY for folder {:?}", folder),
};
let new_uid_validity = mailbox.uid_validity.unwrap();
if new_uid_validity != uid_validity {
// First time this folder is selected or UIDVALIDITY has changed.
// Init lastseenuid and save it to config.
info!(
context,
"new_uid_validity={} current local uid_validity={} lastseenuid={}",
new_uid_validity,
uid_validity,
last_seen_uid
);
if new_uid_validity == uid_validity {
return Ok((uid_validity, last_seen_uid));
}
if mailbox.exists == 0 {
info!(context, "Folder \"{}\" is empty.", folder.as_ref());
info!(context, "Folder \"{}\" is empty.", folder);
// set lastseenuid=0 for empty folders.
// id we do not do this here, we'll miss the first message
// as we will get in here again and fetch from lastseenuid+1 then
self.set_config_last_seen_uid(context, &folder, new_uid_validity, 0);
return Ok(false);
return Ok((new_uid_validity, 0));
}
let list = if let Some(ref mut session) = &mut *self.session.lock().await {
// `FETCH <message sequence number> (UID)`
let set = format!("{}", mailbox.exists);
match session.fetch(set, PREFETCH_FLAGS).await {
Ok(list) => list,
Err(err) => {
bail!("fetch failed: {}", err);
// uid_validity has changed or is being set the first time.
// find the last seen uid within the new uid_validity scope.
let new_last_seen_uid = match mailbox.uid_next {
Some(uid_next) => {
uid_next - 1 // XXX could uid_next be 0?
}
None => {
warn!(
context,
"IMAP folder has no uid_next, fall back to fetching"
);
if let Some(ref mut session) = &mut *self.session.lock().await {
// note that we use fetch by sequence number
// and thus we only need to get exactly the
// last-index message.
let set = format!("{}", mailbox.exists);
match session.fetch(set, JUST_UID).await {
Ok(list) => list[0].uid.unwrap_or_default(),
Err(err) => {
bail!("fetch failed: {:?}", err);
}
}
} else {
return Err(Error::ImapNoConnection);
}
}
} else {
return Err(Error::ImapNoConnection);
};
last_seen_uid = list[0].uid.unwrap_or_else(|| 0);
// if the UIDVALIDITY has _changed_, decrease lastseenuid by one to avoid gaps (well add 1 below
if uid_validity > 0 && last_seen_uid > 1 {
last_seen_uid -= 1;
}
uid_validity = new_uid_validity;
self.set_config_last_seen_uid(context, &folder, uid_validity, last_seen_uid);
self.set_config_last_seen_uid(context, &folder, new_uid_validity, new_last_seen_uid);
info!(
context,
"lastseenuid initialized to {} for {}@{}",
last_seen_uid,
folder.as_ref(),
"uid/validity change: new {}/{} current {}/{}",
new_last_seen_uid,
new_uid_validity,
uid_validity,
last_seen_uid
);
}
Ok((new_uid_validity, new_last_seen_uid))
})
}
async fn fetch_from_single_folder<S: AsRef<str>>(
&self,
context: &Context,
folder: S,
) -> Result<bool, Error> {
let (uid_validity, last_seen_uid) =
self.select_with_uidvalidity(context, folder.as_ref())?;
let mut read_cnt = 0;
let mut read_errors = 0;
let mut new_last_seen_uid = 0;
let list = if let Some(ref mut session) = &mut *self.session.lock().await {
let mut list = if let Some(ref mut session) = &mut *self.session.lock().await {
// fetch messages with larger UID than the last one seen
// (`UID FETCH lastseenuid+1:*)`, see RFC 4549
let set = format!("{}:*", last_seen_uid + 1);
@@ -609,44 +634,51 @@ impl Imap {
return Err(Error::ImapNoConnection);
};
// go through all mails in folder (this is typically _fast_ as we already have the whole list)
// prefetch info from all unfetched mails
let mut new_last_seen_uid = last_seen_uid;
let mut read_errors = 0;
list.sort_unstable_by_key(|msg| msg.uid.unwrap_or_default());
for msg in &list {
let cur_uid = msg.uid.unwrap_or_else(|| 0);
if cur_uid > last_seen_uid {
read_cnt += 1;
let cur_uid = msg.uid.unwrap_or_default();
if cur_uid <= last_seen_uid {
warn!(
context,
"wrong uid {}, last seen was {}", cur_uid, last_seen_uid
);
continue;
}
read_cnt += 1;
let message_id = prefetch_get_message_id(msg).unwrap_or_default();
let message_id = prefetch_get_message_id(msg).unwrap_or_default();
if !precheck_imf(context, &message_id, folder.as_ref(), cur_uid) {
// check passed, go fetch the rest
if self.fetch_single_msg(context, &folder, cur_uid).await == 0 {
info!(
context,
"Read error for message {} from \"{}\", trying over later.",
message_id,
folder.as_ref()
);
read_errors += 1;
}
} else {
// check failed
if !precheck_imf(context, &message_id, folder.as_ref(), cur_uid) {
// check passed, go fetch the rest
if self.fetch_single_msg(context, &folder, cur_uid).await == 0 {
info!(
context,
"Skipping message {} from \"{}\" by precheck.",
"Read error for message {} from \"{}\", trying over later.",
message_id,
folder.as_ref(),
folder.as_ref()
);
read_errors += 1;
}
if cur_uid > new_last_seen_uid {
new_last_seen_uid = cur_uid
}
} else {
// we know the message-id already or don't want the message otherwise.
info!(
context,
"Skipping message {} from \"{}\" by precheck.",
message_id,
folder.as_ref(),
);
}
if read_errors == 0 {
new_last_seen_uid = cur_uid;
}
}
if 0 == read_errors && new_last_seen_uid > 0 {
// TODO: it might be better to increase the lastseenuid also on partial errors.
// however, this requires to sort the list before going through it above.
if new_last_seen_uid > last_seen_uid {
self.set_config_last_seen_uid(context, &folder, uid_validity, new_last_seen_uid);
}
@@ -754,7 +786,7 @@ impl Imap {
1
}
pub fn idle(&self, context: &Context, watch_folder: Option<String>) -> Result<()> {
pub fn idle(&self, context: &Context, watch_folder: Option<String>) -> Result<(), Error> {
task::block_on(async move {
if !self.config.read().await.can_idle {
return Err(Error::ImapMissesIdle);
@@ -762,12 +794,11 @@ impl Imap {
self.setup_handle_if_needed(context)?;
match self.select_folder(context, watch_folder.clone()).await {
ImapActionResult::Success | ImapActionResult::AlreadyDone => {}
ImapActionResult::Failed | ImapActionResult::RetryLater => {
return Err(Error::ImapSelectFailed(format!("{:?}", watch_folder)));
}
if let Err(err) = self.select_folder(context, watch_folder.clone()).await {
return Err(Error::ImapSelectFailed(format!(
"{:?}: {:?}",
watch_folder, err
)));
}
let session = self.session.lock().await.take();
@@ -1097,14 +1128,22 @@ impl Imap {
}
}
match self.select_folder(context, Some(&folder)).await {
ImapActionResult::Success | ImapActionResult::AlreadyDone => None,
res => {
warn!(
context,
"Cannot select folder {} for preparing IMAP operation", folder
);
Some(res)
Ok(()) => None,
Err(SelectError::ConnectionLost) => {
warn!(context, "Lost imap connection");
Some(ImapActionResult::RetryLater)
}
Err(SelectError::NoSession) => {
warn!(context, "no imap session");
Some(ImapActionResult::Failed)
}
Err(SelectError::BadFolderName(folder_name)) => {
warn!(context, "invalid folder name: {:?}", folder_name);
Some(ImapActionResult::Failed)
}
Err(err) => {
warn!(context, "failed to select folder: {:?}: {:?}", folder, err);
Some(ImapActionResult::RetryLater)
}
}
})
@@ -1206,19 +1245,35 @@ impl Imap {
})
}
pub fn configure_folders(&self, context: &Context, create_mvbox: bool) {
pub fn ensure_configured_folders(
&self,
context: &Context,
create_mvbox: bool,
) -> Result<(), Error> {
let folders_configured = context
.sql
.get_raw_config_int(context, "folders_configured");
if folders_configured.unwrap_or_default() >= 3 {
// the "3" here we increase if we have future updates to
// to folder configuration
return Ok(());
}
task::block_on(async move {
if !self.is_connected().await {
return;
}
ensure!(
self.is_connected().await,
"cannot configure folders: not connected"
);
info!(context, "Configuring IMAP-folders.");
if let Some(ref mut session) = &mut *self.session.lock().await {
let folders = self
.list_folders(session, context)
.await
.expect("no folders found");
let folders = match self.list_folders(session, context).await {
Some(f) => f,
None => {
bail!("could not obtain list of imap folders");
}
};
let sentbox_folder =
folders
@@ -1249,7 +1304,7 @@ impl Imap {
Err(err) => {
warn!(
context,
"Cannot create MVBOX-folder, using trying INBOX subfolder. ({})",
"Cannot create MVBOX-folder, trying to create INBOX subfolder. ({})",
err
);
@@ -1271,35 +1326,34 @@ impl Imap {
// that may be used by other MUAs to list folders.
// for the LIST command, the folder is always visible.
if let Some(ref mvbox) = mvbox_folder {
// TODO: better error handling
session.subscribe(mvbox).await.expect("failed to subscribe");
if let Err(err) = session.subscribe(mvbox).await {
warn!(context, "could not subscribe to {:?}: {:?}", mvbox, err);
}
}
}
context
.sql
.set_raw_config(context, "configured_inbox_folder", Some("INBOX"))
.ok();
.set_raw_config(context, "configured_inbox_folder", Some("INBOX"))?;
if let Some(ref mvbox_folder) = mvbox_folder {
context
.sql
.set_raw_config(context, "configured_mvbox_folder", Some(mvbox_folder))
.ok();
context.sql.set_raw_config(
context,
"configured_mvbox_folder",
Some(mvbox_folder),
)?;
}
if let Some(ref sentbox_folder) = sentbox_folder {
context
.sql
.set_raw_config(
context,
"configured_sentbox_folder",
Some(sentbox_folder.name()),
)
.ok();
context.sql.set_raw_config(
context,
"configured_sentbox_folder",
Some(sentbox_folder.name()),
)?;
}
context
.sql
.set_raw_config_int(context, "folders_configured", 3)
.ok();
.set_raw_config_int(context, "folders_configured", 3)?;
}
info!(context, "FINISHED configuring IMAP-folders.");
Ok(())
})
}
@@ -1330,33 +1384,35 @@ impl Imap {
info!(context, "emptying folder {}", folder);
if folder.is_empty() {
warn!(context, "cannot perform empty, folder not set");
error!(context, "cannot perform empty, folder not set");
return;
}
match self.select_folder(context, Some(&folder)).await {
ImapActionResult::Success | ImapActionResult::AlreadyDone => {
if !self
.add_flag_finalized_with_set(context, SELECT_ALL, "\\Deleted")
.await
{
warn!(context, "Cannot empty folder {}", folder);
} else {
// we now trigger expunge to actually delete messages
self.config.write().await.selected_folder_needs_expunge = true;
if self.select_folder::<String>(context, None).await
== ImapActionResult::Success
{
emit_event!(context, Event::ImapFolderEmptied(folder.to_string()));
} else {
warn!(
context,
"could not perform expunge on empty-marked folder {}", folder
);
}
}
if let Err(err) = self.select_folder(context, Some(&folder)).await {
// we want to report all error to the user
// (no retry should be attempted)
error!(
context,
"Could not select {} for expunging: {:?}", folder, err
);
return;
}
if !self
.add_flag_finalized_with_set(context, SELECT_ALL, "\\Deleted")
.await
{
error!(context, "Cannot mark messages for deletion {}", folder);
return;
}
// we now trigger expunge to actually delete messages
self.config.write().await.selected_folder_needs_expunge = true;
match self.select_folder::<String>(context, None).await {
Ok(()) => {
emit_event!(context, Event::ImapFolderEmptied(folder.to_string()));
}
ImapActionResult::Failed | ImapActionResult::RetryLater => {
warn!(context, "could not select folder {}", folder);
Err(err) => {
error!(context, "expunge failed {}: {:?}", folder, err);
}
}
});
@@ -1434,7 +1490,7 @@ fn precheck_imf(context: &Context, rfc724_mid: &str, server_folder: &str, server
}
}
fn prefetch_get_message_id(prefetch_msg: &Fetch) -> Result<String> {
fn prefetch_get_message_id(prefetch_msg: &Fetch) -> Result<String, Error> {
ensure!(
prefetch_msg.envelope().is_some(),
"Fetched message has no envelope"

View File

@@ -228,13 +228,10 @@ impl Job {
let imap_inbox = &context.inbox_thread.read().unwrap().imap;
if let Ok(msg) = Message::load_from_db(context, MsgId::new(self.foreign_id)) {
if context
.sql
.get_raw_config_int(context, "folders_configured")
.unwrap_or_default()
< 3
{
imap_inbox.configure_folders(context, true);
if let Err(err) = imap_inbox.ensure_configured_folders(context, true) {
self.try_again_later(TryAgain::StandardDelay, None);
warn!(context, "could not configure folders: {:?}", err);
return;
}
let dest_folder = context
.sql
@@ -355,13 +352,10 @@ impl Job {
return;
}
if 0 != self.param.get_int(Param::AlsoMove).unwrap_or_default() {
if context
.sql
.get_raw_config_int(context, "folders_configured")
.unwrap_or_default()
< 3
{
imap_inbox.configure_folders(context, true);
if let Err(err) = imap_inbox.ensure_configured_folders(context, true) {
self.try_again_later(TryAgain::StandardDelay, None);
warn!(context, "configuring folders failed: {:?}", err);
return;
}
let dest_folder = context
.sql