pulb / mailnag

An extensible mail notification daemon
GNU General Public License v2.0
254 stars 32 forks source link

no email checking after no internet connection is detected (even when internet becomes available) #87

Open kparal opened 9 years ago

kparal commented 9 years ago

Usually, I see the following message from mailnagd to repeat every 10 minutes in system log:

Nov 19 17:23:43 titan mailnagd[7689]: INFO (2014-11-19 17:23:43): Checking 1 email account(s).

However, if I resume my computer, I see this:

Nov 19 18:57:43 titan mailnagd[7689]: INFO (2014-11-19 18:57:43): Checking 1 email account(s).
Nov 19 18:57:43 titan mailnagd[7689]: ERROR (2014-11-19 18:57:43): No internet connection.

Since then, no regular (10-minute) checking occurs. I need to restart mailnag manually. I usually do that by running mailnag configuration dialog and closing it.

Even if there's no internet connection, please don't stop checking email. Of course it would be nice if you listened to NetworkManager and started checking when it announces we're connected. (But checking all the time is better than not checking at all.). Furthermore, it would solve the resume use case - I would expect mailnag to inform me about new emails shortly after resume, not after 10 minutes. But that means it needs to wait for the internet connection to become active.

Thanks.

mailnag-1.0.0-1.fc21.noarch Fedora 20

pulb commented 9 years ago

That really shouldn't happen, at least not with IMAP Idle accounts. Do you use POP3 oder IMAP with Idle disabled?

kparal commented 9 years ago

My account type is Gmail, so I guess IMAP.

kparal commented 9 years ago

Hmm, today it works well after resume:

Nov 20 18:12:53 titan mailnagd[13253]: INFO (2014-11-20 18:12:53): Checking 1 email account(s).
Nov 20 18:12:53 titan mailnagd[13253]: ERROR (2014-11-20 18:12:53): No internet connection.
Nov 20 18:22:53 titan mailnagd[13253]: INFO (2014-11-20 18:22:53): Checking 1 email account(s).
Nov 20 18:32:56 titan mailnagd[13253]: INFO (2014-11-20 18:32:56): Checking 1 email account(s).

So I'm sorry, it must have been a different glitch. The NetworkManager integration would still certainly be nice.

If I see again mailnag stuck on system resume, is there some way to debug it and find out the reason?

pulb commented 9 years ago

Strange, there should also be a message like "Idler thread for account x has been disconnected. Trying to reconnect Idler thread for account x". Can you post your mailnag.cfg?

kparal commented 9 years ago
[spamfilterplugin]
filter_text = newsletter, viagra

[core]
enabled_plugins = dbusplugin, soundplugin
imap_idle_timeout = 10
poll_interval = 10
autostart = 1

[soundplugin]
soundfile = mailnag.ogg

[libnotifyplugin]
notification_mode = 1
max_visible_mails = 10

[script]
script0_file = 
script0_enabled = 0
script1_file = 
script1_enabled = 0

[general]
soundfile = mailnag.ogg
check_interval = 5
sender_format = 1
notification_mode = 0
autostart = 1
playsound = 1

[filter]
filter_enabled = 0
filter_text = newsletter, viagra

[account1]
enabled = 1
name = user.name (Gmail)
user = user.name
server = imap.gmail.com
port = 993
ssl = 1
imap = 1
idle = 0
folder = INBOX,Gar&AOEBfg-,Issues,Upozorn&ARs-n&AO0-,V&AP0-pisy

[userscriptplugin]
script_file = 
pulb commented 9 years ago

Ok, I see. You specified folder names so IMAP Idle is not enabled (not supported). The reconnection issue you got shouldn't happen anyway. Please let me know if it happens again.

kparal commented 9 years ago

OK, thanks.

kparal commented 9 years ago

Another interesting issue:

$ journalctl -ab _COMM=mailnagd
-- Logs begin at Sat 2013-11-30 23:30:44 CET, end at Fri 2014-11-28 12:32:42 CET. --
Nov 27 18:00:23 titan mailnagd[1206]: INFO (2014-11-27 18:00:23): Successfully enabled plugin 'dbusplugin'.
Nov 27 18:00:23 titan mailnagd[1206]: INFO (2014-11-27 18:00:23): Successfully enabled plugin 'soundplugin'.
Nov 27 18:00:23 titan mailnagd[1206]: INFO (2014-11-27 18:00:23): Checking 1 email account(s).
Nov 27 18:20:05 titan mailnagd[1206]: INFO (2014-11-27 18:20:05): Checking 1 email account(s).
Nov 27 18:20:05 titan mailnagd[1206]: ERROR (2014-11-27 18:20:05): No internet connection.
Nov 27 18:30:05 titan mailnagd[1206]: INFO (2014-11-27 18:30:05): Checking 1 email account(s).
Nov 27 18:30:05 titan mailnagd[1206]: ERROR (2014-11-27 18:30:05): No internet connection.
Nov 27 18:40:05 titan mailnagd[1206]: INFO (2014-11-27 18:40:05): Checking 1 email account(s).
Nov 27 18:40:05 titan mailnagd[1206]: ERROR (2014-11-27 18:40:05): No internet connection.
Nov 27 18:50:05 titan mailnagd[1206]: INFO (2014-11-27 18:50:05): Checking 1 email account(s).
Nov 27 18:50:05 titan mailnagd[1206]: ERROR (2014-11-27 18:50:05): No internet connection.
Nov 27 19:00:05 titan mailnagd[1206]: INFO (2014-11-27 19:00:05): Checking 1 email account(s).
Nov 27 19:00:05 titan mailnagd[1206]: ERROR (2014-11-27 19:00:05): No internet connection.
Nov 27 19:10:05 titan mailnagd[1206]: INFO (2014-11-27 19:10:05): Checking 1 email account(s).
Nov 27 19:10:05 titan mailnagd[1206]: ERROR (2014-11-27 19:10:05): No internet connection.
Nov 27 19:20:05 titan mailnagd[1206]: INFO (2014-11-27 19:20:05): Checking 1 email account(s).
Nov 27 19:20:05 titan mailnagd[1206]: ERROR (2014-11-27 19:20:05): No internet connection.
Nov 27 19:30:05 titan mailnagd[1206]: INFO (2014-11-27 19:30:05): Checking 1 email account(s).
Nov 27 19:30:05 titan mailnagd[1206]: ERROR (2014-11-27 19:30:05): No internet connection.
Nov 27 19:40:05 titan mailnagd[1206]: INFO (2014-11-27 19:40:05): Checking 1 email account(s).
Nov 27 19:40:05 titan mailnagd[1206]: ERROR (2014-11-27 19:40:05): No internet connection.
Nov 27 19:50:05 titan mailnagd[1206]: INFO (2014-11-27 19:50:05): Checking 1 email account(s).
Nov 27 19:50:05 titan mailnagd[1206]: ERROR (2014-11-27 19:50:05): No internet connection.
Nov 27 20:00:05 titan mailnagd[1206]: INFO (2014-11-27 20:00:05): Checking 1 email account(s).
Nov 27 20:00:05 titan mailnagd[1206]: ERROR (2014-11-27 20:00:05): No internet connection.
Nov 27 21:41:58 titan mailnagd[1206]: INFO (2014-11-27 21:41:58): Checking 1 email account(s).
Nov 27 21:41:58 titan mailnagd[1206]: ERROR (2014-11-27 21:41:58): No internet connection.
Nov 28 08:56:52 titan mailnagd[1206]: INFO (2014-11-28 08:56:52): Checking 1 email account(s).
Nov 28 08:56:52 titan mailnagd[1206]: ERROR (2014-11-28 08:56:52): No internet connection.
Nov 28 09:06:52 titan mailnagd[1206]: INFO (2014-11-28 09:06:52): Checking 1 email account(s).
Nov 28 09:06:52 titan mailnagd[1206]: ERROR (2014-11-28 09:06:52): No internet connection.
Nov 28 09:16:52 titan mailnagd[1206]: INFO (2014-11-28 09:16:52): Checking 1 email account(s).
Nov 28 09:16:52 titan mailnagd[1206]: ERROR (2014-11-28 09:16:52): No internet connection.
Nov 28 09:26:52 titan mailnagd[1206]: INFO (2014-11-28 09:26:52): Checking 1 email account(s).
Nov 28 09:26:52 titan mailnagd[1206]: ERROR (2014-11-28 09:26:52): No internet connection.
Nov 28 09:36:52 titan mailnagd[1206]: INFO (2014-11-28 09:36:52): Checking 1 email account(s).
Nov 28 09:36:52 titan mailnagd[1206]: ERROR (2014-11-28 09:36:52): No internet connection.
Nov 28 09:46:52 titan mailnagd[1206]: INFO (2014-11-28 09:46:52): Checking 1 email account(s).
Nov 28 09:46:52 titan mailnagd[1206]: ERROR (2014-11-28 09:46:52): No internet connection.
Nov 28 09:56:52 titan mailnagd[1206]: INFO (2014-11-28 09:56:52): Checking 1 email account(s).
Nov 28 09:56:52 titan mailnagd[1206]: ERROR (2014-11-28 09:56:52): No internet connection.
Nov 28 10:06:52 titan mailnagd[1206]: INFO (2014-11-28 10:06:52): Checking 1 email account(s).
Nov 28 10:06:52 titan mailnagd[1206]: ERROR (2014-11-28 10:06:52): No internet connection.
Nov 28 10:16:52 titan mailnagd[1206]: INFO (2014-11-28 10:16:52): Checking 1 email account(s).
Nov 28 10:16:52 titan mailnagd[1206]: ERROR (2014-11-28 10:16:52): No internet connection.
Nov 28 10:26:52 titan mailnagd[1206]: INFO (2014-11-28 10:26:52): Checking 1 email account(s).
Nov 28 10:26:52 titan mailnagd[1206]: ERROR (2014-11-28 10:26:52): No internet connection.
Nov 28 10:36:52 titan mailnagd[1206]: INFO (2014-11-28 10:36:52): Checking 1 email account(s).
Nov 28 10:36:52 titan mailnagd[1206]: ERROR (2014-11-28 10:36:52): No internet connection.
Nov 28 10:46:52 titan mailnagd[1206]: INFO (2014-11-28 10:46:52): Checking 1 email account(s).
Nov 28 10:46:52 titan mailnagd[1206]: ERROR (2014-11-28 10:46:52): No internet connection.
Nov 28 10:56:52 titan mailnagd[1206]: INFO (2014-11-28 10:56:52): Checking 1 email account(s).
Nov 28 10:56:52 titan mailnagd[1206]: ERROR (2014-11-28 10:56:52): No internet connection.
Nov 28 11:06:52 titan mailnagd[1206]: INFO (2014-11-28 11:06:52): Checking 1 email account(s).
Nov 28 11:06:52 titan mailnagd[1206]: ERROR (2014-11-28 11:06:52): No internet connection.
Nov 28 11:16:52 titan mailnagd[1206]: INFO (2014-11-28 11:16:52): Checking 1 email account(s).
Nov 28 11:16:52 titan mailnagd[1206]: ERROR (2014-11-28 11:16:52): No internet connection.
Nov 28 11:26:52 titan mailnagd[1206]: INFO (2014-11-28 11:26:52): Checking 1 email account(s).
Nov 28 11:26:52 titan mailnagd[1206]: ERROR (2014-11-28 11:26:52): No internet connection.
Nov 28 12:11:29 titan mailnagd[1206]: INFO (2014-11-28 12:11:29): Checking 1 email account(s).
Nov 28 12:11:29 titan mailnagd[1206]: ERROR (2014-11-28 12:11:29): No internet connection.
Nov 28 12:21:29 titan mailnagd[1206]: INFO (2014-11-28 12:21:29): Checking 1 email account(s).
Nov 28 12:21:29 titan mailnagd[1206]: ERROR (2014-11-28 12:21:29): No internet connection.
Nov 28 12:31:29 titan mailnagd[1206]: INFO (2014-11-28 12:31:29): Checking 1 email account(s).
Nov 28 12:31:29 titan mailnagd[1206]: ERROR (2014-11-28 12:31:29): No internet connection.

Except for a few cases when mailnagd starts too early after system resume, I can assure you that my internet connection is working and gmail works as well.

After I started mailnag configuration dialog and exited it:

Nov 28 12:37:21 titan mailnagd[1206]: INFO (2014-11-28 12:37:21): Shutting down...
Nov 28 12:37:21 titan mailnagd[1206]: INFO (2014-11-28 12:37:21): Polling thread exited successfully.
Nov 28 12:37:21 titan mailnagd[1206]: INFO (2014-11-28 12:37:21): Plugins disabled successfully.
Nov 28 12:37:24 titan mailnagd[7718]: INFO (2014-11-28 12:37:24): Successfully enabled plugin 'dbusplugin'.
Nov 28 12:37:24 titan mailnagd[7718]: INFO (2014-11-28 12:37:24): Successfully enabled plugin 'soundplugin'.
Nov 28 12:37:24 titan mailnagd[7718]: INFO (2014-11-28 12:37:24): Checking 1 email account(s).

and I received a successful notification.

So, it was somehow stuck.

pulb commented 9 years ago

Ok, I guess the best solution would be to ask networkmanager via dbus for the connection state and fallback to the current solutoin (urllib2) where networkmanager is not available.

pulb commented 9 years ago

Mailnag (master branch) now uses NetworkManager to test connectivity when available and falls back to a ping-test if not. This behaviour can be overriden in the config file. The connectivity_test setting can be one of auto, networkmanager, ping. Please let me know if it works for you.

kparal commented 9 years ago

I guess running mailnagd from the checkout is sufficient? However, how can I run it in the foreground, so that it does not daemonize itself? Also, I don't see any debug messages when NM connectivity changes (I disable and re-enable my wired connection), so I can't say whether mailnag checked the messages again or not.

pulb commented 9 years ago

You can start either mailnagd or mailnag-config directly from the checkout folder (If you run mailnag-config, mailnagd is also autostarted at the next boot from there). If you run mailnagd in a terminal you should see some messages, though there is currently no message indicating connects/reconnects. You can verify if it works by sending a mail to your disconnected account and check if it is fetched after a reconnect. You can also use this local Mailnag branch as a temporary replacement until a new release is available. In fact I only run the current git branch from a local folder.

kparal commented 9 years ago

It has not worked.

$ ./mailnagd 
$ INFO (2014-12-14 13:16:14): Successfully enabled plugin 'dbusplugin'.
INFO (2014-12-14 13:16:14): Successfully enabled plugin 'soundplugin'.
INFO (2014-12-14 13:16:14): Checking 1 email account(s).
$ 
### 13:17 send an email to myself
### 13:17 disconnect and reconnect to wired connection
$ 
$ INFO (2014-12-14 13:26:17): Checking 1 email account(s).

So, it took 10 minutes to find out, not immediately after reconnect.

However, I'm not totally sure it used the checkout libraries instead of system-installed libraries. If you want people to debug and verify issues reliably, you really need to: a) print program version on start, so that people can verify which program version is running. Program version should be defined in Mailnag/__init__.py. b) make mailnagd --help work properly (i.e. quit after using it) c) add mailnagd -f to make mailnagd run in foreground (i.e. not daemonize itself) d) add important debug messages (either by default or when run with --debug), which means: system connection detected, whether you're running the check immediately or delaying it for some reason, whether you have found some new emails and how many.

If we have this, it's going to much easier to find out whether it works, or why not :)

pulb commented 9 years ago

Yes, Mailnag could be a little bit more verbose. Though if you run ./mailnagd in the checkout folder, you can be assured it will not use bits of another (e.g. system) installation. And it's normal that you aren't notified immediately after a disconnect. You don't have IMAP IDLE enabled, so your mail is checked in 10 minute intervals.

The new connectivity code just assures that you'll keep receiving notifications after a disconnect, it does not change the checking behaviour.

kparal commented 9 years ago

Oh, I see. So I guess it worked. Still, it would be nice if a new network connection established would trigger a new email check, regardless of the timeout. That would ensure that I get notified a) after my pc starts and my wifi gets connected (that can take some time) b) after my pc resumes and my ethernet gets connected (that is almost instant, but still, mailnag is faster and I need to wait 10 minutes) c) after I'm disconnected for quite some time and I finally connected to a wifi d) after I log in to a VPN. In all those cases it would be very convenient if I received the new email notification right away.

pulb commented 9 years ago

While it's technically possible to immediately check for mails on a reconnect, I'm reluctant to implement it for the following reasons:

pulb commented 9 years ago

Case a) is covered by the current implementation already btw.

kparal commented 9 years ago

Well... NM is in 99% of Linux desktop installations already. And you could do it just for accounts not covered with IMAP IDLE?

pulb commented 9 years ago

Ok, your goal is obviously to get instant notifications. The problem is you can't have them with polling connections and adding workarounds like polling on connection change don't feel like a proper solution and won't improve the situation as a whole.

So let's try to get IMAP IDLE working for you. Do you really need to specify folders in mailnag-config? Aren't all folders checked automatically if you just leave the folders text entry blank? If not, how about setting up multiple accounts in mailnag-config, each for the same provider but with a different single folder?

kparal commented 9 years ago

Instant would be nice, but it would be sufficient to have them instant at least on system resume, and then polled. Because that's what I need to know immediately after resuming my PC - do I have any new emails? If I can't rely on mailnag to tell me immediately, I need to go and check manually, which is inconvenient.

If I don't specify any imap folders, only INBOX is checked. I'll consider creating several accounts as a workaround, unfortunately it has some maintenance cost.

pulb commented 9 years ago

I'm sorry, I won't change the current behaviour due to the reasons stated above. If the solutions I proposed are not acceptable for you, you could also decrease the polling interval in mailnag.cfg.

tristan-k commented 9 years ago

I'm experiencing the same issue. After I suspended my laptop and wake him up again, mailnag complains about "No internet connection". Even though I'm connected to Wifi again. I need to restart mailnag manually to become it aware of the connection again.

Apr 13 14:55:32 tk-ubuntu INFO (2015-04-13 14:55:32): Checking 1 email account(s).
Apr 13 14:55:32 tk-ubuntu WARNING (2015-04-13 14:55:32): No internet connection.
Apr 13 14:56:39 tk-ubuntu INFO (2015-04-13 14:56:39): Shutting down...
Apr 13 14:56:40 tk-ubuntu INFO (2015-04-13 14:56:40): Polling thread exited successfully.
Apr 13 14:56:40 tk-ubuntu INFO (2015-04-13 14:56:40): Plugins disabled successfully.
Apr 13 14:56:42 tk-ubuntu INFO (2015-04-13 14:56:42): Successfully enabled plugin 'soundplugin'.
Apr 13 14:56:42 tk-ubuntu INFO (2015-04-13 14:56:42): Successfully enabled plugin 'libnotifyplugin'.
Apr 13 14:56:42 tk-ubuntu INFO (2015-04-13 14:56:42): Successfully enabled plugin 'unityplugin'.
Apr 13 14:56:42 tk-ubuntu INFO (2015-04-13 14:56:42): Successfully enabled plugin 'dbusplugin'.
Apr 13 14:56:42 tk-ubuntu INFO (2015-04-13 14:56:42): Checking 5 email account(s)
pulb commented 9 years ago

@tristan-k: What Mailnag version are you using? Do you have IMAP IDLE enabled? Did you specify folder names in mailnag-config? According to the log you posted, Mailnag was shut down ~1 minute after wifi became available again. Depending on your account settings (IMAP IDLE or POP 3) it may take up to 10 minutes to become aware of new mails.