Hi,
with sogo 2.0_20121212-1.centos6 with native Outlook support - when opening
Outlook on a client, I can see that the ssl handshake is successfull and
failing by turns.
/var/log/httpd/ssl_error_log:
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 read client key exchange A
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1914): OpenSSL: read 5/5
bytes from BIO#7f59b0cd40a0 [mem: 7f59b0adc853] (BIO dump follows)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1847):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0000: 14 03 01 00
01 ..... |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1892):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1914): OpenSSL: read 1/1
bytes from BIO#7f59b0cd40a0 [mem: 7f59b0adc858] (BIO dump follows)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1847):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0000: 01
. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1892):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1914): OpenSSL: read 5/5
bytes from BIO#7f59b0cd40a0 [mem: 7f59b0adc853] (BIO dump follows)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1847):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0000: 16 03 01 00
30 ....0 |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1892):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1914): OpenSSL: read 48/48
bytes from BIO#7f59b0cd40a0 [mem: 7f59b0adc858] (BIO dump follows)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1847):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0000: f8 d5 a7 05
02 0e c7 95-18 4c 1f 92 97 5c a7 1b .........L...\\.. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0010: dc bb 3d 7a
1a 58 80 09-ed 67 73 16 1c be 16 43 ..=z.X...gs....C |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0020: be 76 6a c2
71 e7 d6 7e-a1 98 6a 8e 0b c5 21 7f .vj.q..~..j...!. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1892):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 read finished A
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 write change cipher spec A
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 write finished A
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 flush data
[Fri Dec 21 10:38:41 2012] [debug] ssl_scache_shmcb.c(353):
ssl_scache_shmcb_store (0xd8 -> subcache 24)
[Fri Dec 21 10:38:41 2012] [debug] ssl_scache_shmcb.c(645): insert happened at
idx=1, data=176
[Fri Dec 21 10:38:41 2012] [debug] ssl_scache_shmcb.c(647): finished insert,
subcache: idx_pos/idx_used=0/2, data_pos/data_used=0/339
[Fri Dec 21 10:38:41 2012] [debug] ssl_scache_shmcb.c(378): leaving
ssl_scache_shmcb_store successfully
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1734): Inter-Process
Session Cache: request=SET status=OK
id=D8FC48680C9591897C4391F04AF2BD3ECA3980D54BB885131FA0FEF5039E9E16
timeout=300s (session caching)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1872): OpenSSL:
Handshake: done
[Fri Dec 21 10:38:41 2012] [info] Connection: Client IP: 192.168.40.167,
Protocol: TLSv1, Cipher: AES128-SHA (128/128 bits)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1925): OpenSSL: I/O error, 5
bytes expected to read on BIO#7f59b0cd40a0 [mem: 7f59b0adc853]
[Fri Dec 21 10:38:41 2012] [info] [client 192.168.40.167] (70014)End of file
found: SSL input filter read failed.
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1886): OpenSSL: Write:
SSL negotiation finished successfully
[Fri Dec 21 10:38:41 2012] [info] [client 192.168.40.167] Connection closed to
child 8 with standard shutdown (server remote.airwerk.net:443)
[Fri Dec 21 10:38:41 2012] [info] [client 192.168.40.167] Connection to child 2
established (server remote.airwerk.net:443)
[Fri Dec 21 10:38:41 2012] [info] Seeding PRNG with 144 bytes of entropy
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1868): OpenSSL:
Handshake: start
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
before/accept initialization
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1914): OpenSSL: read 11/11
bytes from BIO#7f59b0d7e750 [mem: 7f59b0adc850] (BIO dump follows)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1847):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0000: 16 03 01 00
7d 01 00 00-79 03 01 ....}...y.. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1892):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1914): OpenSSL: read 119/119
bytes from BIO#7f59b0d7e750 [mem: 7f59b0adc85e] (BIO dump follows)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1847):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0000: 50 d4 2e 0e
b2 bd 03 16-00 06 1e 74 1e a7 e5 82 P..........t.... |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0010: 2d f9 88 fe
0a c1 de 06-6e 33 ab 92 cf 76 31 32 -.......n3...v12 |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0020: 00 00 18 00
2f 00 35 00-05 00 0a c0 09 c0 0a c0 ..../.5......... |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0030: 13 c0 14 00
32 00 38 00-13 00 04 01 00 00 38 00 ....2.8.......8. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0040: 00 00 1d 00
1b 00 00 18-61 75 74 6f 64 69 73 63 ........autodisc |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0050: 6f 76 65 72
2e 61 69 72-77 65 72 6b 2e 6e 65 74 over.airwerk.net |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0060: 00 0a 00 08
00 06 00 17-00 18 00 19 00 0b 00 02 ................ |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0070: 01 00 ff 01
00 01 ...... |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1890): | 0119 -
<SPACES/NULS>
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1892):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1995): [client
192.168.40.167] No matching SSL virtual host for servername
autodiscover.airwerk.net found (using default/first virtual host)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1886): OpenSSL: Write:
SSLv3 read client hello C
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 read client hello A
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 write server hello A
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 write certificate A
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 write server done A
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 flush data
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1914): OpenSSL: read 5/5
bytes from BIO#7f59b0d7e750 [mem: 7f59b0adc853] (BIO dump follows)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1847):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0000: 16 03 01 01
06 ..... |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1892):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1914): OpenSSL: read 262/262
bytes from BIO#7f59b0d7e750 [mem: 7f59b0adc858] (BIO dump follows)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1847):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0000: 10 00 01 02
01 00 7b 53-0b e4 74 7b 9a 50 b1 c9 ......{S..t{.P.. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0010: d9 3d 6b 7a
e8 4b 36 46-cc f7 97 64 72 1d 48 fc .=kz.K6F...dr.H. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0020: 6c fd 3c af
5f b0 da 4e-19 04 ec 49 72 8d 84 98 l.<._..N...Ir... |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0030: 45 8f fd d8
1b b7 8b 57-79 fe 87 43 9b 58 b9 ea E......Wy..C.X.. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0040: ff 63 f3 1e
e0 b2 19 a5-a4 9c c4 83 84 54 96 47 .c...........T.G |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0050: 99 17 27 af
1d 3c 9b e9-88 47 0b e3 23 ad bb 86 ..'..<...G..#... |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0060: d6 84 15 ee
a6 b3 cc 8a-72 63 de 8c c2 8a 38 d0 ........rc....8. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0070: 5f 5d 06 50
6f e4 1d 8b-d5 c6 6f dd e9 2e 2a 94 _].Po.....o...*. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0080: c9 49 4c 19
8c 76 68 26-7d 58 cc 66 16 ef fa 0e .IL..vh&}X.f.... |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0090: 79 82 a3 e9
8a 30 f5 ed-30 a8 b2 2f 3a ed 62 c2 y....0..0../:.b. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 00a0: fd 17 c4 85
aa c0 92 74-6f 4f a3 e3 6e 49 78 f8 .......toO..nIx. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 00b0: f5 df 5e 30
05 ab be e8-d3 c2 6d 5a ee e3 7e d9 ..^0......mZ..~. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 00c0: 51 69 8b 83
1f b2 ce b9-bd ae e4 ba 07 b9 61 ca Qi............a. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 00d0: 53 14 15 8f
d1 a0 5d 87-c7 50 1a 48 be 19 4b 67 S.....]..P.H..Kg |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 00e0: f2 13 e5 84
72 e0 94 81-10 d2 eb 0e 0c 34 17 43 ....r........4.C |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 00f0: 48 74 31 d3
98 24 e4 b5-25 c0 64 24 9f b2 01 d4 Ht1..$..%.d$.... |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0100: eb bf 70 6b
b3 3f ..pk.? |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1892):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 read client key exchange A
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1914): OpenSSL: read 5/5
bytes from BIO#7f59b0d7e750 [mem: 7f59b0adc853] (BIO dump follows)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1847):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0000: 14 03 01 00
01 ..... |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1892):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1914): OpenSSL: read 1/1
bytes from BIO#7f59b0d7e750 [mem: 7f59b0adc858] (BIO dump follows)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1847):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0000: 01
. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1892):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1914): OpenSSL: read 5/5
bytes from BIO#7f59b0d7e750 [mem: 7f59b0adc853] (BIO dump follows)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1847):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0000: 16 03 01 00
30 ....0 |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1892):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1914): OpenSSL: read 48/48
bytes from BIO#7f59b0d7e750 [mem: 7f59b0adc858] (BIO dump follows)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1847):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0000: 8f 0e 5d ef
54 2a d7 8b-6a a4 4a c4 04 3d d0 45 ..].T*..j.J..=.E |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0010: 38 44 f4 b7
8c 54 bf 94-60 28 ef 84 c3 3f 80 b8 8D...T..`(...?.. |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1886): | 0020: 8d ca 2d 00
69 96 08 d2-e3 b4 92 fb fe 66 93 7d ..-.i........f.} |
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1892):
+-------------------------------------------------------------------------+
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 read finished A
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 write change cipher spec A
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 write finished A
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1876): OpenSSL: Loop:
SSLv3 flush data
[Fri Dec 21 10:38:41 2012] [debug] ssl_scache_shmcb.c(353):
ssl_scache_shmcb_store (0x1e -> subcache 30)
[Fri Dec 21 10:38:41 2012] [debug] ssl_scache_shmcb.c(645): insert happened at
idx=3, data=496
[Fri Dec 21 10:38:41 2012] [debug] ssl_scache_shmcb.c(647): finished insert,
subcache: idx_pos/idx_used=0/4, data_pos/data_used=0/672
[Fri Dec 21 10:38:41 2012] [debug] ssl_scache_shmcb.c(378): leaving
ssl_scache_shmcb_store successfully
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1734): Inter-Process
Session Cache: request=SET status=OK
id=1ED12D973A8339BADEA5A14A116464782FA92D73C515A490F70C09C3140392DE
timeout=300s (session caching)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1872): OpenSSL:
Handshake: done
[Fri Dec 21 10:38:41 2012] [info] Connection: Client IP: 192.168.40.167,
Protocol: TLSv1, Cipher: AES128-SHA (128/128 bits)
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_io.c(1925): OpenSSL: I/O error, 5
bytes expected to read on BIO#7f59b0d7e750 [mem: 7f59b0adc853]
[Fri Dec 21 10:38:41 2012] [info] [client 192.168.40.167] (70014)End of file
found: SSL input filter read failed.
[Fri Dec 21 10:38:41 2012] [debug] ssl_engine_kernel.c(1886): OpenSSL: Write:
SSL negotiation finished successfully
[Fri Dec 21 10:38:41 2012] [info] [client 192.168.40.167] Connection closed to
child 2 with standard shutdown (server remote.airwerk.net:443)
How could I investigate this 'OpenSSL: I/O error, 5 bytes expected to read'
error? I have found very much and nothing concrete about that.
Best,
Dirk
--
users@sogo.nu
https://inverse.ca/sogo/lists
