Exception due to incorrect Winsock API call

Bart_Vandewoestyne

I am debugging a Qt 4.8.7 application that we build with Visual Studio 2015 (14.0.25431.01 Update 3) on Windows 10 (64-bit).
If I run the application under Application Verifier with "Networking" selected...

... and then start my debugger, it quasi immediately triggers a breakpoint due to an exception, and I get the following Application Verifier message in my VS2015 Output window:

VERIFIER STOP 0000E107: pid 0x3C80: A Winsock API was called before a successful WSAStartup() or after a balancing successful WSACleanup() call was made 

	00000000 : Last sucessfull WSAStartup call by this caller. Use dps to dump the stack if not NULL
	00000000 : Last sucessfull WSACleanup call by this caller. Use dps to dump the stack if not NULL
	088BB4C8 : Last successful WSAStartup call in this process. Use dps to dump the stack if not NULL
	088BB43C : Last sucessfull WSACleanup call in this process. Use dps to dump the stack if not NULL

and the call stack looks as follows:

So my educated guess is that we (or actually the Qt code in QEventDispatcherWin32Private::doWsaAsyncSelect) are/is calling WSAAsyncSelect somewhere out of the WSAStartup()/WSACleanup() scope.

Since in our own code we are not calling any Winsock API functions directly, but always work using the Qt classes (e.g. QUdpSocket), I am wondering if this is a problem in our code or in the Qt 4.8.7 code. Hence my questions:

Is this a known problem/bug in the Qt 4.8.7 code? I searched the Qt bug database at https://bugreports.qt.io/ but could not immediately find anything related.
If this could also be a bug in our code, then what are the things I should look out for? Notice that the call stack is from a separate thread that is being run... could it be a threading issue?

JonB

@Bart_Vandewoestyne said in Exception due to incorrect Winsock API call:

Notice that the call stack is from a separate thread that is being run... could it be a threading issue?

Indeed I'm pretty sure it could be. I would guess (but not verified) that each thread needs its own WSAStartup() call. So the question is: are you using a QUdpSocket (or whichever) in a thread other than where it was created? Again, I believe this is not allowed: sockets and their operations must only performed in the same thread as where they were created (or moved to).

I stand to be corrected by a better Qt expert.....

Bart_Vandewoestyne

For the record: I searched the Qt 4.8.7 code for calls to WSAStartup and WSACleanup and found these locations:

$ grep -rI 'WSAStartup\|WSACleanup' *
src/network/socket/qnativesocketengine.cpp:    On Windows, WSAStartup is called "recursively" for every
src/network/socket/qnativesocketengine.cpp:    concurrent QNativeSocketEngine. This is safe, because WSAStartup and
src/network/socket/qnativesocketengine.cpp:    WSACleanup are reference counted.
src/network/socket/qnativesocketengine_win.cpp:    if (WSAStartup(MAKEWORD(2,0), &wsadata) != 0) {
src/network/socket/qnativesocketengine_win.cpp:    WSACleanup();
src/plugins/bearer/nla/qnlaengine.cpp:    if (WSAStartup(MAKEWORD(2,0), &wsadata) != 0) {
src/plugins/bearer/nla/qnlaengine.cpp:    WSACleanup();
src/qt3support/network/q3socketdevice_win.cpp:    WSACleanup();
src/qt3support/network/q3socketdevice_win.cpp:  if ( WSAStartup( MAKEWORD(2,0), &wsadata ) != 0 ) {
src/qt3support/network/q3socketdevice_win.cpp:  if ( WSAStartup( MAKEWORD(1,1), &wsadata ) != 0 ) {

I will add breakpoints at all these locations to see which ones get called... to be continued!

Bart_Vandewoestyne

For as far as I can see it now, we are creating all these sockets in one and the same thread:

void BSPPolarisMasterBroadCastListenerThread::run()
{
	mvWaitingOver = false;

	BSPPolarisMasterBroadCastListener listener;

	LOGGER.mfLog(LOG_DEBUG) << "Broadcast listener thread started. ThreadId: " << this;

	// List of sockets to send/receive message to/from remote hosts.
	QList<QUdpSocket*>	udpSocketsForReceiveAndSend;

	QUdpSocket *pUdpSocket = NULL;

	SetupMgrSingleton.mpSetLock();

	//Bind socket with broadcast port.
	unsigned short broadcastPort = SetupMgrSingleton.mfGetConfigurationSetup()->mfGetElementAttributeValue(BSP_CONFIGSETUP_NETWORK, BSP_CONFIGSETUP_BROADCASTPORT_ATTR).toUShort();

	SetupMgrSingleton.mpSetUnLock();

	// Get all local IP addresses of this PC.
	QStringList ipAddresses(gfGetLocalIPAddresses());
	
	// Iterate over local IP addresses and create UDP socket for each one.
    QStringList::iterator ipAddressIt(ipAddresses.begin());

#ifdef Q_WS_WIN32
	while(ipAddressIt!=ipAddresses.end())
	{
		pUdpSocket = new QUdpSocket;

		// If binding this socket fails, delete it and don't add it to list.

		if (pUdpSocket->bind(QHostAddress(*ipAddressIt), broadcastPort) == false)
		{
			delete (pUdpSocket);
			pUdpSocket = NULL;
			LOGGER.mfLog(LOG_ERROR) << "Error binding broadcast listener on port " << broadcastPort << " at IP " << (*ipAddressIt);
		}
		else
		{
			connect(pUdpSocket, SIGNAL(readyRead()), &listener, SLOT(mpDataReceived()));
			
			// Add socket to list.
			udpSocketsForReceiveAndSend.push_back(pUdpSocket);
		}
		ipAddressIt++;
	}
#endif

	mvWaitingOver = true;
	
	// Enters the event loop and waits until exit() is called.
	exec();

	// Close and delete all sockets.
	QList<QUdpSocket *>::iterator socketIt(udpSocketsForReceiveAndSend.begin());
	while(socketIt!=udpSocketsForReceiveAndSend.end())
	{
		(*socketIt)->close();
		delete (*socketIt);
		socketIt++;
	}
	LOGGER.mfLog(LOG_DEBUG)<<"Broadcast listener thread terminated. ThreadId: "<< this;
}

I've added two breakpoints in src\network\socket\qnativesocketengine_win.cpp in the calls to WSAStartup and WSACleanup:

QWindowsSockInit::QWindowsSockInit()
:   version(0)
{
    //### should we try for 2.2 on all platforms ??
    WSAData wsadata;

    // IPv6 requires Winsock v2.0 or better.
    if (WSAStartup(MAKEWORD(2,0), &wsadata) != 0) {
	qWarning("QTcpSocketAPI: WinSock v2.0 initialization failed.");
    } else {
        version = 0x20;
    }
}

QWindowsSockInit::~QWindowsSockInit()
{
    WSACleanup();
}

Each time WSAStartup or WSACleanup is called, I print out which method is called. My output is as follows:

WSAStartup called
WSAStartup called
WSACleanup called
WSAStartup called
WSAStartup called
WSAStartup called
WSAStartup called
WSAStartup called
WSAStartup called
WSACleanup called
WSAStartup called
WSAStartup called
WSACleanup called
WSAStartup called
WSAStartup called
WSACleanup called
WSAStartup called
WSAStartup called
WSAStartup called
WSAStartup called
WSACleanup called
WSAStartup called

Notice there are 17 calls to WSAStartup, but only 5 calls to WSACleanup. 17 is the correct number as that is the number of IP addresses in ipAddresses. So now I'm trying to find out why there are only 5 calls to WSACleanup...

Bart_Vandewoestyne

@Bart_Vandewoestyne said in Exception due to incorrect Winsock API call:

Notice there are 17 calls to WSAStartup, but only 5 calls to WSACleanup. 17 is the correct number as that is the number of IP addresses in ipAddresses. So now I'm trying to find out why there are only 5 calls to WSACleanup...

Figured that one out: of course, at the moment the exception occurs all 17 WSAStartups already occurred, but not all WSACleanups were called yet... so that is rather normal.

Now I need to figure out why apparently there is a call to WSAAsyncSelect (from within the exec() event loop) after that specific socket already got deleted.... (because at the moment we reach exec(), all 17 WSAStartups were already called, so the only reason for the failure can be that the call to WSAAsyncSelect occurs after a WSACleanup.

Bart_Vandewoestyne

From https://docs.microsoft.com/en-us/windows-hardware/drivers/devtest/application-verifier-tests-within-application-verifier#networking:

Winsock requires application developers to call the WSAStartup() at least once before making any Winsock calls. This is tracked by Winsock process-wide. The initial reference count instructs a Winsock library (ws2_32.dll) to initialize and load the Winsock catalog and providers. Further calls to WSAStartup increments that reference count. Winsock also requires application developers to call WSACleanup() when they have 'finished'calling into Winsock. The calls to WSACleanup must be paired correctly with a prior call to WSAStartup(). The call to WSACleanup() decrements the process-wide reference count. When the reference count falls to zero, Winsock releases its resources and unloads the Winsock catalog and providers.

So for as far as I understand it, the following sequence of calls shouldn't be a problem:

WSAStartup called
WSAStartup called
WSACleanup called
WSAStartup called
WSAStartup called
WSAStartup called
WSAStartup called
WSAStartup called
WSAStartup called
WSACleanup called
WSAStartup called
WSAStartup called
WSACleanup called
WSAStartup called
WSAStartup called
WSACleanup called
WSAStartup called
WSAStartup called
WSAStartup called
WSAStartup called
WSACleanup called
WSAStartup called
WSAAsyncSelect called => Why does this give an exception???

But then why does Application Verifier reports something like

VERIFIER STOP 0000E107: pid 0x7B4: A Winsock API was called before a successful WSAStartup() or after a balancing successful WSACleanup() call was made 

	00000000 : Last sucessfull WSAStartup call by this caller. Use dps to dump the stack if not NULL
	00000000 : Last sucessfull WSACleanup call by this caller. Use dps to dump the stack if not NULL
	07E3B554 : Last successful WSAStartup call in this process. Use dps to dump the stack if not NULL
	07E3B43C : Last sucessfull WSACleanup call in this process. Use dps to dump the stack if not NULL

Since there were 17 calls to WSAStartup and only 5 to WSACleanup, the reference count has not reached zero yet and calling WSAAsyncSelect shouldn't throw an exception, right?