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

Long delay between steps #2429

#1
amn ·
There is a 2 and a half minute delay here. It is while one step is checked its execute condition, but all that is checking is to see if all previous steps were successful and if a variable is empty or null.

groovy: vars.getValue("dbName") != null && !vars.getValue("dbName").isEmpty()


08:00:38,594 [master>Sequential Across Hosts?currentNodeAddress=host>Activate Symlinks@host:8811] INFO - Executing post-execute action...
08:00:38,672 [master>Sequential Across Hosts?currentNodeAddress=host>Apply Database Changes@host:8811] INFO - Checking step execute condition...
08:03:01,312 [master>Sequential Across Hosts?currentNodeAddress=host>Apply Database Changes@host:8811] INFO - Step execute condition not satisfied, step will be skipped.

This time lines up with the log below on the host that looks to be trying to gather some sort of information about the host.

2013-08-02 08:02:12,023 [MeasurementPollingTask] WARN  com.pmease.quickbuild.plugin.measurement.core.sysinfo.NativeSystemInfo - Failed gathering file system usage for mount point [/nfsmounts/sq]
    org.hyperic.sigar.NfsUnreachableException: devnas7-517.dev.oclc.org:/sq nfs server unreachable
        at org.hyperic.sigar.NfsFileSystem.getUnreachableException(NfsFileSystem.java:64)
        at org.hyperic.sigar.Sigar.getMountedFileSystemUsage(Sigar.java:710)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at com.pmease.quickbuild.plugin.measurement.core.sysinfo.SigarAccess$SigarAccessHandler.invoke(SigarAccess.java:88)
        at $Proxy29.getMountedFileSystemUsage(Unknown Source)
        at com.pmease.quickbuild.plugin.measurement.core.sysinfo.NativeSystemInfo.getFileSystem(NativeSystemInfo.java:191)
        at com.pmease.quickbuild.plugin.measurement.core.sysinfo.NativeSystemInfo.getFileSystems(NativeSystemInfo.java:160)
        at com.pmease.quickbuild.plugin.measurement.core.supplier.DiskMetricsSupplier.<init>(DiskMetricsSupplier.java:33)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:525)
        at com.google.inject.internal.DefaultConstructionProxyFactory$2.newInstance(DefaultConstructionProxyFactory.java:85)
        at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:85)
        at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:254)
        at com.google.inject.internal.FactoryProxy.get(FactoryProxy.java:54)
        at com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:46)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
        at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)
        at com.google.inject.Scopes$1$1.get(Scopes.java:65)
        at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
        at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
        at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
        at com.google.inject.multibindings.Multibinder$RealMultibinder.get(Multibinder.java:326)
        at com.google.inject.multibindings.Multibinder$RealMultibinder.get(Multibinder.java:220)
        at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
        at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1024)
        at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
        at com.google.inject.internal.InjectorImpl.getInstance(InjectorImpl.java:1009)
        at com.pmease.quickbuild.plugin.measurement.core.supplier.MeasurementSuppliers.getAllSuppliers(MeasurementSuppliers.java:15)
        at com.pmease.quickbuild.plugin.measurement.core.poller.MeasurementPollingTask.collectMetrics(MeasurementPollingTask.java:74)
        at com.pmease.quickbuild.plugin.measurement.core.poller.MeasurementPollingTask.execute(MeasurementPollingTask.java:56)
        at com.pmease.quickbuild.plugin.measurement.core.poller.MeasurementPollingTask.run(MeasurementPollingTask.java:108)
        at com.google.common.util.concurrent.AbstractExecutionThreadService$1$1.run(AbstractExecutionThreadService.java:52)
        at java.lang.Thread.run(Thread.java:722)
2013-08-02 08:02:12,047 [MeasurementPollingTask] WARN  com.pmease.quickbuild.plugin.measurement.core.sysinfo.NativeSystemInfo - Failed gathering file system usage for mount point [/nfsmounts/nasinfo6]
    org.hyperic.sigar.NfsUnreachableException: devnas6-517.dev.oclc.org:/nasinfo6 nfs server unreachable
        at org.hyperic.sigar.NfsFileSystem.getUnreachableException(NfsFileSystem.java:64)
        at org.hyperic.sigar.Sigar.getMountedFileSystemUsage(Sigar.java:710)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at com.pmease.quickbuild.plugin.measurement.core.sysinfo.SigarAccess$SigarAccessHandler.invoke(SigarAccess.java:88)
        at $Proxy29.getMountedFileSystemUsage(Unknown Source)
        at com.pmease.quickbuild.plugin.measurement.core.sysinfo.NativeSystemInfo.getFileSystem(NativeSystemInfo.java:191)
        at com.pmease.quickbuild.plugin.measurement.core.sysinfo.NativeSystemInfo.getFileSystems(NativeSystemInfo.java:160)
        at com.pmease.quickbuild.plugin.measurement.core.supplier.DiskMetricsSupplier.<init>(DiskMetricsSupplier.java:33)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:525)
        at com.google.inject.internal.DefaultConstructionProxyFactory$2.newInstance(DefaultConstructionProxyFactory.java:85)
        at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:85)
        at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:254)
        at com.google.inject.internal.FactoryProxy.get(FactoryProxy.java:54)
        at com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:46)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
        at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)
        at com.google.inject.Scopes$1$1.get(Scopes.java:65)
        at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
        at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
        at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
        at com.google.inject.multibindings.Multibinder$RealMultibinder.get(Multibinder.java:326)
        at com.google.inject.multibindings.Multibinder$RealMultibinder.get(Multibinder.java:220)
        at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
        at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1024)
        at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
        at com.google.inject.internal.InjectorImpl.getInstance(InjectorImpl.java:1009)
        at com.pmease.quickbuild.plugin.measurement.core.supplier.MeasurementSuppliers.getAllSuppliers(MeasurementSuppliers.java:15)
        at com.pmease.quickbuild.plugin.measurement.core.poller.MeasurementPollingTask.collectMetrics(MeasurementPollingTask.java:74)
        at com.pmease.quickbuild.plugin.measurement.core.poller.MeasurementPollingTask.execute(MeasurementPollingTask.java:56)
        at com.pmease.quickbuild.plugin.measurement.core.poller.MeasurementPollingTask.run(MeasurementPollingTask.java:108)
        at com.google.common.util.concurrent.AbstractExecutionThreadService$1$1.run(AbstractExecutionThreadService.java:52)
        at java.lang.Thread.run(Thread.java:722)
2013-08-02 08:02:12,081 [MeasurementPollingTask] WARN  com.pmease.quickbuild.plugin.measurement.core.sysinfo.NativeSystemInfo - Failed gathering file system usage for mount point [/nfsmounts/nasinfo7]
    org.hyperic.sigar.NfsUnreachableException: devnas7-517.dev.oclc.org:/nasinfo7 nfs server unreachable
        at org.hyperic.sigar.NfsFileSystem.getUnreachableException(NfsFileSystem.java:64)
        at org.hyperic.sigar.Sigar.getMountedFileSystemUsage(Sigar.java:710)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at com.pmease.quickbuild.plugin.measurement.core.sysinfo.SigarAccess$SigarAccessHandler.invoke(SigarAccess.java:88)
        at $Proxy29.getMountedFileSystemUsage(Unknown Source)
        at com.pmease.quickbuild.plugin.measurement.core.sysinfo.NativeSystemInfo.getFileSystem(NativeSystemInfo.java:191)
        at com.pmease.quickbuild.plugin.measurement.core.sysinfo.NativeSystemInfo.getFileSystems(NativeSystemInfo.java:160)
        at com.pmease.quickbuild.plugin.measurement.core.supplier.DiskMetricsSupplier.<init>(DiskMetricsSupplier.java:33)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:525)
        at com.google.inject.internal.DefaultConstructionProxyFactory$2.newInstance(DefaultConstructionProxyFactory.java:85)
        at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:85)
        at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:254)
        at com.google.inject.internal.FactoryProxy.get(FactoryProxy.java:54)
        at com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:46)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
        at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)
        at com.google.inject.Scopes$1$1.get(Scopes.java:65)
        at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
        at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
        at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
        at com.google.inject.multibindings.Multibinder$RealMultibinder.get(Multibinder.java:326)
        at com.google.inject.multibindings.Multibinder$RealMultibinder.get(Multibinder.java:220)
        at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
        at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1024)
        at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
        at com.google.inject.internal.InjectorImpl.getInstance(InjectorImpl.java:1009)
        at com.pmease.quickbuild.plugin.measurement.core.supplier.MeasurementSuppliers.getAllSuppliers(MeasurementSuppliers.java:15)
        at com.pmease.quickbuild.plugin.measurement.core.poller.MeasurementPollingTask.collectMetrics(MeasurementPollingTask.java:74)
        at com.pmease.quickbuild.plugin.measurement.core.poller.MeasurementPollingTask.execute(MeasurementPollingTask.java:56)
        at com.pmease.quickbuild.plugin.measurement.core.poller.MeasurementPollingTask.run(MeasurementPollingTask.java:108)
        at com.google.common.util.concurrent.AbstractExecutionThreadService$1$1.run(AbstractExecutionThreadService.java:52)
        at java.lang.Thread.run(Thread.java:722)
  • replies 8
  • views 2836
  • stars 0
#2
robinshen ADMIN ·
How is variable "dbName" defined?
#3
amn ·
The variable dbName's value is 
${groovy:vars.getValue(configuration.getName() + '_dbName')}
#4
robinshen ADMIN ·
Then how is variable value of "configuration.getName() + '_dbName' being defined? QB will evaluate it recursively until it resolves to an actual text value. The only reason I can think of is that evaluating variable takes considerable of time.
#5
amn ·
I'm not sure what you mean by how that is being defined. All the variable is doing is using QuickBuild syntax to get the name of its configuration and then appending _dbName to it.

So if I'm running root > project1 > test, then it would be test_dbName.
#6
robinshen ADMIN ·
Sorry for not being clear. If you are running root > project1 > test, you are actually accessing value of variable "test_dbName", and what I mean is that how variable "test_dbName" is defined in variables section. If its value contains script which take some time to run, QB will be slow on calling vars.getValue("test_dbName")
#7
amn ·
Sorry, this has moved off topic a little. I'm trying to focus on if the initial error messages could have affected performance of this at all, and what those messages are. They seem to be new with our recent upgrade from version 5.0.13 to 5.0.31.
#8
robinshen ADMIN ·
No the initial message will not affect the performance, and it means that QB can not collect file system usage for that mount point for some reason. And the only possible reason for this delay is for variable resolving, and this is why I am checking how relevant variables are defined.
#9
amn ·
The variable is resolved and then it uses the groovy config slurper to parse a file in our Maven repository so something must have been slow at that time. The issue was brought to our attention because it seemed to be tied with QB trying to collect file system usage which we had not seen before.
Log in to reply