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
