Your browser was unable to load all of the resources. They may have been blocked by your firewall, proxy or browser configuration.
Press Ctrl+F5 or Ctrl+Shift+R to have your browser try again.

QuickBuild

Grooy for loop hangs after first Powershell command #2809

#1
bakerb ·
I have an "Execute Script" step that has a simple "for" loop that runs a Powershell command for each loop iteration. When running the step, the first Powershell command completes (it's a file copt operation so I know that it actually worked). However after the command has run, the step is stuck and doesn't proceed to a logger.info command just after the Powershell command.

If I just log the Powershell command using logger.info, the loop proceeds to process all iterations and is successful.

I've tried using util.execute and util.readOutput, with the same results.

For debugging I also tried converting the Powershell commands to robocopy commands, and the loop processes successfully. However I need to use Powershell's "Invoke-Command" option so that the copy commands actually run on the server where the source files to be copied are located, in order to greatly reduce copying times (we're copying several gigabytes of files).

Also, when running the Powershell command directly from a command prompt on the same QB agent, it runs successfully and exits as it should.

Any ideas?
  • replies 5
  • views 2327
  • stars 0
#2
robinshen ADMIN ·
Will the step proceed if you start the agent in console mode (by running agent.bat console) from the same command line where you can run the powershell command successfully?
#3
bakerb ·
There were errors when running agent.bat:

D:\qb_sfa\bin>agent.bat console
wrapper  | --> Wrapper Started as Console
wrapper  | Java Service Wrapper Standard Edition 64-bit 3.5.12
wrapper  |   Copyright (C) 1999-2011 Tanuki Software, Ltd. All Rights Reserved.
wrapper  |     http://wrapper.tanukisoftware.com
wrapper  |   Licensed to PMEase Inc. for QuickBuild
wrapper  |
wrapper  | Launching a JVM...
jvm 1    | WrapperManager: Initializing...
jvm 1    | 2014-05-13 10:04:20,284 INFO  - Cleaning cached plugin libraries...
jvm 1    | WrapperStartStopApp:
jvm 1    | WrapperStartStopApp Error: Encountered an error running start main: java.io.IOException: Unable to delete file: D:\qb_sfa\framework\configuration\org
.eclipse.osgi\org\jvnet\winp\winp.x64.dll
jvm 1    | WrapperStartStopApp Error: java.io.IOException: Unable to delete file: D:\qb_sfa\framework\configuration\org.eclipse.osgi\org\jvnet\winp\winp.x64.dll

jvm 1    | WrapperStartStopApp Error:   at org.apache.commons.io.FileUtils.forceDelete(FileUtils.java:1390)
jvm 1    | WrapperStartStopApp Error:   at org.apache.commons.io.FileUtils.cleanDirectory(FileUtils.java:1044)
jvm 1    | WrapperStartStopApp Error:   at org.apache.commons.io.FileUtils.deleteDirectory(FileUtils.java:977)
jvm 1    | WrapperStartStopApp Error:   at org.apache.commons.io.FileUtils.forceDelete(FileUtils.java:1381)
jvm 1    | WrapperStartStopApp Error:   at org.apache.commons.io.FileUtils.cleanDirectory(FileUtils.java:1044)
jvm 1    | WrapperStartStopApp Error:   at org.apache.commons.io.FileUtils.deleteDirectory(FileUtils.java:977)
jvm 1    | WrapperStartStopApp Error:   at org.apache.commons.io.FileUtils.forceDelete(FileUtils.java:1381)
jvm 1    | WrapperStartStopApp Error:   at org.apache.commons.io.FileUtils.cleanDirectory(FileUtils.java:1044)
jvm 1    | WrapperStartStopApp Error:   at org.apache.commons.io.FileUtils.deleteDirectory(FileUtils.java:977)
jvm 1    | WrapperStartStopApp Error:   at org.apache.commons.io.FileUtils.forceDelete(FileUtils.java:1381)
jvm 1    | WrapperStartStopApp Error:   at org.apache.commons.io.FileUtils.cleanDirectory(FileUtils.java:1044)
jvm 1    | WrapperStartStopApp Error:   at com.pmease.quickbuild.bootstrap.Bootstrap.init(Bootstrap.java:216)
jvm 1    | WrapperStartStopApp Error:   at com.pmease.quickbuild.bootstrap.Bootstrap.main(Bootstrap.java:125)
jvm 1    | WrapperStartStopApp Error:   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
jvm 1    | WrapperStartStopApp Error:   at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
jvm 1    | WrapperStartStopApp Error:   at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
jvm 1    | WrapperStartStopApp Error:   at java.lang.reflect.Method.invoke(Unknown Source)
jvm 1    | WrapperStartStopApp Error:   at org.tanukisoftware.wrapper.WrapperStartStopApp.run(WrapperStartStopApp.java:264)
jvm 1    | WrapperStartStopApp Error:   at java.lang.Thread.run(Unknown Source)
wrapper  | <-- Wrapper Stopped


Although this didn't run using agent.bat, I ran the command again. Details in {braces} have been modified to not show server and user name info:

D:\qb_sfa\bin>powershell.exe -command "& {" Invoke-Command -ComputerName {source_server} -FilePath \{shared_scripts_server}\Powershell\scripts\FileCopy.ps1 -ArgumentList \{target_server}\test_folder,install,\{source_server}\test_folder}
[{source_server}] TIMESTAMP: Start: 5/13/2014 10:04:48 AM
[{source_server}] Action: install
[{source_server}] Running as: {user}
[{source_server}] Impersonating: {user2}
[{source_server}] Source: \{source_server}\test_folder
[{source_server}] Destination: \{target_server}\test_folder
[{source_server}] Performing mirror: False
[{source_server}] Performing update: False
[{source_server}] FileCopy10:04:48 job status: Running
[{source_server}] \{target_server}\test_folder folder does exist, using textbook recursion...
[{source_server}] FileCopy10:04:48 job status: Stopped (Time Taken: 00:00:02.8392364)
[{source_server}] SUCCESS: Source location "\{source_server}\test_folder" copied to \{target_server}\test_folder!
[{source_server}] TIMESTAMP: Stop: 5/13/2014 10:04:51 AM

D:\qb_sfa\bin>


Obviously this test doesn't include the looping function of the original groovy code. Can groovy code be run in the agent window (assuming I can get agent.bat to run successfully)?
#4
robinshen ADMIN ·
Have you stopped QB agent service before running "agent.bat console"? After starting agent in console mode, you may run the build again in QB to see if it works (run the build containing the groovy script step, instead of running the powershell command directly from command line).
#5
bakerb ·
Here are the results when running agent.bat:

D:\qb_sfa\bin>agent.bat console
wrapper  | --> Wrapper Started as Console
wrapper  | Java Service Wrapper Standard Edition 64-bit 3.5.12
wrapper  |   Copyright (C) 1999-2011 Tanuki Software, Ltd. All Rights Reserved.
wrapper  |     http://wrapper.tanukisoftware.com
wrapper  |   Licensed to PMEase Inc. for QuickBuild
wrapper  |
wrapper  | Launching a JVM...
jvm 1    | WrapperManager: Initializing...
jvm 1    | 2014-05-15 09:03:34,925 INFO  - Cleaning cached plugin libraries...
jvm 1    | 2014-05-15 09:03:35,024 INFO  - Cleaning temp directory...
jvm 1    | 2014-05-15 09:03:35,035 INFO  - Benchmarking...
jvm 1    | 2014-05-15 09:03:36,046 INFO  - Connecting to server 'http://ubit-sfa.intel.com:82'...
jvm 1    | 2014-05-15 09:03:36,387 INFO  - Updating framework...
jvm 1    | 2014-05-15 09:03:36,397 INFO  - Updating plugins...
jvm 1    | 2014-05-15 09:03:36,403 INFO  - Updating plugins/com.pmease.quickbuild.libs...
jvm 1    | 2014-05-15 09:03:36,405 INFO  - Updating asset...
jvm 1    | 2014-05-15 09:03:36,408 INFO  - Booting QuickBuild from 'D:\qb_sfa'...
jvm 1    | 2014-05-15 09:03:36,417 INFO  - Starting framework...
jvm 1    | 2014-05-15 09:03:36,521 INFO  - Caching plugin libraries...
jvm 1    | 2014-05-15 09:03:41,733 INFO  - Starting QuickBuild agent...
jvm 1    | 2014-05-15 09:03:41,780 INFO  - Initializing velocity...
jvm 1    | 2014-05-15 09:03:41,914 INFO  - Starting plugins...
jvm 1    | 2014-05-15 09:03:42,376 INFO  - Constructing report category for plugin: PMD Report (5.1.2)
jvm 1    | 2014-05-15 09:03:42,935 INFO  - Constructing report category for plugin: Fxcop Report (5.1.2)
jvm 1    | 2014-05-15 09:03:43,082 INFO  - Constructing report category for plugin: SCM Changes (5.1.2)
jvm 1    | 2014-05-15 09:03:43,145 INFO  - Constructing report category for plugin: Cppcheck Report (5.1.1)
jvm 1    | 2014-05-15 09:03:43,261 INFO  - Constructing report category for plugin: JUnit Report (5.1.4)
jvm 1    | 2014-05-15 09:03:43,437 INFO  - Constructing report category for plugin: MSTest report (5.1.4)
jvm 1    | 2014-05-15 09:03:43,535 INFO  - Constructing report category for plugin: EMMA Report (5.1.2)
jvm 1    | 2014-05-15 09:03:43,608 INFO  - Constructing report category for plugin: Build Statistics (5.1.3)
jvm 1    | 2014-05-15 09:03:43,620 INFO  - Constructing report category for plugin: CPD Report (5.1.2)
jvm 1    | 2014-05-15 09:03:43,635 INFO  - Constructing report category for plugin: MBUnit Report (5.1.2)
jvm 1    | 2014-05-15 09:03:43,722 INFO  - Constructing report category for plugin: NCover Report (5.1.2)
jvm 1    | 2014-05-15 09:03:43,828 INFO  - Constructing report category for plugin: TestNG Report (5.1.2)
jvm 1    | 2014-05-15 09:03:43,957 INFO  - Constructing report category for plugin: NUnit Report (5.1.2)
jvm 1    | 2014-05-15 09:03:44,031 INFO  - Constructing report category for plugin: Coverity Report (5.1.1)
jvm 1    | 2014-05-15 09:03:44,060 INFO  - Constructing report category for plugin: Jacoco Coverage (5.1.2)
jvm 1    | 2014-05-15 09:03:44,118 INFO  - Constructing report category for plugin: Cobertura Report (5.1.2)
jvm 1    | 2014-05-15 09:03:44,162 INFO  - Constructing report category for plugin: Checkstyle Report (5.1.2)
jvm 1    | 2014-05-15 09:03:44,225 INFO  - Constructing report category for plugin: Findbugs Report (5.1.2)
jvm 1    | 2014-05-15 09:03:44,345 INFO  - Constructing report category for plugin: Boost Test Integration (5.1.2)
jvm 1    | 2014-05-15 09:03:44,509 INFO  - Constructing report category for plugin: Redmine Integration (5.1.2)
jvm 1    | 2014-05-15 09:03:44,545 INFO  - Constructing report category for plugin: Trac Integration (5.1.2)
jvm 1    | 2014-05-15 09:03:44,564 INFO  - Constructing report category for plugin: CollabNet TeamForge Integration (5.1.2)
jvm 1    | 2014-05-15 09:03:44,585 INFO  - Constructing report category for plugin: Bugzilla Integration (5.1.2)
jvm 1    | 2014-05-15 09:03:44,598 INFO  - Constructing report category for plugin: Atlassian Jira Integration (5.1.2)
jvm 1    | 2014-05-15 09:03:44,613 INFO  - Constructing report category for plugin: GitHub Integration (5.1.3)
jvm 1    | 2014-05-15 09:03:45,095 INFO  - QuickBuild agent started.
jvm 1    | 2014-05-15 09:03:57,896 INFO  - Taking repository snapshots...
jvm 1    | 2014-05-15 09:13:45,082 INFO  - Removing obsolete live log entries of build: 10460


The "Taking repository snapshots..." line was added when the build was started. I let it run for 10 minutes (it was stuck in the first iteration of the loop after running the powershell command). When I stopped the build, the "Removing obsolete live log entries of build: 10460" line was added to the agent console window.
#6
robinshen ADMIN ·
That seems odd. Would it be possible that you share the script so that I run it here to test what happens?
Log in to reply