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

node-js 10.0.0 msi installer ended prematurely #20538

Closed
laundmo opened this issue May 5, 2018 · 19 comments
Closed

node-js 10.0.0 msi installer ended prematurely #20538

laundmo opened this issue May 5, 2018 · 19 comments

Comments

@laundmo
Copy link

laundmo commented May 5, 2018

  • Version: 10.0.0-x64
  • Platform: windows 10 pro 64bit
  • Subsystem: installer

when trying to install node.js from the msi installer i get the message that the installer ended prematurely. there are no other error messages popping up.

log is larger than 10mb, so here is the link: https://drive.google.com/open?id=1Arvb4nSp6w3I5Bfs9nfrsR28y1iMrU3M

@bzoz
Copy link
Contributor

bzoz commented May 7, 2018

/cc @nodejs/platform-windows

@tniessen
Copy link
Member

tniessen commented May 7, 2018

Extract from log:

MSI (s) (D4:5C) [11:49:44:838]: MainEngineThread is returning 1603
MSI (s) (D4:0C) [11:49:44:841]: RESTART MANAGER: Session closed.
MSI (s) (D4:0C) [11:49:44:844]: User policy value 'DisableRollback' is 0
MSI (s) (D4:0C) [11:49:44:844]: Machine policy value 'DisableRollback' is 0
MSI (s) (D4:0C) [11:49:44:844]: Incrementing counter to disable shutdown. Counter after increment: 0
MSI (s) (D4:0C) [11:49:44:844]: Note: 1: 1402 2: HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Installer\Rollback\Scripts 3: 2 
MSI (s) (D4:0C) [11:49:44:846]: Note: 1: 1402 2: HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Installer\Rollback\Scripts 3: 2 
MSI (s) (D4:0C) [11:49:44:846]: Decrementing counter to disable shutdown. If counter >= 0, shutdown will be denied.  Counter after decrement: -1
MSI (s) (D4:0C) [11:49:44:847]: Destroying RemoteAPI object.
MSI (s) (D4:00) [11:49:44:847]: Custom Action Manager thread ending.
MSI (c) (A8:14) [11:49:44:850]: Back from server. Return value: 1603
MSI (c) (A8:14) [11:49:44:850]: Decrementing counter to disable shutdown. If counter >= 0, shutdown will be denied.  Counter after decrement: -1
MSI (c) (A8:14) [11:49:44:850]: PROPERTY CHANGE: Deleting SECONDSEQUENCE property. Its current value is '1'.
Action ended 11:49:44: ExecuteAction. Return value 3.
MSI (c) (A8:14) [11:49:44:850]: Doing action: FatalError
Action 11:49:44: FatalError. 
Action start 11:49:44: FatalError.
Action 11:49:44: FatalError. Dialog created
Action ended 11:49:46: FatalError. Return value 2.
Action ended 11:49:46: INSTALL. Return value 3.
MSI (c) (A8:14) [11:49:46:556]: Destroying RemoteAPI object.
MSI (c) (A8:F0) [11:49:46:556]: Custom Action Manager thread ending.

Similar problems have been reported in the past, please have a look at this (incomplete) list.

@tniessen
Copy link
Member

tniessen commented May 7, 2018

It might be performance counters once again:

Action 11:49:33: RollbackRegisterPerfmonManifest. 
MSI (s) (D4:5C) [11:49:33:253]: Executing op: CustomActionSchedule(Action=RollbackRegisterPerfmonManifest,ActionType=3393,Source=BinaryData,Target=CAQuietExec,CustomActionData="unlodctr.exe" /m:"C:\Program Files\nodejs\node_perfctr_provider.man")
MSI (s) (D4:5C) [11:49:33:255]: Executing op: ActionStart(Name=RegisterPerfmonManifest,,)
Action 11:49:33: RegisterPerfmonManifest. 
MSI (s) (D4:5C) [11:49:33:256]: Executing op: CustomActionSchedule(Action=RegisterPerfmonManifest,ActionType=3073,Source=BinaryData,Target=CAQuietExec,CustomActionData="lodctr.exe" /m:"C:\Program Files\nodejs\node_perfctr_provider.man" "C:\Program Files\nodejs")
MSI (s) (D4:58) [11:49:33:259]: Invoking remote custom action. DLL: C:\WINDOWS\Installer\MSI30D6.tmp, Entrypoint: CAQuietExec
MSI (s) (D4:00) [11:49:33:259]: Generating random cookie.
MSI (s) (D4:00) [11:49:33:266]: Created Custom Action Server with PID 6600 (0x19C8).
MSI (s) (D4:0C) [11:49:33:336]: Running as a service.
MSI (s) (D4:0C) [11:49:33:339]: Hello, I'm your 32bit Elevated Non-remapped custom action server.
CAQuietExec:  
MSI (s) (D4:5C) [11:49:33:420]: Executing op: ActionStart(Name=ExecXmlFile,,)
Action 11:49:33: ExecXmlFile. 
MSI (s) (D4:5C) [11:49:33:421]: Executing op: CustomActionSchedule(Action=ExecXmlFile,ActionType=11265,Source=BinaryData,Target=**********,CustomActionData=**********)
MSI (s) (D4:38) [11:49:33:426]: Invoking remote custom action. DLL: C:\WINDOWS\Installer\MSI3183.tmp, Entrypoint: ExecXmlFile
MSI (s) (D4:5C) [11:49:33:454]: Executing op: ActionStart(Name=RollbackRegisterEventManifest,,)
Action 11:49:33: RollbackRegisterEventManifest. 
MSI (s) (D4:5C) [11:49:33:455]: Executing op: CustomActionSchedule(Action=RollbackRegisterEventManifest,ActionType=3393,Source=BinaryData,Target=CAQuietExec,CustomActionData="wevtutil.exe" um "C:\Program Files\nodejs\node_etw_provider.man")
MSI (s) (D4:5C) [11:49:33:457]: Executing op: ActionStart(Name=RegisterEventManifest,,)
Action 11:49:33: RegisterEventManifest. 
MSI (s) (D4:5C) [11:49:33:458]: Executing op: CustomActionSchedule(Action=RegisterEventManifest,ActionType=3073,Source=BinaryData,Target=CAQuietExec,CustomActionData="wevtutil.exe" im "C:\Program Files\nodejs\node_etw_provider.man")
MSI (s) (D4:54) [11:49:33:462]: Invoking remote custom action. DLL: C:\WINDOWS\Installer\MSI31A3.tmp, Entrypoint: CAQuietExec
CAQuietExec:  Error 0xc0000409: Command line returned an error.
CAQuietExec:  Error 0xc0000409: QuietExec Failed
CAQuietExec:  Error 0xc0000409: Failed in ExecCommon method
CustomAction RegisterEventManifest returned actual error code 1603 (note this may not be 100% accurate if translation happened inside sandbox)
Action ended 11:49:35: InstallFinalize. Return value 3.
MSI (s) (D4:5C) [11:49:35:079]: Note: 1: 2265 2:  3: -2147287035 
MSI (s) (D4:5C) [11:49:35:079]: User policy value 'DisableRollback' is 0
MSI (s) (D4:5C) [11:49:35:079]: Machine policy value 'DisableRollback' is 0
MSI (s) (D4:5C) [11:49:35:102]: Executing op: Header(Signature=1397708873,Version=500,Timestamp=1285905962,LangId=1033,Platform=589824,ScriptType=2,ScriptMajorVersion=21,ScriptMinorVersion=4,ScriptAttributes=1)
MSI (s) (D4:5C) [11:49:35:102]: Executing op: DialogInfo(Type=0,Argument=1033)
MSI (s) (D4:5C) [11:49:35:103]: Executing op: DialogInfo(Type=1,Argument=Node.js)
MSI (s) (D4:5C) [11:49:35:103]: Executing op: RollbackInfo(,RollbackAction=Rollback,RollbackDescription=Rolling back action:,RollbackTemplate=[1],CleanupAction=RollbackCleanup,CleanupDescription=Removing backup files,CleanupTemplate=File: [1])
Action 11:49:35: Rollback. Rolling back action:
Rollback: RegisterEventManifest
MSI (s) (D4:5C) [11:49:35:105]: Executing op: ActionStart(Name=RegisterEventManifest,,)
MSI (s) (D4:5C) [11:49:35:105]: Executing op: ProductInfo(ProductKey={4B86B960-B8C2-443F-B8FD-915C0F27BFA7},ProductName=Node.js,PackageName=node-v10.0.0-x64.msi,Language=1033,Version=167772160,Assignment=1,ObsoleteArg=0,ProductIcon=NodeIcon,,PackageCode={BBBA006C-B8A3-4A82-B60F-5B0930124E0F},,,InstanceType=0,LUASetting=0,RemoteURTInstalls=0,ProductDeploymentFlags=2)
Rollback: RollbackRegisterEventManifest
MSI (s) (D4:5C) [11:49:35:105]: Executing op: ActionStart(Name=RollbackRegisterEventManifest,,)
MSI (s) (D4:5C) [11:49:35:106]: Executing op: CustomActionRollback(Action=RollbackRegisterEventManifest,ActionType=3393,Source=BinaryData,Target=CAQuietExec,CustomActionData="wevtutil.exe" um "C:\Program Files\nodejs\node_etw_provider.man")
MSI (s) (D4:20) [11:49:35:109]: Invoking remote custom action. DLL: C:\WINDOWS\Installer\MSI381C.tmp, Entrypoint: CAQuietExec
CAQuietExec:  Error 0xc0000409: Command line returned an error.
CAQuietExec:  Error 0xc0000409: QuietExec Failed
CAQuietExec:  Error 0xc0000409: Failed in ExecCommon method
CustomAction RollbackRegisterEventManifest returned actual error code 1603 but will be translated to success due to continue marking
Rollback: ExecXmlFile
MSI (s) (D4:5C) [11:49:36:634]: Executing op: ActionStart(Name=ExecXmlFile,,)
Rollback: RegisterPerfmonManifest
MSI (s) (D4:5C) [11:49:36:634]: Executing op: ActionStart(Name=RegisterPerfmonManifest,,)
Rollback: RollbackRegisterPerfmonManifest
MSI (s) (D4:5C) [11:49:36:635]: Executing op: ActionStart(Name=RollbackRegisterPerfmonManifest,,)
MSI (s) (D4:5C) [11:49:36:635]: Executing op: CustomActionRollback(Action=RollbackRegisterPerfmonManifest,ActionType=3393,Source=BinaryData,Target=CAQuietExec,CustomActionData="unlodctr.exe" /m:"C:\Program Files\nodejs\node_perfctr_provider.man")
MSI (s) (D4:30) [11:49:36:639]: Invoking remote custom action. DLL: C:\WINDOWS\Installer\MSI3E09.tmp, Entrypoint: CAQuietExec
CAQuietExec:  
Rollback: Copying new files

See issues such as #4329, please try installing with performance counters disabled if you can.

@tniessen
Copy link
Member

@laundmo Did you solve the problem?

@laundmo
Copy link
Author

laundmo commented May 13, 2018

im sorry @tniessen , i forgot about this whole thing. i tried installing without performance counters but it didnt seem to change anything, still rolling back at the end.

log: https://drive.google.com/file/d/1vk0hEVYnCHJ_cK1BoCPva_RGzHvwE2KP/view?usp=sharing

@wesleytabaka
Copy link

Same issue on Windows 10 x64 version 1803 trying to install Node 8.11.1.

Turned off "Performance counters" and "Event tracing (ETW)" under Node.js runtime during the install and it installed successfully.

@tniessen
Copy link
Member

Still seems to be related to ETW:

MSI (s) (0C:B4) [21:38:41:735]: Executing op: CustomActionSchedule(Action=ExecXmlFile,ActionType=11265,Source=BinaryData,Target=**********,CustomActionData=**********)
MSI (s) (0C:80) [21:38:41:739]: Invoking remote custom action. DLL: C:\WINDOWS\Installer\MSI7D2A.tmp, Entrypoint: ExecXmlFile
MSI (s) (0C:34) [21:38:41:740]: Generating random cookie.
MSI (s) (0C:34) [21:38:41:747]: Created Custom Action Server with PID 15064 (0x3AD8).
MSI (s) (0C:F8) [21:38:41:822]: Running as a service.
MSI (s) (0C:F8) [21:38:41:825]: Hello, I'm your 32bit Elevated Non-remapped custom action server.
MSI (s) (0C:B4) [21:38:41:865]: Executing op: ActionStart(Name=RollbackRegisterEventManifest,,)
Action 21:38:41: RollbackRegisterEventManifest. 
MSI (s) (0C:B4) [21:38:41:866]: Executing op: CustomActionSchedule(Action=RollbackRegisterEventManifest,ActionType=3393,Source=BinaryData,Target=CAQuietExec,CustomActionData="wevtutil.exe" um "C:\Program Files\nodejs\node_etw_provider.man")
MSI (s) (0C:B4) [21:38:41:868]: Executing op: ActionStart(Name=RegisterEventManifest,,)
Action 21:38:41: RegisterEventManifest. 
MSI (s) (0C:B4) [21:38:41:869]: Executing op: CustomActionSchedule(Action=RegisterEventManifest,ActionType=3073,Source=BinaryData,Target=CAQuietExec,CustomActionData="wevtutil.exe" im "C:\Program Files\nodejs\node_etw_provider.man")
MSI (s) (0C:F0) [21:38:41:874]: Invoking remote custom action. DLL: C:\WINDOWS\Installer\MSI7DB8.tmp, Entrypoint: CAQuietExec
CAQuietExec:  Error 0xc0000409: Command line returned an error.
CAQuietExec:  Error 0xc0000409: QuietExec Failed
CAQuietExec:  Error 0xc0000409: Failed in ExecCommon method
CustomAction RegisterEventManifest returned actual error code 1603 (note this may not be 100% accurate if translation happened inside sandbox)
Action ended 21:38:43: InstallFinalize. Return value 3.

Please try disabling event tracing as well. Thanks for the hint, @wesleytabaka.

@laundmo
Copy link
Author

laundmo commented May 15, 2018

@tniessen i tried disabling ETW and it worked. thank you.

because the problem still exists, i would like to ask to keep this issue open.

@jorrit
Copy link

jorrit commented May 24, 2018

According to #4329 (comment) (and my own experience) antivirus (Avast) may be the culprit.

@techinvoker
Copy link

Avast antivirus ended up being my issue with this

@tniessen
Copy link
Member

@laundmo Can you confirm this issue was related to Avast / other antivirus software?

@laundmo
Copy link
Author

laundmo commented May 27, 2018

installing without ETW and Performance Counters worked.

using the installer to the ETW and Performance Counter modules with Avast deactivated worked

seems like avast is the problem

@vsemozhetbyt
Copy link
Contributor

As this issue emerges rather often, should we add some note/FAQ/etc somewhere about the Avast impact and maybe reach out to the Avast developers? cc @nodejs/platform-windows

@tniessen
Copy link
Member

@vsemozhetbyt I already reached out to Avast, let's see whether they respond.

@JamesShaver
Copy link

Ahh, finally! Same 1603 error here. Stopped Avast for 10 minutes, and the install worked fine - Performance counter and ETW both enabled.

@tniessen
Copy link
Member

Response from Avast:

Hi Tobias, Thanks for your report - I was able to induce it and submitted bug CCS-5598 to our developers for further investigation.

Regards,

Jan

@Osiris1975
Copy link

I can also confirm that Avast was the problem on my machine as well.

@kittycatbytes
Copy link

This is a few months old, but for anybody else visiting here who doesn't have Avast, the issue for me was resolved by rebooting my machine.

@apapirovski
Copy link
Member

Given the lack of a follow up and all the reports about Avast, I'm going to close this out. Doesn't seem like there's much actionable here.

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