I have been running IO::Socket::SSL 2.0.33 though have just updated to 2.0.38. 
I don't think this is going to be related as I have seen this issue for a long 
time and will undoubtedly have had previous versions of OpenSSL.

Don't forget that I see the issue from more than just Google.

I'm quite pushed for time at the moment. Ken, what did you do specifically to 
grab the necessary debugs? - save me having to stop and think :)

All the best,
Colin Waring.


Colin Waring
Technical Manager
Dolphin ICT Limited
T
+44 (0)151 438 2246 Ext 2003
www.dolphinict.co.uk
co...@dolphinict.co.uk
US15a, Armstrong House, First Avenue, Robin Hood Airport, Doncaster, DN9 3GA





Dolphin ICT Limited. NOTICE & DISCLAIMER Dolphin ICT Limited, a private limited 
company, with company registration number 6206916, registered in the United 
Kingdom, the registered office of which is at US15a, Armstrong House, First 
Avenue, Robin Hood Airport, Doncaster, DN9 3GA VAT registration number GB 918 
1896 88. 



-----Original Message-----
From: K Post [mailto:nntp.p...@gmail.com]
Sent: 27 September 2016 04:53
To: ASSP development mailing list <assp-test@lists.sourceforge.net>
Subject: Re: [Assp-test] Inbound TLS from gmail.com addresses / servers

I have IO::Socket::SSL 2.036 installed instead of 2.020.  Could this have 
anything to do with any of this?

On Mon, Sep 26, 2016 at 11:49 PM, K Post <nntp.p...@gmail.com> wrote:

> THANK YOU again for taking all the time on this.  It's nuts that this 
> only seems to happen (to me and others reporting) with TLS on and mail 
> sent through google servers.
>
> I've confirmed the version of Convert::Scalar to be 1.11
>
> I'll get you a debug log privately, but here's what I'm seeing with 
> the latest version:
>
> 11mb attachment, tls on, newest version, but without the 
> $main::neverQueueSize = 4194304; line took 620 seconds.  That's better 
> than the 772seconds that saw before I but still pretty terrible - and 
> of course, that's only one test.
>
> I see a message which I assume is now expected:
> message is too large ( SIZE 15700413 byte > neverQueueSize 12000000
> byte) to be queued for further internal processing! Skipping DKIM, 
> Plugins and charset conversion. for that message
>
> I saw a X-ASSP-KEEP line in the header too.  Don't know what that means.
> Haven't seen that before.
>
> Once I added the $main::neverQueueSize = 4194304; line to 
> ASSP_Correct.pm, speed improves for sure.  It took 327 seconds.  Still 
> really slow considering that without TLS it only takes 19 seconds.
> Similar line noting the 4MB size limit Removing the full message 
> analysis seems like a shame especially since it doesn't seem to even 
> stutter if TLS is off.
>
> So more questions for your consideration
> 1) What is TLS doing that slows things down so much for GOOGLE mails 
> only (or at least only google that I've seen be slow)
> 2) What encryption related modules need checking?
> 3) Why would things be fine on your old Windows 2003 rig, but clearly 
> not okay on my (presumably) faster machine
> 4) What is similar between my machine and the others who reported TLS 
> problems with Google.  I know one at least was a Linux rig.
>
>
>
>
>
>
> On Mon, Sep 26, 2016 at 4:02 AM, Thomas Eckardt < 
> thomas.ecka...@thockar.com> wrote:
>
>> First, thank you for the debug file.
>>
>> There is one big problem. The debug file explains the general 
>> behavior of the slowing down connection while the data size is growing.
>> It not explains, why this should only happens at connections from 
>> gmail.com and only if TLS is used.
>>
>> looking at the following timeline - the *** lines are from me and are 
>> showing the count of read-socketcalls within this second
>>
>> ....
>> Sep-23-16 21:14:37 [Worker_2] <wrote: 
>> IO::Socket::INET=GLOB(0x11c1e3bc) (6)<DATA[CR][LF]
>> Sep-23-16 21:14:37 [Worker_2] <getheader
>> Sep-23-16 21:14:38 [Worker_2] <getbody - done: maillength:77206
>> Sep-23-16 21:14:39 [Worker_2] <doing full ***socketcalls per second 
>> (each 1440 byte) 164 ...
>> Sep-23-16 21:14:40 [Worker_2] <doing full ***socketcalls per second 
>> (each 1440 byte) 167 ...
>> Sep-23-16 21:14:41 [Worker_2] <doing full ***socketcalls per second 
>> (each 1440 byte) 108 ...
>> Sep-23-16 21:14:42 [Worker_2] <doing full ***socketcalls per second 
>> (each 1440 byte) 95 ...
>> Sep-23-16 21:14:43 [Worker_2] <doing full ***socketcalls per second 
>> (each 1440 byte) 82 ...
>> Sep-23-16 21:14:44 [Worker_2] <doing full ***socketcalls per second 
>> (each 1440 byte) 74 ...
>> Sep-23-16 21:15:09 [Worker_2] <doing full ***socketcalls per second 
>> (each 1440 byte) 43 ...
>> Sep-23-16 21:15:39 [Worker_2] <doing full ***socketcalls per second 
>> (each 1440 byte) 35 ...
>> Sep-23-16 21:16:39 [Worker_2] <doing full ***socketcalls per second 
>> (each 1440 byte) 21 ...
>> Sep-23-16 21:18:39 [Worker_2] <doing full ***socketcalls per second 
>> (each 1440 byte) 12 ...
>> Sep-23-16 21:22:41 msg79676-04975 209.85.223.177 
>> <nntp.p...@gmail.com>
>> to:
>> testtls@[[ OUR DOMAIN ]].org info: message is too large ( > 
>> neverQueueSize
>> 12000000 byte) to be queued for further internal processing! Skipping 
>> DKMI, Plugins and charset conversion.
>> ***socketcalls per second (each 1440 byte) 8 ...
>> Sep-23-16 21:22:45 [Worker_2] <wrote: 
>> IO::Socket::INET=GLOB(0x11c1e3bc)
>> (1404)
>> ***socketcalls per second (each 1440 byte) 150 ...
>> Sep-23-16 21:23:53 [Worker_2] <wrote: 
>> IO::Socket::INET=GLOB(0x11c1e3bc)
>> (1404)
>> ***socketcalls per second (each 1440 byte) 161 ...
>> Sep-23-16 21:23:53 [Worker_2] <wrote: 
>> IO::Socket::INET=GLOB(0x11c1e3bc)
>> (1404)
>> ***socketcalls per second (each 1440 byte) 161
>> Sep-23-16 21:25:29 [Worker_2] <doing line <250 Queued (652.288 
>> seconds)[CR][LF] ....
>>
>> Until Sep-23-16 21:22:41 the mail is queued. While this is done, the 
>> speed slows down with the growing data.
>> After this timestamp, large (65 kB)data junks are sent to the MTA 
>> (small
>> (1400 Byte) are received) and as the queued data are getting less, 
>> the speed grows.
>> At Sep-23-16 21:22:45 the outqueue is empty and the data are sent as 
>> they are received (1404 Byte each) with a normal speed.
>>
>> This behavior can't be explained with the usage of TLS, because the 
>> code behind is the same for all connections. The read data size for 
>> each read operation is always the same 1400 Byte.
>> For me, the behavior can be exactly described with a not working Perl 
>> module 'Convert::Scalar' or a code operation, which is done over all 
>> the growing data after each read operation.
>> The latter I can exclude. To make this 100% sure, I've made some 
>> small changes in the next release (will be published today).
>>
>> It is not possible to check, that 'Convert::Scalar' is working like 
>> expected for the 'grow' operation - even the module maintainer is not 
>> able to do this in the installation test scripts.
>> At least make sure that version 1.11 is installed.
>>
>> >Sep-23-16 21:14:37 [Worker_2] <allocate memory: header=15703707 ,
>> maillogbuf=15703707 , outgoing=15703707
>>
>> shows, that the module is installed and called by assp.
>>
>> What are the options to solve the problem?
>>
>> 1. in any case - check that Convert::Scalar version 1.11 is installed 
>> 2. Try the new version of assp.pl - I'll publish today. It contains 
>> code changes to prevent this behavior, at least to indentify the 
>> reason somehow better
>>     If the same behavior happens, please provide me the debug file again.
>>
>> 3. if this does not help, add the following code line to the module 
>> 'assp/lib/CorrectASSPcfg.pm' in 'sub set { '
>>
>> $main::neverQueueSize = 4194304;
>>
>> This hidden value defines the maximum size of mail data, that should 
>> be queued for all full mail checks. If a mail is larger, queueing is 
>> switched off - charset conversion, full DKIM checks, DKIM signing and 
>> all Plugins for full mail operations (level 2) will be skipped.
>>
>> 4194304 are 4MB - you may try any other value of your choice. Default 
>> value is 12000000.
>> This solution will also work with the current code.
>>
>>
>> Thomas
>>
>>
>>
>>
>>
>>
>>
>>
>>
>>
>> Von:    K Post <nntp.p...@gmail.com>
>> An:     ASSP development mailing list <assp-test@lists.sourceforge.net>
>> Datum:  24.09.2016 04:05
>> Betreff:        Re: [Assp-test] Inbound TLS from gmail.com addresses /
>> servers
>>
>>
>>
>> in the debug that I'm about to send you, I'm seeing lines like:
>> <left over <46 Byte>
>> periodically in the file.
>> Don't know if that's notable or not.
>>
>> On Fri, Sep 23, 2016 at 9:43 PM, K Post <nntp.p...@gmail.com> wrote:
>>
>> > I'll get you a sample debug asap.
>> >
>> > FYI, I forgot to mention yesterday - I've noticed times (not
>> > always)
>> when
>> > watching the SMTP Connections Window with large test gmail emails 
>> > where
>> a
>> > message will start transferring and after some time (7-8 minutes, 
>> > maybe
>> a
>> > little less), that google will connect a second time and start
>> transferring
>> > the message again, even though the first one is still being received.
>> >
>> > The first message completed after say 12 minutes, and then 3-4 
>> > minutes after that, the 2nd google connection disconnects and 
>> > doesn't try again (nor should it).
>> >
>> > This does NOT happen every time, and I can't find find a reason why 
>> > it would do this on occasion for some but not other big messages.
>> >
>> >
>> > On Fri, Sep 23, 2016 at 7:02 AM, Thomas Eckardt < 
>> > thomas.ecka...@thockar.com> wrote:
>> >
>> >> Thank you Ken.
>> >>
>> >> Please would you send me the debug log for the large (15MB) TLS 
>> >> mail as ZIP or make it available to me for download anywhere, if 
>> >> it is too
>> large
>> >> for SMTP.
>> >>
>> >> Thomas
>> >>
>> >>
>> >
>> ------------------------------------------------------------
>> ------------------
>> _______________________________________________
>> Assp-test mailing list
>> Assp-test@lists.sourceforge.net
>> https://lists.sourceforge.net/lists/listinfo/assp-test
>>
>>
>>
>>
>> DISCLAIMER:
>> *******************************************************
>> This email and any files transmitted with it may be confidential, 
>> legally privileged and protected in law and are intended solely for 
>> the use of the
>>
>> individual to whom it is addressed.
>> This email was multiple times scanned for viruses. There should be no 
>> known virus in this email!
>> *******************************************************
>>
>>
>> ------------------------------------------------------------
>> ------------------
>>
>> _______________________________________________
>> Assp-test mailing list
>> Assp-test@lists.sourceforge.net
>> https://lists.sourceforge.net/lists/listinfo/assp-test
>>
>>
>
------------------------------------------------------------------------------
_______________________________________________
Assp-test mailing list
Assp-test@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/assp-test

Reply via email to