Strange output in the console

[BlindSide]

With the latest update from the SVN (I think it started when I updated to revision 1632), I have been getting very strange messages in the MSVC debug console when I run an Irrlicht app. It will happen on anything, so a testcase is not necessary, just try helloworld.

This happens in both D3D9, OpenGL drivers, and BurningsVideo's drivers, so I assume it is a device issue.

I admit I am not certain this is a bug in Irrlicht per-se, but the messages began appearing more or less around the time I updated my revision, and also they do not appear when I do not create an Irrlicht device (Even if the symbols are linked in.)

I have no idea really why this is happening, but I suspect someone is mixing managed/unmanaged code somewhere, as it is linking to the .NET api, and the strange debug message seems rather managed-esque (Yes it's a word, google it.). I'd like to know if anyone else is experiencing this issue. Before I forget to mention I am using MSVC 2005 (No service pack).

Anyway here is the unusual output, the netapi loading/unloading happens every second or so, and occasionally that strange debug message appears:

Code: Select all

'MRT.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'MRT.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'MRT.exe': Loaded 'C:\WINDOWS\system32\setupapi.dll', No symbols loaded.
[ DEBUG ][ 10/23/2008 23:35:37 ] [ PID: 4196 ] [ TID: 4860 ] [ McciMT-Log ] [ McciMT::Thread ] [ Msg: Destructor running, aborting any underlying thread with a deadlock timeout value = 5000 (milliseconds). ]
'MRT.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'MRT.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'MRT.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'MRT.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'MRT.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'MRT.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'MRT.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'MRT.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'MRT.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'MRT.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'MRT.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'MRT.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'MRT.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'MRT.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'MRT.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'MRT.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'MRT.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'MRT.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'MRT.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'MRT.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
[ DEBUG ][ 10/23/2008 23:35:51 ] [ PID: 4196 ] [ TID: 4860 ] [ McciMT-Log ] [ McciMT::Thread ] [ Msg: Destructor running, aborting any underlying thread with a deadlock timeout value = 5000 (milliseconds). ]

Cheers, I hope we can resolve this issue together

[hybrid]

That seems to be from the change for threadsafe window caption changes. Maybe it wasn't done completely right - I tried to understand what MSDN told me, but was too often lost in strange references and hints about things I never heard of before... Maybe some win32 guru will look into this issue - it's starting from setWindowCaption in CIrrDeiveWin32.cpp

[BlindSide]

Ahh yes that explains the timing between the messages. Removing "setWindowCaption" indeed removes the constant netapi loading/unloading. The strangeness doesn't end there however, please observe.

Ok, so I've made a simple test case:

Code: Select all

#include <irrlicht.h>

using namespace irr;

#pragma comment(lib, "irrlicht.lib")

int main()
{
	IrrlichtDevice* device = createDevice(video::EDT_OPENGL, core::dimension2di(800, 600), 32);

	// Creating a rendertarget also produces loading/unloading netapi.
	device->getLogger()->log("Logging rtt creation");
	device->getVideoDriver()->addRenderTargetTexture(core::dimension2di(512, 512));
	device->getLogger()->log("Logging rtt creation end");

	while(device->run())
	{
		device->sleep(100);
	}

	device->drop();
	device = NULL;
}

This produces the following output (Starting from Irrlicht device creation):

Code: Select all

Irrlicht Engine version 1.4.2
Microsoft Windows XP Professional Service Pack 2 (Build 2600)
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\uxtheme.dll', No symbols loaded.
'IrrDebug.exe': Loaded 'C:\Program Files\Common Files\Motive\McciContextHook_5-0-0_DSR.dll', No symbols loaded.
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\shell32.dll', No symbols loaded.
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\shlwapi.dll', No symbols loaded.
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\ole32.dll', No symbols loaded.
'IrrDebug.exe': Loaded 'C:\WINDOWS\WinSxS\x86_Microsoft.Windows.Common-Controls_6595b64144ccf1df_6.0.2600.2180_x-ww_a84f1ff9\comctl32.dll', No symbols loaded.
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\comctl32.dll', No symbols loaded.
[ DEBUG ][ 10/25/2008 18:00:28 ] [ PID: 2428 ] [ TID: 3476 ] [ McciMT-Log ] [ McciMT::Mutex ] [ Msg: Internel CreateMutex call was successful, but indicated that a handle to an already existing named object was returned. ]
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\secur32.dll', No symbols loaded.
'IrrDebug.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'IrrDebug.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\nvoglnt.dll', No symbols loaded.
The thread 'Win32 Thread' (0xdd8) has exited with code 0 (0x0).
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\mcd32.dll', No symbols loaded.
'IrrDebug.exe': Unloaded 'C:\WINDOWS\system32\mcd32.dll'
Using renderer: OpenGL 2.1.1
GeForce 6800 GT/AGP/SSE/3DNOW!: NVIDIA Corporation
OpenGL driver version is 1.2 or better.
GLSL version: 1.3
Logging rtt creation
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'IrrDebug.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
Logging rtt creation end
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\psapi.dll', No symbols loaded.
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\vdmdbg.dll', No symbols loaded.
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\netapi32.dll', No symbols loaded.
'IrrDebug.exe': Unloaded 'C:\WINDOWS\system32\netapi32.dll'
'IrrDebug.exe': Loaded 'C:\WINDOWS\system32\setupapi.dll', No symbols loaded.
[ DEBUG ][ 10/25/2008 18:00:29 ] [ PID: 2428 ] [ TID: 3476 ] [ McciMT-Log ] [ McciMT::Thread ] [ Msg: Destructor running, aborting any underlying thread with a deadlock timeout value = 5000 (milliseconds). ]
[ DEBUG ][ 10/25/2008 18:00:32 ] [ PID: 2428 ] [ TID: 3476 ] [ McciMT-Log ] [ McciMT::Thread ] [ Msg: Destructor running, aborting any underlying thread with a deadlock timeout value = 5000 (milliseconds). ]

A few things to notice:
- Creating an RTT produces the netapi loading/unloading, the corresponding output with the creation commented out is simply:

Code: Select all

Logging rtt creation
Logging rtt creation end

- The strange debug messages at the end, the first one appears after device creation has full completed (I assume on the first instance of device->run()), the second one appears when the device is dropped. The second one only appears when the device is closed properly (Destructed, etc), not when it is closed forcefully from the console.

- The messages appear both in release and debug mode, compiled with /MD and /MDd respectively.

I hope that's of some help to anybody willing to track down the problem.

Cheers

[rogerborg]

I suspect someone is mixing managed/unmanaged code somewhere, as it is linking to the .NET api

Psyche! netapi32.dll is from the Early Olden Days when net meant the inter-net, not the dot-net.

I can't replicate this behaviour on XP 64 SP 2 with MSVC 2k8 Express or 2K Pro SP4 with MSVC 2k5 Express. It seems very peculiar; I can't see why sending a windows message to an HWND in the same process should cause a networking API to be loaded, let alone creating a texture.

Using SendMessageTimeout() is a perfectly reasonable way to cover the possibility that the HWND isn't owned by Irrlicht. We can't use PostMessage() since we'd have to put the string on the heap with no way to know when it's safe to free it. We could use SendMessageCallback() for that purpose, but I'd expect it to have the same (unexpected) issue as SendMessageTimeout().

Sorry, I'm rambling a bit here. Without being able to replicate the problem, and with no obvious cause, I'm rather at a loss to explain what's going on.

Is there any chance that you've got some windows hooking happening in the background, either by design or accident? I hate to say "ZOMG UV BIN ROOTAD!!!1!", but it is a remote possibility.

[BlindSide]

I hate to say "ZOMG UV BIN ROOTAD!!!1!", but it is a remote possibility.

That may be true, thanks for enlightening me, lets put this whole thing on hold while I run an exhaustive check on my system.

Cheers