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.

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

Nightly Dev can`t connect #651

Open
jerseywurzel opened this Issue Feb 11, 2017 · 21 comments

Comments

Projects
None yet
4 participants
@jerseywurzel

jerseywurzel commented Feb 11, 2017

Submission type

  • Bug report

NOTE: Do not submit anything other than bug reports or feature requests via the issue tracker!

YAM version the issue has been seen with

… February 2017 nightly build

NOTE: Do not submit bug reports about anything but the two most recently released YAM versions!

Used operating system

  • AmigaOS3/m68k

In case of bug report: Expected behaviour you didn't see

… Forced to update the nightly update, installation went well but now, YAM cannot connect to Hotmail servers and times out.

In case of bug report: Unexpected behaviour you saw

… YAM cannot connect to server, tried testing the settings but still no connection. Worked fine in the January build.

In case of bug report: Steps to reproduce the problem

… I have MUI 5, AmiSSL 4, latest build YAM. Update YAM from previous, working version, load YAM, auto download of mails fails because cannot connect

@jens-maus

This comment has been minimized.

Show comment
Hide comment
@jens-maus

jens-maus Feb 11, 2017

Owner

Please provide more information (use debug version or start YAM from command-line with DEBUG option) and report the actual problem it reports. Please also state the specs of your amiga system.

Owner

jens-maus commented Feb 11, 2017

Please provide more information (use debug version or start YAM from command-line with DEBUG option) and report the actual problem it reports. Please also state the specs of your amiga system.

@jerseywurzel

This comment has been minimized.

Show comment
Hide comment
@jerseywurzel

jerseywurzel Feb 11, 2017

Amiga is A1200 with Blizzard 060 with 400mb RAM (yes!)
Started YAM from CLI using DEBUG.
The "Checking Mails" window shows "Initialising TLSv/SSLv3 session"
Eroor window pops up "Couldn`t initialise TLSv1/SSL3 session with host"

Using SnoopDos, it fails to load Resources/certificates/b85455c4.0

I cannot find where a Debug log is saved (if any)

jerseywurzel commented Feb 11, 2017

Amiga is A1200 with Blizzard 060 with 400mb RAM (yes!)
Started YAM from CLI using DEBUG.
The "Checking Mails" window shows "Initialising TLSv/SSLv3 session"
Eroor window pops up "Couldn`t initialise TLSv1/SSL3 session with host"

Using SnoopDos, it fails to load Resources/certificates/b85455c4.0

I cannot find where a Debug log is saved (if any)

@raziel-

This comment has been minimized.

Show comment
Hide comment
@raziel-

raziel- Feb 11, 2017

@jerseywurzel

Try "YAM DEBUG >debug.log"

raziel- commented Feb 11, 2017

@jerseywurzel

Try "YAM DEBUG >debug.log"

@jerseywurzel

This comment has been minimized.

Show comment
Hide comment
@jerseywurzel

jerseywurzel Feb 11, 2017

Ok, I did the above (long time since I did that, I`d forgotten).
The resultant file is zero bytes, ie, nothing in it.

jerseywurzel commented Feb 11, 2017

Ok, I did the above (long time since I did that, I`d forgotten).
The resultant file is zero bytes, ie, nothing in it.

@jens-maus

This comment has been minimized.

Show comment
Hide comment
@jens-maus

jens-maus Feb 11, 2017

Owner

@jerseywurzel Then you did a mistake. With the DEBUG cli parameter it should output something on the cli as soon as you open a TCP connection to your server. Besides that, please download the debug version of YAM nightly build and execute the following command before starting YAM:

setenv yamdebug net,file:ram:debuglog.txt

Then try to do the network connection and it should generate debuglog.txt file in RAM:

Owner

jens-maus commented Feb 11, 2017

@jerseywurzel Then you did a mistake. With the DEBUG cli parameter it should output something on the cli as soon as you open a TCP connection to your server. Besides that, please download the debug version of YAM nightly build and execute the following command before starting YAM:

setenv yamdebug net,file:ram:debuglog.txt

Then try to do the network connection and it should generate debuglog.txt file in RAM:

@jerseywurzel

This comment has been minimized.

Show comment
Hide comment
@jerseywurzel

jerseywurzel Feb 11, 2017

@jens-maus
Ok, so I did that and got this log:

jerseywurzel commented Feb 11, 2017

@jens-maus
Ok, so I did that and got this log:

@jens-maus

This comment has been minimized.

Show comment
Hide comment
@jens-maus

jens-maus Feb 12, 2017

Owner

@jerseywurzel I can see that you have actual two POP3 server configured and that YAM is querying both at the same time using multithreading. Can you please regenerate the debug log, but please make sure that the second POP account is disabled when you are starting YAM to capture the logfile? This would make it more easier to identify the root cause.

Owner

jens-maus commented Feb 12, 2017

@jerseywurzel I can see that you have actual two POP3 server configured and that YAM is querying both at the same time using multithreading. Can you please regenerate the debug log, but please make sure that the second POP account is disabled when you are starting YAM to capture the logfile? This would make it more easier to identify the root cause.

@jerseywurzel

This comment has been minimized.

Show comment
Hide comment
@jerseywurzel

jerseywurzel Feb 12, 2017

@jens-maus
Thanks Jens-maus, I have done that.

jerseywurzel commented Feb 12, 2017

@jens-maus
Thanks Jens-maus, I have done that.

@jens-maus

This comment has been minimized.

Show comment
Hide comment
@jens-maus

jens-maus Feb 12, 2017

Owner

@jerseywurzel
Please execute the following command line program of AmiSSLv4 to test if SSL connections to pop3.live.com work in principle for your system:

openssl s_client -connect pop3.live.com:995

And please show the output here (simple cut&paste) in single backquotes should be enough.

BTW: I also just tested it here with my OS3/UAE installation and I can perfectly connect with YAM to pop3.live.com:995 and it asks me for username/password.

Owner

jens-maus commented Feb 12, 2017

@jerseywurzel
Please execute the following command line program of AmiSSLv4 to test if SSL connections to pop3.live.com work in principle for your system:

openssl s_client -connect pop3.live.com:995

And please show the output here (simple cut&paste) in single backquotes should be enough.

BTW: I also just tested it here with my OS3/UAE installation and I can perfectly connect with YAM to pop3.live.com:995 and it asks me for username/password.

@Weber-Frank

This comment has been minimized.

Show comment
Hide comment
@Weber-Frank

Weber-Frank Feb 12, 2017

Maybe you must activate your POP/SMTP access again in your Hotmail WEB-Account. I got yesterday another but wrong errormessage from the gmx and web.de server an must activate the access again. After that YAM was able to get and send mails via both servers.
see http://www.wolfgang-frank.eu/mailserver.php#EM15

Weber-Frank commented Feb 12, 2017

Maybe you must activate your POP/SMTP access again in your Hotmail WEB-Account. I got yesterday another but wrong errormessage from the gmx and web.de server an must activate the access again. After that YAM was able to get and send mails via both servers.
see http://www.wolfgang-frank.eu/mailserver.php#EM15

@jens-maus

This comment has been minimized.

Show comment
Hide comment
@jens-maus

jens-maus Feb 12, 2017

Owner

@Weber-Frank This is a nice idea, Frank. However, the problem @jerseywurzel has cannot be the same like you had because in his case the debug log clearly states that his YAM cannot even open an SSL connection, so it doesn't even reach the point where it is supposed to login with his account.

But where you could help is tell us @Weber-Frank which Amiga system you are using with YAM so that we can see if there are any similarities.

Owner

jens-maus commented Feb 12, 2017

@Weber-Frank This is a nice idea, Frank. However, the problem @jerseywurzel has cannot be the same like you had because in his case the debug log clearly states that his YAM cannot even open an SSL connection, so it doesn't even reach the point where it is supposed to login with his account.

But where you could help is tell us @Weber-Frank which Amiga system you are using with YAM so that we can see if there are any similarities.

@jerseywurzel

This comment has been minimized.

Show comment
Hide comment

jerseywurzel commented Feb 12, 2017

@jens-maus
This is what I got:
Openssl output.txt

@jens-maus

This comment has been minimized.

Show comment
Hide comment
@jens-maus

jens-maus Feb 12, 2017

Owner

@jerseywurzel Thanks. but your output seems to be mixed up. Please next time pipe it to a file (>file.txt) instead of using copy&paste that breaks it.

The output of the command is also missing the following final server output:

---
+OK DUB005-POP61 POP3 server ready

Please wait a longer time (several minutes) until it either returns an error message or this +OK message.

So please re-execute the openssl command again and attach the non-wrapped up output here again.

Owner

jens-maus commented Feb 12, 2017

@jerseywurzel Thanks. but your output seems to be mixed up. Please next time pipe it to a file (>file.txt) instead of using copy&paste that breaks it.

The output of the command is also missing the following final server output:

---
+OK DUB005-POP61 POP3 server ready

Please wait a longer time (several minutes) until it either returns an error message or this +OK message.

So please re-execute the openssl command again and attach the non-wrapped up output here again.

@jens-maus

This comment has been minimized.

Show comment
Hide comment
@jens-maus

jens-maus Feb 12, 2017

Owner

@jerseywurzel
Please also try to add the -debug option in a second execution like:

openssl s_client -debug -connect pop3.live.com:995
Owner

jens-maus commented Feb 12, 2017

@jerseywurzel
Please also try to add the -debug option in a second execution like:

openssl s_client -debug -connect pop3.live.com:995
@jerseywurzel

This comment has been minimized.

Show comment
Hide comment
@jerseywurzel

jerseywurzel Feb 12, 2017

@jens-maus
Here you are, this one has the debug option and I hope this is better. I have to transfer the file from the miggy to laptop, because IBrowse cannot connect to GitHub.
Also, the is no other output, CLI goes back to waiting for command.

output.pdf

jerseywurzel commented Feb 12, 2017

@jens-maus
Here you are, this one has the debug option and I hope this is better. I have to transfer the file from the miggy to laptop, because IBrowse cannot connect to GitHub.
Also, the is no other output, CLI goes back to waiting for command.

output.pdf

@raziel-

This comment has been minimized.

Show comment
Hide comment
@raziel-

raziel- Feb 12, 2017

Just for the record, i get an OK with the provided command on that live.com address from here.

Something fishy on your system @jerseywurzel

raziel- commented Feb 12, 2017

Just for the record, i get an OK with the provided command on that live.com address from here.

Something fishy on your system @jerseywurzel

@jens-maus

This comment has been minimized.

Show comment
Hide comment
@jens-maus

jens-maus Feb 12, 2017

Owner

@jerseywurzel Can you please measure the absolute time the execution of the openssl s_client ... command execution takes until the final last --- output. And is there some blocking in between the output or does the output appear at once?

My current suspicion is, unfortunately, that your real A1200/m68k system is simply to slow to calculate certain modern ciphers/checksums using AmiSSL/OpenSSL and therefore the TCP connection is dropped by the mail server and then when openssl or YAM wants to continue (after openssl is finished with cipher/encryption calculation) it receives a connection dropped error and recognises that the TCP connection to the mail server was aborted. In your debug output, for example, you can see that at a certain point you see something like:

[...]
write to 0x60ca7a7c [0x60c5f40c] (166 bytes => -1 (0xFFFFFFFF))
write:errno=32
[...]

This happens right before the output of the "Certificate chain". And in fast write:errno=32 means "Broken pipe" and points exactly at the rational I am stating above (the mail server has aborted the connection, probably due to timeout). In my test connections I can see at the same point that here openssl continues to write out something to the server and also receives some valid response:

write to 0x7179a0 [0x726f30] (107 bytes => 107 (0x6B))
0000 - 16 03 01 00 66 10 00 00-62 61 04 46 26 8e 8a ca   ....f...ba.F&...
0010 - 18 10 5a e8 34 c5 00 a7-d4 d4 de f6 bc a6 18 a5   ..Z.4...........
0020 - dd 66 93 23 01 16 ff 00-dc 97 8a 2d f7 b9 fb a3   .f.#.......-....
0030 - 92 93 69 79 18 fe a8 4f-9a 24 08 a6 09 eb 25 9f   ..iy...O.$....%.
0040 - 74 67 9a 08 47 67 d9 09-25 e8 82 d5 be 27 71 9e   tg..Gg..%....'q.
0050 - 46 6b 8b f0 36 8c 0d e1-72 25 93 b5 24 8e 7d 22   Fk..6...r%..$.}"
0060 - 1a fa 01 49 07 b9 4d 40-a1 63 75                  ...I..M@.cu
write to 0x7179a0 [0x726f30] (6 bytes => 6 (0x6))
0000 - 14 03 01 00 01 01                                 ......
write to 0x7179a0 [0x726f30] (53 bytes => 53 (0x35))
0000 - 16 03 01 00 30 01 e2 c1-f8 15 1e 5f 8c 6f 56 97   ....0......_.oV.
0010 - 4f 73 df b5 21 dd d8 06-fe ee 80 2b b6 a9 3a 69   Os..!......+..:i
0020 - 5b 31 31 87 17 7e a9 38-1c a5 c9 f3 02 4b 9b 0a   [11..~.8.....K..
0030 - 68 f0 32 a7 7d                                    h.2.}
read from 0x7179a0 [0x71cf83] (5 bytes => 5 (0x5))
0000 - 14 03 01 00 01                                    .....
read from 0x7179a0 [0x71cf88] (1 bytes => 1 (0x1))
0000 - 01                                                .
read from 0x7179a0 [0x71cf83] (5 bytes => 5 (0x5))
0000 - 16 03 01 00 30                                    ....0
read from 0x7179a0 [0x71cf88] (48 bytes => 48 (0x30))
0000 - 5d d4 6f 98 18 52 cf 24-be 85 c5 80 f3 d3 d8 71   ].o..R.$.......q
0010 - a9 bc e2 f2 7a 3e 1b a7-4b e8 2a 56 71 e2 04 ed   ....z>..K.*Vq...
0020 - 36 8d 1c 35 84 48 18 6f-05 c1 79 4b 3e 84 30 bc   6..5.H.o..yK>.0.
---
[...]

The final question, however, remains -> why is this happening? As said, my suspicion is that some calculations take too long on your system while on an UAE driven system like for me it works fine. Therefore I am really curious what other users with real outdated Amiga hardware reports. @Weber-Frank Don't you use a real 68k system as well?

Nevertheless, I think we can summarise that this isn't a problem in YAM itself, but rather in AmiSSL/OpenSSL being using on your real Amiga 68k hardware. It, however, remains open if this can be somehow fixed or worked around – for this to answer we would need to investigate that matter a bit more. Thus, I have already created a corresponding ticket at the AmiSSL ticket (see jens-maus/amissl#11).

Owner

jens-maus commented Feb 12, 2017

@jerseywurzel Can you please measure the absolute time the execution of the openssl s_client ... command execution takes until the final last --- output. And is there some blocking in between the output or does the output appear at once?

My current suspicion is, unfortunately, that your real A1200/m68k system is simply to slow to calculate certain modern ciphers/checksums using AmiSSL/OpenSSL and therefore the TCP connection is dropped by the mail server and then when openssl or YAM wants to continue (after openssl is finished with cipher/encryption calculation) it receives a connection dropped error and recognises that the TCP connection to the mail server was aborted. In your debug output, for example, you can see that at a certain point you see something like:

[...]
write to 0x60ca7a7c [0x60c5f40c] (166 bytes => -1 (0xFFFFFFFF))
write:errno=32
[...]

This happens right before the output of the "Certificate chain". And in fast write:errno=32 means "Broken pipe" and points exactly at the rational I am stating above (the mail server has aborted the connection, probably due to timeout). In my test connections I can see at the same point that here openssl continues to write out something to the server and also receives some valid response:

write to 0x7179a0 [0x726f30] (107 bytes => 107 (0x6B))
0000 - 16 03 01 00 66 10 00 00-62 61 04 46 26 8e 8a ca   ....f...ba.F&...
0010 - 18 10 5a e8 34 c5 00 a7-d4 d4 de f6 bc a6 18 a5   ..Z.4...........
0020 - dd 66 93 23 01 16 ff 00-dc 97 8a 2d f7 b9 fb a3   .f.#.......-....
0030 - 92 93 69 79 18 fe a8 4f-9a 24 08 a6 09 eb 25 9f   ..iy...O.$....%.
0040 - 74 67 9a 08 47 67 d9 09-25 e8 82 d5 be 27 71 9e   tg..Gg..%....'q.
0050 - 46 6b 8b f0 36 8c 0d e1-72 25 93 b5 24 8e 7d 22   Fk..6...r%..$.}"
0060 - 1a fa 01 49 07 b9 4d 40-a1 63 75                  ...I..M@.cu
write to 0x7179a0 [0x726f30] (6 bytes => 6 (0x6))
0000 - 14 03 01 00 01 01                                 ......
write to 0x7179a0 [0x726f30] (53 bytes => 53 (0x35))
0000 - 16 03 01 00 30 01 e2 c1-f8 15 1e 5f 8c 6f 56 97   ....0......_.oV.
0010 - 4f 73 df b5 21 dd d8 06-fe ee 80 2b b6 a9 3a 69   Os..!......+..:i
0020 - 5b 31 31 87 17 7e a9 38-1c a5 c9 f3 02 4b 9b 0a   [11..~.8.....K..
0030 - 68 f0 32 a7 7d                                    h.2.}
read from 0x7179a0 [0x71cf83] (5 bytes => 5 (0x5))
0000 - 14 03 01 00 01                                    .....
read from 0x7179a0 [0x71cf88] (1 bytes => 1 (0x1))
0000 - 01                                                .
read from 0x7179a0 [0x71cf83] (5 bytes => 5 (0x5))
0000 - 16 03 01 00 30                                    ....0
read from 0x7179a0 [0x71cf88] (48 bytes => 48 (0x30))
0000 - 5d d4 6f 98 18 52 cf 24-be 85 c5 80 f3 d3 d8 71   ].o..R.$.......q
0010 - a9 bc e2 f2 7a 3e 1b a7-4b e8 2a 56 71 e2 04 ed   ....z>..K.*Vq...
0020 - 36 8d 1c 35 84 48 18 6f-05 c1 79 4b 3e 84 30 bc   6..5.H.o..yK>.0.
---
[...]

The final question, however, remains -> why is this happening? As said, my suspicion is that some calculations take too long on your system while on an UAE driven system like for me it works fine. Therefore I am really curious what other users with real outdated Amiga hardware reports. @Weber-Frank Don't you use a real 68k system as well?

Nevertheless, I think we can summarise that this isn't a problem in YAM itself, but rather in AmiSSL/OpenSSL being using on your real Amiga 68k hardware. It, however, remains open if this can be somehow fixed or worked around – for this to answer we would need to investigate that matter a bit more. Thus, I have already created a corresponding ticket at the AmiSSL ticket (see jens-maus/amissl#11).

@jerseywurzel

This comment has been minimized.

Show comment
Hide comment
@jerseywurzel

jerseywurzel Feb 12, 2017

Ok, it takes 1minute, 30 seconds from start to finish. There are some stops between the depth=02 to depth=0. This is around 10 seconds. The longest break is after depth=0 to certificate chain, and is about a minute. Then it whizzes through to the end.

I have an 060 in my system.

jerseywurzel commented Feb 12, 2017

Ok, it takes 1minute, 30 seconds from start to finish. There are some stops between the depth=02 to depth=0. This is around 10 seconds. The longest break is after depth=0 to certificate chain, and is about a minute. Then it whizzes through to the end.

I have an 060 in my system.

@jerseywurzel

This comment has been minimized.

Show comment
Hide comment

jerseywurzel commented Feb 12, 2017

@jens-maus
Thanks

@jerseywurzel

This comment has been minimized.

Show comment
Hide comment
@jerseywurzel

jerseywurzel Feb 12, 2017

@raziel-
Are you using amissl 4?

jerseywurzel commented Feb 12, 2017

@raziel-
Are you using amissl 4?

@raziel-

This comment has been minimized.

Show comment
Hide comment
@raziel-

raziel- Feb 12, 2017

Yepster, but i'm also on X1000, so...

raziel- commented Feb 12, 2017

Yepster, but i'm also on X1000, so...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment