On Feb 13, 5:55 pm, Cosmere Infahm <[email protected]> wrote:
> I analysed node-0.6.10/windows2008r2 running my clustered http server
> script in VTune with a view to understanding why node took 50% more CPU
> than nginx/apache for a given scenario. The results indicate that
> GetQueuedCompletionStatusEx takes 40% of CPU. Does this make sense?
>
> I was wondering if the reported stacks are meaningful for a HTTP server
> script that pipes the contents of a static file as response to all requests
> coming over 1000's of concurrent connections. Are there really any
> exceptions and buffer initializations as shown?
>
> Call Stack Time Total Module Function (Full)
> Total [Unknown] 100.0%
>   v8::V8::GetCompressedStartupDataAlgorithm 0s 92.2% node.exe
> v8::V8::GetCompressedStartupDataAlgorithm(void)
>     RtlInitializeExceptionChain 0s 92.2% ntdll.dll
> RtlInitializeExceptionChain
>       RtlInitializeExceptionChain 0s 92.2% ntdll.dll
> RtlInitializeExceptionChain
>         BaseThreadInitThunk 0s 92.2% kernel32.dll BaseThreadInitThunk
>           v8::V8::GetCompressedStartupDataAlgorithm 0s 92.2% node.exe
> v8::V8::GetCompressedStartupDataAlgorithm(void)
>             node::Buffer::Initialize 0s 92.2% node.exe
> node::Buffer::Initialize(class
> v8::Handle<class v8::Object>)
>               node::FatalException 0s 90.5% node.exe 
> node::FatalException(class
> v8::TryCatch &)
>                 uv_unref 0.015s 41.4% node.exe uv_unref
>                   GetQueuedCompletionStatusEx 0.292s 41.4% KERNELBASE.dll
> GetQueuedCompletionStatusEx
>                     NtRemoveIoCompletionEx 180.77s 41.4% ntdll.dll
> NtRemoveIoCompletionEx
>                     IsNLSDefinedString 0.017s 0.0% KERNELBASE.dll
> IsNLSDefinedString
>                   uv_timer_get_repeat 0.025s 0.0% node.exe
> uv_timer_get_repeat
>                 [Unknown stack frame(s)] 0s 37.1% [Unknown] [Unknown stack
> frame(s)]
>                   node::Buffer::Initialize 0.955s 16.3% node.exe
> node::Buffer::Initialize(class
> v8::Handle<class v8::Object>)
>                     uv_write 0.181s 10.1% node.exe uv_write
>                       uv_tcp_getpeername 0.332s 10.1% node.exe
> uv_tcp_getpeername
>                         WSASend 0.179s 9.9% WS2_32.dll WSASend
>                           [mswsock.dll] 0.397s 9.6% mswsock.dll
> [mswsock.dll]
>                             NtDeviceIoControlFile 41.577s 9.5% ntdll.dll
> NtDeviceIoControlFile
>
> For readability here are some stacks that correspond to the busy data:
> ntdll.dll!NtRemoveIoCompletionEx - [Unknown]
> KERNELBASE.dll!GetQueuedCompletionStatusEx+0x7790 - [Unknown]
> node.exe!uv_unref+0x4ec35 - [Unknown]
> node.exe!node::FatalException(class v8::TryCatch &)+0x1afb7 - [Unknown]
> node.exe!node::Buffer::Initialize(class v8::Handle<class
> v8::Object>)+0x2b0ed - [Unknown]
> node.exe!v8::V8::GetCompressedStartupDataAlgorithm(void)+0x298759 -
> [Unknown]
> kernel32.dll!BaseThreadInitThunk+0x13399 - [Unknown]
> ntdll.dll!RtlInitializeExceptionChain+0x39ef1 - [Unknown]
> ntdll.dll!RtlInitializeExceptionChain+0x39ec4 - [Unknown]
> node.exe!v8::V8::GetCompressedStartupDataAlgorithm(void)+0x2987af -
> [Unknown]
>
> ntdll.dll!NtDeviceIoControlFile - [Unknown]
> mswsock.dll![mswsock.dll]+0x44f3 - [Unknown]
> WS2_32.dll!WSASend+0x447e - [Unknown]
> node.exe!uv_tcp_getpeername+0x5d7b6 - [Unknown]
> node.exe!uv_write+0x52e0f - [Unknown]
> node.exe!node::Buffer::Initialize(class v8::Handle<class
> v8::Object>)+0x2bcdd - [Unknown]
> [Unknown]![Unknown stack frame(s)]+0x0 - [Unknown]
> node.exe!node::FatalException(class v8::TryCatch &)+0x1afb7 - [Unknown]
> node.exe!node::Buffer::Initialize(class v8::Handle<class
> v8::Object>)+0x2b0ed - [Unknown]
> node.exe!v8::V8::GetCompressedStartupDataAlgorithm(void)+0x298759 -
> [Unknown]
> kernel32.dll!BaseThreadInitThunk+0x13399 - [Unknown]
> ntdll.dll!RtlInitializeExceptionChain+0x39ef1 - [Unknown]
> ntdll.dll!RtlInitializeExceptionChain+0x39ec4 - [Unknown]
> node.exe!v8::V8::GetCompressedStartupDataAlgorithm(void)+0x2987af -
> [Unknown]
>
> --

I am not sure - but you should take into consideration that
GetQueuedCompletionStatus(Ex) is the only function in libuv that
blocks. Are you sure that VTune does not take the time into account
that GetQueuedCompletionStatus blocks because there are no events to
report?

- Bert

-- 
Job Board: http://jobs.nodejs.org/
Posting guidelines: 
https://github.com/joyent/node/wiki/Mailing-List-Posting-Guidelines
You received this message because you are subscribed to the Google
Groups "nodejs" group.
To post to this group, send email to [email protected]
To unsubscribe from this group, send email to
[email protected]
For more options, visit this group at
http://groups.google.com/group/nodejs?hl=en?hl=en

Reply via email to