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

New messages don't arrive unless bot is restarted #69

Open
missytake opened this issue Dec 16, 2022 · 1 comment
Open

New messages don't arrive unless bot is restarted #69

missytake opened this issue Dec 16, 2022 · 1 comment
Labels
bug Something isn't working

Comments

@missytake
Copy link
Contributor

  • Mailadm Version: 690d096
  • DC core version: 1.101.0
  • Expected behavior: if there is a new message in the admin group, the bot shows it in the logs and reacts to it.
  • Actual behavior: the message doesn't appear in the logs. After you restart the bot, it shows up.
  • Steps to reproduce the problem:
    • send a bunch of messages to the bot, until they don't appear in the logs anymore.
  • Logs:

before restart:

2022-12-16T13:27:37.141485069Z 0.00 [events-bot] DC_EVENT_INFO data1=0 data2=src/blob.rs:415: Final scaled-down image size: 10759B (256px)
2022-12-16T13:27:37.141489342Z 0.00 [events-bot] DC_EVENT_SELFAVATAR_CHANGED data1=0 data2=0
2022-12-16T13:27:37.141492481Z 0.00 [events-bot] DC_EVENT_INFO data1=0 data2=src/context.rs:380: starting IO
2022-12-16T13:27:37.141495497Z 0.00 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2022-12-16T13:27:37.141498378Z 0.00 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2022-12-16T13:27:37.141501368Z 0.00 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:96: starting inbox loop
2022-12-16T13:27:37.141504330Z 0.00 [events-bot] DC_EVENT_INFO data1=0 data2=src/job.rs:350: loading job
2022-12-16T13:27:37.141507353Z 0.00 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2022-12-16T13:27:37.141510276Z 0.00 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:324: starting smtp loop
2022-12-16T13:27:37.141513277Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/smtp.rs:627: Sending MDNs
2022-12-16T13:27:37.141516175Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:363: smtp fake idle - started
2022-12-16T13:27:37.141519108Z 0.01 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2022-12-16T13:27:37.141521999Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:385: smtp has no messages to retry, waiting for interrupt
2022-12-16T13:27:37.141525093Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/ephemeral.rs:544: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
2022-12-16T13:27:37.141530344Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/location.rs:603: Location loop is waiting for 24h 0m 0s or interrupt
2022-12-16T13:27:37.141533350Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1518: Recently seen loop waiting for 0h 8m 8s or interupt
2022-12-16T13:27:37.141536371Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:517: scheduler is running
2022-12-16T13:27:37.388029732Z 0.25 [events-bot] DC_EVENT_IMAP_CONNECTED data1=0 data2=IMAP-LOGIN as mailadm@example.org
2022-12-16T13:27:37.390264424Z 0.25 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:469: Server ID: Some({"name": "Dovecot"})
2022-12-16T13:27:37.393471620Z 0.26 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:905: 0 mails read from "INBOX".
2022-12-16T13:27:37.393487193Z 0.26 [events-bot] DC_EVENT_INCOMING_MSG_BUNCH data1=0 data2=0
2022-12-16T13:27:37.393491376Z 0.26 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap/scan_folders.rs:28: Starting full folder scan
2022-12-16T13:27:37.439679777Z 0.30 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:766: No new emails in folder DeltaChat
2022-12-16T13:27:37.441466031Z 0.31 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:766: No new emails in folder Junk
2022-12-16T13:27:37.443130628Z 0.31 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:766: No new emails in folder Sent
2022-12-16T13:27:37.444573975Z 0.31 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:766: No new emails in folder Archive
2022-12-16T13:27:37.446051825Z 0.31 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:766: No new emails in folder Trash
2022-12-16T13:27:37.448646582Z 0.31 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:905: 0 mails read from "INBOX".
2022-12-16T13:27:37.448673389Z 0.31 [events-bot] DC_EVENT_INCOMING_MSG_BUNCH data1=0 data2=0
2022-12-16T13:27:37.450103170Z 0.31 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2022-12-16T13:27:37.494212181Z 0.36 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap/idle.rs:58: INBOX: Idle entering wait-on-remote state
2022-12-16T13:35:46.001976689Z 488.87 [events-bot] DC_EVENT_CONTACTS_CHANGED data1=11 data2=0
2022-12-16T13:35:46.002032294Z 488.87 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1518: Recently seen loop waiting for 24h 0m 0s or interupt
2022-12-16T13:37:37.160229959Z nothing to prune

after restart:

2022-12-16T13:39:25.120627878Z [2022-12-16 13:39:25 +0000] [1] [INFO] Handling signal: term                                                                                                                                                  
2022-12-16T13:39:25.120676089Z [2022-12-16 13:39:25 +0000] [11] [INFO] Worker exiting (pid: 11)                                                                                                                                              
2022-12-16T13:39:25.324472054Z [2022-12-16 13:39:25 +0000] [1] [INFO] Shutting down: Master                                                                                                                                                  
2022-12-16T13:39:26.888415161Z [2022-12-16 13:39:26 +0000] [1] [INFO] Starting gunicorn 20.1.0                                                                                                                                               
2022-12-16T13:39:27.280501108Z nothing to prune                                                                                                                                                                                              
2022-12-16T13:39:27.292583971Z [2022-12-16 13:39:27 +0000] [1] [INFO] Listening at: http://0.0.0.0:3691 (1)                                                                                                                                  
2022-12-16T13:39:27.292626222Z [2022-12-16 13:39:27 +0000] [1] [INFO] Using worker: sync                                                                                                                                                     
2022-12-16T13:39:27.292630910Z [2022-12-16 13:39:27 +0000] [14] [INFO] Booting worker with pid: 14                                                                                                                                           
2022-12-16T13:39:27.342920953Z adding plugin <mailadm.bot.AdmBot object at 0x7f8582bb6fd0>                                                                                                                                                   
2022-12-16T13:39:27.342945917Z 0.00 [events-bot] DC_EVENT_INFO data1=0 data2=src/blob.rs:415: Final scaled-down image size: 10759B (256px)                                                                                                   
2022-12-16T13:39:27.342950343Z 0.00 [events-bot] DC_EVENT_SELFAVATAR_CHANGED data1=0 data2=0                                                                                                                                                 
2022-12-16T13:39:27.342953835Z 0.00 [events-bot] DC_EVENT_INFO data1=0 data2=src/context.rs:380: starting IO                                                                                                                                 
2022-12-16T13:39:27.342964152Z 0.00 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0                                                                                                                                               
2022-12-16T13:39:27.342967598Z 0.00 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0                                                                                                                                               
2022-12-16T13:39:27.342971085Z 0.00 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:96: starting inbox loop                                                                                                                        
2022-12-16T13:39:27.342974679Z 0.00 [events-bot] DC_EVENT_INFO data1=0 data2=src/job.rs:350: loading job                                                                                                                                     
2022-12-16T13:39:27.342978025Z 0.01 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0                                                                                                                                               
2022-12-16T13:39:27.342981280Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:324: starting smtp loop                                                                                                                        
2022-12-16T13:39:27.342984780Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/smtp.rs:627: Sending MDNs                                                                                                                                   
2022-12-16T13:39:27.342988070Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:363: smtp fake idle - started                                                                                                                  
2022-12-16T13:39:27.343001303Z 0.01 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0                                                                                                                                               
2022-12-16T13:39:27.343004570Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:385: smtp has no messages to retry, waiting for interrupt                                                                                      
2022-12-16T13:39:27.343012378Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/ephemeral.rs:544: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt                                                                             
2022-12-16T13:39:27.343020140Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/location.rs:603: Location loop is waiting for 24h 0m 0s or interrupt                                                                                        
2022-12-16T13:39:27.343023315Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1518: Recently seen loop waiting for 24h 0m 0s or interupt                                                                                       
2022-12-16T13:39:27.343026388Z 0.01 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:517: scheduler is running                                                                                                                      
2022-12-16T13:39:27.679782063Z 0.34 [events-bot] DC_EVENT_IMAP_CONNECTED data1=0 data2=IMAP-LOGIN as mailadm@example.org                                                                                                                  
2022-12-16T13:39:27.681905915Z 0.34 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:469: Server ID: Some({"name": "Dovecot"})                                                                                                           
2022-12-16T13:39:27.686637579Z 0.35 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:905: 0 mails read from "INBOX".                                                                                                                     
2022-12-16T13:39:27.686667627Z 0.35 [events-bot] DC_EVENT_INCOMING_MSG_BUNCH data1=0 data2=0                                                                                                                                                 
2022-12-16T13:39:27.686672439Z 0.35 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap/scan_folders.rs:28: Starting full folder scan                                                                                                          
2022-12-16T13:39:27.699007652Z 0.36 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0                                                                                                                                               
2022-12-16T13:39:27.724727397Z 0.38 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:99: Receiving message, seen=false...                                                                                                         
2022-12-16T13:39:27.748719017Z 0.41 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:121: received message has Message-Id: Mr.FdTooq06SbD.cI0zzos1S7R@testrun.org                                                                 
2022-12-16T13:39:27.748754010Z 0.41 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1447: creating ad-hoc group prevented from caller                                                                                            
2022-12-16T13:39:27.750246455Z 0.41 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1217: Message has 1 parts and is assigned to chat #Chat#Trash.                                                                               
2022-12-16T13:39:27.750260065Z 0.41 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1547: Recently seen loop is not waiting, event is already due.                                                                                   
2022-12-16T13:39:27.750264066Z 0.41 [events-bot] DC_EVENT_CONTACTS_CHANGED data1=10 data2=0                                                                                                                                                  
2022-12-16T13:39:27.750267332Z 0.41 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1518: Recently seen loop waiting for 24h 0m 0s or interupt                                                                                       
2022-12-16T13:39:27.752868289Z 0.42 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:99: Receiving message, seen=false...                                                                                                         
2022-12-16T13:39:27.752884104Z 0.42 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:121: received message has Message-Id: Mr.UjyIa1TeyUJ.mv6-RHbrl6h@testrun.org                                                                 
2022-12-16T13:39:27.752888086Z 0.42 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1447: creating ad-hoc group prevented from caller                                                                                            
2022-12-16T13:39:27.754645156Z 0.42 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1217: Message has 1 parts and is assigned to chat #Chat#Trash.                                                                               
2022-12-16T13:39:27.754658368Z 0.42 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:99: Receiving message, seen=false...                                                                                                         
2022-12-16T13:39:27.754673448Z 0.42 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1547: Recently seen loop is not waiting, event is already due.                                                                                   
2022-12-16T13:39:27.754677162Z 0.42 [events-bot] DC_EVENT_CONTACTS_CHANGED data1=10 data2=0                                                                                                                                                  
2022-12-16T13:39:27.754677162Z 0.42 [events-bot] DC_EVENT_CONTACTS_CHANGED data1=10 data2=0                                                                                                                                                  
2022-12-16T13:39:27.754680317Z 0.42 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1518: Recently seen loop waiting for 24h 0m 0s or interupt                                                                                       
2022-12-16T13:39:27.757674333Z 0.42 [events-bot] DC_EVENT_INFO data1=0 data2=src/decrypt.rs:46: Detected Autocrypt-mime message                                                                                                              
2022-12-16T13:39:27.768429494Z 0.43 [events-bot] DC_EVENT_WARNING data1=0 data2=src/mimeparser.rs:739: Ignoring nested protected headers                                                                                                     
2022-12-16T13:39:27.768453286Z 0.43 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:121: received message has Message-Id: Gr.6_j3n9_tr34.dsBw-z2aJFb@testrun.org                                                                 
2022-12-16T13:39:27.768457529Z 0.43 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1375: Assigning message to Chat#15 as it's a reply to Gr.6_j3n9_tr34.G2Rfx2Ji_pe@testrun.org                                                 
2022-12-16T13:39:27.768460941Z 0.43 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "asdfg@testrun.org" self=Ok(false)                                                                          
2022-12-16T13:39:27.768464381Z 0.43 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "12345@testrun.org" self=Ok(false)                                                                          
2022-12-16T13:39:27.768467691Z 0.43 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "asdfg@testrun.org" self=Ok(false)                                                                          
2022-12-16T13:39:27.768471380Z 0.43 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "12345@testrun.org" self=Ok(false)                                                                          
2022-12-16T13:39:27.768476790Z 0.43 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1217: Message has 1 parts and is assigned to chat #Chat#15.                                                                                  
2022-12-16T13:39:27.768485603Z 0.43 [events-bot] DC_EVENT_CONTACTS_CHANGED data1=10 data2=0                                                                                                                                                  
2022-12-16T13:39:27.768494150Z 0.43 [events-bot] DC_EVENT_CHAT_MODIFIED data1=15 data2=0                                                                                                                                                     
2022-12-16T13:39:27.768499947Z 0.43 [events-bot] DC_EVENT_INCOMING_MSG data1=15 data2=65
2022-12-16T13:39:27.788476827Z process_incoming message: /list-tokens
2022-12-16T13:39:27.788503548Z /list-tokens seems to be a valid message.
2022-12-16T13:39:27.788507972Z 0.45 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:99: Receiving message, seen=false...
2022-12-16T13:39:27.788513213Z 0.45 [events-bot] DC_EVENT_INFO data1=0 data2=src/decrypt.rs:46: Detected Autocrypt-mime message
2022-12-16T13:39:27.788516474Z 0.45 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1518: Recently seen loop waiting for 0h 0m 7s or interupt
2022-12-16T13:39:27.788519590Z 0.45 [events-bot] DC_EVENT_WARNING data1=0 data2=src/mimeparser.rs:739: Ignoring nested protected headers
2022-12-16T13:39:27.788523429Z 0.45 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:121: received message has Message-Id: Gr.6_j3n9_tr34.esKr8zkU1Qq@testrun.org
2022-12-16T13:39:27.788526599Z 0.45 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1375: Assigning message to Chat#15 as it's a reply to Gr.6_j3n9_tr34.dsBw-z2aJFb@testrun.org
2022-12-16T13:39:27.788541689Z 0.45 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "tmp.zuiop@testrun.org" self=Ok(false)
2022-12-16T13:39:27.788545547Z 0.45 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "12345@testrun.org" self=Ok(false)
2022-12-16T13:39:27.788548684Z 0.45 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "tmp.zuiop@testrun.org" self=Ok(false)
2022-12-16T13:39:27.788551818Z 0.45 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "12345@testrun.org" self=Ok(false)
2022-12-16T13:39:27.788555057Z 0.45 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1217: Message has 1 parts and is assigned to chat #Chat#15.
2022-12-16T13:39:27.788558093Z 0.45 [events-bot] DC_EVENT_INCOMING_MSG data1=15 data2=66
2022-12-16T13:39:27.796464865Z process_incoming message: test
2022-12-16T13:39:27.796488900Z test seems to be a valid message.
2022-12-16T13:39:27.796492912Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:99: Receiving message, seen=false...
2022-12-16T13:39:27.796496171Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/decrypt.rs:46: Detected Autocrypt-mime message
2022-12-16T13:39:27.796499364Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1518: Recently seen loop waiting for 0h 0m 7s or interupt
2022-12-16T13:39:27.796502524Z 0.46 [events-bot] DC_EVENT_WARNING data1=0 data2=src/mimeparser.rs:739: Ignoring nested protected headers
2022-12-16T13:39:27.796506477Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:121: received message has Message-Id: Gr.6_j3n9_tr34.v32nQkE2XnJ@testrun.org
2022-12-16T13:39:27.796509761Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1375: Assigning message to Chat#15 as it's a reply to Gr.6_j3n9_tr34.dsBw-z2aJFb@testrun.org
2022-12-16T13:39:27.796512952Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "tmp.zuiop@testrun.org" self=Ok(false)
2022-12-16T13:39:27.796516265Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "12345@testrun.org" self=Ok(false)
2022-12-16T13:39:27.796519502Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "tmp.zuiop@testrun.org" self=Ok(false)
2022-12-16T13:39:27.799958001Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "12345@testrun.org" self=Ok(false)
2022-12-16T13:39:27.799986462Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1217: Message has 1 parts and is assigned to chat #Chat#15.
2022-12-16T13:39:27.799990708Z 0.46 [events-bot] DC_EVENT_INCOMING_MSG data1=15 data2=67
2022-12-16T13:39:27.799993885Z process_incoming message: test
2022-12-16T13:39:27.799996858Z test seems to be a valid message.
2022-12-16T13:39:27.799999944Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:99: Receiving message, seen=false...
2022-12-16T13:39:27.800016879Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/decrypt.rs:46: Detected Autocrypt-mime message
2022-12-16T13:39:27.800022511Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1518: Recently seen loop waiting for 0h 0m 7s or interupt
2022-12-16T13:39:27.800034125Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/e2ee.rs:66: peerstate for "asdfg@testrun.org" is mutual
2022-12-16T13:39:27.800041538Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/e2ee.rs:66: peerstate for "12345@testrun.org" is mutual
2022-12-16T13:39:27.800047196Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/e2ee.rs:66: peerstate for "tmp.zuiop@testrun.org" is mutual
2022-12-16T13:39:27.800052470Z 0.46 [events-bot] DC_EVENT_MSGS_CHANGED data1=15 data2=68
2022-12-16T13:39:27.800057529Z 0.46 [events-bot] DC_EVENT_WARNING data1=0 data2=src/mimeparser.rs:739: Ignoring nested protected headers
2022-12-16T13:39:27.800061507Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:121: received message has Message-Id: Gr.6_j3n9_tr34.ZwNM2vLD0no@testrun.org
2022-12-16T13:39:27.800070509Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1375: Assigning message to Chat#15 as it's a reply to Gr.6_j3n9_tr34.esKr8zkU1Qq@testrun.org
2022-12-16T13:39:27.800074739Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "tmp.zuiop@testrun.org" self=Ok(false)
2022-12-16T13:39:27.800077917Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "12345@testrun.org" self=Ok(false)
2022-12-16T13:39:27.800081113Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "tmp.zuiop@testrun.org" self=Ok(false)
2022-12-16T13:39:27.800084213Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "12345@testrun.org" self=Ok(false)
2022-12-16T13:39:27.800088386Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/ephemeral.rs:544: Ephemeral loop waiting for deletion in 24h 0m 0s or interrupt
2022-12-16T13:39:27.800091493Z 0.46 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:389: smtp fake idle - interrupted
2022-12-16T13:39:27.806343829Z 0.47 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1217: Message has 1 parts and is assigned to chat #Chat#15.
2022-12-16T13:39:27.821518947Z 0.48 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1518: Recently seen loop waiting for 0h 0m 7s or interupt
2022-12-16T13:39:27.832495205Z 0.49 [events-bot] DC_EVENT_INCOMING_MSG data1=15 data2=69
2022-12-16T13:39:27.832527405Z process_incoming message: test3
2022-12-16T13:39:27.832533853Z test3 seems to be a valid message.
2022-12-16T13:39:27.832539006Z 0.49 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:99: Receiving message, seen=false...
2022-12-16T13:39:27.847916219Z 0.51 [events-bot] DC_EVENT_INFO data1=0 data2=src/decrypt.rs:46: Detected Autocrypt-mime message
2022-12-16T13:39:27.847941291Z 0.51 [events-bot] DC_EVENT_WARNING data1=0 data2=src/mimeparser.rs:739: Ignoring nested protected headers
2022-12-16T13:39:27.847965908Z 0.51 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:121: received message has Message-Id: Gr.6_j3n9_tr34.7hRj6xraqVi@testrun.org
2022-12-16T13:39:27.847970230Z 0.51 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1375: Assigning message to Chat#15 as it's a reply to Gr.6_j3n9_tr34.v32nQkE2XnJ@testrun.org
2022-12-16T13:39:27.847973570Z 0.51 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "tmp.zuiop@testrun.org" self=Ok(false)
2022-12-16T13:39:27.847976888Z 0.51 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "12345@testrun.org" self=Ok(false)
2022-12-16T13:39:27.847980249Z 0.51 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "tmp.zuiop@testrun.org" self=Ok(false)
2022-12-16T13:39:27.847983463Z 0.51 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:2098: check_verified_properties: "12345@testrun.org" self=Ok(false)
2022-12-16T13:39:27.853253759Z 0.52 [events-bot] DC_EVENT_INFO data1=0 data2=src/receive_imf.rs:1217: Message has 1 parts and is assigned to chat #Chat#15.
2022-12-16T13:39:27.862596133Z 0.53 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1518: Recently seen loop waiting for 0h 0m 7s or interupt
2022-12-16T13:39:27.869646393Z 0.53 [events-bot] DC_EVENT_INCOMING_MSG data1=15 data2=70
2022-12-16T13:39:27.874739635Z process_incoming message: test4
2022-12-16T13:39:27.874777272Z test4 seems to be a valid message.
2022-12-16T13:39:27.874784661Z 0.54 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:905: 7 mails read from "DeltaChat".
2022-12-16T13:39:27.874790346Z 0.54 [events-bot] DC_EVENT_INCOMING_MSG_BUNCH data1=0 data2=0
2022-12-16T13:39:27.877462775Z 0.54 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2022-12-16T13:39:27.919641230Z 0.58 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:766: No new emails in folder Junk
2022-12-16T13:39:27.922347880Z 0.59 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:766: No new emails in folder Sent
2022-12-16T13:39:27.923863507Z 0.59 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:766: No new emails in folder Archive
2022-12-16T13:39:27.925515911Z 0.59 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:766: No new emails in folder Trash
2022-12-16T13:39:27.927925045Z 0.59 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:905: 0 mails read from "INBOX".
2022-12-16T13:39:27.927939768Z 0.59 [events-bot] DC_EVENT_INCOMING_MSG_BUNCH data1=0 data2=0
2022-12-16T13:39:27.929391394Z 0.59 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2022-12-16T13:39:27.929409110Z 0.59 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap/idle.rs:40: skip idle, got interrupt InterruptInfo { probe_network: false }
2022-12-16T13:39:27.929416663Z 0.59 [events-bot] DC_EVENT_INFO data1=0 data2=src/job.rs:350: loading job
2022-12-16T13:39:27.933090630Z 0.60 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:1157: Marked messages 135:136 in folder DeltaChat as seen.
2022-12-16T13:39:27.942663968Z 0.61 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap.rs:905: 0 mails read from "INBOX".
2022-12-16T13:39:27.942705238Z 0.61 [events-bot] DC_EVENT_INCOMING_MSG_BUNCH data1=0 data2=0
2022-12-16T13:39:27.943834741Z 0.61 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2022-12-16T13:39:27.944693718Z 0.61 [events-bot] DC_EVENT_INFO data1=0 data2=src/imap/idle.rs:58: INBOX: Idle entering wait-on-remote state
2022-12-16T13:39:28.170616526Z 0.83 [events-bot] DC_EVENT_SMTP_CONNECTED data1=0 data2=SMTP-LOGIN as mailadm@example.org ok
2022-12-16T13:39:28.182402914Z 0.85 [events-bot] DC_EVENT_INFO data1=0 data2=src/smtp.rs:418: Try number 1 to send message Msg#68 over SMTP
2022-12-16T13:39:28.182438246Z 0.85 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2022-12-16T13:39:28.660843940Z 1.31 [events-bot] DC_EVENT_SMTP_MESSAGE_SENT data1=0 data2=Message len=17365 was smtp-sent to asdfg@testrun.org,12345@testrun.org,tmp.zuiop@testrun.org,mailadm@example.org
2022-12-16T13:39:28.717537310Z 1.38 [events-bot] DC_EVENT_MSG_DELIVERED data1=15 data2=68
2022-12-16T13:39:28.717579585Z 1.38 [events-bot] DC_EVENT_INFO data1=0 data2=src/smtp.rs:627: Sending MDNs
2022-12-16T13:39:28.717585518Z 1.38 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:363: smtp fake idle - started
2022-12-16T13:39:28.717589086Z 1.38 [events-bot] DC_EVENT_CONNECTIVITY_CHANGED data1=0 data2=0
2022-12-16T13:39:28.717592442Z 1.38 [events-bot] DC_EVENT_INFO data1=0 data2=src/scheduler.rs:385: smtp has no messages to retry, waiting for interrupt
2022-12-16T13:39:35.002044954Z 7.66 [events-bot] DC_EVENT_CONTACTS_CHANGED data1=10 data2=0
2022-12-16T13:39:35.002095433Z 7.67 [events-bot] DC_EVENT_INFO data1=0 data2=src/contact.rs:1518: Recently seen loop waiting for 0h 8m 45s or interupt
@missytake missytake added the bug Something isn't working label Dec 30, 2022
@missytake
Copy link
Contributor Author

(probably a "lack of resource" issue, as it only appeared on one instance with very little RAM and CPU power.)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@missytake