Search code examples
javascriptbabeljsiisnode

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?


Solution

  • 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