lieser / dkim_verifier

DKIM Verifier Extension for Mozilla Thunderbird
MIT License
210 stars 35 forks source link

Verification on unsigned e-mails from domains in "Default signers rules" doesn't complete / DNS problems #20

Closed Joey3000 closed 10 years ago

Joey3000 commented 10 years ago

This refers to the functionality introduced on #15.

I just checked the latest release "dkim_verifier-1.0.2.xpi" (with TB (Icedove) 17.0.8 on Debian) and there seems to be an issue after the latest changes: On unsigned (old) e-mails of domains which are in the "Default signers rules" the validation does not complete. Instead of a missing signature error/warning there is "DKIM: Validating..." shown in the status bar (which I use instead of the header line), which never completes. And the Error Console shows following:

2013-12-11 22:42:27 DKIM_Verifier.Policy    DEBUG   shouldBeSigned: true; sdid: yahoo.com; hideFail: false; foundRule: true

The JavaScript DNS library is used. This is not domain dependent - it appears on all domains as far as I can see.

P.S.: It might be relevant: Due to change of my location, I had to switch to Google DNS resolver, as the local one does not support DKIM records apparently. So, maybe this issue is not due to latest code changes, but appeared due to my resolver change.

lieser commented 10 years ago

Thanks for reporting. Should be fixed in version 1.0.3, which can be downloaded from https://github.com/lieser/dkim_verifier/releases.

Joey3000 commented 10 years ago

The issue described above has been fixed, thanks.

There is another issue now though (dkim_verifier-1.0.3.xpi): The validation doesn't complete (i.e. "DKIM: Validating..." is shown in the status bar) on all signed e-mails (if body hash is correct), no matter if from domains in the "Default signers rules" of not.

Following debugging output is shown thereby (latest first):

2013-12-12 14:31:37 DKIM_Verifier.JSDNS INFO    Resolving s1024._domainkey.yahoo.com TXT by querying 8.8.8.8
2013-12-12 14:31:37 DKIM_Verifier.Verifier  DEBUG   computed body hash: [removed]
2013-12-12 14:31:37 DKIM_Verifier.Verifier  DEBUG   Parsed DKIM-Signature: ({v:"1", a_sig:"rsa", a_hash:"sha256", b:"[removed]", b_folded:"[removed]", bh:"[removed]", c_header:"relaxed", c_body:"relaxed", d:"yahoo.com", h:"X-YMail-OSG:Received:X-Rocket-MIMEInfo:X-Mailer:References:Message-ID:Date:From:Reply-To:Subject:To:In-Reply-To:MIME-Version:Content-Type", h_array:["x-ymail-osg", "received", "x-rocket-mimeinfo", "x-mailer", "references", "message-id", "date", "from", "reply-to", "subject", "to", "in-reply-to", "mime-version", "content-type"], i:"@yahoo.com", i_domain:"yahoo.com", l:null, q:"dns/txt", s:"s1024", t:[removed], x:null, z:null})
2013-12-12 14:31:37 DKIM_Verifier.Policy    DEBUG   shouldBeSigned: true; sdid: yahoo.com; hideFail: false; foundRule: true

Then, after closing Icedove which had been started from a terminal, I get following debugging output into the terminal (please note that my DNS resolver config on this test is "8.8.8.8;8.8.4.4", with the local (OS) resolver disabled):

2013-12-12 14:56:04 DKIM_Verifier.JSDNS DEBUG   Resolving s1024._domainkey.yahoo.com/TXT: Failed to connect to DNS server 8.8.8.8 with error code 2147500036.
2013-12-12 14:56:04 DKIM_Verifier.JSDNS INFO    Resolving s1024._domainkey.yahoo.com TXT by querying 8.8.4.4
2013-12-12 14:56:04 DKIM_Verifier.JSDNS FATAL   [Exception... "Component returned failure code: 0xc1f30001 (NS_ERROR_NOT_INITIALIZED) [nsISocketTransport.openOutputStream]"  nsresult: "0xc1f30001 (NS_ERROR_NOT_INITIALIZED)"  location: "JS frame :: resource://dkim_verifier/JSDNS.jsm :: DNS_readAllFromSocket :: line 902"  data: no]
undefined
lieser commented 10 years ago

Thanks again for reporting. Could not reproduce it with Thunderbird 24.2.0 or 17.0.11 and add-on version 1.0.3 so I will need a little more Information.

First, the Error for connecting to 8.8.8.8 and 8.8.4.4 are different. Both errors are looking a little odd. Did you try it again after a restart of Thunderbird? And the debug output in the terminal should also have appeared in the Error Console. Also you sad you tried it with different e-mail, but the error log only seems to be from one e-mail. I suspect the error for the connection to 8.8.4.4 is repeating itself, but it would be nice to confirm this.

for 8.8.8.8: the network connection fails with NS_ERROR_ABORT. I have no clue why. Also there seems to be 25 seconds between the connection attempt and the error. If you didn't change the connection timeout in the options it should have failed after 10 seconds with NS_ERROR_NET_TIMEOUT.

for 8.8.4.4: It seems the opening of the outward connection to the server fails. The part there the error seems to occur didn't change since version 0.5.1. Could you try it with an older version, for example 0.6.3 (or something before it)? This error crashes the DNS lookup, and is the reason why the validation never finishes.

An explanation would be that something went internally wrong in Thunderbird's network module on the thirst connection to 8.8.8.8, so that all future attempts to open a connection are failing.

Joey3000 commented 10 years ago

Thanks for the quick reply. I'm going to insert the answers into your reply:

Thanks again for reporting. Could not reproduce it with Thunderbird 24.2.0 or 17.0.11 and add-on version 1.0.3 so I will need a little more Information.

First, the Error for connecting to 8.8.8.8 and 8.8.4.4 are different. Both errors are looking a little odd. Did you try it again after a restart of Thunderbird?

Yes, I did. It made no difference.

And the debug output in the terminal should also have appeared in the Error Console.

For some reason, some debug output - specifically on non-completed verification - did not appear in the Error Console, but was output into the terminal window after closing of TB.

Also you sad you tried it with different e-mail, but the error log only seems to be from one e-mail. I suspect the error for the connection to 8.8.4.4 is repeating itself, but it would be nice to confirm this.

That's right. I tried different e-mails from different domains, with same results. I just included only one example, from one e-mail.

for 8.8.8.8: the network connection fails with NS_ERROR_ABORT. I have no clue why. Also there seems to be 25 seconds between the connection attempt and the error. If you didn't change the connection timeout in the options it should have failed after 10 seconds with NS_ERROR_NET_TIMEOUT.

I didn't change the default 10-seconds timeout. There seems to be an issue with the timeout configuration being ignored - please see my new report below.

for 8.8.4.4: It seems the opening of the outward connection to the server fails. The part there the error seems to occur didn't change since version 0.5.1. Could you try it with an older version, for example 0.6.3 (or something before it)? This error crashes the DNS lookup, and is the reason why the validation never finishes.

An explanation would be that something went internally wrong in Thunderbird's network module on the thirst connection to 8.8.8.8, so that all future attempts to open a connection are failing.

Here comes the new test:

I checked with previous releases 1.0.2, 0.6.3 and 0.6.0 and the issue seems to be nothing new in the latest release 1.0.3, but I guess are related to some sort of network latencies where I currently am. The validation sometimes completes (verified), sometimes it doesn't. I should have tried the previous versions before posting another issue.

But the real issue seams to be the fact that the "DNS connect timeout" is ignored, on all tested releases: 0.6.0, 0.6.3, 1.0.2 and 1.0.3.

Here is an example when validation first completes (step 2) and then doesn't (step 4), with release 1.0.3 (please note that the verification failure is not necessarily reproducible in that order, this is just an example of one occurrance - it may fail several times then succeed, or succeed several times then fail):

Non-default configuration used: General:

Display:

Advanced:

Test steps:

1) Restart TB (close and restart in terminal) 2) Click on a signed e-mail (for it to be opened in the below preview pane) 3) Check Error Console 4) Open the Preferences window of the DKIM_verifier add-on, go to the DNS tab to verify timiout of 1s and close the window 5) Check Error Console 6) Close TB 7) Check Terminal output

Results:

2) Verification completed successfully (OK)

3) (Latest first - horizontal lines added for clarity, to separate output parts where not by DKIM_verifier):

2013-12-12 21:34:19    DKIM_Verifier.Verifier    DEBUG    Header hash input:
date:Tue, 10 Dec 2013 08:27:05 -0800
to:[Removed]
from:[Removed]@facebookmail.com>
subject:[Removed]
mime-version:1.0
content-type:multipart/alternative; boundary="[Removed]"
dkim-signature:v=1; a=rsa-sha256; c=relaxed/simple; d=facebookmail.com; s=s1024-2013-q3; t=[Removed]; bh=[Removed]; h=Date:To:From:Subject:MIME-Version:Content-Type; b=
2013-12-12 21:34:19    DKIM_Verifier.Verifier    DEBUG    Parsed DKIM-Key: ({v:"DKIM1", h:"sha256", h_array:["sha256"], k:"rsa", n:null, p:"MIGfMA0GCSqGSIb3DQEBAQUAA4GNADCBiQKBgQDAUemE56fSDRo+H9Cu8u0uEIOXKON0YbB5A10wuWvNc7bUFIjL0tiUIzhktZjhAXc5CWw2/TZnTZaLZtmtJ2MRfd2e+ty7LylkRAiZUWaT3dcDGVVibWn27DIz3+oCnbL7CFiLzxCZnxHx8B7BC/UM7UCCJMrAgaJWJR6tYwz0MwIDAQAB", s:"*", t:"s", t_array:["s"]})
2013-12-12 21:34:19    DKIM_Verifier.JSDNS    DEBUG    s1024-2013-q3._domainkey.facebookmail.com/TXT: Answer: k=rsa; t=s; h=sha256; p=MIGfMA0GCSqGSIb3DQEBAQUAA4GNADCBiQKBgQDAUemE56fSDRo+H9Cu8u0uEIOXKON0YbB5A10wuWvNc7bUFIjL0tiUIzhktZjhAXc5CWw2/TZnTZaLZtmtJ2MRfd2e+ty7LylkRAiZUWaT3dcDGVVibWn27DIz3+oCnbL7CFiLzxCZnxHx8B7BC/UM7UCCJMrAgaJWJR6tYwz0MwIDAQAB
2013-12-12 21:33:58    DKIM_Verifier.JSDNS    INFO    Resolving s1024-2013-q3._domainkey.facebookmail.com TXT by querying 8.8.8.8
2013-12-12 21:33:58    DKIM_Verifier.JSDNS    CONFIG    changed DNS Servers to : [{server:"8.8.8.8", alive:true}]
2013-12-12 21:33:58    DKIM_Verifier.JSDNS    CONFIG    changed DNS Servers to : [{server:"8.8.8.8", alive:true}]
2013-12-12 21:33:58    DKIM_Verifier.Verifier    DEBUG    computed body hash: [Removed]
2013-12-12 21:33:58    DKIM_Verifier.Verifier    DEBUG    Parsed DKIM-Signature: ({v:"1", a_sig:"rsa", a_hash:"sha256", b:"[Removed]", b_folded:"[Removed]", bh:"[Removed]", c_header:"relaxed", c_body:"simple", d:"facebookmail.com", h:"Date:To:From:Subject:MIME-Version:Content-Type", h_array:["date", "to", "from", "subject", "mime-version", "content-type"], i:"@facebookmail.com", i_domain:"facebookmail.com", l:null, q:"dns/txt", s:"s1024-2013-q3", t:[Removed], x:null, z:null})
------------
Timestamp: 12/12/2013 09:33:17 PM
Error: formatURLPref: Couldn't get pref: app.releaseNotesURL
Source File: resource:///components/nsURLFormatter.js
Line: 148
------------
Not setting growth increment on blist.sqlite because the available disk space is limited
------------
Timestamp: 12/12/2013 09:33:15 PM
Warning: Use of Mutation Events is deprecated. Use MutationObserver instead.
Source File: chrome://messenger/content/msgMail3PaneWindow.js
Line: 944
------------
2013-12-12 21:33:13    DKIM_Verifier.DKIM_Verifier.Logging    DEBUG    initialized

4) Re-verification of the same e-mail is triggered and doesn't complete (not OK)

5) New output (latest first):

2013-12-12 21:47:36    DKIM_Verifier.JSDNS    INFO    Resolving s1024-2013-q3._domainkey.facebookmail.com TXT by querying 8.8.8.8
2013-12-12 21:47:36    DKIM_Verifier.Verifier    DEBUG    computed body hash: [Removed]
2013-12-12 21:47:36    DKIM_Verifier.Verifier    DEBUG    Parsed DKIM-Signature: ({v:"1", a_sig:"rsa", a_hash:"sha256", b:"[Removed]", b_folded:"[Removed]", bh:"[Removed]", c_header:"relaxed", c_body:"simple", d:"facebookmail.com", h:"Date:To:From:Subject:MIME-Version:Content-Type", h_array:["date", "to", "from", "subject", "mime-version", "content-type"], i:"@facebookmail.com", i_domain:"facebookmail.com", l:null, q:"dns/txt", s:"s1024-2013-q3", t:[Removed], x:null, z:null})

6) Terminal output after closure (latest last):

2013-12-12 21:53:55    DKIM_Verifier.JSDNS    DEBUG    Resolving s1024-2013-q3._domainkey.facebookmail.com/TXT: Failed to connect to DNS server 8.8.8.8 with error code 2147500036.
2013-12-12 21:53:55    DKIM_Verifier.JSDNS    DEBUG    no DNS Server alive
2013-12-12 21:53:55    DKIM_Verifier.Verifier    FATAL    handleExeption: TypeError: headerBox.emailAddresses is undefined

But then, after playing around (or just waiting) a while, the 1-second timeout seems to kick in and (or for whatever other reason) I get an instant "DNS server error" (or so) shown in the status bar on e-mail check, and following Error Console output (latest first):

Timestamp: 12/12/2013 10:20:17 PM
Error: 2013-12-12 22:20:17    DKIM_Verifier.Verifier    ERROR    DKIM_DNSERROR_SERVER_ERROR: no DNS Server alive JS Stack trace: @dkimKey.jsm:311 < effort@core.js:53 < resolveDeferred@core.js:125 < then@core.js:34 < then@core.js:138 < getKeyFromDNS@dkimKey.jsm:301 < @dkimKey.jsm:168 < Key_getKey@dkimKey.jsm:160 < @dkimVerifier.jsm:1101 < verifySignaturePart1@dkimVerifier.jsm:1043 < @dkimVerifier.jsm:1030 < effort@core.js:53 < resolveDeferred@core.js:125 < then@core.js:34 < then@core.js:138 < verifyBegin@dkimVerifier.jsm:993 < @dkimVerifier.jsm:273

Source File: resource://dkim_verifier/mozilla/log4moz.js
Line: 410
----------
2013-12-12 22:20:17    DKIM_Verifier.JSDNS    DEBUG    no DNS Server alive
2013-12-12 22:20:17    DKIM_Verifier.Verifier    DEBUG    computed body hash: [Removed]
2013-12-12 22:20:16    DKIM_Verifier.Verifier    DEBUG    Parsed DKIM-Signature: ({v:"1", a_sig:"rsa", a_hash:"sha256", b:"[Removed]", b_folded:"[Removed]", bh:"[Removed]", c_header:"relaxed", c_body:"relaxed", d:"yahoo.com", h:"X-YMail-OSG:Received:X-Rocket-MIMEInfo:X-Mailer:References:Message-ID:Date:From:Reply-To:Subject:To:In-Reply-To:MIME-Version:Content-Type", h_array:["x-ymail-osg", "received", "x-rocket-mimeinfo", "x-mailer", "references", "message-id", "date", "from", "reply-to", "subject", "to", "in-reply-to", "mime-version", "content-type"], i:"@yahoo.com", i_domain:"yahoo.com", l:null, q:"dns/txt", s:"s1024", t:[Removed], x:null, z:null})

Another test:

Then (yes, I had time :) ) I upgraded to TB (Icedove) 17.0.10 and (after some completed verifications) got an uncompleted verification ("DKIM: Validating..." stays in the status bar) with following Error Console output, with same add-on configuration as before, in case this helps (latest first):

Timestamp: 12/12/2013 11:25:12 PM
Error: DNS_STRINGS.getFormattedString is not a function
Source File: resource://dkim_verifier/JSDNS.jsm
Line: 623
-----------
2013-12-12 23:25:12    DKIM_Verifier.JSDNS    DEBUG    Resolving s1024-2013-q3._domainkey.facebookmail.com/TXT: Response was incomplete.
2013-12-12 23:25:10    DKIM_Verifier.JSDNS    INFO    Resolving s1024-2013-q3._domainkey.facebookmail.com TXT by querying 8.8.8.8
2013-12-12 23:25:10    DKIM_Verifier.Verifier    DEBUG    computed body hash: [Removed]
2013-12-12 23:25:10    DKIM_Verifier.Verifier    DEBUG    Parsed DKIM-Signature: ({v:"1", a_sig:"rsa", a_hash:"sha256", b:"[Removed]", b_folded:"[Removed]", bh:"[Removed]", c_header:"relaxed", c_body:"simple", d:"facebookmail.com", h:"Date:To:From:Subject:MIME-Version:Content-Type", h_array:["date", "to", "from", "subject", "mime-version", "content-type"], i:"@facebookmail.com", i_domain:"facebookmail.com", l:null, q:"dns/txt", s:"s1024-2013-q3", t:[Removed], x:null, z:null})

And once the 1-second connection timeout seems to kick in after some playing around, or whatever other reason resulting in "DNS server error" (or so) instantly being shown in the status bar on e-mail check (latest first):

Timestamp: 12/12/2013 11:34:56 PM
Error: 2013-12-12 23:34:56    DKIM_Verifier.Verifier    ERROR    DKIM_DNSERROR_SERVER_ERROR: no DNS Server alive JS Stack trace: promise<@dkimKey.jsm:311 < effort@core.js:53 < resolveDeferred@core.js:125 < then@core.js:34 < resolve@core.js:167 < dnsCallback@DNSWrapper.jsm:131 < queryDNSRecursive@JSDNS.jsm:530 < listener.finished@JSDNS.jsm:615 < dataListener.onStopRequest@JSDNS.jsm:915

Source File: resource://dkim_verifier/mozilla/log4moz.js
Line: 410
------------
2013-12-12 23:34:56    DKIM_Verifier.JSDNS    DEBUG    no DNS Server alive
2013-12-12 23:34:56    DKIM_Verifier.JSDNS    DEBUG    Resolving s1024-2013-q3._domainkey.facebookmail.com/TXT: DNS server 8.8.8.8 timed out on a TCP connection (NS_ERROR_NET_TIMEOUT).
2013-12-12 23:34:55    DKIM_Verifier.JSDNS    INFO    Resolving s1024-2013-q3._domainkey.facebookmail.com TXT by querying 8.8.8.8
2013-12-12 23:34:55    DKIM_Verifier.Verifier    DEBUG    computed body hash: [Removed]
2013-12-12 23:34:55    DKIM_Verifier.Verifier    DEBUG    Parsed DKIM-Signature: ({v:"1", a_sig:"rsa", a_hash:"sha256", b:"[Removed]", b_folded:"[Removed]", bh:"[Removed]", c_header:"relaxed", c_body:"simple", d:"facebookmail.com", h:"Date:To:From:Subject:MIME-Version:Content-Type", h_array:["date", "to", "from", "subject", "mime-version", "content-type"], i:"@facebookmail.com", i_domain:"facebookmail.com", l:null, q:"dns/txt", s:"s1024-2013-q3", t:[Removed], x:null, z:null})

Sorry that this got a bit too long. Please let me know if you need any additional info.

lieser commented 10 years ago

Thanks for the detailed response. As a workaround for now I recommend to enable the storing of the DKIM keys (without comparing to the current one), so fewer DNS lookups are needed who could possible fail. Except for testing of course.


You are right, it seems the timeout is ignored sometimes.

To see if the setting of the timeout causes problems, could you please try again with add-on version 0.4.4 (or before)? In this version no timeout is set by the add-on, so the default is used (If I remember correctly it was for me something like 20 seconds). Note that in this version you can only have one DNS server set, like you have at the moment.

It would also help if you could test it with a clean profile, to exclude it having to do something with Thunderbird options differing form the default.

I think I now the reason for the error only showing in the terminal (Failed to connect to DNS server 8.8.8.8 with error code 2147500036 (NS_ERROR_ABORT)) The connection is still open and is forcefully closed if Thunderbird is closed.

Before the instant "DNS server error", there should be a debug output of the error marking the DNS server as being down (more bellow at DNS error no DNS Server alive).


DNS error Response was incomplete.

As it seems to not always happen, even for the same DKIM key, its probably the result of a bad network connection.

The reason why validation does not finish is the error happening after that, DNS_STRINGS.getFormattedString is not a function. This crashes the DNS lookup. Will try to fix this, so the validation finishes with "Error connecting to DNS server".


DNS error no DNS Server alive

If an error (like the timeout) happens connecting to a DNS server, the server is marked as being down and is not tried again. Because in your case no other server is set, all future DNS query's are failing instantly with no DNS Server alive. This will be reset if Thunderbird is restarted or the DNS servers are changed in the option.

Joey3000 commented 10 years ago

Thank you very much for your analysis.

I ran the test with TB (Icedove) 17.0.10, with a new profile and add-on v0.4.4 (preferenche changes: activated highlighting and the debugging output). Apparently, my assumed network latency has decreased slightly, so that there were fewer failures (which were harder to reproduce) and more completed verifications (also on add-on v1.0.3 below). Here are the results with v0.4.4:

I) When an instant failure with "Response was incomplete" occurs (after some successful verifications, latest first):

Timestamp: 12/13/2013 10:45:55 PM
Error: DKIM Signature Error: DNS query for key failed
that.dnsCallback@chrome://dkim_verifier/content/dkim.js:1318
listener.finished@chrome://dkim_verifier/content/dns.js:289
dataListener.onStopRequest@chrome://dkim_verifier/content/dns.js:534

Source File: chrome://dkim_verifier/content/dkim.js
Line: 906
------------
DNS: Resolving s1024-2013-q3._domainkey.facebookmail.com/TXT: Response was incomplete.
DNS: Resolving s1024-2013-q3._domainkey.facebookmail.com TXT by querying 8.8.8.8
DKIM: computed body hash: [Removed]
DKIM: Parsed DKIM-Signature: ({v:"1", a_sig:"rsa", a_hash:"sha256", b:"[Removed]", b_folded:"[Removed]", bh:"[Removed]", c_header:"relaxed", c_body:"simple", d:"facebookmail.com", h:"Date:To:From:Subject:MIME-Version:Content-Type", h_array:["date", "to", "from", "subject", "mime-version", "content-type"], i:"@facebookmail.com", l:null, q:"dns/txt", s:"s1024-2013-q3", t:[Removed], x:null, z:null})

I guess that is all fine.

II) And an example of a verification not completing ("Validating..." stays in the DKIM header after waiting for more than three minutes) on same add-on version (after many completed; latest first):

DNS: Resolving 20120113._domainkey.gmail.com TXT by querying 8.8.8.8
DKIM: computed body hash: [Removed]
DKIM: Parsed DKIM-Signature: ({v:"1", a_sig:"rsa", a_hash:"sha256", b:"[Removed]", b_folded:"[Removed]", bh:"[Removed]", c_header:"relaxed", c_body:"relaxed", d:"gmail.com", h:"mime-version:in-reply-to:references:date:message-id:subject:from:to:content-type", h_array:["mime-version", "in-reply-to", "references", "date", "message-id", "subject", "from", "to", "content-type"], i:"@gmail.com", l:null, q:"dns/txt", s:"20120113", t:null, x:null, z:null})

Terminal output: None whatsoever - neither with Icedove open, nor after closing.

To summarize:

With v1.0.3 on TB (Icedove) 17.0.10, there seem to be following possible issues, same as in my previous post (same add-on preferences configuration): a) Error: DNS_STRINGS.getFormattedString is not a function causing incomplete verification as in the "Another test" in my previous post. I guess you have just fixed this in v1.0.4pre1.

b) The timeout time configuration is ignored when verification completes successfully, but takes a long time (e.g. 20s, i.e. much longer than the configured timeout) - as in the result 2) in my previous post. I guess this is of minor importance if it's an independent issue, or an issue at all. Because "Validating..." shows that one needs to wait.

c) The timeout time configuration is ignored on incomplete verification (waited ca. 3.5min) - as in the result 5) in my previous post. Also: I don't know if it is expected, but DKIM_Verifier.Verifier FATAL handleExeption: TypeError: headerBox.emailAddresses is undefined is output into the Terminal on closure of Icedove, as on result 6). See also the terminal output at the bottom of this post.

Note: The point c) is very difficult for me to reproduce right now. The point a) happens much more often - possibly on quick switching between e-mails. (Possibly due to the newly used TB version 17.0.10, as I don't remember seeing point a) with my previously used version 17.0.8, where I had also used a new profile.) And the two times I have been able to reproduce the point c) now, there were two and three incomplete outputs respectively both in the Error Console and in the terminal after closing TB - one of the current and one of the previous e-mail (same sender) (and an additional one of the current when three), which is likely just the e-mail order I tested. I mean two or three "incomplete" outputs on one incomplete verification. Where, at least on the occurrence with three outputs, I'm sure I didn't switch quickly between e-mails, but waited for their verification result. Maybe some verification results do not get stored internally (and therefore is not shown in debugging output), causing the subsequent verification to not complete? I didn't check the debugging output on completed verifications though, so I didn't see when they were output. Here is the occurrence of c) with three incomplete outputs I saw on a sole incomplete verification (the verifications before it were successfully completed):

Error Console (latest first):

2013-12-14 00:54:19 DKIM_Verifier.JSDNS INFO    Resolving s1024-2013-q3._domainkey.facebookmail.com TXT by querying 8.8.8.8
2013-12-14 00:54:19 DKIM_Verifier.Verifier  DEBUG   computed body hash: [Removed]
2013-12-14 00:54:19 DKIM_Verifier.Verifier  DEBUG   Parsed DKIM-Signature: ({v:"1", a_sig:"rsa", a_hash:"sha256", b:"[Removed]", b_folded:"[Removed]", bh:"[Removed]", c_header:"relaxed", c_body:"simple", d:"facebookmail.com", h:"Date:To:From:Subject:MIME-Version:Content-Type", h_array:["date", "to", "from", "subject", "mime-version", "content-type"], i:"@facebookmail.com", i_domain:"facebookmail.com", l:null, q:"dns/txt", s:"s1024-2013-q3", t:[Removed], x:null, z:null})
2013-12-14 00:54:01 DKIM_Verifier.JSDNS INFO    Resolving s1024-2013-q3._domainkey.facebookmail.com TXT by querying 8.8.8.8
2013-12-14 00:54:01 DKIM_Verifier.Verifier  DEBUG   computed body hash: [Removed]
2013-12-14 00:54:01 DKIM_Verifier.Verifier  DEBUG   Parsed DKIM-Signature: ({v:"1", a_sig:"rsa", a_hash:"sha256", b:"[Removed]", b_folded:"[Removed]", bh:"[Removed]", c_header:"relaxed", c_body:"simple", d:"facebookmail.com", h:"Date:To:From:Subject:MIME-Version:Content-Type", h_array:["date", "to", "from", "subject", "mime-version", "content-type"], i:"@facebookmail.com", i_domain:"facebookmail.com", l:null, q:"dns/txt", s:"s1024-2013-q3", t:[Removed], x:null, z:null})
2013-12-14 00:53:27 DKIM_Verifier.JSDNS INFO    Resolving s1024-2013-q3._domainkey.facebookmail.com TXT by querying 8.8.8.8
2013-12-14 00:53:27 DKIM_Verifier.Verifier  DEBUG   computed body hash: [Removed]
2013-12-14 00:53:27 DKIM_Verifier.Verifier  DEBUG   Parsed DKIM-Signature: ({v:"1", a_sig:"rsa", a_hash:"sha256", b:"[Removed]", b_folded:"[Removed]", bh:"[Removed]", c_header:"relaxed", c_body:"simple", d:"facebookmail.com", h:"Date:To:From:Subject:MIME-Version:Content-Type", h_array:["date", "to", "from", "subject", "mime-version", "content-type"], i:"@facebookmail.com", i_domain:"facebookmail.com", l:null, q:"dns/txt", s:"s1024-2013-q3", t:[Removed], x:null, z:null})

_Terminal output after closing (latest last - note the DKIM_Verifier.Verifier FATAL handleExeption: TypeError: headerBox.emailAddresses is undefined lines):_

2013-12-14 01:03:27 DKIM_Verifier.JSDNS DEBUG   Resolving s1024-2013-q3._domainkey.facebookmail.com/TXT: Failed to connect to DNS server 8.8.8.8 with error code 2147500036.
2013-12-14 01:03:27 DKIM_Verifier.JSDNS DEBUG   no DNS Server alive
2013-12-14 01:03:27 DKIM_Verifier.Verifier  FATAL   handleExeption: TypeError: headerBox.emailAddresses is undefined
2013-12-14 01:03:27 DKIM_Verifier.JSDNS DEBUG   Resolving s1024-2013-q3._domainkey.facebookmail.com/TXT: Failed to connect to DNS server 8.8.8.8 with error code 2147500036.
2013-12-14 01:03:27 DKIM_Verifier.JSDNS DEBUG   no DNS Server alive
2013-12-14 01:03:27 DKIM_Verifier.Verifier  FATAL   handleExeption: TypeError: headerBox.emailAddresses is undefined
2013-12-14 01:03:27 DKIM_Verifier.JSDNS DEBUG   Resolving s1024-2013-q3._domainkey.facebookmail.com/TXT: Failed to connect to DNS server 8.8.8.8 with error code 2147500036.
2013-12-14 01:03:27 DKIM_Verifier.JSDNS DEBUG   no DNS Server alive
2013-12-14 01:03:27 DKIM_Verifier.Verifier  FATAL   handleExeption: TypeError: headerBox.emailAddresses is undefined

That is meant just as feedback to you. It doesn't bother me much if the issues are due to my configuration and current network latencies, and because I usually use the "save verification results" option and can re-trigger the verification if needed. And I can use your suggested workaround. (And I'm changing location tomorrow. :) )

lieser commented 10 years ago
Test with add-on v0.4.4:

Debug output to the terminal was added in v1.0.0, so its normal you don't see it.

a)

yes, this should be fixed in v1.0.4pre1

c)

I don't think TypeError: headerBox.emailAddresses is undefined is a Problem, as this only occurs on closing (the header doesn't exist anymore because the window was already closed before the script finished), and is not the reason why the validation doesn't finish.


One reason the timeout is ignored my be because the problem does not occur on the opening of the connection, but on read/write to the connection. The current timeout is only for the opening, I will also add one for read/write. I'm unsure if this will help, as I would expect the default read/write timeout to be less than the 3 minutes you waited.

lieser commented 10 years ago

I have now added the timeout for read and write. To enable it create the integer preference extensions.dkim_verifier.dns.timeout_read_write and set it to the timeout you want.

I also added the option extensions.dkim_verifier.dns.jsdns.autoResetServerAlive. If you set this to true, all DNS servers are set to alive again after a no DNS Server alive error occurs. With this you don't have to set them to alive again yourself, if they are falsely detected as down because of a bad network connection.

lieser commented 10 years ago

Version 1.0.4 is now released. In case the problems occurs again, and the changes do not help, please reopen this issue.