You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@trafficserver.apache.org by "Zhao Yongming (JIRA)" <ji...@apache.org> on 2011/05/20 13:04:47 UTC

[jira] [Commented] (TS-794) ssl session reuse can not pass sslswamp testing

    [ https://issues.apache.org/jira/browse/TS-794?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13036776#comment-13036776 ] 

Zhao Yongming commented on TS-794:
----------------------------------

sslswamp is from the “distcache” package

and the problem is confirmed on trunk

> ssl session reuse can not pass sslswamp testing
> -----------------------------------------------
>
>                 Key: TS-794
>                 URL: https://issues.apache.org/jira/browse/TS-794
>             Project: Traffic Server
>          Issue Type: Bug
>          Components: SSL
>    Affects Versions: 2.1.8
>         Environment: sslv3 tlsv1
>            Reporter: Zhao Yongming
>             Fix For: 2.1.9
>
>
> When I testing from the patches from qianshi, for TS-718, the ssl session resumption looks perfect, but still can not pass the sslswamp testing, it looks like the second and later request will not be handled from the https connection. it may be a issue for https handler, here is some information
> testing from sslswamp:
> {code}
> [root@unknown-10-62-163-x ~]# sslswamp -connect IP:10.32.21.75:443 -num 1 -count 4 -session srrr -update 10 -request "GET https://img02.taobaocdn.com/tps/i2/T1.SVEXcXJXXXXXXXX-770-300.jpg HTTP/1.0\r\n\r\n" -session_ids -nologo -expect 64000 -sslmeth tlsv1
> No 'cacert' supplied, trying defaults ... '/usr/share/swamp/CA.pem' found.
> no client cert provided, continuing anyway.
> Certificate verification failed, probably a self-signed server cert *or*
> the signing CA cert is not trusted by us (hint: use '-CAfile').
> This message will only be printed once
> session-id[conn:0]:04E7E83CD58E8D566673EDB244146C808ECF7AF517CF39282017E053C7A7D0CC
> session-id[conn:0]:04E7E83CD58E8D566673EDB244146C808ECF7AF517CF39282017E053C7A7D0CC
> 120 seconds since starting, 1 successful, 0 failed, resumes(+1,-0) 0.01 ops/sec
> 120 seconds since starting, 1 successful, 1 failed, resumes(+1,-0) 0.00 ops/sec
> 120 seconds since starting, 1 successful, 1 failed, resumes(+1,-0) 0.00 ops/sec
> session-id[conn:0]:04E7E83CD58E8D566673EDB244146C808ECF7AF517CF39282017E053C7A7D0CC
> 120 seconds since starting, 1 successful, 1 failed, resumes(+2,-0) 0.00 ops/sec
> 240 seconds since starting, 1 successful, 1 failed, resumes(+2,-0) 0.00 ops/sec
> 240 seconds since starting, 1 successful, 2 failed, resumes(+2,-0) 0.00 ops/sec
> 240 seconds since starting, 1 successful, 2 failed, resumes(+2,-0) 0.00 ops/sec
> session-id[conn:0]:04E7E83CD58E8D566673EDB244146C808ECF7AF517CF39282017E053C7A7D0CC
> 240 seconds since starting, 1 successful, 2 failed, resumes(+3,-0) 0.00 ops/sec
> 361 seconds since starting, 1 successful, 2 failed, resumes(+3,-0) 0.00 ops/sec
> 361 seconds since starting, 1 successful, 3 failed, resumes(+3,-0) 0.00 ops/sec
> {code}
> the log from traffic.out:
> {code}
> [May 20 18:30:59.544] Manager {140339380279072} NOTE: [LocalManager::pollMgmtProcessServer] New process connecting fd '10'
> [May 20 18:30:59.544] Manager {140339380279072} NOTE: [Alarms::signalAlarm] Server Process born
> [May 20 18:31:00.564] {47816222021376} STATUS: opened /var/log/trafficserver/diags.log
> [May 20 18:31:00.613] {47816222021376} NOTE: updated diags config
> [May 20 18:31:00.648] Server {47816222021376} NOTE: cache clustering disabled
> [May 20 18:31:00.784] Server {47816222021376} NOTE: cache clustering disabled
> [May 20 18:31:01.237] Server {47816222021376} DEBUG: (ssl) [SSLNetProcessor::initSSLServerCTX] set the callback for external session caching.
> [May 20 18:31:01.412] Server {47816222021376} NOTE: logging initialized[7], logging_mode = 3
> [May 20 18:31:01.669] Server {47816222021376} NOTE: traffic server running
> [May 20 18:31:01.793] Server {47816237516544} NOTE: cache enabled
> [May 20 18:31:57.001] Server {47816310503168} DEBUG: (ssl) [ssl_callback_NewSessionCacheEntry] store id [D91C5F59EB43C5E8864303B449B9B1673D3218300EE03FDC4790125A7BCB521D]'s session into cache.
> [May 20 18:31:57.001] Server {47816310503168} DEBUG: (ssl) SSLNetVConnection::sslServerHandShakeEvent, handshake completed successfully
> [May 20 18:31:57.004] Server {47816310503168} DEBUG: (ssl) [SSL_NetVConnection::ssl_read_from_net] b->write_avail()=4096
> [May 20 18:31:57.004] Server {47816310503168} DEBUG: (ssl) [SSL_NetVConnection::ssl_read_from_net] rres=82
> SSL Read
> GET https://img02.taobaocdn.com/tps/i2/T1.SVEXcXJXXXXXXXX-770-300.jpg HTTP/1.0
> [May 20 18:31:57.004] Server {47816310503168} DEBUG: (ssl) [SSL_NetVConnection::ssl_read_from_net] rres=-1
> [May 20 18:31:57.004] Server {47816310503168} DEBUG: (ssl) [SSL_NetVConnection::ssl_read_from_net] SSL_ERROR_WOULD_BLOCK
> [May 20 18:31:57.004] Server {47816310503168} DEBUG: (ssl) [SSL_NetVConnection::ssl_read_from_net] bytes_read=82
> [May 20 18:31:57.004] Server {47816310503168} DEBUG: (ssl) [SSL_NetVConnection::ssl_read_from_net] b->write_avail()=4014
> [May 20 18:31:57.004] Server {47816310503168} DEBUG: (ssl) [SSL_NetVConnection::ssl_read_from_net] rres=-1
> [May 20 18:31:57.004] Server {47816310503168} DEBUG: (ssl) [SSL_NetVConnection::ssl_read_from_net] SSL_ERROR_WOULD_BLOCK
> [May 20 18:31:57.004] Server {47816310503168} DEBUG: (ssl) [SSL_NetVConnection::ssl_read_from_net] bytes_read == 0
> [May 20 18:31:57.021] Server {47816310503168} DEBUG: (ssl) read_from_net, read finished - would block
> [May 20 18:31:57.107] Server {47816310503168} DEBUG: (ssl) SSLNetVConnection::loadBufferAndCallWrite, before do_SSL_write, l = 351, towrite = 77440, b = f4e7d0
> [May 20 18:31:57.107] Server {47816310503168} DEBUG: (ssl) SSLNetVConnection::loadBufferAndCallWrite,Number of bytes written =351 , total =351
> [May 20 18:31:57.107] Server {47816310503168} DEBUG: (ssl) SSLNetVConnection::loadBufferAndCallWrite, before do_SSL_write, l = 77089, towrite = 77440, b = f4e790
> [May 20 18:31:57.109] Server {47816310503168} DEBUG: (ssl) SSLNetVConnection::loadBufferAndCallWrite,Number of bytes written =-11 , total =77440
> [May 20 18:31:57.109] Server {47816310503168} DEBUG: (ssl) SSL_write-SSL_ERROR_WANT_WRITE
> [May 20 18:31:57.109] Server {47816310503168} DEBUG: (ssl) SSLNetVConnection::loadBufferAndCallWrite, before do_SSL_write, l = 77089, towrite = 77089, b = f4e790
> [May 20 18:31:57.109] Server {47816310503168} DEBUG: (ssl) SSLNetVConnection::loadBufferAndCallWrite,Number of bytes written =-11 , total =77089
> [May 20 18:31:57.109] Server {47816310503168} DEBUG: (ssl) SSL_write-SSL_ERROR_WANT_WRITE
> [May 20 18:31:57.111] Server {47816310503168} DEBUG: (ssl) SSLNetVConnection::loadBufferAndCallWrite, before do_SSL_write, l = 77089, towrite = 77089, b = f4e790
> [May 20 18:31:57.114] Server {47816310503168} DEBUG: (ssl) SSLNetVConnection::loadBufferAndCallWrite,Number of bytes written =77089 , total =77089
> [May 20 18:31:57.114] Server {47816310503168} DEBUG: (ssl) SSLNetVConnection::loadBufferAndCallWrite, write successful.
> [May 20 18:31:57.118] Server {47816311555840} DEBUG: (ssl) [ssl_callback_GetSessionCacheEntry] lookup id [D91C5F59EB43C5E8864303B449B9B1673D3218300EE03FDC4790125A7BCB521D] successfully.
> [May 20 18:31:57.121] Server {47816311555840} DEBUG: (ssl) SSLNetVConnection::sslServerHandShakeEvent, handshake completed successfully
> [May 20 18:33:57.567] Server {47816310503168} DEBUG: (ssl) [ssl_callback_GetSessionCacheEntry] lookup id [D91C5F59EB43C5E8864303B449B9B1673D3218300EE03FDC4790125A7BCB521D] successfully.
> [May 20 18:33:57.570] Server {47816310503168} DEBUG: (ssl) SSLNetVConnection::sslServerHandShakeEvent, handshake completed successfully
> {code}
> the logs from squid.blog:
> {code}
> 1305887517.114 211 10.62.163.251 TCP_HIT/200 77440 GET http://img02.taobaocdn.com/tps/i2/T1.SVEXcXJXXXXXXXX-770-300.jpg - NONE/- image/jpeg -
> 1305887637.564 120445 10.62.163.251 ERROR_UNKNOWN(90)/000 0 - / - EMPTY/- - -
> 1305887757.811 120243 10.62.163.251 ERROR_UNKNOWN(90)/000 0 - / - EMPTY/- - -
> {code}
> when the netstat show:
> {code}
> zym6400 trafficserver # netstat -lantp | grep 443
> tcp        0      0 0.0.0.0:443             0.0.0.0:*               LISTEN      27937/traffic_manag 
> tcp      154      0 10.32.21.75:443         10.62.163.251:41718     ESTABLISHED 27948/traffic_serve 
> {code}
> while the s_client testing just cool:
> {code}
> [root@unknown-10-62-163-x ~]# echo | openssl s_client -ssl3 -no_comp -reconnect -connect 10.32.21.75:443 2>&1CONNECTED(00000003)
> depth=0 C = CN, ST = Beijing, L = Beijing, O = ZYMLinux.net, OU = CA, CN = zym.zymlinux.net
> verify error:num=20:unable to get local issuer certificate
> verify return:1
> depth=0 C = CN, ST = Beijing, L = Beijing, O = ZYMLinux.net, OU = CA, CN = zym.zymlinux.net
> verify error:num=27:certificate not trusted
> verify return:1
> depth=0 C = CN, ST = Beijing, L = Beijing, O = ZYMLinux.net, OU = CA, CN = zym.zymlinux.net
> verify error:num=21:unable to verify the first certificate
> verify return:1
> ---
> Certificate chain
>  0 s:/C=CN/ST=Beijing/L=Beijing/O=ZYMLinux.net/OU=CA/CN=zym.zymlinux.net
>    i:/C=CN/ST=Beijing/L=Beijing/O=ZYMLinux.net/OU=CA/CN=ca.ZYMLinux.net/emailAddress=ca@ZYMLinux.net
> ---
> Server certificate
> -----BEGIN CERTIFICATE-----
> MIIG6DCCBNCgAwIBAgIBDzANBgkqhkiG9w0BAQUFADCBjzELMAkGA1UEBhMCQ04x
> EDAOBgNVBAgTB0JlaWppbmcxEDAOBgNVBAcTB0JlaWppbmcxFTATBgNVBAoTDFpZ
> TUxpbnV4Lm5ldDELMAkGA1UECxMCQ0ExGDAWBgNVBAMTD2NhLlpZTUxpbnV4Lm5l
> dDEeMBwGCSqGSIb3DQEJARYPY2FAWllNTGludXgubmV0MB4XDTExMDMwODA4MDAy
> N1oXDTExMDQwNzA4MDAyN1owcDELMAkGA1UEBhMCQ04xEDAOBgNVBAgTB0JlaWpp
> bmcxEDAOBgNVBAcTB0JlaWppbmcxFTATBgNVBAoTDFpZTUxpbnV4Lm5ldDELMAkG
> A1UECxMCQ0ExGTAXBgNVBAMTEHp5bS56eW1saW51eC5uZXQwggIiMA0GCSqGSIb3
> DQEBAQUAA4ICDwAwggIKAoICAQDVT3uLJwvIP+4t0hFmcjOBHEcj5CviX4cWHwkA
> jCnX8EPJBCkBWemebaYNWT7MHfbKKb0tXpF19kHNpq3uCpa/AtDpYj0662Lr1xTw
> Qbw8v38lCv7FxcbQXMUuyMvA+DoYdYocVGCrk/7lBzvURGtuEiMWC18R/nNMXiYZ
> PvfYTiyC8FojhXLBLW+EdXBoRfBHBejePhbULiQlYHuHudD2v6boAb2ptNuv3hjT
> ed5PR2dskmg8US1tUwBSAmcFNoHzbvb1rNa2IaOjRGbipU0dQDAlzT6dVz2I6uGm
> R66eJXGNTCtbPDmKm9oddIAL2YtdzIriIsrZmXD68iUYoDlWk1n4k7LCo1tMhB/S
> yeIXTgjqeXlhOpExTx/KAd4KNBRgBobmkMNBmi2k3VQRQGoUPfZPy6/G/9NsAIgK
> kRNJ3Je7b5V21xFUNAxL7GkdcJKRnfy3jT8fQhvWU714wTc10SPQInxioCwxwiyn
> LSo3MQUIzQfxwvNvYGiSyKirIzqlSrZQKNzNE4LCW73glMJWwhMyxLZ6PkJfZaDG
> psXqCTfqLEQf7FsyGFBOqB/X+VKfp9WD/oboDGei++wL4bpaqLR7fF1iDhxS3FTz
> BTZtz6Aphpj5MvzFG0/N3ShbT/dubaHJwKf1vZV6uCMc6k8prLgjB9JtMuaC5+Kp
> dQcMLQIDAQABo4IBazCCAWcwCQYDVR0TBAIwADARBglghkgBhvhCAQEEBAMCBkAw
> KwYJYIZIAYb4QgENBB4WHFRpbnlDQSBHZW5lcmF0ZWQgQ2VydGlmaWNhdGUwHQYD
> VR0OBBYEFGAuZv/WvnUTG+Jro4Ge59/tJ/xeMIG8BgNVHSMEgbQwgbGAFBu7K8O9
> gw7YNnxCcA1B/Xdjamg8oYGVpIGSMIGPMQswCQYDVQQGEwJDTjEQMA4GA1UECBMH
> QmVpamluZzEQMA4GA1UEBxMHQmVpamluZzEVMBMGA1UEChMMWllNTGludXgubmV0
> MQswCQYDVQQLEwJDQTEYMBYGA1UEAxMPY2EuWllNTGludXgubmV0MR4wHAYJKoZI
> hvcNAQkBFg9jYUBaWU1MaW51eC5uZXSCAQAwGgYDVR0SBBMwEYEPY2FAWllNTGlu
> dXgubmV0MCAGA1UdEQQZMBeBFW1pbmdfenltQHlhaG9vLmNvbS5jbjANBgkqhkiG
> 9w0BAQUFAAOCAgEAMVdS3+/g6DlGj5gmEY8ySkq4ccc3Jpe3lcNjw178bylxdNVE
> m1aKlOGEH8I90BaPG9kDTy2hj3E302ianLtFUREOzza3MAplGvXnWYZT4gn9KTQ9
> bqNnR424NZivW1rxy31REF10wyF7wPnFBvR6bLtFl/UdXXMvaW2fkOQO9wKMLi8j
> 6EQsUwYlD9t9pghCD/dVhcaPGrLn9/06Tlaiw3TywutZ+V/qNpGOxunIXS1bWFFI
> 9IrEHVYQVXuGFuofV8C2J6wic27lpVxalFQGU1poL/fDSKQY3E5OMJWNt3sDX7bD
> 8x4iL76KoDe3q0Y0Mc2UDtt2Stwyh15Y1mFJuA10uT7OSmQJeyqk7byeqXgIzyGf
> MJX3AoBCZ2ffwfJ/fiLtyR7Bw0ZKwwGuYCXot0UrPPWDHVV/CR2r6W5BQnytuFfQ
> sMVtA38fcSOpiHFBqkPR+YmMSSKdkjImZYjjwa2TY9fSSoGVJox0ek759vo6JIyw
> 6S0b9tvIejYlGqTHGVU5FdQTIbFpHWZTex28wDpVY89E15ZDAPhqzl5gKtEnA4Cl
> 7qN2bHTOKKyYo7ccBxlBc6rKmEFLou/KOgLXK2aonus+MMLc1NmKDiS1mVXFj0dE
> QBidn73JeQoidtLVWNDOCgDX+x5K4tMfrcgjRTb0ZlpL8kw8QfDyA9dPwqU=
> -----END CERTIFICATE-----
> subject=/C=CN/ST=Beijing/L=Beijing/O=ZYMLinux.net/OU=CA/CN=zym.zymlinux.net
> issuer=/C=CN/ST=Beijing/L=Beijing/O=ZYMLinux.net/OU=CA/CN=ca.ZYMLinux.net/emailAddress=ca@ZYMLinux.net
> ---
> No client certificate CA names sent
> ---
> SSL handshake has read 1957 bytes and written 702 bytes
> ---
> New, TLSv1/SSLv3, Cipher is AES256-SHA
> Server public key is 4096 bit
> Secure Renegotiation IS supported
> Compression: NONE
> Expansion: NONE
> SSL-Session:
>     Protocol  : SSLv3
>     Cipher    : AES256-SHA
>     Session-ID: 98E7B8CBE086C1B576B221751A6DE65D9B2D54CAE5CC7D9F5941B03616EF2ED2
>     Session-ID-ctx: 
>     Master-Key: E7ED18A3C9994CCD3B394E932478527983C1E31AA59FDEBD2D6C305806ADF866B67338B89C4613636A41BF13582AE960
>     Key-Arg   : None
>     Krb5 Principal: None
>     PSK identity: None
>     PSK identity hint: None
>     Start Time: 1305859243
>     Timeout   : 7200 (sec)
>     Verify return code: 21 (unable to verify the first certificate)
> ---
> drop connection and then reconnect
> CONNECTED(00000003)
> ---
> Reused, TLSv1/SSLv3, Cipher is AES256-SHA
> Secure Renegotiation IS supported
> Compression: NONE
> Expansion: NONE
> SSL-Session:
>     Protocol  : SSLv3
>     Cipher    : AES256-SHA
>     Session-ID: 98E7B8CBE086C1B576B221751A6DE65D9B2D54CAE5CC7D9F5941B03616EF2ED2
>     Session-ID-ctx: 
>     Master-Key: E7ED18A3C9994CCD3B394E932478527983C1E31AA59FDEBD2D6C305806ADF866B67338B89C4613636A41BF13582AE960
>     Key-Arg   : None
>     Krb5 Principal: None
>     PSK identity: None
>     PSK identity hint: None
>     Start Time: 1305859243
>     Timeout   : 7200 (sec)
>     Verify return code: 21 (unable to verify the first certificate)
> ---
> drop connection and then reconnect
> CONNECTED(00000003)
> ---
> Reused, TLSv1/SSLv3, Cipher is AES256-SHA
> Secure Renegotiation IS supported
> Compression: NONE
> Expansion: NONE
> SSL-Session:
>     Protocol  : SSLv3
>     Cipher    : AES256-SHA
>     Session-ID: 98E7B8CBE086C1B576B221751A6DE65D9B2D54CAE5CC7D9F5941B03616EF2ED2
>     Session-ID-ctx: 
>     Master-Key: E7ED18A3C9994CCD3B394E932478527983C1E31AA59FDEBD2D6C305806ADF866B67338B89C4613636A41BF13582AE960
>     Key-Arg   : None
>     Krb5 Principal: None
>     PSK identity: None
>     PSK identity hint: None
>     Start Time: 1305859243
>     Timeout   : 7200 (sec)
>     Verify return code: 21 (unable to verify the first certificate)
> ---
> drop connection and then reconnect
> CONNECTED(00000003)
> ---
> Reused, TLSv1/SSLv3, Cipher is AES256-SHA
> Secure Renegotiation IS supported
> Compression: NONE
> Expansion: NONE
> SSL-Session:
>     Protocol  : SSLv3
>     Cipher    : AES256-SHA
>     Session-ID: 98E7B8CBE086C1B576B221751A6DE65D9B2D54CAE5CC7D9F5941B03616EF2ED2
>     Session-ID-ctx: 
>     Master-Key: E7ED18A3C9994CCD3B394E932478527983C1E31AA59FDEBD2D6C305806ADF866B67338B89C4613636A41BF13582AE960
>     Key-Arg   : None
>     Krb5 Principal: None
>     PSK identity: None
>     PSK identity hint: None
>     Start Time: 1305859243
>     Timeout   : 7200 (sec)
>     Verify return code: 21 (unable to verify the first certificate)
> ---
> drop connection and then reconnect
> CONNECTED(00000003)
> ---
> Reused, TLSv1/SSLv3, Cipher is AES256-SHA
> Secure Renegotiation IS supported
> Compression: NONE
> Expansion: NONE
> SSL-Session:
>     Protocol  : SSLv3
>     Cipher    : AES256-SHA
>     Session-ID: 98E7B8CBE086C1B576B221751A6DE65D9B2D54CAE5CC7D9F5941B03616EF2ED2
>     Session-ID-ctx: 
>     Master-Key: E7ED18A3C9994CCD3B394E932478527983C1E31AA59FDEBD2D6C305806ADF866B67338B89C4613636A41BF13582AE960
>     Key-Arg   : None
>     Krb5 Principal: None
>     PSK identity: None
>     PSK identity hint: None
>     Start Time: 1305859243
>     Timeout   : 7200 (sec)
>     Verify return code: 21 (unable to verify the first certificate)
> ---
> drop connection and then reconnect
> CONNECTED(00000003)
> ---
> Reused, TLSv1/SSLv3, Cipher is AES256-SHA
> Secure Renegotiation IS supported
> Compression: NONE
> Expansion: NONE
> SSL-Session:
>     Protocol  : SSLv3
>     Cipher    : AES256-SHA
>     Session-ID: 98E7B8CBE086C1B576B221751A6DE65D9B2D54CAE5CC7D9F5941B03616EF2ED2
>     Session-ID-ctx: 
>     Master-Key: E7ED18A3C9994CCD3B394E932478527983C1E31AA59FDEBD2D6C305806ADF866B67338B89C4613636A41BF13582AE960
>     Key-Arg   : None
>     Krb5 Principal: None
>     PSK identity: None
>     PSK identity hint: None
>     Start Time: 1305859243
>     Timeout   : 7200 (sec)
>     Verify return code: 21 (unable to verify the first certificate)
> ---
> DONE
> {code}

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira