Notifications

69 views

Description

When the MID server does auto upgrade, it may fail to copy wrapper-windows-x86-64.exe, activation.jar or other files from temp to agent folder.

Wrapper logs and activities are similar to those traced below. The UPGRADE LOG section of the wrapper log is from the temporary upgrade service, and suggests Windows and/or Antivirus software is holding on to files too long, or has them locked.


<< UPGRADE LOG BEGIN >>
ERROR | wrapper | 2018/04/27 17:11:56.537 | The ServiceNow Platform Distribution Upgrade (mid-mtv-003-p) service is not installed - The specified service does not exist as an installed service. (0x424)
STATUS | wrapper | 2018/04/27 17:11:59.271 | ServiceNow Platform Distribution Upgrade (mid-mtv-003-p) service installed.
STATUS | wrapper | 2018/04/27 17:12:02.099 | Starting the ServiceNow Platform Distribution Upgrade (mid-mtv-003-p) service...
STATUS | wrapper | 2018/04/27 17:12:02.146 | --> Wrapper Started as Service
STATUS | wrapper | 2018/04/27 17:12:02.209 | Java Service Wrapper Standard Edition 64-bit 3.5.17
STATUS | wrapper | 2018/04/27 17:12:02.224 | Copyright (C) 1999-2012 Tanuki Software, Ltd. All Rights Reserved.
STATUS | wrapper | 2018/04/27 17:12:02.240 | http://wrapper.tanukisoftware.com
STATUS | wrapper | 2018/04/27 17:12:02.255 | Licensed to ServiceNow, Inc. for MID Upgrade
STATUS | wrapper | 2018/04/27 17:12:02.271 |
STATUS | wrapper | 2018/04/27 17:12:02.677 | Launching a JVM...
INFO | jvm 1 | 2018/04/27 17:12:03.035 | WrapperManager: Initializing...
INFO | jvm 1 | 2018/04/27 17:12:03.269 | Apr 27, 2018 5:12:03 PM com.snc.dist.mid_upgrade.UpgradeMain$1 start
INFO | jvm 1 | 2018/04/27 17:12:03.332 | INFO: WrapperListener.start()
INFO | jvm 1 | 2018/04/27 17:12:03.347 | Apr 27, 2018 5:12:03 PM com.snc.dist.mid_upgrade.UpgradeMain logArguments
INFO | jvm 1 | 2018/04/27 17:12:03.347 | INFO: Command-line arguments: --dist-file=C:\Windows\Temp\1524874268184-0\mid-upgrade.jakarta-05-03-2017__patch8-hotfix2-04-02-2018_04-16-2018_1426.universal.universal.zip --mode=dist-upgrade --current-dir=E:\CiscoIT\ESP\ServiceNow\MID_Server\agent
INFO | jvm 1 | 2018/04/27 17:12:03.363 | Apr 27, 2018 5:12:03 PM com.snc.dist.mid_upgrade.UpgradeMain run
INFO | jvm 1 | 2018/04/27 17:12:03.363 | INFO: MID Server upgrade v2.0 starting...
INFO | jvm 1 | 2018/04/27 17:12:03.379 | Apr 27, 2018 5:12:03 PM com.snc.dist.mid_upgrade.UpgradeMain run
INFO | jvm 1 | 2018/04/27 17:12:03.394 | INFO: Upgrading MID `E:\CiscoIT\ESP\ServiceNow\MID_Server\agent` with contents from `C:\Windows\Temp\1524874268184-0\agent`.
INFO | jvm 1 | 2018/04/27 17:12:04.769 | Apr 27, 2018 5:12:04 PM com.snc.dist.mid_upgrade.UpgradeMain missingOrCanDelete
INFO | jvm 1 | 2018/04/27 17:12:04.785 | INFO: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll cannot be deleted: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll (The process cannot access the file because it is being used by another process)
INFO | jvm 1 | 2018/04/27 17:12:04.832 | Retrying in 1000ms...
STATUS | wrapper | 2018/04/27 17:12:05.191 | ServiceNow Platform Distribution Upgrade (mid-mtv-003-p) started.
INFO | jvm 1 | 2018/04/27 17:12:05.832 | Apr 27, 2018 5:12:05 PM com.snc.dist.mid_upgrade.UpgradeMain missingOrCanDelete
INFO | jvm 1 | 2018/04/27 17:12:05.847 | INFO: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll cannot be deleted: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll (The process cannot access the file because it is being used by another process)
INFO | jvm 1 | 2018/04/27 17:12:05.879 | Retrying in 1000ms...
INFO | jvm 1 | 2018/04/27 17:12:06.754 | Apr 27, 2018 5:12:06 PM com.snc.dist.mid_upgrade.UpgradeMain missingOrCanDelete
INFO | jvm 1 | 2018/04/27 17:12:06.754 | INFO: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll cannot be deleted: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll (The process cannot access the file because it is being used by another process)
INFO | jvm 1 | 2018/04/27 17:12:06.769 | Retrying in 1000ms...
INFO | jvm 1 | 2018/04/27 17:12:07.754 | Apr 27, 2018 5:12:07 PM com.snc.dist.mid_upgrade.UpgradeMain missingOrCanDelete
INFO | jvm 1 | 2018/04/27 17:12:07.769 | INFO: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll cannot be deleted: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll (The process cannot access the file because it is being used by another process)
INFO | jvm 1 | 2018/04/27 17:12:07.816 | Retrying in 1000ms...
INFO | jvm 1 | 2018/04/27 17:12:08.816 | Apr 27, 2018 5:12:08 PM com.snc.dist.mid_upgrade.UpgradeMain missingOrCanDelete
INFO | jvm 1 | 2018/04/27 17:12:08.816 | INFO: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll cannot be deleted: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll (The process cannot access the file because it is being used by another process)
INFO | jvm 1 | 2018/04/27 17:12:08.847 | Retrying in 1000ms...
INFO | jvm 1 | 2018/04/27 17:12:09.841 | Apr 27, 2018 5:12:09 PM com.snc.dist.mid_upgrade.UpgradeMain missingOrCanDelete
INFO | jvm 1 | 2018/04/27 17:12:09.841 | INFO: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll cannot be deleted: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll (The process cannot access the file because it is being used by another process)
INFO | jvm 1 | 2018/04/27 17:12:09.873 | Retrying in 1000ms...
INFO | jvm 1 | 2018/04/27 17:12:10.873 | Apr 27, 2018 5:12:10 PM com.snc.dist.mid_upgrade.UpgradeMain missingOrCanDelete
INFO | jvm 1 | 2018/04/27 17:12:11.044 | INFO: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll cannot be deleted: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll (The process cannot access the file because it is being used by another process)
INFO | jvm 1 | 2018/04/27 17:12:11.076 | Retrying in 1000ms...
INFO | jvm 1 | 2018/04/27 17:12:11.951 | Apr 27, 2018 5:12:11 PM com.snc.dist.mid_upgrade.UpgradeMain missingOrCanDelete
INFO | jvm 1 | 2018/04/27 17:12:11.951 | INFO: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll cannot be deleted: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll (The process cannot access the file because it is being used by another process)
INFO | jvm 1 | 2018/04/27 17:12:11.966 | Retrying in 1000ms...
INFO | jvm 1 | 2018/04/27 17:12:12.951 | Apr 27, 2018 5:12:12 PM com.snc.dist.mid_upgrade.UpgradeMain missingOrCanDelete
INFO | jvm 1 | 2018/04/27 17:12:12.951 | INFO: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\lib\sigar-amd64-winnt.dll is no longer locked after 8 checks.
INFO | jvm 1 | 2018/04/27 17:12:15.154 | Apr 27, 2018 5:12:15 PM com.snc.dist.mid_upgrade.UpgradeMarker markService
INFO | jvm 1 | 2018/04/27 17:12:15.154 | INFO: Added service `snc-platform-dist-upgrade-mid-mtv-003-p` to upgrade marker file.
INFO | jvm 1 | 2018/04/27 17:12:18.560 | Apr 27, 2018 5:12:18 PM com.snc.dist.mid_upgrade.UpgradeMain migrateToTarget
INFO | jvm 1 | 2018/04/27 17:12:18.560 | INFO: Copying files to MID server installation path.
INFO | jvm 1 | 2018/04/27 17:12:19.232 | Apr 27, 2018 5:12:19 PM com.snc.dist.mid_upgrade.UpgradeMain run
INFO | jvm 1 | 2018/04/27 17:12:19.232 | SEVERE: com.snc.dist.mid_upgrade.UpgradeException: java.io.FileNotFoundException: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\bin\wrapper-windows-x86-64.exe (Access is denied)
INFO | jvm 1 | 2018/04/27 17:12:19.248 | com.snc.dist.mid_upgrade.UpgradeException: java.io.FileNotFoundException: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\bin\wrapper-windows-x86-64.exe (Access is denied)
INFO | jvm 1 | 2018/04/27 17:12:19.263 | at com.snc.dist.mid_upgrade.UpgradeMain.migrateToTarget(UpgradeMain.java:810)
INFO | jvm 1 | 2018/04/27 17:12:19.263 | at com.snc.dist.mid_upgrade.UpgradeMain.run(UpgradeMain.java:311)
INFO | jvm 1 | 2018/04/27 17:12:19.263 | at java.lang.Thread.run(Thread.java:745)
INFO | jvm 1 | 2018/04/27 17:12:19.279 | Caused by: java.io.FileNotFoundException: E:\CiscoIT\ESP\ServiceNow\MID_Server\agent\bin\wrapper-windows-x86-64.exe (Access is denied)
INFO | jvm 1 | 2018/04/27 17:12:19.279 | at java.io.FileOutputStream.open0(Native Method)
INFO | jvm 1 | 2018/04/27 17:12:19.279 | at java.io.FileOutputStream.open(FileOutputStream.java:270)
INFO | jvm 1 | 2018/04/27 17:12:19.294 | at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
INFO | jvm 1 | 2018/04/27 17:12:19.294 | at java.io.FileOutputStream.<init>(FileOutputStream.java:162)
INFO | jvm 1 | 2018/04/27 17:12:19.294 | at org.apache.commons.io.FileUtils.doCopyFile(FileUtils.java:936)
INFO | jvm 1 | 2018/04/27 17:12:19.310 | at org.apache.commons.io.FileUtils.doCopyDirectory(FileUtils.java:1225)
INFO | jvm 1 | 2018/04/27 17:12:19.310 | at org.apache.commons.io.FileUtils.doCopyDirectory(FileUtils.java:1223)
INFO | jvm 1 | 2018/04/27 17:12:19.310 | at org.apache.commons.io.FileUtils.copyDirectory(FileUtils.java:1186)
INFO | jvm 1 | 2018/04/27 17:12:19.310 | at org.apache.commons.io.FileUtils.copyDirectory(FileUtils.java:1107)
INFO | jvm 1 | 2018/04/27 17:12:19.326 | at com.snc.dist.mid_upgrade.UpgradeMain.migrateToTarget(UpgradeMain.java:807)
INFO | jvm 1 | 2018/04/27 17:12:19.326 | ... 2 more
INFO | jvm 1 | 2018/04/27 17:12:19.326 |
INFO | jvm 1 | 2018/04/27 17:12:19.326 | Apr 27, 2018 5:12:19 PM com.snc.dist.mid_upgrade.UpgradeMain appendMidLogs
INFO | jvm 1 | 2018/04/27 17:12:19.341 | INFO: Flushing logs

Steps to Reproduce

  1. The issue occurs intermittently. The logs above has been observed on Windows Server 2012 R2, with McAfee antivirus running.
  2. Configure the MID server to auto upgrade.
  3. Check the 'Application Experience' is enabled for the MID server auto upgrade to work.
  4. Check if he MID server service comes back up.
  5. Inspect the MID agent logs and wrapper logs.

Workaround

This problem is under review and targeted as a future product enhancement. As a workaround you will need to manually upgrade the MID server applying the configuration below:

  1. Ensure the Windows 'Application Experience' is enabled and the Windows machine has been restarted after the change.
  2. Run the MID server service with an account with local administration privileges.
  3. Install the MID server at the top of the file system tree, for example C:\ServiceNow.
  4. The MID will instead run as local admin, therefore will not be able to remove files. 
  5. Update the account.
  6. Restart the MID server.
  7. Verify the upgrade completed successfully.


Related Problem: PRB1279578

Seen In

There is no data to report.

Associated Community Threads

There is no data to report.

Article Information

Last Updated:2019-01-17 15:09:34
Published:2019-01-17