Evaldas Buinauskas Evaldas Buinauskas - 5 months ago 69
Javascript Question

iisnode not working with babel

I've got this little server, which runs fine on iisnode:

index.js



var express = require('express')

var app = express()
var port = process.env.PORT

app.get('/test/foo', function(req, res) {
res.send('HALLO WORLD')
})

app.listen(port)


However, if I want to use Babel and rewrite my application like that:

index.js



require('babel-register')
require('babel-polyfill')
require('./server')


server.js



import express from 'express'

const app = express()
const port = process.env.PORT

app.get('/test/foo', (req, res) => {
res.send('HALLO WORLD')
})

app.listen(port)


Now if I navigate to
localhost/test/foo
, I receive this error message:

Application has thrown an uncaught exception and is terminated:
Error: EEXIST: file already exists, mkdir 'C:\Windows\system32\config\systemprofile'
at Error (native)
at Object.fs.mkdirSync (fs.js:916:18)
at sync (C:\Projects\winAuthTest\node_modules\mkdirp\index.js:71:13)
at save (C:\Projects\winAuthTest\node_modules\babel-register\lib\cache.js:56:44)
at _combinedTickCallback (internal/process/next_tick.js:67:7)
at process._tickCallback (internal/process/next_tick.js:98:9)
at Function.Module.runMain (module.js:577:11)
at startup (node.js:159:18)
at node.js:444:3


That's the log from
etw.bat
:

<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="2016-06-18T18:19:06.126498500Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="3272" ThreadID="5704" ProcessorID="0" KernelTime="15" UserTime="0" />
<Channel />
<Computer />
</System>
<EventData>
<Data Name="BufferSize"> 8192</Data>
<Data Name="Version">83951626</Data>
<Data Name="ProviderVersion"> 10586</Data>
<Data Name="NumberOfProcessors"> 4</Data>
<Data Name="EndTime">131107367592610163</Data>
<Data Name="TimerResolution"> 156250</Data>
<Data Name="MaxFileSize"> 0</Data>
<Data Name="LogFileMode">0x0</Data>
<Data Name="BuffersWritten"> 5</Data>
<Data Name="StartBuffers"> 1</Data>
<Data Name="PointerSize"> 8</Data>
<Data Name="EventsLost"> 0</Data>
<Data Name="CPUSpeed"> 3392</Data>
<Data Name="LoggerName">0x9</Data>
<Data Name="LogFileName">0x6</Data>
<Data Name="BootTime">131107297904974955</Data>
<Data Name="PerfFreq">3312787</Data>
<Data Name="StartTime">131107367461264985</Data>
<Data Name="ReservedFlags">0x1</Data>
<Data Name="BuffersLost"> 0</Data>
<Data Name="SessionNameString">iisnode</Data>
<Data Name="LogFileNameString">C:\Users\buina\AppData\Local\Temp\iisnode.etl</Data>
</EventData>
<RenderingInfo Culture="lt-LT">
<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="{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="2016-06-18T18:19:09.406205500Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="10636" ProcessorID="0" KernelTime="0" UserTime="15" />
<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>5</Level>
<Task>0</Task>
<Opcode>0</Opcode>
<Keywords>0x0</Keywords>
<TimeCreated SystemTime="2016-06-18T18:19:09.406219400Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="10636" ProcessorID="0" KernelTime="0" UserTime="15" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:09.428481900Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="10636" ProcessorID="3" KernelTime="0" UserTime="15" />
<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="2016-06-18T18:19:09.428514200Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="10636" ProcessorID="3" KernelTime="0" UserTime="15" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:09.428522700Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="10636" ProcessorID="3" KernelTime="0" UserTime="15" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:09.428523300Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="10636" ProcessorID="3" KernelTime="0" UserTime="15" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:09.428523900Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="10636" ProcessorID="3" KernelTime="0" UserTime="15" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:09.679108400Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="8060" ProcessorID="2" KernelTime="0" UserTime="0" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:09.929845000Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="8060" ProcessorID="2" KernelTime="0" UserTime="0" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:10.180069400Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="8060" ProcessorID="2" KernelTime="0" UserTime="0" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:10.282203900Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="9200" ProcessorID="2" 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="2016-06-18T18:19:10.430106300Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="8060" ProcessorID="3" KernelTime="0" UserTime="0" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:10.430108100Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="8060" ProcessorID="3" KernelTime="0" UserTime="0" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:10.430355600Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="8060" ProcessorID="3" KernelTime="0" UserTime="0" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:10.430356500Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="8060" ProcessorID="3" KernelTime="0" UserTime="0" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:10.430413900Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="10636" ProcessorID="1" KernelTime="0" UserTime="15" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:10.430414800Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="10636" ProcessorID="1" KernelTime="0" UserTime="15" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:10.430415400Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="10636" ProcessorID="1" KernelTime="0" UserTime="15" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: 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="2016-06-18T18:19:10.430416000Z" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="1020" ThreadID="10636" ProcessorID="1" KernelTime="0" UserTime="15" />
<Channel />
<Computer />
</System>
<Data>{B731012E-2C0B-48E5-BDE6-D78B4C16C484}: iisnode leaves CNodeHttpModule::OnAsyncCompletion with RQ_NOTIFICATION_FINISH_REQUEST</Data>
</Event>
</Events>


The following code works fine if I run
node index.js
from command line in my application folder.

What do I have to modify in order to have my desired application, written in Babel, working on iisnode?

Answer

This appears to be a bug in iisnode and babel-register. If you compile it manually it works fine.

I've filed a bug in the meantime: https://github.com/tjanczuk/iisnode/issues/518

EDIT: Better workaround posted on issue tracker by matterker:

For development you can disable the cache with an app configuration setting in the web.config:

<configuration>
  <appSettings>
    <add key="BABEL_DISABLE_CACHE" value="true" />
  </appSettings>
  [...]
</configuration>

Additionally you can change the cache location if using babel/register in production: https://babeljs.io/docs/usage/require/#environment-variables