add support for returning dev errors, improving diagnostics of most common failure cases

This commit is contained in:
Tomasz Janczuk 2011-11-18 12:53:31 -08:00
Родитель 7f398dbc7a
Коммит f1fd9f1365
20 изменённых файлов: 269 добавлений и 57 удалений

Просмотреть файл

@ -47,5 +47,6 @@ Details at http://learn.iis.net/page.aspx/241/configuration-extensibility/
<attribute name="maxLogFileSizeInKB" type="uint" defaultValue="128"/>
<attribute name="loggingEnabled" type="bool" defaultValue="true"/>
<attribute name="appendToExistingLog" type="bool" defaultValue="false"/>
<attribute name="devErrorsEnabled" type="bool" defaultValue="true"/>
</sectionSchema>
</configSchema>

Просмотреть файл

@ -47,5 +47,6 @@ Details at http://learn.iis.net/page.aspx/241/configuration-extensibility/
<attribute name="maxLogFileSizeInKB" type="uint" defaultValue="128"/>
<attribute name="loggingEnabled" type="bool" defaultValue="true"/>
<attribute name="appendToExistingLog" type="bool" defaultValue="false"/>
<attribute name="devErrorsEnabled" type="bool" defaultValue="true"/>
</sectionSchema>
</configSchema>

Просмотреть файл

@ -429,6 +429,7 @@ HRESULT CModuleConfiguration::GetConfig(IHttpContext* context, CModuleConfigurat
CheckError(GetDWORD(section, L"maxLogFileSizeInKB", &c->maxLogFileSizeInKB));
CheckError(GetBOOL(section, L"loggingEnabled", &c->loggingEnabled));
CheckError(GetBOOL(section, L"appendToExistingLog", &c->appendToExistingLog));
CheckError(GetBOOL(section, L"devErrorsEnabled", &c->devErrorsEnabled));
CheckError(GetString(section, L"logDirectoryNameSuffix", &c->logDirectoryNameSuffix));
CheckError(GetBOOL(section, L"debuggingEnabled", &c->debuggingEnabled));
CheckError(GetString(section, L"node_env", &c->node_env));
@ -585,6 +586,11 @@ LPWSTR CModuleConfiguration::GetNodeEnv(IHttpContext* ctx)
GETCONFIG(node_env)
}
BOOL CModuleConfiguration::GetDevErrorsEnabled(IHttpContext* ctx)
{
GETCONFIG(devErrorsEnabled)
}
HRESULT CModuleConfiguration::GetDebugPortRange(IHttpContext* ctx, DWORD* start, DWORD* end)
{
HRESULT hr;

Просмотреть файл

@ -30,6 +30,7 @@ private:
DWORD debugPortStart;
DWORD debugPortEnd;
LPWSTR node_env;
BOOL devErrorsEnabled;
static IHttpServer* server;
static HTTP_MODULE_ID moduleId;
@ -67,6 +68,7 @@ public:
static BOOL GetDebuggingEnabled(IHttpContext* ctx);
static HRESULT GetDebugPortRange(IHttpContext* ctx, DWORD* start, DWORD* end);
static LPWSTR GetNodeEnv(IHttpContext* ctx);
static BOOL GetDevErrorsEnabled(IHttpContext* ctx);
static HRESULT CreateNodeEnvironment(IHttpContext* ctx, DWORD debugPort, PCH namedPipe, PCH* env);

Просмотреть файл

@ -377,7 +377,7 @@ Error:
this->GetEventProvider()->Log(
L"iisnode failed to unpack debugger files", WINEVENT_LEVEL_ERROR);
return hr;
return IISNODE_ERROR_UNABLE_TO_CREATE_DEBUGGER_FILES;
}
BOOL CALLBACK CNodeApplicationManager::EnsureDebuggerFile(HMODULE hModule, LPCTSTR lpszType, LPTSTR lpszName, LONG_PTR lParam)

Просмотреть файл

@ -58,54 +58,7 @@ Error:
}
CProtocolBridge::SendEmptyResponse(pHttpContext, 501, _T("Not Implemented"), hr);
}
else if (IISNODE_ERROR_UNRECOGNIZED_DEBUG_COMMAND == hr)
{
CProtocolBridge::SendSyncResponse(
pHttpContext,
200,
"OK",
hr,
TRUE,
"Unrecognized debugging command. Supported commands are ?debug (default), ?brk, and ?kill.");
}
else if (IISNODE_ERROR_UNABLE_TO_FIND_DEBUGGING_PORT == hr)
{
CProtocolBridge::SendSyncResponse(
pHttpContext,
200,
"OK",
hr,
TRUE,
"The debugger was unable to acquire a TCP port to establish communication with the debugee. "
"This may be due to lack of free TCP ports in the range specified in the system.webServer/iisnode/@debuggerPortRange configuration "
"section, or due to lack of permissions to create TCP listeners by the identity of the IIS worker process.");
}
else if (IISNODE_ERROR_UNABLE_TO_CONNECT_TO_DEBUGEE == hr)
{
CProtocolBridge::SendSyncResponse(
pHttpContext,
200,
"OK",
hr,
TRUE,
"The debugger was unable to connect to the the debugee. "
"This may be due to the debugee process terminating during startup (e.g. due to an unhandled exception) or "
"failing to establish a TCP listener on the debugging port. ");
}
else if (IISNODE_ERROR_INSPECTOR_NOT_FOUND == hr)
{
CProtocolBridge::SendSyncResponse(
pHttpContext,
200,
"OK",
hr,
TRUE,
"The version of iisnode installed on the server does not support remote debugging. "
"To use remote debugging, please update your iisnode installation on the server to one available from "
"<a href=""http://github.com/tjanczuk/iisnode/downloads"">http://github.com/tjanczuk/iisnode/downloads</a>. "
"We apologize for inconvenience.");
}
else
else if (!CProtocolBridge::SendIisnodeError(pHttpContext, hr))
{
CProtocolBridge::SendEmptyResponse(pHttpContext, 500, _T("Internal Server Error"), hr);
}

Просмотреть файл

@ -170,7 +170,7 @@ HRESULT CNodeProcess::Initialize(IHttpContext* context)
flags |= CREATE_BREAKAWAY_FROM_JOB;
}
ErrorIf(FALSE == CreateProcess(
if(!CreateProcess(
NULL,
fullCommandLine,
NULL,
@ -180,8 +180,16 @@ HRESULT CNodeProcess::Initialize(IHttpContext* context)
newEnvironment,
currentDirectoryA,
&this->startupInfo,
&processInformation
), GetLastError());
&processInformation))
{
if (ERROR_FILE_NOT_FOUND == (hr = GetLastError()))
{
hr = IISNODE_ERROR_UNABLE_TO_START_NODE_EXE;
}
CheckError(hr);
}
// duplicate stdout and stderr handles to allow flushing without regard for whether the node process exited
// closing of the original handles will be taken care of by the newly started process
@ -490,6 +498,7 @@ HRESULT CNodeProcess::CreateStdHandles(IHttpContext* context)
this->GetProcessManager()->GetEventProvider()->Log(
L"iisnode failed to create directory to store log files for the node.exe process", WINEVENT_LEVEL_ERROR);
hr = IISNODE_ERROR_UNABLE_TO_CREATE_LOG_FILE;
CheckError(hr);
}
}
@ -511,15 +520,18 @@ HRESULT CNodeProcess::CreateStdHandles(IHttpContext* context)
security.bInheritHandle = TRUE;
security.nLength = sizeof SECURITY_ATTRIBUTES;
ErrorIf(INVALID_HANDLE_VALUE == (this->startupInfo.hStdOutput = CreateFileW(
if (INVALID_HANDLE_VALUE == (this->startupInfo.hStdOutput = CreateFileW(
this->loggingEnabled ? logName : L"NUL",
GENERIC_READ | GENERIC_WRITE,
FILE_SHARE_READ | FILE_SHARE_WRITE,
&security,
creationDisposition,
FILE_ATTRIBUTE_NORMAL | FILE_FLAG_WRITE_THROUGH,
NULL)),
GetLastError());
NULL)))
{
hr = this->loggingEnabled ? IISNODE_ERROR_UNABLE_TO_CREATE_LOG_FILE : GetLastError();
CheckError(hr);
}
ErrorIf(0 == DuplicateHandle(
GetCurrentProcess(),

Просмотреть файл

@ -163,7 +163,10 @@ Error:
this->GetEventProvider()->Log(
L"iisnode failed to initiate processing of a request dequeued from the pending request queue", WINEVENT_LEVEL_ERROR);
CProtocolBridge::SendEmptyResponse(request, 503, _T("Service Unavailable"), hr);
if (!CProtocolBridge::SendIisnodeError(request, hr))
{
CProtocolBridge::SendEmptyResponse(request, 503, _T("Service Unavailable"), hr);
}
}
this->DecRef(); // incremented in CNodeProcessManager::PostDispatchOneRequest

Просмотреть файл

@ -10,10 +10,158 @@ HRESULT CProtocolBridge::PostponeProcessing(CNodeHttpStoredContext* context, DWO
return async->SetTimer(context->GetAsyncContext(), &delay);
}
BOOL CProtocolBridge::SendIisnodeError(IHttpContext* httpCtx, HRESULT hr)
{
if (!CModuleConfiguration::GetDevErrorsEnabled(httpCtx))
{
return FALSE;
}
switch (hr) {
default:
return FALSE;
case IISNODE_ERROR_UNRECOGNIZED_DEBUG_COMMAND:
CProtocolBridge::SendSyncResponse(
httpCtx,
200,
"OK",
hr,
TRUE,
"Unrecognized debugging command. Supported commands are ?debug (default), ?brk, and ?kill.");
break;
case IISNODE_ERROR_UNABLE_TO_FIND_DEBUGGING_PORT:
CProtocolBridge::SendSyncResponse(
httpCtx,
200,
"OK",
hr,
TRUE,
"The debugger was unable to acquire a TCP port to establish communication with the debugee. "
"This may be due to lack of free TCP ports in the range specified in the <a href=""https://github.com/tjanczuk/iisnode/blob/master/src/samples/configuration/web.config"">"
"system.webServer/iisnode/@debuggerPortRange</a> configuration "
"section, or due to lack of permissions to create TCP listeners by the identity of the IIS worker process.");
break;
case IISNODE_ERROR_UNABLE_TO_CONNECT_TO_DEBUGEE:
CProtocolBridge::SendSyncResponse(
httpCtx,
200,
"OK",
hr,
TRUE,
"The debugger was unable to connect to the the debugee. "
"This may be due to the debugee process terminating during startup (e.g. due to an unhandled exception) or "
"failing to establish a TCP listener on the debugging port. ");
break;
case IISNODE_ERROR_INSPECTOR_NOT_FOUND:
CProtocolBridge::SendSyncResponse(
httpCtx,
200,
"OK",
hr,
TRUE,
"The version of iisnode installed on the server does not support remote debugging. "
"To use remote debugging, please update your iisnode installation on the server to one available from "
"<a href=""http://github.com/tjanczuk/iisnode/downloads"">http://github.com/tjanczuk/iisnode/downloads</a>. "
"We apologize for inconvenience.");
break;
case IISNODE_ERROR_UNABLE_TO_CREATE_LOG_FILE:
CProtocolBridge::SendSyncResponse(
httpCtx,
200,
"OK",
hr,
TRUE,
"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 <a href=""https://github.com/tjanczuk/iisnode/blob/master/src/samples/configuration/web.config"">"
"system.webServer/iisnode/@loggingEnabled</a> element of web.config to 'false'.");
break;
case IISNODE_ERROR_UNABLE_TO_CREATE_DEBUGGER_FILES:
CProtocolBridge::SendSyncResponse(
httpCtx,
200,
"OK",
hr,
TRUE,
"The iisnode module is unable to deploy supporting files necessary to initialize the debugger. "
"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.");
break;
case IISNODE_ERROR_UNABLE_TO_START_NODE_EXE:
LPCTSTR commandLine = CModuleConfiguration::GetNodeProcessCommandLine(httpCtx);
char* errorMessage;
if (NULL == (errorMessage = (char*)httpCtx->AllocateRequestMemory(strlen(commandLine) + 512)))
{
errorMessage =
"The iisnode module is unable to start the node.exe process. Make sure the node.exe executable is available "
"at the location specified in the <a href=""https://github.com/tjanczuk/iisnode/blob/master/src/samples/configuration/web.config"">"
"system.webServer/iisnode/@nodeProcessCommandLine</a> element of web.config. "
"By default node.exe is expected to be installed in %ProgramFiles%\\nodejs folder on x86 systems and "
"%ProgramFiles(x86)%\\nodejs folder on x64 systems.";
}
else
{
sprintf(errorMessage,
"The iisnode module is unable to start the node.exe process. Make sure the node.exe executable is available "
"at the location specified in the <a href=""https://github.com/tjanczuk/iisnode/blob/master/src/samples/configuration/web.config"">"
"system.webServer/iisnode/@nodeProcessCommandLine</a> element of web.config. "
"The command line iisnode attempted to run was:<br><br>%s", commandLine);
}
CProtocolBridge::SendSyncResponse(
httpCtx,
200,
"OK",
hr,
TRUE,
errorMessage);
break;
};
return TRUE;
}
BOOL CProtocolBridge::SendIisnodeError(CNodeHttpStoredContext* ctx, HRESULT hr)
{
if (CProtocolBridge::SendIisnodeError(ctx->GetHttpContext(), hr))
{
ctx->GetNodeApplication()->GetApplicationManager()->GetEventProvider()->Log(
L"iisnode request processing failed for reasons recognized by iisnode", WINEVENT_LEVEL_VERBOSE, ctx->GetActivityId());
if (INVALID_HANDLE_VALUE != ctx->GetPipe())
{
CloseHandle(ctx->GetPipe());
ctx->SetPipe(INVALID_HANDLE_VALUE);
}
CProtocolBridge::FinalizeResponseCore(
ctx,
RQ_NOTIFICATION_FINISH_REQUEST,
hr,
ctx->GetNodeApplication()->GetApplicationManager()->GetEventProvider(),
L"iisnode posts completion from SendIisnodeError",
WINEVENT_LEVEL_VERBOSE);
return TRUE;
}
return FALSE;
}
HRESULT CProtocolBridge::SendEmptyResponse(CNodeHttpStoredContext* context, USHORT status, PCTSTR reason, HRESULT hresult, BOOL disableCache)
{
context->GetNodeApplication()->GetApplicationManager()->GetEventProvider()->Log(
L"iisnode request processing failed", WINEVENT_LEVEL_VERBOSE, context->GetActivityId());
L"iisnode request processing failed for reasons unrecognized by iisnode", WINEVENT_LEVEL_VERBOSE, context->GetActivityId());
if (INVALID_HANDLE_VALUE != context->GetPipe())
{

Просмотреть файл

@ -39,6 +39,8 @@ private:
public:
static HRESULT InitiateRequest(CNodeHttpStoredContext* context);
static BOOL SendIisnodeError(IHttpContext* httpCtx, HRESULT hr);
static BOOL SendIisnodeError(CNodeHttpStoredContext* ctx, HRESULT hr);
static HRESULT SendEmptyResponse(CNodeHttpStoredContext* context, USHORT status, PCTSTR reason, HRESULT hresult, BOOL disableCache = FALSE);
static HRESULT SendSyncResponse(IHttpContext* httpCtx, USHORT status, PCTSTR reason, HRESULT hresult, BOOL disableCache, PCSTR htmlBody);
static void SendEmptyResponse(IHttpContext* httpCtx, USHORT status, PCTSTR reason, HRESULT hresult, BOOL disableCache = FALSE);

Просмотреть файл

@ -5,5 +5,8 @@
#define IISNODE_ERROR_UNABLE_TO_FIND_DEBUGGING_PORT 1025L
#define IISNODE_ERROR_UNABLE_TO_CONNECT_TO_DEBUGEE 1026L
#define IISNODE_ERROR_INSPECTOR_NOT_FOUND 1027L
#define IISNODE_ERROR_UNABLE_TO_START_NODE_EXE 1028L
#define IISNODE_ERROR_UNABLE_TO_CREATE_LOG_FILE 1029L
#define IISNODE_ERROR_UNABLE_TO_CREATE_DEBUGGER_FILES 1030L
#endif

Просмотреть файл

@ -236,6 +236,7 @@ copy /y $(SolutionDir)\..\config\* $(SolutionDir)\..\..\build\$(Configuration)\$
<None Include="..\..\test\functional\tests\109_helloworld_debug.js" />
<None Include="..\..\test\functional\tests\110_log_size_quota.js" />
<None Include="..\..\test\functional\tests\111_node_env.js" />
<None Include="..\..\test\functional\tests\112_dev_errors.js" />
<None Include="..\..\test\functional\tests\200_samples.bat" />
<None Include="..\..\test\functional\tests\node_modules\iisnodeassert.js" />
<None Include="..\..\test\functional\tests\parts\106_autoupdate_first.js" />
@ -265,6 +266,10 @@ copy /y $(SolutionDir)\..\config\* $(SolutionDir)\..\..\build\$(Configuration)\$
<None Include="..\..\test\functional\www\110_log_size_quota\web.config" />
<None Include="..\..\test\functional\www\111_node_env\hello.js" />
<None Include="..\..\test\functional\www\111_node_env\web.config" />
<None Include="..\..\test\functional\www\112_dev_errors\off\hello.js" />
<None Include="..\..\test\functional\www\112_dev_errors\off\web.config" />
<None Include="..\..\test\functional\www\112_dev_errors\on\hello.js" />
<None Include="..\..\test\functional\www\112_dev_errors\on\web.config" />
<None Include="..\config\iisnode_schema.xml" />
<None Include="..\config\iisnode_schema_x64.xml" />
<None Include="..\samples\configuration\hello.js" />

Просмотреть файл

@ -90,6 +90,15 @@
<Filter Include="Tests\functional\www\111_node_env">
<UniqueIdentifier>{b806867c-572b-4438-a6d4-7d24825fc492}</UniqueIdentifier>
</Filter>
<Filter Include="Tests\functional\www\112_dev_errors">
<UniqueIdentifier>{2d285139-9862-4a82-be6a-768c87f19c20}</UniqueIdentifier>
</Filter>
<Filter Include="Tests\functional\www\112_dev_errors\on">
<UniqueIdentifier>{5df8227d-9e97-4693-a70e-82e98c6bd301}</UniqueIdentifier>
</Filter>
<Filter Include="Tests\functional\www\112_dev_errors\off">
<UniqueIdentifier>{4242898e-a656-4ae5-bc35-eb202a42a304}</UniqueIdentifier>
</Filter>
</ItemGroup>
<ItemGroup>
<ClCompile Include="main.cpp">
@ -414,5 +423,20 @@
<None Include="..\..\test\functional\tests\111_node_env.js">
<Filter>Tests\functional\tests</Filter>
</None>
<None Include="..\..\test\functional\tests\112_dev_errors.js">
<Filter>Tests\functional\tests</Filter>
</None>
<None Include="..\..\test\functional\www\112_dev_errors\off\hello.js">
<Filter>Tests\functional\www\112_dev_errors\off</Filter>
</None>
<None Include="..\..\test\functional\www\112_dev_errors\off\web.config">
<Filter>Tests\functional\www\112_dev_errors\off</Filter>
</None>
<None Include="..\..\test\functional\www\112_dev_errors\on\hello.js">
<Filter>Tests\functional\www\112_dev_errors\on</Filter>
</None>
<None Include="..\..\test\functional\www\112_dev_errors\on\web.config">
<Filter>Tests\functional\www\112_dev_errors\on</Filter>
</None>
</ItemGroup>
</Project>

Просмотреть файл

@ -110,6 +110,10 @@ console.log('Application started at location ' + process.env.PORT);</pre>
number starts; appending may be useful to diagnose unorderly node process terminations or recycling
* logFileFlushInterval - interval in milliseconds for flushing logs to the log files
* devErrorsEnabled - controls how much information is sent back in the HTTP response to the browser when an error occurrs in iisnode;
when true, error conditions in iisnode result in HTTP 200 response with the body containing error details; when false,
iisnode will return generic HTTP 5xx responses
--&gt;
@ -132,6 +136,7 @@ console.log('Application started at location ' + process.env.PORT);</pre>
debuggerPathSegment="debug"
maxLogFileSizeInKB="128"
appendToExistingLog="false"
devErrorsEnabled="true"
/&gt;
&lt;!--

Просмотреть файл

@ -76,6 +76,10 @@
number starts; appending may be useful to diagnose unorderly node process terminations or recycling
* logFileFlushInterval - interval in milliseconds for flushing logs to the log files
* devErrorsEnabled - controls how much information is sent back in the HTTP response to the browser when an error occurrs in iisnode;
when true, error conditions in iisnode result in HTTP 200 response with the body containing error details; when false,
iisnode will return generic HTTP 5xx responses
-->
@ -99,6 +103,7 @@
maxLogFileSizeInKB="128"
appendToExistingLog="false"
logFileFlushInterval="5000"
devErrorsEnabled="true"
/>
<!--

Просмотреть файл

@ -0,0 +1,10 @@
/*
When devErrorsEnabled="true", iis failures are reported as HTTP 200, otherwise 5xx
*/
var iisnodeassert = require("iisnodeassert");
iisnodeassert.sequence([
iisnodeassert.get(10000, "/112_dev_errors/on/hello.js", 200),
iisnodeassert.get(10000, "/112_dev_errors/off/hello.js", 503)
]);

Просмотреть файл

@ -0,0 +1,6 @@
var http = require('http');
http.createServer(function (req, res) {
res.writeHead(200, {'Content-Type': 'text/html'});
res.end('Hello, world!');
}).listen(process.env.PORT);

Просмотреть файл

@ -0,0 +1,10 @@
<configuration>
<system.webServer>
<handlers>
<add name="iisnode" path="hello.js" verb="*" modules="iisnode" />
</handlers>
<iisnode nodeProcessCommandLine="idontexist.exe" devErrorsEnabled="false" />
</system.webServer>
</configuration>

Просмотреть файл

@ -0,0 +1,6 @@
var http = require('http');
http.createServer(function (req, res) {
res.writeHead(200, {'Content-Type': 'text/html'});
res.end('Hello, world!');
}).listen(process.env.PORT);

Просмотреть файл

@ -0,0 +1,10 @@
<configuration>
<system.webServer>
<handlers>
<add name="iisnode" path="hello.js" verb="*" modules="iisnode" />
</handlers>
<iisnode nodeProcessCommandLine="idontexist.exe" />
</system.webServer>
</configuration>