[DAEMON-190] Windows: Daemon doesn't start first time when downloading node binary

GitHub Issue	n/a
Type	Bug
Priority	High
Status	Resolved
Resolution	Fixed
Resolution Date	2017-11-27T18:21:53.000+0000
Affected Version/s	Appc Daemon 1.0.0
Fix Version/s	Appc Daemon 1.0.0
Components	appcd, appcd-nodejs
Labels	n/a
Reporter	Ewan Harris
Assignee	Ewan Harris
Created	2017-11-27T13:41:55.000+0000
Updated	2017-11-27T18:21:53.000+0000

Description

*This error should have bubbled through to the cli I think* Starting the daemon when the node binaries are not downloaded on Windows doesn't work first time, logs below. Looking at appcd-nodejs it only handles EXTBUSY which I think is unixy, windows is EBUSY

C:\Users\Archibald Thornburnt>appc appcd start --debug
Appcelerator Command-Line Interface, version 7.0.0-master.44
Copyright (c) 2014-2017, Appcelerator, Inc.  All Rights Reserved.

2017-11-27T13:32:58.805Z cli-kit:context Adding command: config
2017-11-27T13:32:58.992Z cli-kit:context Adding command: dump
2017-11-27T13:32:58.992Z cli-kit:context Adding command: exec
2017-11-27T13:32:58.992Z cli-kit:context Adding command: logcat
2017-11-27T13:32:58.992Z cli-kit:context Adding command: restart
2017-11-27T13:32:59.008Z cli-kit:context Adding command: start
2017-11-27T13:32:59.008Z cli-kit:context Adding command: status
2017-11-27T13:32:59.008Z cli-kit:context Adding command: stop
2017-11-27T13:32:59.008Z cli-kit:context Adding command: help
2017-11-27T13:32:59.008Z cli-kit:context Context Lookup:
2017-11-27T13:32:59.008Z cli-kit:context   Commands:
2017-11-27T13:32:59.008Z cli-kit:context     config => config
2017-11-27T13:32:59.008Z cli-kit:context     dump => dump
2017-11-27T13:32:59.008Z cli-kit:context     exec => exec
2017-11-27T13:32:59.008Z cli-kit:context     logcat => logcat
2017-11-27T13:32:59.008Z cli-kit:context     restart => restart
2017-11-27T13:32:59.008Z cli-kit:context     start => start
2017-11-27T13:32:59.008Z cli-kit:context     status => status
2017-11-27T13:32:59.008Z cli-kit:context     stop => stop
2017-11-27T13:32:59.008Z cli-kit:context     help => help
2017-11-27T13:32:59.008Z cli-kit:context   Options:
2017-11-27T13:32:59.008Z cli-kit:context     --config => config
2017-11-27T13:32:59.008Z cli-kit:context     --config-file => config-file
2017-11-27T13:32:59.008Z cli-kit:context     --colors => colors
2017-11-27T13:32:59.008Z cli-kit:context     --help => help
2017-11-27T13:32:59.008Z cli-kit:context     --version => version
2017-11-27T13:32:59.008Z cli-kit:context     -h => help
2017-11-27T13:32:59.008Z cli-kit:context     -v => version
2017-11-27T13:32:59.008Z cli-kit:context Parsing: [ 'start', '--debug' ]
2017-11-27T13:32:59.008Z cli-kit:context Parsing argument: start
2017-11-27T13:32:59.008Z cli-kit:context Found command: start
2017-11-27T13:32:59.008Z cli-kit:context Parsing argument: --debug
2017-11-27T13:32:59.008Z cli-kit:context Descending into next context's parser
2017-11-27T13:32:59.023Z cli-kit:context Context Lookup:
2017-11-27T13:32:59.023Z cli-kit:context   Options:
2017-11-27T13:32:59.023Z cli-kit:context     --debug => debug
2017-11-27T13:32:59.023Z cli-kit:context Parsing: [ { type: 'command',
2017-11-27T13:32:59.023Z cli-kit:context     command:
2017-11-27T13:32:59.023Z cli-kit:context      Command {
2017-11-27T13:32:59.023Z cli-kit:context        _events: Map {},
2017-11-27T13:32:59.023Z cli-kit:context        _links: [Array],
2017-11-27T13:32:59.023Z cli-kit:context        desc: 'starts the Appc Daemon if it\'s not already running',
2017-11-27T13:32:59.023Z cli-kit:context        options: [Array],
2017-11-27T13:32:59.023Z cli-kit:context        action: [AsyncFunction: action],
2017-11-27T13:32:59.023Z cli-kit:context        parent: [Object],
2017-11-27T13:32:59.023Z cli-kit:context        title: 'start',
2017-11-27T13:32:59.023Z cli-kit:context        args: [],
2017-11-27T13:32:59.023Z cli-kit:context        commands: {},
2017-11-27T13:32:59.023Z cli-kit:context        groups: [Object],
2017-11-27T13:32:59.023Z cli-kit:context        lookup: [Object],
2017-11-27T13:32:59.023Z cli-kit:context        camelCase: true,
2017-11-27T13:32:59.023Z cli-kit:context        name: 'start',
2017-11-27T13:32:59.023Z cli-kit:context        aliases: {} } },
2017-11-27T13:32:59.023Z cli-kit:context   { type: 'unknown option', orig: '--debug' } ]
2017-11-27T13:32:59.023Z cli-kit:context Parsing argument: --debug
2017-11-27T13:32:59.023Z cli-kit:context Found option: debug
2017-11-27T13:32:59.023Z cli-kit:context Negated? false
2017-11-27T13:32:59.023Z cli-kit:context Finalizing parsing
2017-11-27T13:32:59.023Z cli-kit:context Processing default options and environment variables for 2 contexts
2017-11-27T13:32:59.023Z cli-kit:context Filling argv and _
2017-11-27T13:32:59.023Z cli-kit:context Mixing in environment variable values
2017-11-27T13:32:59.039Z appcd:config Loading JavaScript config file: C:\Users\Archibald Thornburnt\.appcelerator\install\7.0.0-master.44\package\node_modules\appcd-core\conf\default.js
2017-11-27T13:32:59.117Z appcd:config Parsing AST...
2017-11-27T13:32:59.148Z appcd:config Loading JSON config file: C:\Users\Archibald Thornburnt\.appcelerator\install\7.0.0-master.44\package\node_modules\appcd-core\conf\preprod.json
2017-11-27T13:32:59.148Z appcd:common {
2017-11-27T13:32:59.148Z appcd:common   "core": {
2017-11-27T13:32:59.148Z appcd:common     "enforceNodeVersion": true,
2017-11-27T13:32:59.148Z appcd:common     "v8": {
2017-11-27T13:32:59.148Z appcd:common       "memory": "auto"
2017-11-27T13:32:59.148Z appcd:common     }
2017-11-27T13:32:59.148Z appcd:common   },
2017-11-27T13:32:59.148Z appcd:common   "home": "~/.appcelerator/appcd",
2017-11-27T13:32:59.148Z appcd:common   "network": {
2017-11-27T13:32:59.148Z appcd:common     "agentOptions": null,
2017-11-27T13:32:59.148Z appcd:common     "caFile": null,
2017-11-27T13:32:59.148Z appcd:common     "certFile": null,
2017-11-27T13:32:59.148Z appcd:common     "httpProxy": null,
2017-11-27T13:32:59.148Z appcd:common     "httpsProxy": null,
2017-11-27T13:32:59.148Z appcd:common     "keyFile": null,
2017-11-27T13:32:59.148Z appcd:common     "passphrase": null,
2017-11-27T13:32:59.148Z appcd:common     "strictSSL": true
2017-11-27T13:32:59.148Z appcd:common   },
2017-11-27T13:32:59.148Z appcd:common   "plugins": {
2017-11-27T13:32:59.148Z appcd:common     "autoReload": true,
2017-11-27T13:32:59.148Z appcd:common     "defaultInactivityTimeout": 3600000
2017-11-27T13:32:59.148Z appcd:common   },
2017-11-27T13:32:59.148Z appcd:common   "server": {
2017-11-27T13:32:59.148Z appcd:common     "agentPollInterval": 1000,
2017-11-27T13:32:59.148Z appcd:common     "daemonize": true,
2017-11-27T13:32:59.148Z appcd:common     "group": null,
2017-11-27T13:32:59.148Z appcd:common     "hostname": "127.0.0.1",
2017-11-27T13:32:59.148Z appcd:common     "pidFile": "~/.appcelerator/appcd/appcd.pid",
2017-11-27T13:32:59.148Z appcd:common     "port": 1732,
2017-11-27T13:32:59.148Z appcd:common     "user": null
2017-11-27T13:32:59.148Z appcd:common   },
2017-11-27T13:32:59.148Z appcd:common   "telemetry": {
2017-11-27T13:32:59.148Z appcd:common     "enabled": true,
2017-11-27T13:32:59.148Z appcd:common     "eventsDir": "~/.appcelerator/appcd/telemetry",
2017-11-27T13:32:59.148Z appcd:common     "sendBatchSize": 10,
2017-11-27T13:32:59.148Z appcd:common     "sendInterval": 60000,
2017-11-27T13:32:59.148Z appcd:common     "sendTimeout": 60000,
2017-11-27T13:32:59.148Z appcd:common     "url": "https://api.appcelerator.com/p/v1/app-track"
2017-11-27T13:32:59.148Z appcd:common   },
2017-11-27T13:32:59.148Z appcd:common   "appcd": {
2017-11-27T13:32:59.148Z appcd:common     "guid": "14c84daf-b01e-486c-96d3-b8f66da44481"
2017-11-27T13:32:59.148Z appcd:common   },
2017-11-27T13:32:59.148Z appcd:common   "environment": {
2017-11-27T13:32:59.148Z appcd:common     "name": "preprod",
2017-11-27T13:32:59.148Z appcd:common     "title": "Pre-production"
2017-11-27T13:32:59.148Z appcd:common   }
2017-11-27T13:32:59.148Z appcd:common }

2017-11-27T13:32:59.195Z appcd:nodejs Checking C:\Users\Archibald Thornburnt\.appcelerator\appcd\node\v8.9.1\win32\x64\node.exe
2017-11-27T13:32:59.227Z appcd:nodejs Downloading https://nodejs.org/dist/v8.9.1/node-v8.9.1-win-x64.zip => C:\Users\ARCHIB~1\AppData\Local\Temp\node-v8.9.1-win-x64.zip
2017-11-27T13:32:59.227Z appcd:dispatcher Searching for route handler: /appcd/config/network
2017-11-27T13:32:59.351Z appcd:dispatcher Route not found: /appcd/config/network
2017-11-27T13:33:00.053Z appcd:request GET https://nodejs.org/dist/v8.9.1/node-v8.9.1-win-x64.zip 200 (16.11 MB)
2017-11-27T13:33:01.819Z appcd:nodejs Downloaded 16,892,891 bytes
2017-11-27T13:33:01.819Z appcd:nodejs Creating C:\Users\Archibald Thornburnt\.appcelerator\appcd\node\v8.9.1\win32\x64
2017-11-27T13:33:01.819Z appcd:nodejs Extracting zip file: C:\Users\ARCHIB~1\AppData\Local\Temp\node-v8.9.1-win-x64.zip
2017-11-27T13:33:01.850Z appcd:nodejs Found node executable (23,089,816 bytes)
2017-11-27T13:33:02.116Z appcd:nodejs Spawning: C:\Users\Archibald Thornburnt\.appcelerator\appcd\node\v8.9.1\win32\x64\node.exe --max_old_space_size=3000 --inspect "C:\Users\Archibald Thornburnt\.appcelerator\install\7.0.0-master.44\package\node_modules\appcd-core\dist\main.js" # {"stdio":["inherit","inherit","inherit","ipc"]}

Steps to reproduce

Remove ~/.appcelerator/appcd/node

`set SNOOPLOGG=*`

`appcd start --debug`

Actual

Daemon doesnt start

Expected

Daemon should start

Comments

Ewan Harris 2017-11-27

[~cbarber] is appcd-nodejs correct in returning the error to the spawnNode call [here](https://github.com/appcelerator/appc-daemon/blob/master/packages/appcd-nodejs/src/nodejs.js#L446) rather than throwing?
Ewan Harris 2017-11-27

https://github.com/appcelerator/appc-daemon/pull/195

JSON Source