[ https://issues.apache.org/jira/browse/TS-794?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13612972#comment-13612972 ]
Leif Hedstrom commented on TS-794: ---------------------------------- Ming, is this still an issue / problem? If not, please close, otherwise, help suggest a fix version for this (3.5.0 if it won't go into 3.4.0). > 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: 3.3.3 > > > 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=c...@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=c...@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. If you think it was sent incorrectly, please contact your JIRA administrators For more information on JIRA, see: http://www.atlassian.com/software/jira