Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

test_echo_quit_plugin is flaky #4976

Open
link2xt opened this issue Nov 10, 2023 · 0 comments · May be fixed by #5330
Open

test_echo_quit_plugin is flaky #4976

link2xt opened this issue Nov 10, 2023 · 0 comments · May be fixed by #5330
Assignees
@iequidoo

Comments

@link2xt
Copy link
Collaborator

link2xt commented Nov 10, 2023

Here is a failure log:

=================================== FAILURES ===================================
____________________________ test_echo_quit_plugin _____________________________
[gw5] darwin -- Python 3.10.13 /Users/runner/work/deltachat-core-rust/deltachat-core-rust/python/.tox/py/bin/python

acfactory = <deltachat.testplugin.ACFactory object at 0x00007fd613225280>
lp = <deltachat.testplugin.lp.<locals>.Printer object at 0x00007fd6132252b8>

    def test_echo_quit_plugin(acfactory, lp):
        lp.sec("creating one echo_and_quit bot")
        botproc = acfactory.run_bot_process(echo_and_quit)
    
        lp.sec("creating a temp account to contact the bot")
        (ac1,) = acfactory.get_online_accounts(1)
    
        lp.sec("sending a message to the bot")
        bot_contact = ac1.create_contact(botproc.addr)
        bot_chat = bot_contact.create_chat()
        bot_chat.send_text("hello")
    
        lp.sec("waiting for the reply message from the bot to arrive")
>       reply = ac1._evtracker.wait_next_incoming_message()

examples/test_examples.py:33: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
.tox/py/lib/pypy3.10/site-packages/deltachat/events.py:197: in wait_next_incoming_message
    ev = self.get_matching("DC_EVENT_INCOMING_MSG")
.tox/py/lib/pypy3.10/site-packages/deltachat/events.py:119: in get_matching
    for ev in self.iter_events(timeout=timeout, check_error=check_error):
.tox/py/lib/pypy3.10/site-packages/deltachat/events.py:115: in iter_events
    yield self.get(timeout=timeout, check_error=check_error)
.tox/py/lib/pypy3.10/site-packages/deltachat/events.py:108: in get
    ev = self._event_queue.get(timeout=timeout)
../../../../hostedtoolcache/PyPy/3.10.13/x64/lib/pypy3.10/queue.py:171: in get
    self.not_empty.wait()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <Condition(<unlocked _thread.lock object at 0x00007fd6122e9718>, 0)>
timeout = None

    def wait(self, timeout=None):
        """Wait until notified or until a timeout occurs.
    
        If the calling thread has not acquired the lock when this method is
        called, a RuntimeError is raised.
    
        This method releases the underlying lock, and then blocks until it is
        awakened by a notify() or notify_all() call for the same condition
        variable in another thread, or until the optional timeout occurs. Once
        awakened or timed out, it re-acquires the lock and returns.
    
        When the timeout argument is present and not None, it should be a
        floating point number specifying a timeout for the operation in seconds
        (or fractions thereof).
    
        When the underlying lock is an RLock, it is not released using its
        release() method, since this may not actually unlock the lock when it
        was acquired multiple times recursively. Instead, an internal interface
        of the RLock class is used, which really unlocks it even when it has
        been recursively acquired several times. Another internal interface is
        then used to restore the recursion level when the lock is reacquired.
    
        """
        if not self._is_owned():
            raise RuntimeError("cannot wait on un-acquired lock")
        waiter = _allocate_lock()
        waiter.acquire()
        self._waiters.append(waiter)
        saved_state = self._release_save()
        gotit = False
        try:    # restore state no matter what (e.g., KeyboardInterrupt)
            if timeout is None:
>               waiter.acquire()
E               Failed: Timeout >300.0s

../../../../hostedtoolcache/PyPy/3.10.13/x64/lib/pypy3.10/threading.py:320: Failed
----------------------------- Captured stdout call -----------------------------

========== creating one echo_and_quit bot ==========
$ /Users/runner/work/deltachat-core-rust/deltachat-core-rust/python/.tox/py/bin/python -u /Users/runner/work/deltachat-core-rust/deltachat-core-rust/python/examples/echo_and_quit.py --email ci-nr9ud9@*** --password ci-nr9ud9$ci-nr9ud9 --show-ffi /private/var/folders/3s/vfzpb5r51gs6y328rmlgzm7c0000gn/T/pytest-of-runner/pytest-0/popen-gw5/test_echo_quit_plugin0/ac1/dc.db

========== creating a temp account to contact the bot ==========
CACHE HIT for ci-yrwvvr@***
[acsetup] 0.129 added already configured account <Account path=/private/var/folders/3s/vfzpb5r51gs6y328rmlgzm7c0000gn/T/pytest-of-runner/pytest-0/popen-gw5/test_echo_quit_plugin0/ac2/dc.db> ci-yrwvvr@***
bringing accounts online
wait_all_configured finds accounts= {<Account path=/private/var/folders/3s/vfzpb5r51gs6y328rmlgzm7c0000gn/T/pytest-of-runner/pytest-0/popen-gw5/test_echo_quit_plugin0/ac2/dc.db>: 'CONFIGURED'}
/etc/ssl/cert.pem /etc/ssl/certs
bot-stdout:  adding plugin <__main__.EchoPlugin object at 0x00007fa347376d08>
bot-stdout:  0.00 [events] INFO src/sql.rs:292: Opened database "/private/var/folders/3s/vfzpb5r51gs6y328rmlgzm7c0000gn/T/pytest-of-runner/pytest-0/popen-gw5/test_echo_quit_plugin0/ac1/dc.db".
bot-stdout:  0.01 [events] INFO src/configure.rs:110: Configure ...
bot-stdout:  0.02 [events] DC_EVENT_CONFIGURE_PROGRESS data1=1 data2=None
bot-stdout:  0.02 [events] DC_EVENT_CONFIGURE_PROGRESS data1=200 data2=None
bot-stdout:  0.02 [events] INFO src/configure.rs:227: checking internal provider-info for offline autoconfig
bot-stdout:  0.02 [events] INFO src/configure.rs:242: offline autoconfig found
bot-stdout:  0.02 [events] DC_EVENT_CONFIGURE_PROGRESS data1=500 data2=None
bot-stdout:  0.02 [events] DC_EVENT_CONFIGURE_PROGRESS data1=550 data2=None
bot-stdout:  0.02 [events] DC_EVENT_CONFIGURE_PROGRESS data1=600 data2=None
bot-stdout:  0.02 [events] INFO src/configure.rs:593: Trying: imap: ci-nr9ud9@***@***:993 security=Ssl certificate_checks=strict oauth2=false socks5_config=None
bot-stdout:  0.02 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
bot-stdout:  0.02 [events] INFO src/imap.rs:307: Connecting to IMAP server
bot-stdout:  0.02 [events] INFO src/configure.rs:645: Trying: smtp: ci-nr9ud9@***@***:465 security=Ssl certificate_checks=strict oauth2=false socks5_config=None
bot-stdout:  0.03 [events] INFO src/net.rs:71: Resolved ***:465 into 116.202.233.236:465.
bot-stdout:  0.03 [events] INFO src/net.rs:71: Resolved ***:993 into 116.202.233.236:993.
bot-stdout:  0.43 [events] INFO src/imap.rs:376: Logging into IMAP server with LOGIN
bot-stdout:  4.82 [events] DC_EVENT_SMTP_CONNECTED data1=0 data2=SMTP-LOGIN as ci-nr9ud9@*** ok
bot-stdout:  4.82 [events] INFO src/configure.rs:657: success: smtp: ci-nr9ud9@***@***:465 security=Ssl certificate_checks=strict oauth2=false socks5_config=None
6.21 [events-ac2] INFO src/scheduler.rs:64: starting IO
6.21 [events-ac2] INFO src/scheduler.rs:364: starting inbox loop
ac2 waiting for inbox IDLE to become ready
6.21 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
6.21 [events-ac2] INFO src/imap.rs:307: Connecting to IMAP server
6.21 [events-ac2] INFO src/scheduler.rs:690: starting smtp loop
6.21 [events-ac2] INFO src/scheduler.rs:853: scheduler is running
6.21 [events-ac2] INFO src/contact.rs:1739: Recently seen loop waiting for 24h 0m 0s or interrupt
6.21 [events-ac2] INFO src/ephemeral.rs:567: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
6.21 [events-ac2] INFO src/location.rs:676: Location loop is waiting for 24h 0m 0s or interrupt
6.21 [events-ac2] INFO src/net.rs:71: Resolved ***:993 into 116.202.233.236:993.
6.21 [events-ac2] INFO src/smtp.rs:652: Selected rows from SMTP queue: [].
6.21 [events-ac2] INFO src/smtp.rs:757: Sending MDNs
6.21 [events-ac2] INFO src/scheduler.rs:729: smtp fake idle - started
6.21 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
6.21 [events-ac2] INFO src/scheduler.rs:751: smtp has no messages to retry, waiting for interrupt
6.60 [events-ac2] INFO src/imap.rs:376: Logging into IMAP server with LOGIN
6.91 [events-ac2] DC_EVENT_IMAP_CONNECTED data1=0 data2=IMAP-LOGIN as ci-yrwvvr@***
6.91 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
6.91 [events-ac2] INFO src/imap.rs:393: Successfully logged into IMAP server
7.03 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
7.31 [events-ac2] INFO src/imap.rs:894: 0 mails read from "INBOX".
7.31 [events-ac2] INFO src/imap/scan_folders.rs:27: Starting full folder scan
7.69 [events-ac2] INFO src/imap.rs:894: 0 mails read from "DeltaChat".
7.82 [events-ac2] INFO src/imap.rs:712: No new emails in folder "INBOX".
7.95 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
7.95 [events-ac2] DC_EVENT_IMAP_INBOX_IDLE data1=0 data2=None
7.95 [events-ac2] INFO src/scheduler.rs:618: IMAP session supports IDLE, using it.
7.95 [MAIN-ac2] inbox IDLE ready
finished, account2state {<Account path=/private/var/folders/3s/vfzpb5r51gs6y328rmlgzm7c0000gn/T/pytest-of-runner/pytest-0/popen-gw5/test_echo_quit_plugin0/ac2/dc.db>: 'IDLEREADY'}
all accounts online

========== sending a message to the bot ==========
7.95 [events-ac2] INFO src/contact.rs:777: added contact id=10 addr=ci-nr9ud9@***
7.95 [events-ac2] DC_EVENT_CONTACTS_CHANGED data1=10 data2=0
7.95 [events-ac2] DC_EVENT_MSGS_CHANGED data1=0 data2=0
7.96 [events-ac2] INFO src/ephemeral.rs:567: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
7.96 [events-ac2] INFO src/e2ee.rs:79: peerstate for "ci-nr9ud9@***" missing, cannot encrypt
7.96 [events-ac2] DC_EVENT_MSGS_CHANGED data1=12 data2=12

========== waiting for the reply message from the bot to arrive ==========
7.96 [events-ac2] INFO src/scheduler.rs:755: smtp fake idle - interrupted
7.96 [events-ac2] INFO src/smtp.rs:652: Selected rows from SMTP queue: [1].
7.96 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
7.96 [events-ac2] INFO src/net.rs:71: Resolved ***:465 into 116.202.233.236:465.
8.20 [events-ac2] INFO src/imap/idle.rs:87: INBOX: Idle entering wait-on-remote state
8.78 [events-ac2] DC_EVENT_SMTP_CONNECTED data1=0 data2=SMTP-LOGIN as ci-yrwvvr@*** ok
8.78 [events-ac2] INFO src/smtp.rs:565: Try number 1 to send message Msg#12 (entry 1) over SMTP
8.78 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
9.19 [events-ac2] INFO src/smtp/send.rs:70: Message len=2242 was SMTP-sent to ci-nr9ud9@***.
9.19 [events-ac2] DC_EVENT_SMTP_MESSAGE_SENT data1=0 data2=Message len=2242 was SMTP-sent to ci-nr9ud9@***
9.19 [events-ac2] DC_EVENT_MSG_DELIVERED data1=12 data2=12
9.19 [events-ac2] INFO src/smtp.rs:757: Sending MDNs
9.19 [events-ac2] INFO src/scheduler.rs:729: smtp fake idle - started
9.19 [events-ac2] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
9.19 [events-ac2] INFO src/scheduler.rs:751: smtp has no messages to retry, waiting for interrupt
bot-stdout:  8.75 [events] DC_EVENT_IMAP_CONNECTED data1=0 data2=IMAP-LOGIN as ci-nr9ud9@***
bot-stdout:  8.75 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
bot-stdout:  8.75 [events] INFO src/imap.rs:393: Successfully logged into IMAP server
bot-stdout:  8.75 [events] INFO src/configure.rs:617: success: imap: ci-nr9ud9@***@***:993 security=Ssl certificate_checks=strict oauth2=false socks5_config=None
bot-stdout:  8.75 [events] DC_EVENT_CONFIGURE_PROGRESS data1=850 data2=None
bot-stdout:  8.75 [events] DC_EVENT_CONFIGURE_PROGRESS data1=900 data2=None
bot-stdout:  8.88 [events] INFO src/imap.rs:1732: Scanning folder: Name { owner: ResponseData { raw: 4096, response: MailboxData(List { name_attributes: [Extension("\\HasNoChildren")], delimiter: Some("."), name: "DeltaChat" }) }, dependent: InnerName { attributes: [Extension("\\HasNoChildren")], delimiter: Some("."), name: "DeltaChat" } }
bot-stdout:  8.88 [events] INFO src/imap.rs:1732: Scanning folder: Name { owner: ResponseData { raw: 4096, response: MailboxData(List { name_attributes: [Extension("\\HasNoChildren")], delimiter: Some("."), name: "INBOX" }) }, dependent: InnerName { attributes: [Extension("\\HasNoChildren")], delimiter: Some("."), name: "INBOX" } }
bot-stdout:  8.88 [events] INFO src/imap.rs:1756: Using "." as folder-delimiter.
bot-stdout:  8.88 [events] INFO src/imap.rs:1688: Looking for MVBOX-folder "DeltaChat"...
bot-stdout:  9.00 [events] INFO src/imap.rs:1691: MVBOX-folder "DeltaChat" successfully selected, using it.
bot-stdout:  9.13 [events] INFO src/imap.rs:1768: Setting MVBOX FOLDER TO DeltaChat
bot-stdout:  9.13 [events] INFO src/imap.rs:1781: FINISHED configuring IMAP-folders.
bot-stdout:  9.26 [events] INFO src/imap.rs:679: uid/validity change folder INBOX: new 14/1699594993 previous 0/0.
bot-stdout:  9.26 [events] DC_EVENT_CONFIGURE_PROGRESS data1=910 data2=None
bot-stdout:  9.26 [events] DC_EVENT_CONFIGURE_PROGRESS data1=920 data2=None
bot-stdout:  9.26 [events] INFO src/configure.rs:480: key generation completed
bot-stdout:  9.26 [events] DC_EVENT_CONFIGURE_PROGRESS data1=940 data2=None
bot-stdout:  9.26 [events] INFO src/configure.rs:138: skip already set config_defaults mvbox_move=0
bot-stdout:  9.26 [events] DC_EVENT_CONFIGURE_PROGRESS data1=1000 data2=None
bot-stdout:  9.26 [events] INFO src/scheduler.rs:64: starting IO
bot-stdout:  9.26 [events] INFO src/scheduler.rs:364: starting inbox loop
bot-stdout:  9.26 [events] INFO src/scheduler.rs:690: starting smtp loop
bot-stdout:  9.26 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
bot-stdout:  9.26 [events] INFO src/imap.rs:307: Connecting to IMAP server
bot-stdout:  9.26 [events] INFO src/scheduler.rs:853: scheduler is running
bot-stdout:  9.26 [events] INFO src/location.rs:676: Location loop is waiting for 24h 0m 0s or interrupt
bot-stdout:  9.26 [events] INFO src/smtp.rs:652: Selected rows from SMTP queue: [].
bot-stdout:  9.26 [events] INFO src/smtp.rs:757: Sending MDNs
bot-stdout:  9.26 [events] INFO src/scheduler.rs:729: smtp fake idle - started
bot-stdout:  9.26 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
bot-stdout:  9.26 [events] INFO src/scheduler.rs:751: smtp has no messages to retry, waiting for interrupt
bot-stdout:  9.26 [events] INFO src/ephemeral.rs:567: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
bot-stdout:  ci-nr9ud9@***: waiting for message
bot-stdout:  9.27 [events] INFO src/contact.rs:1739: Recently seen loop waiting for 24h 0m 0s or interrupt
bot-stdout:  9.27 [events] INFO src/net.rs:71: Resolved ***:993 into 116.202.233.236:993.
bot-stdout:  9.65 [events] INFO src/imap.rs:376: Logging into IMAP server with LOGIN
bot-stdout:  9.96 [events] DC_EVENT_IMAP_CONNECTED data1=0 data2=IMAP-LOGIN as ci-nr9ud9@***
bot-stdout:  9.96 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
bot-stdout:  9.96 [events] INFO src/imap.rs:393: Successfully logged into IMAP server
bot-stdout:  10.09 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
bot-stdout:  10.09 [events] INFO src/sql.rs:806: Start housekeeping...
bot-stdout:  10.09 [events] INFO src/sql.rs:852: 0 files in use.
bot-stdout:  10.09 [events] INFO src/sql.rs:787: Housekeeping done.
bot-stdout:  10.21 [events] INFO src/imap.rs:712: No new emails in folder "INBOX".
bot-stdout:  10.21 [events] INFO src/imap/scan_folders.rs:27: Starting full folder scan
bot-stdout:  10.47 [events] INFO src/imap.rs:679: uid/validity change folder DeltaChat: new 3/1699594994 previous 0/0.
bot-stdout:  10.47 [events] INFO src/imap.rs:712: No new emails in folder "DeltaChat".
bot-stdout:  10.59 [events] INFO src/imap.rs:712: No new emails in folder "INBOX".
bot-stdout:  10.72 [events] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
bot-stdout:  10.72 [events] DC_EVENT_IMAP_INBOX_IDLE data1=0 data2=None
bot-stdout:  10.72 [events] INFO src/scheduler.rs:618: IMAP session supports IDLE, using it.
bot-stdout:  10.97 [events] INFO src/imap/idle.rs:87: INBOX: Idle entering wait-on-remote state
----------------------------- Captured stderr call -----------------------------

+++++++++++++++++++++++++++++++++++ Timeout ++++++++++++++++++++++++++++++++++++

~~~~~~~~~~~~~~~~~~~~~ Stack of <unknown> (123145348345856) ~~~~~~~~~~~~~~~~~~~~~
  File "/Users/runner/work/deltachat-core-rust/deltachat-core-rust/python/.tox/py/lib/pypy3.10/site-packages/execnet/gateway_base.py", line 361, in _perform_spawn
    reply.run()
  File "/Users/runner/work/deltachat-core-rust/deltachat-core-rust/python/.tox/py/lib/pypy3.10/site-packages/execnet/gateway_base.py", line 296, in run
    self._result = func(*args, **kwargs)
  File "/Users/runner/work/deltachat-core-rust/deltachat-core-rust/python/.tox/py/lib/pypy3.10/site-packages/execnet/gateway_base.py", line 1049, in _thread_receiver
    msg = Message.from_io(io)
  File "/Users/runner/work/deltachat-core-rust/deltachat-core-rust/python/.tox/py/lib/pypy3.10/site-packages/execnet/gateway_base.py", line 507, in from_io
    header = io.read(9)  # type 1, channel 4, payload 4
  File "/Users/runner/work/deltachat-core-rust/deltachat-core-rust/python/.tox/py/lib/pypy3.10/site-packages/execnet/gateway_base.py", line 474, in read
    data = self._read(numbytes - len(buf))

~~~~~~~~~~~~~~~~~~~~~~ Stack of events (123145386692608) ~~~~~~~~~~~~~~~~~~~~~~~
  File "/Users/runner/hostedtoolcache/PyPy/3.10.13/x64/lib/pypy3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()
  File "/Users/runner/hostedtoolcache/PyPy/3.10.13/x64/lib/pypy3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/Users/runner/work/deltachat-core-rust/deltachat-core-rust/python/.tox/py/lib/pypy3.10/site-packages/deltachat/events.py", line 260, in run
    event = lib.dc_get_next_event(event_emitter)

~~~~~~~~~~~~~~~~~ Stack of bot-stdout-thread (123145390899200) ~~~~~~~~~~~~~~~~~
  File "/Users/runner/hostedtoolcache/PyPy/3.10.13/x64/lib/pypy3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()
  File "/Users/runner/hostedtoolcache/PyPy/3.10.13/x64/lib/pypy3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/Users/runner/hostedtoolcache/PyPy/3.10.13/x64/lib/pypy3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/Users/runner/work/deltachat-core-rust/deltachat-core-rust/python/.tox/py/lib/pypy3.10/site-packages/deltachat/testplugin.py", line 663, in _run_stdout_thread
    line = self.popen.stdout.readline()

~~~~~~~~~~~~~~~~~~~~~~ Stack of events (123145440768000) ~~~~~~~~~~~~~~~~~~~~~~~
  File "/Users/runner/hostedtoolcache/PyPy/3.10.13/x64/lib/pypy3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()
  File "/Users/runner/hostedtoolcache/PyPy/3.10.13/x64/lib/pypy3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/Users/runner/work/deltachat-core-rust/deltachat-core-rust/python/.tox/py/lib/pypy3.10/site-packages/deltachat/events.py", line 260, in run
    event = lib.dc_get_next_event(event_emitter)

+++++++++++++++++++++++++++++++++++ Timeout ++++++++++++++++++++++++++++++++++++
============== 1 failed, 178 passed, 1 error in 517.75s (0:08:37) ==============

The problem is that bot ignored the messages from the INBOX and DeltaChat folder as it set UIDVALIDITY/UIDNEXT when the message already arrived:

bot-stdout:  9.26 [events] INFO src/imap.rs:679: uid/validity change folder INBOX: new 14/1699594993 previous 0/0.
...
bot-stdout:  10.47 [events] INFO src/imap.rs:679: uid/validity change folder DeltaChat: new 3/1699594994 previous 0/0.
bot-stdout:  10.47 [events] INFO src/imap.rs:712: No new emails in folder "DeltaChat".
bot-stdout:  10.59 [events] INFO src/imap.rs:712: No new emails in folder "INBOX".

Normally for accounts we wait for IDLE acc._evtracker.wait_idle_inbox_ready() (should actually also wait for DeltaChat folder to go IDLE) as this means we have UIDNEXT set and will receive messages that arrive afterwards. But for the bot it is not done.
@iequidoo iequidoo self-assigned this Mar 9, 2024
iequidoo added a commit that referenced this issue Mar 9, 2024
@iequidoo
test: Set fetch_existing_msgs for bots (#4976)
bf031a3 
A bot process is run asynchronously, so some messages can arrive before the bot is fully
initialised.
@iequidoo iequidoo linked a pull request Mar 9, 2024 that will close this issue
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@iequidoo iequidoo

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

test: Set fetch_existing_msgs for bots (#4976) deltachat/deltachat-core-rust
2 participants
@link2xt @iequidoo