Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

iisnode <ErrorCode>15005</ErrorCode> on iis 10 #673

Open
Mds92 opened this issue Sep 27, 2019 · 1 comment
Open

iisnode <ErrorCode>15005</ErrorCode> on iis 10 #673

Mds92 opened this issue Sep 27, 2019 · 1 comment

Comments

@Mds92
Copy link

Mds92 commented Sep 27, 2019

I'm using Windows 10, IIS 10
I installed latest version of iisnode.
On my website, IUSR and IIS_IUSRS have full access but I'm getting this error on running my website:

iisnode encountered an error when processing the request.

HRESULT: 0x2
HTTP status: 500
HTTP subStatus: 1002
HTTP reason: Internal Server Error
You are receiving this HTTP 200 response because system.webServer/iisnode/@devErrorsEnabled configuration setting is 'true'.

In addition to the log of stdout and stderr of the node.exe process, consider using debugging and ETW traces to further diagnose the problem.

The node.exe process has not written any information to stderr or iisnode was unable to capture this information. Frequent reason is that the iisnode module is unable to create a log file to capture stdout and stderr output from node.exe. Please check that the identity of the IIS application pool running the node.js application has read and write access permissions to the directory on the server where the node.js application is located. Alternatively you can disable logging by setting system.webServer/iisnode/@loggingEnabled element of web.config to 'false'.

ETW log:

<Events>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{9e814aad-3204-11d2-9a82-006008a86939}" />
		<EventID>0</EventID>
		<Version>2</Version>
		<Level>0</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:13.876985500+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="16784" ThreadID="10896" ProcessorID="0" KernelTime="15" UserTime="0" />
		<Channel />
		<Computer />
	</System>
	<EventData>
		<Data Name="BufferSize">    8192</Data>
		<Data Name="Version">83951626</Data>
		<Data Name="ProviderVersion">   18362</Data>
		<Data Name="NumberOfProcessors">       8</Data>
		<Data Name="EndTime">132140870600994726</Data>
		<Data Name="TimerResolution">  156250</Data>
		<Data Name="MaxFileSize">       0</Data>
		<Data Name="LogFileMode">0x0</Data>
		<Data Name="BuffersWritten">       6</Data>
		<Data Name="StartBuffers">       1</Data>
		<Data Name="PointerSize">       8</Data>
		<Data Name="EventsLost">       0</Data>
		<Data Name="CPUSpeed">    4200</Data>
		<Data Name="LoggerName">0x9</Data>
		<Data Name="LogFileName">0x6</Data>
		<Data Name="BootTime">132140158315000000</Data>
		<Data Name="PerfFreq">10000000</Data>
		<Data Name="StartTime">132140870538769855</Data>
		<Data Name="ReservedFlags">0x1</Data>
		<Data Name="BuffersLost">       0</Data>
		<Data Name="SessionNameString">iisnode</Data>
		<Data Name="LogFileNameString">C:\Users\Mohammad\AppData\Local\Temp\iisnode.etl</Data>
	</EventData>
	<RenderingInfo Culture="en-US">
		<Opcode>Header</Opcode>
		<Provider>MSNT_SystemTrace</Provider>
		<EventName xmlns="http://schemas.microsoft.com/win/2004/08/events/trace">EventTrace</EventName>
	</RenderingInfo>
	<ExtendedTracingInfo xmlns="http://schemas.microsoft.com/win/2004/08/events/trace">
		<EventGuid>{68fdd900-4a3e-11d1-84f4-0000f80464e3}</EventGuid>
	</ExtendedTracingInfo>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{9e814aad-3204-11d2-9a82-006008a86939}" />
		<EventID>0</EventID>
		<Version>2</Version>
		<Level>0</Level>
		<Task>0</Task>
		<Opcode>80</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:13.876985500+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="16784" ThreadID="10896" ProcessorID="0" KernelTime="15" UserTime="0" />
		<Channel />
		<Computer />
	</System>
	<ProcessingErrorData>
		<ErrorCode>15005</ErrorCode>
		<DataItemName />
		<EventPayload>000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000</EventPayload>
	</ProcessingErrorData>
	<RenderingInfo Culture="en-US">
		<Opcode>PartitionInfoExtensionV2</Opcode>
		<Provider>MSNT_SystemTrace</Provider>
		<EventName xmlns="http://schemas.microsoft.com/win/2004/08/events/trace">EventTrace</EventName>
	</RenderingInfo>
	<ExtendedTracingInfo xmlns="http://schemas.microsoft.com/win/2004/08/events/trace">
		<EventGuid>{68fdd900-4a3e-11d1-84f4-0000f80464e3}</EventGuid>
	</ExtendedTracingInfo>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>4</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.347205400+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="0" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>iisnode initialized the application manager</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>4</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.347208100+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="0" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>iisnode received a new http request</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>4</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.348614700+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="7" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>iisnode initialized a new node.exe process</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>4</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.348741400+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="7" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>iisnode initialized a new node.js application</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>5</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.348749100+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="7" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode increases pending async operation count</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>4</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.348770100+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="7" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode scheduled a retry of a named pipe connection to the node.exe process </Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>4</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.348776900+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="7" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode dispatched new http request</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>5</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.348777700+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="7" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode decreases pending async operation count</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>5</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.348778500+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="7" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode leaves CNodeHttpModule::OnExecuteRequestHandler with RQ_NOTIFICATION_PENDING</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>4</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.599307200+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="4584" ProcessorID="1" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode scheduled a retry of a named pipe connection to the node.exe process </Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>2</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.670978100+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="1348" ProcessorID="0" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>iisnode detected termination of node.exe process</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>2</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.850189200+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="4584" ProcessorID="3" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode was unable to establish named pipe connection to the node.exe process before the process terminated</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>5</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.850219900+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="4584" ProcessorID="3" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode request processing failed for reasons unrecognized by iisnode</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>5</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.850682400+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="4584" ProcessorID="6" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode decreases pending async operation count</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>5</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.850690200+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="4584" ProcessorID="6" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode posts completion from SendEmtpyResponse</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>5</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.850757400+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="3" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode increases pending async operation count</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>5</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.850764800+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="3" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode enters CNodeHttpModule::OnAsyncCompletion callback</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>5</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.850770100+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="3" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode decreases pending async operation count</Data>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
	<System>
		<Provider Guid="{1040dfc4-61db-484a-9530-584b2735f7f7}" />
		<EventID>0</EventID>
		<Version>0</Version>
		<Level>5</Level>
		<Task>0</Task>
		<Opcode>0</Opcode>
		<Keywords>0x0</Keywords>
		<TimeCreated SystemTime="2019-09-27T23:14:16.850775400+03:29" />
		<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
		<Execution ProcessID="10868" ThreadID="16048" ProcessorID="3" KernelTime="0" UserTime="0" />
		<Channel />
		<Computer />
	</System>
		<Data>{172374E2-CB94-4840-AE73-523E0378CB22}: iisnode leaves CNodeHttpModule::OnAsyncCompletion with RQ_NOTIFICATION_FINISH_REQUEST</Data>
</Event>
</Events>

web.config

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
	<system.webServer>	
		<handlers>
			<add name="iisnode" path="server.js" verb="*" modules="iisnode" />						
		</handlers>
		<iisnode      
      node_env="%node_env%"
			nodeProcessCommandLine="C:\Program Files\nodejs\node.exe"
      nodeProcessCountPerApplication="1"
      maxConcurrentRequestsPerProcess="1024"
      maxNamedPipeConnectionRetry="100"
      namedPipeConnectionRetryDelay="250"      
      maxNamedPipeConnectionPoolSize="512"
      maxNamedPipePooledConnectionAge="30000"
      asyncCompletionThreadCount="0"
      initialRequestBufferSize="4096"
      maxRequestBufferSize="65536"
      watchedFiles="*.js;iisnode.yml"
      uncFileChangesPollingInterval="5000"      
      gracefulShutdownTimeout="60000"
      loggingEnabled="true"
      logDirectory="iisnode"
      debuggingEnabled="true"
      debugHeaderEnabled="true"
      debuggerPortRange="5058-6058"
      debuggerPathSegment="debug"
      maxLogFileSizeInKB="128"
      maxTotalLogFileSizeInKB="1024"
      maxLogFiles="20"
      devErrorsEnabled="true"
      flushResponse="false"      
      enableXFF="false"
      promoteServerVars=""
      configOverrides="iisnode.yml"
		/>
	</system.webServer>
</configuration>

How can I find the problem !

@pmansoorktr
Copy link

I have the same issue , it has also been found that a detailed page is working , but not the absolute domain
example the domain first page
consoto.com is not working
but consoto.com/index.html -- working
but consoto.com/whatismessed -- working (this will show page not available) but the website will load

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants