Problem :
I’m having this really weird problem on my computer that I can’t seem to wrap my head around. Occasionally (and almost always after a reboot), the spotify app can’t seem to connect to it’s servers. When this happens, Chrome is also affected, and it affects all known websites related to Spotify (their web page, web player, their community etc, basically all of *.spotify.com).
This is what it looks like, note the empty remote address column, which makes me suspect a DNS problem.
Now, after a while, this seems to “fix” itself, but it takes like 5-10 minutes or so. Meanwhile, Brave browser (which is basically chrome in disguise) works fine, so does Invoke-WebRequest from powershell. Running ipconfig /flushdns
and restarting Chrome does nothing.
I do know that the Spotify app does use the Chrome engine under the hood, but I would expect it to run it’s own bundled engine, and not my installed Chrome? So why do they affect each other? Also, when this problem stops, it seems to stop simultaneously for both apps.
One suspicion I had, was that it is IPv6 that is buggering me. Spotify actually resolves IPv6 addresses, and I don’t have IPv6. However, I did disable IPv6 on my Wi-Fi adapter, but to no avail.
I’ve also verified that Chrome and Spotify are both allowed through windows firewall.
I’m kind of stuck in my troubleshooting, and some new ideas would be welcome. Also, Spotify is the only known service that seems to have this problem, which is also strange.
EDIT: I’ve noticed that this affects some more sites. plex.tv, as well as the Netflix app, suffer from the same problem. When I can’t visit these sites, other sites are fine, like github.com, google.com, AWS console etc.
I’m stumped. I’ve managed to start the debug logger in Chrome, and when requesting a url that fails, I get this:
[15564:26264:0704/214452.685:VERBOSE1:network_delegate.cc(32)] NetworkDelegate::NotifyBeforeURLRequest: https://plex.tv/
[33512:27416:0704/214452.735:INFO:cpu_info.cc(53)] Available number of cores: 8
[9692:25292:0704/214454.563:VERBOSE1:cast_socket.cc(220)] [192.168.0.148:8009, auth=SSL_VERIFIED] Connect readyState = ReadyState::NONE
[9692:25292:0704/214454.563:VERBOSE1:cast_socket.cc(379)] [192.168.0.148:8009, auth=SSL_VERIFIED] DoTcpConnect
[9692:25292:0704/214454.607:VERBOSE1:cast_socket.cc(393)] [192.168.0.148:8009, auth=SSL_VERIFIED] DoTcpConnectComplete: 0
[9692:25292:0704/214454.607:VERBOSE1:cast_socket.cc(410)] [192.168.0.148:8009, auth=SSL_VERIFIED] DoSslConnect
[15564:26264:0704/214454.622:ERROR:ssl_client_socket_impl.cc(980)] handshake failed; returned -1, SSL error code 1, net_error -101
[9692:25292:0704/214454.622:VERBOSE1:cast_socket.cc(433)] [192.168.0.148:8009, auth=SSL_VERIFIED] DoSslConnectComplete: -101
[9692:25292:0704/214454.622:VERBOSE1:cast_socket.cc(653)] [192.168.0.148:8009, auth=SSL_VERIFIED] SetErrorState ChannelError::AUTHENTICATION_ERROR
[9692:25292:0704/214454.622:VERBOSE1:cast_socket.cc(575)] DoConnectCallback (error_state = ChannelError::AUTHENTICATION_ERROR)
[9692:25292:0704/214454.622:VERBOSE1:cast_socket.cc(615)] [192.168.0.148:8009, auth=SSL_VERIFIED] Close ReadyState = ReadyState::CONNECTING
[9692:25292:0704/214454.622:VERBOSE1:cast_socket.cc(220)] [192.168.0.148:8009, auth=SSL_VERIFIED] Connect readyState = ReadyState::NONE
[9692:25292:0704/214454.622:VERBOSE1:cast_socket.cc(379)] [192.168.0.148:8009, auth=SSL_VERIFIED] DoTcpConnect
[9692:25292:0704/214454.626:VERBOSE1:cast_socket.cc(393)] [192.168.0.148:8009, auth=SSL_VERIFIED] DoTcpConnectComplete: 0
[9692:25292:0704/214454.627:VERBOSE1:cast_socket.cc(410)] [192.168.0.148:8009, auth=SSL_VERIFIED] DoSslConnect
[15564:26264:0704/214454.632:ERROR:ssl_client_socket_impl.cc(980)] handshake failed; returned -1, SSL error code 1, net_error -101
[9692:25292:0704/214454.633:VERBOSE1:cast_socket.cc(433)] [192.168.0.148:8009, auth=SSL_VERIFIED] DoSslConnectComplete: -101
[9692:25292:0704/214454.633:VERBOSE1:cast_socket.cc(653)] [192.168.0.148:8009, auth=SSL_VERIFIED] SetErrorState ChannelError::AUTHENTICATION_ERROR
[9692:25292:0704/214454.633:VERBOSE1:cast_socket.cc(575)] DoConnectCallback (error_state = ChannelError::AUTHENTICATION_ERROR)
[9692:25292:0704/214454.633:VERBOSE1:cast_socket.cc(615)] [192.168.0.148:8009, auth=SSL_VERIFIED] Close ReadyState = ReadyState::CONNECTING
The 192.168.0.148 is a Chromecast on my network, and those errors might be irrelevant, but the error line is interesting:
[15564:26264:0704/214454.632:ERROR:ssl_client_socket_impl.cc(980)] handshake failed; returned -1, SSL error code 1, net_error -101
I don’t understand why I would get SSL error in multiple applications, which after awhile just goes away. Also, why does it only affect some applications, and not all? (Brave, for instance)
Solution :
It seems to me (from my quick search through chromium source with my really really rusty C++ knowledge) that it’s repeating:
handshake failed; returned -1 (ERROR), SSL error code 1 (internal library error), net_error -101 (CONNECTION_RESET)
over and over and over.
Whatever that might mean might be better followed by someone else more knowledgeable – or me when I’ve actually slept sometime in the future.
From Chromium source code on github
ssl_client_socket_impl.cc around line 980)
int SSLClientSocketImpl::DoHandshake() {
crypto::OpenSSLErrStackTracer err_tracer(FROM_HERE);
int rv = SSL_do_handshake(ssl_.get());
int net_error = OK;
if (rv <= 0) {
int ssl_error = SSL_get_error(ssl_.get(), rv);
if (ssl_error == SSL_ERROR_WANT_X509_LOOKUP && !send_client_cert_) {
return ERR_SSL_CLIENT_AUTH_CERT_NEEDED;
}
if (ssl_error == SSL_ERROR_WANT_PRIVATE_KEY_OPERATION) {
DCHECK(client_private_key_);
DCHECK_NE(kSSLClientSocketNoPendingResult, signature_result_);
next_handshake_state_ = STATE_HANDSHAKE;
return ERR_IO_PENDING;
}
if (ssl_error == SSL_ERROR_WANT_CERTIFICATE_VERIFY) {
DCHECK(cert_verifier_request_);
next_handshake_state_ = STATE_HANDSHAKE;
return ERR_IO_PENDING;
}
OpenSSLErrorInfo error_info;
net_error = MapLastOpenSSLError(ssl_error, err_tracer, &error_info);
if (net_error == ERR_IO_PENDING) {
// If not done, stay in this state
next_handshake_state_ = STATE_HANDSHAKE;
return ERR_IO_PENDING;
}
LOG(ERROR) << "handshake failed; returned " << rv << ", SSL error code "
<< ssl_error << ", net_error " << net_error;
NetLogOpenSSLError(net_log_, NetLogEventType::SSL_HANDSHAKE_ERROR,
net_error, ssl_error, error_info);
}
The error codes
RV (return value) Error Code
When the ssl handhsake (SSL_do_handshake(ssl_.get())
in SSLClientSocketImpl::DoHandshake()
) fails at any time, it returns -1
SSL Error Code
// SSL_ERROR_SSL indicates the operation failed within the library. The caller
// may inspect the error queue for more information.
#define SSL_ERROR_SSL 1
NET ERROR Code
// A connection was reset (corresponding to a TCP RST).
NET_ERROR(CONNECTION_RESET, -101)
I’m making this answer a community wiki in hopes someone will be able to follow on my findings (and because this is too long for a comment).